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