Андрей Костенко

Простейший трейс включается переменной окружения DBIC_TRACE=1. Сейчас каждый запрос будет выводиться на STDERR перед выполнением.

Но что, если нам его недостаточно? Посмотрим, что нам даёт DBIx::Class. А даёт он нам класс DBIx::Class::Storage::Statistics.
Методы этого класса вызываются до и после каждого запроса, либо транзакции.

Попробуем после каждого запроса выводить время, которое он исполнялся. Это описано в DBIx::Class::Manual::Cookbook.

Добавляем схему:

  __PACKAGE__->storage->debugobj(new My::Profiler());
  __PACKAGE__->storage->debug(1);

И создаём модуль:

  package My::Profiler;
  use strict;
 
  use base 'DBIx::Class::Storage::Statistics';
 
  use Time::HiRes qw(time);
 
  my $start;
 
  sub query_start {
    my $self = shift();
    my $sql = shift();
    my $params = @_;
 
    $self->print("Executing $sql: ".join(', ', @params)."\n");
    $start = time();
  }
 
  sub query_end {
    my $self = shift();
    my $sql = shift();
    my @params = @_;
 
    my $elapsed = sprintf("%0.4f", time() - $start);
    $self->print("Execution took $elapsed seconds.\n");
    $start = undef;
  }
 
  1;

Отлично. Сейчас после каждого запроса пишется время выполнения. Если мы в My::Profile::print мы заменим print на carp, то после каждого SQL-запроса мы получим место его выполнения.

Но время выполнения запроса – это средняя температура по больнице, потому что может быть много быстрых запросов. Хотелось бы получить более красивую статистику. И она есть – DBIx::Class::QueryLog

Этот модуль сохраняет статистику по каждому выполненному запросу, группирует одинаковые запросы и сортирует по суммарному времени выполнения. Как им пользоваться – написано в документации. Свою задачу – ткнуть Вас носом в интересную фичу DBIx::Class – я выполнил.
Удачной Вам разработки.