t/storage/debug.t

   1 use strict;
   2 use warnings;
   3 no warnings 'once';
   4
   5 use Test::More;
   6 use Test::Exception;
   7 use Try::Tiny;
   8 use lib qw(t/lib);
   9 use DBICTest;
  10 use Path::Class qw/file/;
  11
  12 BEGIN { delete @ENV{qw(DBIC_TRACE DBIC_TRACE_PROFILE DBICTEST_SQLITE_USE_FILE)} }
  13
  14 my $schema = DBICTest->init_schema();
  15
  16 my $lfn = file("t/var/sql-$$.log");
  17 unlink $lfn or die $!
  18   if -e $lfn;
  19
  20 # make sure we are testing the vanilla debugger and not ::PrettyPrint
  21 require DBIx::Class::Storage::Statistics;
  22 $schema->storage->debugobj(DBIx::Class::Storage::Statistics->new);
  23
  24 ok ( $schema->storage->debug(1), 'debug' );
  25 $schema->storage->debugfh($lfn->openw);
  26 $schema->resultset('CD')->count;
  27
  28 my @loglines = $lfn->slurp;
  29 is (@loglines, 1, 'one line of log');
  30 like($loglines[0], qr/^SELECT COUNT/, 'File log via debugfh success');
  31
  32 $schema->storage->debugfh(undef);
  33
  34 {
  35   local $ENV{DBIC_TRACE} = "=$lfn";
  36   unlink $lfn;
  37
  38   $schema->resultset('CD')->count;
  39
  40   my $schema2 = DBICTest->init_schema(no_deploy => 1);
  41   $schema2->storage->_do_query('SELECT 1'); # _do_query() logs via standard mechanisms
  42
  43   my @loglines = $lfn->slurp;
  44   is(@loglines, 2, '2 lines of log');
  45   like($loglines[0], qr/^SELECT COUNT/, 'Env log from schema1 success');
  46   like($loglines[1], qr/^SELECT 1:/, 'Env log from schema2 success');
  47
  48   $schema->storage->debugobj->debugfh(undef)
  49 }
  50
  51 END {
  52   unlink $lfn;
  53 }
  54
  55 open(STDERRCOPY, '>&STDERR');
  56
  57 # STDERR will be closed, no T::B diag in blocks
  58 my $exception = try {
  59   close(STDERR);
  60   $schema->resultset('CD')->search({})->count;
  61 } catch {
  62   $_
  63 } finally {
  64   # restore STDERR
  65   open(STDERR, '>&STDERRCOPY');
  66 };
  67
  68 like $exception, qr/\QDuplication of STDERR for debug output failed (perhaps your STDERR is closed?)/;
  69
  70
  71
  72 # test debugcb and debugobj protocol
  73 {
  74   my $rs = $schema->resultset('CD')->search( {
  75     artist => 1,
  76     cdid => { -between => [ 1, 3 ] },
  77     title => { '!=' => \[ '?', undef ] }
  78   });
  79
  80   my $sql_trace = 'SELECT me.cdid, me.artist, me.title, me.year, me.genreid, me.single_track FROM cd me WHERE ( ( artist = ? AND ( cdid BETWEEN ? AND ? ) AND title != ? ) )';
  81   my @bind_trace = qw( '1' '1' '3' NULL );  # quotes are in fact part of the trace </facepalm>
  82
  83
  84   my @args;
  85   $schema->storage->debugcb(sub { push @args, @_ } );
  86
  87   $rs->all;
  88
  89   is_deeply( \@args, [
  90     "SELECT",
  91     sprintf( "%s: %s\n", $sql_trace, join ', ', @bind_trace ),
  92   ]);
  93
  94   {
  95     package DBICTest::DebugObj;
  96     our @ISA = 'DBIx::Class::Storage::Statistics';
  97
  98     sub query_start {
  99       my $self = shift;
 100       ( $self->{_traced_sql}, @{$self->{_traced_bind}} ) = @_;
 101     }
 102   }
 103
 104   my $do = $schema->storage->debugobj(DBICTest::DebugObj->new);
 105
 106   $rs->all;
 107
 108   is( $do->{_traced_sql}, $sql_trace );
 109
 110   is_deeply ( $do->{_traced_bind}, \@bind_trace );
 111 }
 112
 113 done_testing;