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