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