t/storage/debug.t

   1 BEGIN { do "./t/lib/ANFANG.pm" or die ( $@ || $! ) }
   2
   3 use strict;
   4 use warnings;
   5 no warnings 'once';
   6
   7 BEGIN {
   8   delete @ENV{qw(
   9     DBIC_TRACE
  10     DBIC_TRACE_PROFILE
  11     DBICTEST_SQLITE_USE_FILE
  12     DBICTEST_VIA_REPLICATED
  13   )};
  14 }
  15
  16 use Test::More;
  17 use Test::Exception;
  18 use Try::Tiny;
  19 use File::Spec;
  20
  21 use DBICTest;
  22 use Path::Class qw/file/;
  23
  24 my $schema = DBICTest->init_schema();
  25
  26 my $lfn = file("t/var/sql-$$.log");
  27 unlink $lfn or die $!
  28   if -e $lfn;
  29
  30 # make sure we are testing the vanilla debugger and not ::PrettyPrint
  31 require DBIx::Class::Storage::Statistics;
  32 $schema->storage->debugobj(DBIx::Class::Storage::Statistics->new);
  33
  34 ok ( $schema->storage->debug(1), 'debug' );
  35 $schema->storage->debugfh($lfn->openw);
  36 $schema->storage->debugfh->autoflush(1);
  37 $schema->resultset('CD')->count;
  38
  39 my @loglines = $lfn->slurp;
  40 is (@loglines, 1, 'one line of log');
  41 like($loglines[0], qr/^SELECT COUNT/, 'File log via debugfh success');
  42
  43 $schema->storage->debugfh(undef);
  44
  45 {
  46   local $ENV{DBIC_TRACE} = "=$lfn";
  47   unlink $lfn;
  48
  49   $schema->resultset('CD')->count;
  50
  51   my $schema2 = DBICTest->init_schema(no_deploy => 1);
  52   $schema2->storage->_do_query('SELECT 1'); # _do_query() logs via standard mechanisms
  53
  54   my @loglines = $lfn->slurp;
  55   is(@loglines, 2, '2 lines of log');
  56   like($loglines[0], qr/^SELECT COUNT/, 'Env log from schema1 success');
  57   like($loglines[1], qr/^SELECT 1:/, 'Env log from schema2 success');
  58
  59   $schema->storage->debugobj->debugfh(undef)
  60 }
  61
  62 END {
  63   unlink $lfn;
  64 }
  65
  66 open(STDERRCOPY, '>&STDERR');
  67
  68 my $exception_line_number;
  69 # STDERR will be closed, no T::B diag in blocks
  70 my $exception = try {
  71   close(STDERR);
  72   $exception_line_number = __LINE__ + 1;  # important for test, do not reformat
  73   $schema->resultset('CD')->search({})->count;
  74 } catch {
  75   $_
  76 } finally {
  77   # restore STDERR
  78   open(STDERR, '>&STDERRCOPY');
  79 };
  80
  81 ok $exception =~ /
  82   \QDuplication of STDERR for debug output failed (perhaps your STDERR is closed?)\E
  83     .+
  84   \Qat @{[__FILE__]} line $exception_line_number\E$
  85 /xms
  86   or diag "Unexpected exception text:\n\n$exception\n";
  87
  88 my @warnings;
  89 $exception = try {
  90   local $SIG{__WARN__} = sub { push @warnings, @_ if $_[0] =~ /character/i };
  91   close STDERR;
  92   open(STDERR, '>', File::Spec->devnull) or die $!;
  93   $schema->resultset('CD')->search({ title => "\x{1f4a9}" })->count;
  94   '';
  95 } catch {
  96   $_;
  97 } finally {
  98   # restore STDERR
  99   close STDERR;
 100   open(STDERR, '>&STDERRCOPY');
 101 };
 102
 103 die "How did that fail... $exception"
 104   if $exception;
 105
 106 is_deeply(\@warnings, [], 'No warnings with unicode on STDERR');
 107
 108 # test debugcb and debugobj protocol
 109 {
 110   my $rs = $schema->resultset('CD')->search( {
 111     artist => 1,
 112     cdid => { -between => [ 1, 3 ] },
 113     title => { '!=' => \[ '?', undef ] }
 114   });
 115
 116   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 != ? ) )';
 117   my @bind_trace = qw( '1' '1' '3' NULL );  # quotes are in fact part of the trace </facepalm>
 118
 119
 120   my @args;
 121   $schema->storage->debugcb(sub { push @args, @_ } );
 122
 123   $rs->all;
 124
 125   is_deeply( \@args, [
 126     "SELECT",
 127     sprintf( "%s: %s\n", $sql_trace, join ', ', @bind_trace ),
 128   ]);
 129
 130   {
 131     package DBICTest::DebugObj;
 132     our @ISA = 'DBIx::Class::Storage::Statistics';
 133
 134     sub query_start {
 135       my $self = shift;
 136       ( $self->{_traced_sql}, @{$self->{_traced_bind}} ) = @_;
 137     }
 138   }
 139
 140   my $do = $schema->storage->debugobj(DBICTest::DebugObj->new);
 141
 142   $rs->all;
 143
 144   is( $do->{_traced_sql}, $sql_trace );
 145
 146   is_deeply ( $do->{_traced_bind}, \@bind_trace );
 147 }
 148
 149 # recreate test as seen in DBIx::Class::QueryLog
 150 # the rationale is that if someone uses a non-IO::Handle object
 151 # on CPAN, many are *bound* to use one on darkpan. Thus this
 152 # test to ensure there is no future silent breakage
 153 {
 154   my $output = "";
 155
 156   {
 157     package DBICTest::_Printable;
 158
 159     sub print {
 160       my ($self, @args) = @_;
 161       $output .= join('', @args);
 162     }
 163   }
 164
 165   $schema->storage->debugobj(undef);
 166   $schema->storage->debug(1);
 167   $schema->storage->debugfh( bless {}, "DBICTest::_Printable" );
 168   $schema->storage->txn_do( sub { $schema->resultset('Artist')->count } );
 169
 170   like (
 171     $output,
 172     qr/
 173       \A
 174       ^ \QBEGIN WORK\E \s*?
 175       ^ \QSELECT COUNT( * ) FROM artist me:\E \s*?
 176       ^ \QCOMMIT\E \s*?
 177       \z
 178     /xm
 179   );
 180
 181   $schema->storage->debug(0);
 182   $schema->storage->debugfh(undef);
 183 }
 184
 185 done_testing;