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