Merge lp:~percona-toolkit-dev/percona-toolkit/simplify-pqd into lp:percona-toolkit/2.2

Proposed by Brian Fraser
Status: Merged
Approved by: Daniel Nichter
Approved revision: 518
Merged at revision: 514
Proposed branch: lp:~percona-toolkit-dev/percona-toolkit/simplify-pqd
Merge into: lp:percona-toolkit/2.2
Diff against target: 224909 lines (+12/-224362)
75 files modified
bin/pt-query-digest (+8/-1514)
lib/HTTPProtocolParser.pm (+0/-242)
lib/MemcachedEvent.pm (+0/-216)
lib/MemcachedProtocolParser.pm (+0/-424)
lib/PgLogParser.pm (+0/-669)
lib/QueryReportFormatter.pm (+1/-3)
lib/SysLogParser.pm (+0/-259)
lib/TcpdumpParser.pm (+1/-4)
t/lib/HTTPProtocolParser.t (+0/-286)
t/lib/MemcachedEvent.t (+0/-766)
t/lib/MemcachedProtocolParser.t (+0/-414)
t/lib/PgLogParser.t (+0/-604)
t/lib/SysLogParser.t (+0/-205)
t/lib/samples/http/http_tcpdump001.txt (+0/-107)
t/lib/samples/http/http_tcpdump002.txt (+0/-3564)
t/lib/samples/http/http_tcpdump003.txt (+0/-16163)
t/lib/samples/http/http_tcpdump004.txt (+0/-898)
t/lib/samples/http/http_tcpdump005.txt (+0/-465)
t/lib/samples/http/http_tcpdump006.txt (+0/-322)
t/lib/samples/http/http_tcpdump007.txt (+0/-184146)
t/lib/samples/http/http_tcpdump008.txt (+0/-112)
t/lib/samples/http/http_tcpdump009.txt (+0/-106)
t/lib/samples/memcached/memc_tcpdump001.txt (+0/-12)
t/lib/samples/memcached/memc_tcpdump002.txt (+0/-13)
t/lib/samples/memcached/memc_tcpdump003.txt (+0/-20)
t/lib/samples/memcached/memc_tcpdump004.txt (+0/-60)
t/lib/samples/memcached/memc_tcpdump005.txt (+0/-1163)
t/lib/samples/memcached/memc_tcpdump006.txt (+0/-1170)
t/lib/samples/memcached/memc_tcpdump007.txt (+0/-11)
t/lib/samples/memcached/memc_tcpdump008.txt (+0/-121)
t/lib/samples/memcached/memc_tcpdump009.txt (+0/-11)
t/lib/samples/memcached/memc_tcpdump010.txt (+0/-11)
t/lib/samples/memcached/memc_tcpdump011.txt (+0/-25)
t/lib/samples/memcached/memc_tcpdump013.txt (+0/-6)
t/lib/samples/memcached/memc_tcpdump014.txt (+0/-19)
t/lib/samples/memcached/memc_tcpdump015.txt (+0/-25)
t/lib/samples/memcached/memc_tcpdump016.txt (+0/-37)
t/lib/samples/pg/pg-log-001.txt (+0/-8)
t/lib/samples/pg/pg-log-002.txt (+0/-15)
t/lib/samples/pg/pg-log-003.txt (+0/-10)
t/lib/samples/pg/pg-log-004.txt (+0/-4)
t/lib/samples/pg/pg-log-005.txt (+0/-6)
t/lib/samples/pg/pg-log-006.txt (+0/-16)
t/lib/samples/pg/pg-log-007.txt (+0/-13)
t/lib/samples/pg/pg-log-008.txt (+0/-3)
t/lib/samples/pg/pg-log-009.txt (+0/-2980)
t/lib/samples/pg/pg-log-010.txt (+0/-3693)
t/lib/samples/pg/pg-syslog-001.txt (+0/-13)
t/lib/samples/pg/pg-syslog-002.txt (+0/-5)
t/lib/samples/pg/pg-syslog-003.txt (+0/-14)
t/lib/samples/pg/pg-syslog-004.txt (+0/-8)
t/lib/samples/pg/pg-syslog-005.txt (+0/-5)
t/lib/samples/pg/pg-syslog-006.txt (+0/-9)
t/lib/samples/pg/pg-syslog-007.txt (+0/-11)
t/lib/samples/pg/pg-syslog-008.txt (+0/-123)
t/lib/samples/pg/pg-syslog-009.txt (+0/-2437)
t/lib/samples/pg/pg-syslog-010.txt (+0/-23)
t/pt-query-digest/http_analyses.t (+0/-26)
t/pt-query-digest/memcached_analyses.t (+0/-90)
t/pt-query-digest/pglog_analyses.t (+0/-44)
t/pt-query-digest/resume.t (+2/-2)
t/pt-query-digest/samples/http_tcpdump002.txt (+0/-240)
t/pt-query-digest/samples/memc_tcpdump001.txt (+0/-25)
t/pt-query-digest/samples/memc_tcpdump002.txt (+0/-25)
t/pt-query-digest/samples/memc_tcpdump003.txt (+0/-50)
t/pt-query-digest/samples/memc_tcpdump003_report_key_print.txt (+0/-29)
t/pt-query-digest/samples/memc_tcpdump004.txt (+0/-52)
t/pt-query-digest/samples/memc_tcpdump005.txt (+0/-25)
t/pt-query-digest/samples/memc_tcpdump006.txt (+0/-25)
t/pt-query-digest/samples/memc_tcpdump007.txt (+0/-26)
t/pt-query-digest/samples/memc_tcpdump008.txt (+0/-26)
t/pt-query-digest/samples/memc_tcpdump009.txt (+0/-26)
t/pt-query-digest/samples/memc_tcpdump010.txt (+0/-25)
t/pt-query-digest/samples/pg-sample1 (+0/-25)
t/pt-query-digest/samples/pg-syslog-sample1 (+0/-12)
To merge this branch: bzr merge lp:~percona-toolkit-dev/percona-toolkit/simplify-pqd
Reviewer Review Type Date Requested Status
Daniel Nichter Approve
Review via email: mp+146196@code.launchpad.net
To post a comment you must log in.
Revision history for this message
Daniel Nichter (daniel-nichter) wrote :

The changes will be/are so extensive as to be beyond the point of pointed review. Just test on all platforms, and when tests are passing, merge.

review: Approve
Revision history for this message
Daniel Nichter (daniel-nichter) wrote :

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'bin/pt-query-digest'
2--- bin/pt-query-digest 2013-01-31 17:52:34 +0000
3+++ bin/pt-query-digest 2013-02-01 18:19:34 +0000
4@@ -23,8 +23,6 @@
5 Processlist
6 TcpdumpParser
7 MySQLProtocolParser
8- SysLogParser
9- PgLogParser
10 SlowLogParser
11 SlowLogWriter
12 EventAggregator
13@@ -36,13 +34,10 @@
14 TableParser
15 QueryReview
16 Daemon
17- MemcachedProtocolParser
18- MemcachedEvent
19 BinaryLogParser
20 GeneralLogParser
21 RawLogParser
22 ProtocolParser
23- HTTPProtocolParser
24 MasterSlave
25 Progress
26 FileIterator
27@@ -3283,10 +3278,7 @@
28 sub port_number {
29 my ( $self, $port ) = @_;
30 return unless $port;
31- return $port eq 'memcached' ? 11211
32- : $port eq 'http' ? 80
33- : $port eq 'mysql' ? 3306
34- : $port;
35+ return $port eq 'mysql' ? 3306 : $port;
36 }
37
38 sub _d {
39@@ -4587,617 +4579,6 @@
40 # ###########################################################################
41
42 # ###########################################################################
43-# SysLogParser package
44-# This package is a copy without comments from the original. The original
45-# with comments and its test file can be found in the Bazaar repository at,
46-# lib/SysLogParser.pm
47-# t/lib/SysLogParser.t
48-# See https://launchpad.net/percona-toolkit for more information.
49-# ###########################################################################
50-{
51-package SysLogParser;
52-
53-use strict;
54-use warnings FATAL => 'all';
55-use English qw(-no_match_vars);
56-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
57-
58-my $syslog_regex = qr{\A.*\w+\[\d+\]: \[(\d+)-(\d+)\] (.*)\Z};
59-
60-sub new {
61- my ( $class ) = @_;
62- my $self = {};
63- return bless $self, $class;
64-}
65-
66-sub parse_event {
67- my ( $self, %args ) = @_;
68- my ( $next_event, $tell, $is_syslog ) = $self->generate_wrappers(%args);
69- return $next_event->();
70-}
71-
72-sub generate_wrappers {
73- my ( $self, %args ) = @_;
74-
75- if ( ($self->{sanity} || '') ne "$args{next_event}" ){
76- PTDEBUG && _d("Clearing and recreating internal state");
77- @{$self}{qw(next_event tell is_syslog)} = $self->make_closures(%args);
78- $self->{sanity} = "$args{next_event}";
79- }
80-
81- return @{$self}{qw(next_event tell is_syslog)};
82-}
83-
84-sub make_closures {
85- my ( $self, %args ) = @_;
86-
87- my $next_event = $args{'next_event'};
88- my $tell = $args{'tell'};
89- my $new_event_test = $args{'misc'}->{'new_event_test'};
90- my $line_filter = $args{'misc'}->{'line_filter'};
91-
92- my $test_line = $next_event->();
93- PTDEBUG && _d('Read first sample/test line:', $test_line);
94-
95- if ( defined $test_line && $test_line =~ m/$syslog_regex/o ) {
96-
97- PTDEBUG && _d('This looks like a syslog line, PTDEBUG prefix=LLSP');
98-
99- my ($msg_nr, $line_nr, $content) = $test_line =~ m/$syslog_regex/o;
100- my @pending = ($test_line);
101- my $last_msg_nr = $msg_nr;
102- my $pos_in_log = 0;
103-
104- my $new_next_event = sub {
105- PTDEBUG && _d('LLSP: next_event()');
106-
107- PTDEBUG && _d('LLSP: Current virtual $fh position:', $pos_in_log);
108- my $new_pos = 0;
109-
110- my @arg_lines;
111-
112- my $line;
113- LINE:
114- while (
115- defined($line = shift @pending)
116- || do {
117- eval { $new_pos = -1; $new_pos = $tell->() };
118- defined($line = $next_event->());
119- }
120- ) {
121- PTDEBUG && _d('LLSP: Line:', $line);
122-
123- ($msg_nr, $line_nr, $content) = $line =~ m/$syslog_regex/o;
124- if ( !$msg_nr ) {
125- die "Can't parse line: $line";
126- }
127-
128- elsif ( $msg_nr != $last_msg_nr ) {
129- PTDEBUG && _d('LLSP: $msg_nr', $last_msg_nr, '=>', $msg_nr);
130- $last_msg_nr = $msg_nr;
131- last LINE;
132- }
133-
134- elsif ( @arg_lines && $new_event_test && $new_event_test->($content) ) {
135- PTDEBUG && _d('LLSP: $new_event_test matches');
136- last LINE;
137- }
138-
139- $content =~ s/#(\d{3})/chr(oct($1))/ge;
140- $content =~ s/\^I/\t/g;
141- if ( $line_filter ) {
142- PTDEBUG && _d('LLSP: applying $line_filter');
143- $content = $line_filter->($content);
144- }
145-
146- push @arg_lines, $content;
147- }
148- PTDEBUG && _d('LLSP: Exited while-loop after finding a complete entry');
149-
150- my $psql_log_event = @arg_lines ? join('', @arg_lines) : undef;
151- PTDEBUG && _d('LLSP: Final log entry:', $psql_log_event);
152-
153- if ( defined $line ) {
154- PTDEBUG && _d('LLSP: Saving $line:', $line);
155- @pending = $line;
156- PTDEBUG && _d('LLSP: $pos_in_log:', $pos_in_log, '=>', $new_pos);
157- $pos_in_log = $new_pos;
158- }
159- else {
160- PTDEBUG && _d('LLSP: EOF reached');
161- @pending = ();
162- $last_msg_nr = 0;
163- }
164-
165- return $psql_log_event;
166- };
167-
168- my $new_tell = sub {
169- PTDEBUG && _d('LLSP: tell()', $pos_in_log);
170- return $pos_in_log;
171- };
172-
173- return ($new_next_event, $new_tell, 1);
174- }
175-
176- else {
177-
178- PTDEBUG && _d('Plain log, or we are at EOF; PTDEBUG prefix=PLAIN');
179-
180- my @pending = defined $test_line ? ($test_line) : ();
181-
182- my $new_next_event = sub {
183- PTDEBUG && _d('PLAIN: next_event(); @pending:', scalar @pending);
184- return @pending ? shift @pending : $next_event->();
185- };
186- my $new_tell = sub {
187- PTDEBUG && _d('PLAIN: tell(); @pending:', scalar @pending);
188- return @pending ? 0 : $tell->();
189- };
190- return ($new_next_event, $new_tell, 0);
191- }
192-}
193-
194-sub _d {
195- my ($package, undef, $line) = caller 0;
196- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
197- map { defined $_ ? $_ : 'undef' }
198- @_;
199- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
200-}
201-
202-1;
203-}
204-# ###########################################################################
205-# End SysLogParser package
206-# ###########################################################################
207-
208-# ###########################################################################
209-# PgLogParser package
210-# This package is a copy without comments from the original. The original
211-# with comments and its test file can be found in the Bazaar repository at,
212-# lib/PgLogParser.pm
213-# t/lib/PgLogParser.t
214-# See https://launchpad.net/percona-toolkit for more information.
215-# ###########################################################################
216-{
217-package PgLogParser;
218-
219-use strict;
220-use warnings FATAL => 'all';
221-use English qw(-no_match_vars);
222-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
223-
224-use Data::Dumper;
225-$Data::Dumper::Indent = 1;
226-$Data::Dumper::Sortkeys = 1;
227-$Data::Dumper::Quotekeys = 0;
228-
229-my $log_line_regex = qr{
230- (LOG|DEBUG|CONTEXT|WARNING|ERROR|FATAL|PANIC|HINT
231- |DETAIL|NOTICE|STATEMENT|INFO|LOCATION)
232- :\s\s+
233- }x;
234-
235-my %attrib_name_for = (
236- u => 'user',
237- d => 'db',
238- r => 'host', # With port
239- h => 'host',
240- p => 'Process_id',
241- t => 'ts',
242- m => 'ts', # With milliseconds
243- i => 'Query_type',
244- c => 'Session_id',
245- l => 'Line_no',
246- s => 'Session_id',
247- v => 'Vrt_trx_id',
248- x => 'Trx_id',
249-);
250-
251-sub new {
252- my ( $class ) = @_;
253- my $self = {
254- pending => [],
255- is_syslog => undef,
256- next_event => undef,
257- 'tell' => undef,
258- };
259- return bless $self, $class;
260-}
261-
262-sub parse_event {
263- my ( $self, %args ) = @_;
264- my @required_args = qw(next_event tell);
265- foreach my $arg ( @required_args ) {
266- die "I need a $arg argument" unless $args{$arg};
267- }
268-
269- my ( $next_event, $tell, $is_syslog ) = $self->generate_wrappers(%args);
270-
271- my @properties = ();
272-
273- my ($pos_in_log, $line, $was_pending) = $self->get_line();
274- my $new_pos;
275-
276- my @arg_lines;
277-
278- my $done;
279-
280- my $got_duration;
281-
282- if ( !$was_pending && (!defined $line || $line !~ m/$log_line_regex/o) ) {
283- PTDEBUG && _d('Skipping lines until I find a header');
284- my $found_header;
285- LINE:
286- while (
287- eval {
288- ($new_pos, $line) = $self->get_line();
289- defined $line;
290- }
291- ) {
292- if ( $line =~ m/$log_line_regex/o ) {
293- $pos_in_log = $new_pos;
294- last LINE;
295- }
296- else {
297- PTDEBUG && _d('Line was not a header, will fetch another');
298- }
299- }
300- PTDEBUG && _d('Found a header line, now at pos_in_line', $pos_in_log);
301- }
302-
303- my $first_line;
304-
305- my $line_type;
306-
307- LINE:
308- while ( !$done && defined $line ) {
309-
310- chomp $line unless $is_syslog;
311-
312- if ( (($line_type) = $line =~ m/$log_line_regex/o) && $line_type ne 'LOG' ) {
313-
314- if ( @arg_lines ) {
315- PTDEBUG && _d('Found a non-LOG line, exiting loop');
316- last LINE;
317- }
318-
319- else {
320- $first_line ||= $line;
321-
322- if ( my ($e) = $line =~ m/ERROR:\s+(\S.*)\Z/s ) {
323- push @properties, 'Error_msg', $e;
324- PTDEBUG && _d('Found an error msg, saving and continuing');
325- ($new_pos, $line) = $self->get_line();
326- next LINE;
327- }
328-
329- elsif ( my ($s) = $line =~ m/STATEMENT:\s+(\S.*)\Z/s ) {
330- push @properties, 'arg', $s, 'cmd', 'Query';
331- PTDEBUG && _d('Found a statement, finishing up event');
332- $done = 1;
333- last LINE;
334- }
335-
336- else {
337- PTDEBUG && _d("I don't know what to do with this line");
338- }
339- }
340-
341- }
342-
343- if (
344- $line =~ m{
345- Address\sfamily\snot\ssupported\sby\sprotocol
346- |archived\stransaction\slog\sfile
347- |autovacuum:\sprocessing\sdatabase
348- |checkpoint\srecord\sis\sat
349- |checkpoints\sare\soccurring\stoo\sfrequently\s\(
350- |could\snot\sreceive\sdata\sfrom\sclient
351- |database\ssystem\sis\sready
352- |database\ssystem\sis\sshut\sdown
353- |database\ssystem\swas\sshut\sdown
354- |incomplete\sstartup\spacket
355- |invalid\slength\sof\sstartup\spacket
356- |next\sMultiXactId:
357- |next\stransaction\sID:
358- |received\ssmart\sshutdown\srequest
359- |recycled\stransaction\slog\sfile
360- |redo\srecord\sis\sat
361- |removing\sfile\s"
362- |removing\stransaction\slog\sfile\s"
363- |shutting\sdown
364- |transaction\sID\swrap\slimit\sis
365- }x
366- ) {
367- PTDEBUG && _d('Skipping this line because it matches skip-pattern');
368- ($new_pos, $line) = $self->get_line();
369- next LINE;
370- }
371-
372- $first_line ||= $line;
373-
374- if ( $line !~ m/$log_line_regex/o && @arg_lines ) {
375-
376- if ( !$is_syslog ) {
377- $line =~ s/\A\t?/\n/;
378- }
379-
380- push @arg_lines, $line;
381- PTDEBUG && _d('This was a continuation line');
382- }
383-
384- elsif (
385- my ( $sev, $label, $rest )
386- = $line =~ m/$log_line_regex(.+?):\s+(.*)\Z/so
387- ) {
388- PTDEBUG && _d('Line is case 1 or case 3');
389-
390- if ( @arg_lines ) {
391- $done = 1;
392- PTDEBUG && _d('There are saved @arg_lines, we are done');
393-
394- if ( $label eq 'duration' && $rest =~ m/[0-9.]+\s+\S+\Z/ ) {
395- if ( $got_duration ) {
396- PTDEBUG && _d('Discarding line, duration already found');
397- }
398- else {
399- push @properties, 'Query_time', $self->duration_to_secs($rest);
400- PTDEBUG && _d("Line's duration is for previous event:", $rest);
401- }
402- }
403- else {
404- $self->pending($new_pos, $line);
405- PTDEBUG && _d('Deferred line');
406- }
407- }
408-
409- elsif ( $label =~ m/\A(?:duration|statement|query)\Z/ ) {
410- PTDEBUG && _d('Case 1: start a multi-line event');
411-
412- if ( $label eq 'duration' ) {
413-
414- if (
415- (my ($dur, $stmt)
416- = $rest =~ m/([0-9.]+ \S+)\s+(?:statement|query): *(.*)\Z/s)
417- ) {
418- push @properties, 'Query_time', $self->duration_to_secs($dur);
419- $got_duration = 1;
420- push @arg_lines, $stmt;
421- PTDEBUG && _d('Duration + statement');
422- }
423-
424- else {
425- $first_line = undef;
426- ($pos_in_log, $line) = $self->get_line();
427- PTDEBUG && _d('Line applies to event we never saw, discarding');
428- next LINE;
429- }
430- }
431- else {
432- push @arg_lines, $rest;
433- PTDEBUG && _d('Putting onto @arg_lines');
434- }
435- }
436-
437- else {
438- $done = 1;
439- PTDEBUG && _d('Line is case 3, event is done');
440-
441- if ( @arg_lines ) {
442- $self->pending($new_pos, $line);
443- PTDEBUG && _d('There was @arg_lines, putting line to pending');
444- }
445-
446- else {
447- PTDEBUG && _d('No need to defer, process event from this line now');
448- push @properties, 'cmd', 'Admin', 'arg', $label;
449-
450- if ( $label =~ m/\A(?:dis)?connection(?: received| authorized)?\Z/ ) {
451- push @properties, $self->get_meta($rest);
452- }
453-
454- else {
455- die "I don't understand line $line";
456- }
457-
458- }
459- }
460-
461- }
462-
463- else {
464- die "I don't understand line $line";
465- }
466-
467- if ( !$done ) {
468- ($new_pos, $line) = $self->get_line();
469- }
470- } # LINE
471-
472- if ( !defined $line ) {
473- PTDEBUG && _d('Line not defined, at EOF; calling oktorun(0) if exists');
474- $args{oktorun}->(0) if $args{oktorun};
475- if ( !@arg_lines ) {
476- PTDEBUG && _d('No saved @arg_lines either, we are all done');
477- return undef;
478- }
479- }
480-
481- if ( $line_type && $line_type ne 'LOG' ) {
482- PTDEBUG && _d('Line is not a LOG line');
483-
484- if ( $line_type eq 'ERROR' ) {
485- PTDEBUG && _d('Line is ERROR');
486-
487- if ( @arg_lines ) {
488- PTDEBUG && _d('There is @arg_lines, will peek ahead one line');
489- my ( $temp_pos, $temp_line ) = $self->get_line();
490- my ( $type, $msg );
491- if (
492- defined $temp_line
493- && ( ($type, $msg) = $temp_line =~ m/$log_line_regex(.*)/o )
494- && ( $type ne 'STATEMENT' || $msg eq $arg_lines[-1] )
495- ) {
496- PTDEBUG && _d('Error/statement line pertain to current event');
497- push @properties, 'Error_msg', $line =~ m/ERROR:\s*(\S.*)\Z/s;
498- if ( $type ne 'STATEMENT' ) {
499- PTDEBUG && _d('Must save peeked line, it is a', $type);
500- $self->pending($temp_pos, $temp_line);
501- }
502- }
503- elsif ( defined $temp_line && defined $type ) {
504- PTDEBUG && _d('Error/statement line are a new event');
505- $self->pending($new_pos, $line);
506- $self->pending($temp_pos, $temp_line);
507- }
508- else {
509- PTDEBUG && _d("Unknown line", $line);
510- }
511- }
512- }
513- else {
514- PTDEBUG && _d("Unknown line", $line);
515- }
516- }
517-
518- if ( $done || @arg_lines ) {
519- PTDEBUG && _d('Making event');
520-
521- push @properties, 'pos_in_log', $pos_in_log;
522-
523- if ( @arg_lines ) {
524- PTDEBUG && _d('Assembling @arg_lines: ', scalar @arg_lines);
525- push @properties, 'arg', join('', @arg_lines), 'cmd', 'Query';
526- }
527-
528- if ( $first_line ) {
529- if ( my ($ts) = $first_line =~ m/([0-9-]{10} [0-9:.]{8,12})/ ) {
530- PTDEBUG && _d('Getting timestamp', $ts);
531- push @properties, 'ts', $ts;
532- }
533-
534- if ( my ($meta) = $first_line =~ m/(.*?)[A-Z]{3,}: / ) {
535- PTDEBUG && _d('Found a meta-data chunk:', $meta);
536- push @properties, $self->get_meta($meta);
537- }
538- }
539-
540- PTDEBUG && _d('Properties of event:', Dumper(\@properties));
541- my $event = { @properties };
542- $event->{bytes} = length($event->{arg} || '');
543- return $event;
544- }
545-
546-}
547-
548-sub get_meta {
549- my ( $self, $meta ) = @_;
550- my @properties;
551- foreach my $set ( $meta =~ m/(\w+=[^, ]+)/g ) {
552- my ($key, $val) = split(/=/, $set);
553- if ( $key && $val ) {
554- if ( my $prop = $attrib_name_for{lc substr($key, 0, 1)} ) {
555- push @properties, $prop, $val;
556- }
557- else {
558- PTDEBUG && _d('Bad meta key', $set);
559- }
560- }
561- else {
562- PTDEBUG && _d("Can't figure out meta from", $set);
563- }
564- }
565- return @properties;
566-}
567-
568-sub get_line {
569- my ( $self ) = @_;
570- my ($pos, $line, $was_pending) = $self->pending;
571- if ( ! defined $line ) {
572- PTDEBUG && _d('Got nothing from pending, trying the $fh');
573- my ( $next_event, $tell) = @{$self}{qw(next_event tell)};
574- eval {
575- $pos = $tell->();
576- $line = $next_event->();
577- };
578- if ( PTDEBUG && $EVAL_ERROR ) {
579- _d($EVAL_ERROR);
580- }
581- }
582-
583- PTDEBUG && _d('Got pos/line:', $pos, $line);
584- return ($pos, $line);
585-}
586-
587-sub pending {
588- my ( $self, $val, $pos_in_log ) = @_;
589- my $was_pending;
590- PTDEBUG && _d('In sub pending, val:', $val);
591- if ( $val ) {
592- push @{$self->{pending}}, [$val, $pos_in_log];
593- }
594- elsif ( @{$self->{pending}} ) {
595- ($val, $pos_in_log) = @{ shift @{$self->{pending}} };
596- $was_pending = 1;
597- }
598- PTDEBUG && _d('Return from pending:', $val, $pos_in_log);
599- return ($val, $pos_in_log, $was_pending);
600-}
601-
602-sub generate_wrappers {
603- my ( $self, %args ) = @_;
604-
605- if ( ($self->{sanity} || '') ne "$args{next_event}" ){
606- PTDEBUG && _d("Clearing and recreating internal state");
607- eval { require SysLogParser; }; # Required for tests to work.
608- my $sl = new SysLogParser();
609-
610- $args{misc}->{new_event_test} = sub {
611- my ( $content ) = @_;
612- return unless defined $content;
613- return $content =~ m/$log_line_regex/o;
614- };
615-
616- $args{misc}->{line_filter} = sub {
617- my ( $content ) = @_;
618- $content =~ s/\A\t/\n/;
619- return $content;
620- };
621-
622- @{$self}{qw(next_event tell is_syslog)} = $sl->make_closures(%args);
623- $self->{sanity} = "$args{next_event}";
624- }
625-
626- return @{$self}{qw(next_event tell is_syslog)};
627-}
628-
629-sub duration_to_secs {
630- my ( $self, $str ) = @_;
631- PTDEBUG && _d('Duration:', $str);
632- my ( $num, $suf ) = split(/\s+/, $str);
633- my $factor = $suf eq 'ms' ? 1000
634- : $suf eq 'sec' ? 1
635- : die("Unknown suffix '$suf'");
636- return $num / $factor;
637-}
638-
639-sub _d {
640- my ($package, undef, $line) = caller 0;
641- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
642- map { defined $_ ? $_ : 'undef' }
643- @_;
644- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
645-}
646-
647-1;
648-}
649-# ###########################################################################
650-# End PgLogParser package
651-# ###########################################################################
652-
653-# ###########################################################################
654 # SlowLogParser package
655 # This package is a copy without comments from the original. The original
656 # with comments and its test file can be found in the Bazaar repository at,
657@@ -7197,9 +6578,7 @@
658 }
659
660 my $log_type = $args{log_type} || '';
661- my $mark = $log_type eq 'memcached'
662- || $log_type eq 'http'
663- || $log_type eq 'pglog' ? '' : '\G';
664+ my $mark = '\G';
665
666 if ( $item =~ m/^(?:[\(\s]*select|insert|replace)/ ) {
667 if ( $item =~ m/^(?:insert|replace)/ ) { # No EXPLAIN
668@@ -9453,522 +8832,6 @@
669 # ###########################################################################
670
671 # ###########################################################################
672-# MemcachedProtocolParser package
673-# This package is a copy without comments from the original. The original
674-# with comments and its test file can be found in the Bazaar repository at,
675-# lib/MemcachedProtocolParser.pm
676-# t/lib/MemcachedProtocolParser.t
677-# See https://launchpad.net/percona-toolkit for more information.
678-# ###########################################################################
679-{
680-package MemcachedProtocolParser;
681-
682-use strict;
683-use warnings FATAL => 'all';
684-use English qw(-no_match_vars);
685-
686-use Data::Dumper;
687-$Data::Dumper::Indent = 1;
688-$Data::Dumper::Sortkeys = 1;
689-$Data::Dumper::Quotekeys = 0;
690-
691-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
692-
693-sub new {
694- my ( $class, %args ) = @_;
695-
696- my $self = {
697- server => $args{server},
698- port => $args{port} || '11211',
699- sessions => {},
700- o => $args{o},
701- };
702- return bless $self, $class;
703-}
704-
705-sub parse_event {
706- my ( $self, %args ) = @_;
707- my @required_args = qw(event);
708- foreach my $arg ( @required_args ) {
709- die "I need a $arg argument" unless $args{$arg};
710- }
711- my $packet = @args{@required_args};
712-
713- if ( $packet->{data_len} == 0 ) {
714- PTDEBUG && _d('No TCP data');
715- $args{stats}->{no_tcp_data}++ if $args{stats};
716- return;
717- }
718-
719- my $src_host = "$packet->{src_host}:$packet->{src_port}";
720- my $dst_host = "$packet->{dst_host}:$packet->{dst_port}";
721-
722- if ( my $server = $self->{server} ) { # Watch only the given server.
723- $server .= ":$self->{port}";
724- if ( $src_host ne $server && $dst_host ne $server ) {
725- PTDEBUG && _d('Packet is not to or from', $server);
726- $args{stats}->{not_watched_server}++ if $args{stats};
727- return;
728- }
729- }
730-
731- my $packet_from;
732- my $client;
733- if ( $src_host =~ m/:$self->{port}$/ ) {
734- $packet_from = 'server';
735- $client = $dst_host;
736- }
737- elsif ( $dst_host =~ m/:$self->{port}$/ ) {
738- $packet_from = 'client';
739- $client = $src_host;
740- }
741- else {
742- warn 'Packet is not to or from memcached server: ', Dumper($packet);
743- return;
744- }
745- PTDEBUG && _d('Client:', $client);
746-
747- if ( !exists $self->{sessions}->{$client} ) {
748- PTDEBUG && _d('New session');
749- $self->{sessions}->{$client} = {
750- client => $client,
751- state => undef,
752- raw_packets => [],
753- };
754- };
755- my $session = $self->{sessions}->{$client};
756-
757- push @{$session->{raw_packets}}, $packet->{raw_packet};
758-
759- $packet->{data} = pack('H*', $packet->{data});
760- my $event;
761- if ( $packet_from eq 'server' ) {
762- $event = $self->_packet_from_server($packet, $session, %args);
763- }
764- elsif ( $packet_from eq 'client' ) {
765- $event = $self->_packet_from_client($packet, $session, %args);
766- }
767- else {
768- $args{stats}->{unknown_packet_origin}++ if $args{stats};
769- die 'Packet origin unknown';
770- }
771-
772- PTDEBUG && _d('Done with packet; event:', Dumper($event));
773- $args{stats}->{events_parsed}++ if $args{stats};
774- return $event;
775-}
776-
777-sub _packet_from_server {
778- my ( $self, $packet, $session, %args ) = @_;
779- die "I need a packet" unless $packet;
780- die "I need a session" unless $session;
781-
782- PTDEBUG && _d('Packet is from server; client state:', $session->{state});
783-
784- my $data = $packet->{data};
785-
786- if ( !$session->{state} ) {
787- PTDEBUG && _d('Ignoring mid-stream server response');
788- $args{stats}->{ignored_midstream_server_response}++ if $args{stats};
789- return;
790- }
791-
792- if ( $session->{state} eq 'awaiting reply' ) {
793- PTDEBUG && _d('State is awaiting reply');
794- my ($line1, $rest) = $packet->{data} =~ m/\A(.*?)\r\n(.*)?/s;
795- if ( !$line1 ) {
796- $args{stats}->{unknown_server_data}++ if $args{stats};
797- die "Unknown memcached data from server";
798- }
799-
800- my @vals = $line1 =~ m/(\S+)/g;
801- $session->{res} = shift @vals;
802- PTDEBUG && _d('Result of last', $session->{cmd}, 'cmd:', $session->{res});
803-
804- if ( $session->{cmd} eq 'incr' || $session->{cmd} eq 'decr' ) {
805- PTDEBUG && _d('It is an incr or decr');
806- if ( $session->{res} !~ m/\D/ ) { # It's an integer, not an error
807- PTDEBUG && _d('Got a value for the incr/decr');
808- $session->{val} = $session->{res};
809- $session->{res} = '';
810- }
811- }
812- elsif ( $session->{res} eq 'VALUE' ) {
813- PTDEBUG && _d('It is the result of a "get"');
814- my ($key, $flags, $bytes) = @vals;
815- defined $session->{flags} or $session->{flags} = $flags;
816- defined $session->{bytes} or $session->{bytes} = $bytes;
817-
818- if ( $rest && $bytes ) {
819- PTDEBUG && _d('There is a value');
820- if ( length($rest) > $bytes ) {
821- PTDEBUG && _d('Got complete response');
822- $session->{val} = substr($rest, 0, $bytes);
823- }
824- else {
825- PTDEBUG && _d('Got partial response, saving for later');
826- push @{$session->{partial}}, [ $packet->{seq}, $rest ];
827- $session->{gathered} += length($rest);
828- $session->{state} = 'partial recv';
829- return; # Prevent firing an event.
830- }
831- }
832- }
833- elsif ( $session->{res} eq 'END' ) {
834- PTDEBUG && _d('Got an END without any data, firing NOT_FOUND');
835- $session->{res} = 'NOT_FOUND';
836- }
837- elsif ( $session->{res} !~ m/STORED|DELETED|NOT_FOUND/ ) {
838- PTDEBUG && _d('Unknown result');
839- }
840- else {
841- $args{stats}->{unknown_server_response}++ if $args{stats};
842- }
843- }
844- else { # Should be 'partial recv'
845- PTDEBUG && _d('Session state: ', $session->{state});
846- push @{$session->{partial}}, [ $packet->{seq}, $data ];
847- $session->{gathered} += length($data);
848- PTDEBUG && _d('Gathered', $session->{gathered}, 'bytes in',
849- scalar(@{$session->{partial}}), 'packets from server');
850- if ( $session->{gathered} >= $session->{bytes} + 2 ) { # Done.
851- PTDEBUG && _d('End of partial response, preparing event');
852- my $val = join('',
853- map { $_->[1] }
854- sort { $a->[0] <=> $b->[0] }
855- @{$session->{partial}});
856- $session->{val} = substr($val, 0, $session->{bytes});
857- }
858- else {
859- PTDEBUG && _d('Partial response continues, no action');
860- return; # Prevent firing event.
861- }
862- }
863-
864- PTDEBUG && _d('Creating event, deleting session');
865- my $event = make_event($session, $packet);
866- delete $self->{sessions}->{$session->{client}}; # memcached is stateless!
867- $session->{raw_packets} = []; # Avoid keeping forever
868- return $event;
869-}
870-
871-sub _packet_from_client {
872- my ( $self, $packet, $session, %args ) = @_;
873- die "I need a packet" unless $packet;
874- die "I need a session" unless $session;
875-
876- PTDEBUG && _d('Packet is from client; state:', $session->{state});
877-
878- my $event;
879- if ( ($session->{state} || '') =~m/awaiting reply|partial recv/ ) {
880- PTDEBUG && _d("Expected data from the client, looks like interrupted");
881- $session->{res} = 'INTERRUPTED';
882- $event = make_event($session, $packet);
883- my $client = $session->{client};
884- delete @{$session}{keys %$session};
885- $session->{client} = $client;
886- }
887-
888- my ($line1, $val);
889- my ($cmd, $key, $flags, $exptime, $bytes);
890-
891- if ( !$session->{state} ) {
892- PTDEBUG && _d('Session state: ', $session->{state});
893- ($line1, $val) = $packet->{data} =~ m/\A(.*?)\r\n(.+)?/s;
894- if ( !$line1 ) {
895- PTDEBUG && _d('Unknown memcached data from client, skipping packet');
896- $args{stats}->{unknown_client_data}++ if $args{stats};
897- return;
898- }
899-
900- my @vals = $line1 =~ m/(\S+)/g;
901- $cmd = lc shift @vals;
902- PTDEBUG && _d('$cmd is a ', $cmd);
903- if ( $cmd eq 'set' || $cmd eq 'add' || $cmd eq 'replace' ) {
904- ($key, $flags, $exptime, $bytes) = @vals;
905- $session->{bytes} = $bytes;
906- }
907- elsif ( $cmd eq 'get' ) {
908- ($key) = @vals;
909- if ( $val ) {
910- PTDEBUG && _d('Multiple cmds:', $val);
911- $val = undef;
912- }
913- }
914- elsif ( $cmd eq 'delete' ) {
915- ($key) = @vals; # TODO: handle the <queue_time>
916- if ( $val ) {
917- PTDEBUG && _d('Multiple cmds:', $val);
918- $val = undef;
919- }
920- }
921- elsif ( $cmd eq 'incr' || $cmd eq 'decr' ) {
922- ($key) = @vals;
923- }
924- else {
925- PTDEBUG && _d("Don't know how to handle", $cmd, "command");
926- $args{stats}->{unknown_client_command}++ if $args{stats};
927- return;
928- }
929-
930- @{$session}{qw(cmd key flags exptime)}
931- = ($cmd, $key, $flags, $exptime);
932- $session->{host} = $packet->{src_host};
933- $session->{pos_in_log} = $packet->{pos_in_log};
934- $session->{ts} = $packet->{ts};
935- }
936- else {
937- PTDEBUG && _d('Session state: ', $session->{state});
938- $val = $packet->{data};
939- }
940-
941- $session->{state} = 'awaiting reply'; # Assume we got the whole packet
942- if ( $val ) {
943- if ( $session->{bytes} + 2 == length($val) ) { # +2 for the \r\n
944- PTDEBUG && _d('Complete send');
945- $val =~ s/\r\n\Z//; # We got the whole thing.
946- $session->{val} = $val;
947- }
948- else { # We apparently did NOT get the whole thing.
949- PTDEBUG && _d('Partial send, saving for later');
950- push @{$session->{partial}},
951- [ $packet->{seq}, $val ];
952- $session->{gathered} += length($val);
953- PTDEBUG && _d('Gathered', $session->{gathered}, 'bytes in',
954- scalar(@{$session->{partial}}), 'packets from client');
955- if ( $session->{gathered} >= $session->{bytes} + 2 ) { # Done.
956- PTDEBUG && _d('Message looks complete now, saving value');
957- $val = join('',
958- map { $_->[1] }
959- sort { $a->[0] <=> $b->[0] }
960- @{$session->{partial}});
961- $val =~ s/\r\n\Z//;
962- $session->{val} = $val;
963- }
964- else {
965- PTDEBUG && _d('Message not complete');
966- $val = '[INCOMPLETE]';
967- $session->{state} = 'partial send';
968- }
969- }
970- }
971-
972- return $event;
973-}
974-
975-sub make_event {
976- my ( $session, $packet ) = @_;
977- my $event = {
978- cmd => $session->{cmd},
979- key => $session->{key},
980- val => $session->{val} || '',
981- res => $session->{res},
982- ts => $session->{ts},
983- host => $session->{host},
984- flags => $session->{flags} || 0,
985- exptime => $session->{exptime} || 0,
986- bytes => $session->{bytes} || 0,
987- Query_time => timestamp_diff($session->{ts}, $packet->{ts}),
988- pos_in_log => $session->{pos_in_log},
989- };
990- return $event;
991-}
992-
993-sub _get_errors_fh {
994- my ( $self ) = @_;
995- my $errors_fh = $self->{errors_fh};
996- return $errors_fh if $errors_fh;
997-
998- my $o = $self->{o};
999- if ( $o && $o->has('tcpdump-errors') && $o->got('tcpdump-errors') ) {
1000- my $errors_file = $o->get('tcpdump-errors');
1001- PTDEBUG && _d('tcpdump-errors file:', $errors_file);
1002- open $errors_fh, '>>', $errors_file
1003- or die "Cannot open tcpdump-errors file $errors_file: $OS_ERROR";
1004- }
1005-
1006- $self->{errors_fh} = $errors_fh;
1007- return $errors_fh;
1008-}
1009-
1010-sub _d {
1011- my ($package, undef, $line) = caller 0;
1012- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
1013- map { defined $_ ? $_ : 'undef' }
1014- @_;
1015- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
1016-}
1017-
1018-sub timestamp_diff {
1019- my ( $start, $end ) = @_;
1020- my $sd = substr($start, 0, 11, '');
1021- my $ed = substr($end, 0, 11, '');
1022- my ( $sh, $sm, $ss ) = split(/:/, $start);
1023- my ( $eh, $em, $es ) = split(/:/, $end);
1024- my $esecs = ($eh * 3600 + $em * 60 + $es);
1025- my $ssecs = ($sh * 3600 + $sm * 60 + $ss);
1026- if ( $sd eq $ed ) {
1027- return sprintf '%.6f', $esecs - $ssecs;
1028- }
1029- else { # Assume only one day boundary has been crossed, no DST, etc
1030- return sprintf '%.6f', ( 86_400 - $ssecs ) + $esecs;
1031- }
1032-}
1033-
1034-1;
1035-}
1036-# ###########################################################################
1037-# End MemcachedProtocolParser package
1038-# ###########################################################################
1039-
1040-# ###########################################################################
1041-# MemcachedEvent package
1042-# This package is a copy without comments from the original. The original
1043-# with comments and its test file can be found in the Bazaar repository at,
1044-# lib/MemcachedEvent.pm
1045-# t/lib/MemcachedEvent.t
1046-# See https://launchpad.net/percona-toolkit for more information.
1047-# ###########################################################################
1048-{
1049-package MemcachedEvent;
1050-
1051-use strict;
1052-use warnings FATAL => 'all';
1053-use English qw(-no_match_vars);
1054-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
1055-
1056-use Data::Dumper;
1057-$Data::Dumper::Indent = 1;
1058-$Data::Dumper::Sortkeys = 1;
1059-$Data::Dumper::Quotekeys = 0;
1060-
1061-my %cmds = map { $_ => 1 } qw(
1062- set
1063- add
1064- replace
1065- append
1066- prepend
1067- cas
1068- get
1069- gets
1070- delete
1071- incr
1072- decr
1073-);
1074-
1075-my %cmd_handler_for = (
1076- set => \&handle_storage_cmd,
1077- add => \&handle_storage_cmd,
1078- replace => \&handle_storage_cmd,
1079- append => \&handle_storage_cmd,
1080- prepend => \&handle_storage_cmd,
1081- cas => \&handle_storage_cmd,
1082- get => \&handle_retr_cmd,
1083- gets => \&handle_retr_cmd,
1084-);
1085-
1086-sub new {
1087- my ( $class, %args ) = @_;
1088- my $self = {};
1089- return bless $self, $class;
1090-}
1091-
1092-sub parse_event {
1093- my ( $self, %args ) = @_;
1094- my $event = $args{event};
1095- return unless $event;
1096-
1097- if ( !$event->{cmd} || !$event->{key} ) {
1098- PTDEBUG && _d('Event has no cmd or key:', Dumper($event));
1099- return;
1100- }
1101-
1102- if ( !$cmds{$event->{cmd}} ) {
1103- PTDEBUG && _d("Don't know how to handle cmd:", $event->{cmd});
1104- return;
1105- }
1106-
1107- $event->{arg} = "$event->{cmd} $event->{key}";
1108- $event->{fingerprint} = $self->fingerprint($event->{arg});
1109- $event->{key_print} = $self->fingerprint($event->{key});
1110-
1111- map { $event->{"Memc_$_"} = 'No' } keys %cmds;
1112- $event->{"Memc_$event->{cmd}"} = 'Yes'; # Got this cmd.
1113- $event->{Memc_error} = 'No'; # A handler may change this.
1114- $event->{Memc_miss} = 'No';
1115- if ( $event->{res} ) {
1116- $event->{Memc_miss} = 'Yes' if $event->{res} eq 'NOT_FOUND';
1117- }
1118- else {
1119- PTDEBUG && _d('Event has no res:', Dumper($event));
1120- }
1121-
1122- if ( $cmd_handler_for{$event->{cmd}} ) {
1123- return $cmd_handler_for{$event->{cmd}}->($event);
1124- }
1125-
1126- return $event;
1127-}
1128-
1129-sub fingerprint {
1130- my ( $self, $val ) = @_;
1131- $val =~ s/[0-9A-Fa-f]{16,}|\d+/?/g;
1132- return $val;
1133-}
1134-
1135-sub handle_storage_cmd {
1136- my ( $event ) = @_;
1137-
1138- if ( !$event->{res} ) {
1139- PTDEBUG && _d('No result for event:', Dumper($event));
1140- return;
1141- }
1142-
1143- $event->{'Memc_Not_Stored'} = $event->{res} eq 'NOT_STORED' ? 'Yes' : 'No';
1144- $event->{'Memc_Exists'} = $event->{res} eq 'EXISTS' ? 'Yes' : 'No';
1145-
1146- return $event;
1147-}
1148-
1149-sub handle_retr_cmd {
1150- my ( $event ) = @_;
1151-
1152- if ( !$event->{res} ) {
1153- PTDEBUG && _d('No result for event:', Dumper($event));
1154- return;
1155- }
1156-
1157- $event->{'Memc_error'} = $event->{res} eq 'INTERRUPTED' ? 'Yes' : 'No';
1158-
1159- return $event;
1160-}
1161-
1162-
1163-sub handle_delete {
1164- my ( $event ) = @_;
1165- return $event;
1166-}
1167-
1168-sub handle_incr_decr_cmd {
1169- my ( $event ) = @_;
1170- return $event;
1171-}
1172-
1173-sub _d {
1174- my ($package, undef, $line) = caller 0;
1175- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
1176- map { defined $_ ? $_ : 'undef' }
1177- @_;
1178- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
1179-}
1180-
1181-1;
1182-}
1183-# ###########################################################################
1184-# End MemcachedEvent package
1185-# ###########################################################################
1186-
1187-# ###########################################################################
1188 # BinaryLogParser package
1189 # This package is a copy without comments from the original. The original
1190 # with comments and its test file can be found in the Bazaar repository at,
1191@@ -10719,209 +9582,6 @@
1192 # ###########################################################################
1193
1194 # ###########################################################################
1195-# HTTPProtocolParser package
1196-# This package is a copy without comments from the original. The original
1197-# with comments and its test file can be found in the Bazaar repository at,
1198-# lib/HTTPProtocolParser.pm
1199-# t/lib/HTTPProtocolParser.t
1200-# See https://launchpad.net/percona-toolkit for more information.
1201-# ###########################################################################
1202-{
1203-package HTTPProtocolParser;
1204-use base 'ProtocolParser';
1205-
1206-use strict;
1207-use warnings FATAL => 'all';
1208-use English qw(-no_match_vars);
1209-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
1210-
1211-sub new {
1212- my ( $class, %args ) = @_;
1213- my $self = $class->SUPER::new(
1214- %args,
1215- port => 80,
1216- );
1217- return $self;
1218-}
1219-
1220-sub _packet_from_server {
1221- my ( $self, $packet, $session, $misc ) = @_;
1222- die "I need a packet" unless $packet;
1223- die "I need a session" unless $session;
1224-
1225- PTDEBUG && _d('Packet is from server; client state:', $session->{state});
1226-
1227- if ( !$session->{state} ) {
1228- PTDEBUG && _d('Ignoring mid-stream server response');
1229- return;
1230- }
1231-
1232- if ( $session->{out_of_order} ) {
1233- my ($line1, $content);
1234- if ( !$session->{have_header} ) {
1235- ($line1, $content) = $self->_parse_header(
1236- $session, $packet->{data}, $packet->{data_len});
1237- }
1238- if ( $line1 ) {
1239- $session->{have_header} = 1;
1240- $packet->{content_len} = length $content;
1241- PTDEBUG && _d('Got out of order header with',
1242- $packet->{content_len}, 'bytes of content');
1243- }
1244- my $have_len = $packet->{content_len} || $packet->{data_len};
1245- map { $have_len += $_->{data_len} }
1246- @{$session->{packets}};
1247- $session->{have_all_packets}
1248- = 1 if $session->{attribs}->{bytes}
1249- && $have_len >= $session->{attribs}->{bytes};
1250- PTDEBUG && _d('Have', $have_len, 'of', $session->{attribs}->{bytes});
1251- return;
1252- }
1253-
1254- if ( $session->{state} eq 'awaiting reply' ) {
1255-
1256- $session->{start_reply} = $packet->{ts} unless $session->{start_reply};
1257-
1258- my ($line1, $content) = $self->_parse_header($session, $packet->{data},
1259- $packet->{data_len});
1260-
1261- if ( !$line1 ) {
1262- $session->{out_of_order} = 1; # alert parent
1263- $session->{have_all_packets} = 0;
1264- return;
1265- }
1266-
1267- my ($version, $code, $phrase) = $line1 =~ m/(\S+)/g;
1268- $session->{attribs}->{Status_code} = $code;
1269- PTDEBUG && _d('Status code for last', $session->{attribs}->{arg},
1270- 'request:', $session->{attribs}->{Status_code});
1271-
1272- my $content_len = $content ? length $content : 0;
1273- PTDEBUG && _d('Got', $content_len, 'bytes of content');
1274- if ( $session->{attribs}->{bytes}
1275- && $content_len < $session->{attribs}->{bytes} ) {
1276- $session->{data_len} = $session->{attribs}->{bytes};
1277- $session->{buff} = $content;
1278- $session->{buff_left} = $session->{attribs}->{bytes} - $content_len;
1279- PTDEBUG && _d('Contents not complete,', $session->{buff_left},
1280- 'bytes left');
1281- $session->{state} = 'recving content';
1282- return;
1283- }
1284- }
1285- elsif ( $session->{state} eq 'recving content' ) {
1286- if ( $session->{buff} ) {
1287- PTDEBUG && _d('Receiving content,', $session->{buff_left},
1288- 'bytes left');
1289- return;
1290- }
1291- PTDEBUG && _d('Contents received');
1292- }
1293- else {
1294- warn "Server response in unknown state";
1295- return;
1296- }
1297-
1298- PTDEBUG && _d('Creating event, deleting session');
1299- $session->{end_reply} = $session->{ts_max} || $packet->{ts};
1300- my $event = $self->make_event($session, $packet);
1301- delete $self->{sessions}->{$session->{client}}; # http is stateless!
1302- return $event;
1303-}
1304-
1305-sub _packet_from_client {
1306- my ( $self, $packet, $session, $misc ) = @_;
1307- die "I need a packet" unless $packet;
1308- die "I need a session" unless $session;
1309-
1310- PTDEBUG && _d('Packet is from client; state:', $session->{state});
1311-
1312- my $event;
1313- if ( ($session->{state} || '') =~ m/awaiting / ) {
1314- PTDEBUG && _d('More client headers:', $packet->{data});
1315- return;
1316- }
1317-
1318- if ( !$session->{state} ) {
1319- $session->{state} = 'awaiting reply';
1320- my ($line1, undef) = $self->_parse_header($session, $packet->{data}, $packet->{data_len});
1321- my ($request, $page, $version) = $line1 =~ m/(\S+)/g;
1322- if ( !$request || !$page ) {
1323- PTDEBUG && _d("Didn't get a request or page:", $request, $page);
1324- return;
1325- }
1326- $request = lc $request;
1327- my $vh = $session->{attribs}->{Virtual_host} || '';
1328- my $arg = "$request $vh$page";
1329- PTDEBUG && _d('arg:', $arg);
1330-
1331- if ( $request eq 'get' || $request eq 'post' ) {
1332- @{$session->{attribs}}{qw(arg)} = ($arg);
1333- }
1334- else {
1335- PTDEBUG && _d("Don't know how to handle a", $request, "request");
1336- return;
1337- }
1338-
1339- $session->{start_request} = $packet->{ts};
1340- $session->{attribs}->{host} = $packet->{src_host};
1341- $session->{attribs}->{pos_in_log} = $packet->{pos_in_log};
1342- $session->{attribs}->{ts} = $packet->{ts};
1343- }
1344- else {
1345- die "Probably multiple GETs from client before a server response?";
1346- }
1347-
1348- return $event;
1349-}
1350-
1351-sub _parse_header {
1352- my ( $self, $session, $data, $len, $no_recurse ) = @_;
1353- die "I need data" unless $data;
1354- my ($header, $content) = split(/\r\n\r\n/, $data);
1355- my ($line1, $header_vals) = $header =~ m/\A(\S+ \S+ .+?)\r\n(.+)?/s;
1356- PTDEBUG && _d('HTTP header:', $line1);
1357- return unless $line1;
1358-
1359- if ( !$header_vals ) {
1360- PTDEBUG && _d('No header vals');
1361- return $line1, undef;
1362- }
1363- my @headers;
1364- foreach my $val ( split(/\r\n/, $header_vals) ) {
1365- last unless $val;
1366- PTDEBUG && _d('HTTP header:', $val);
1367- if ( $val =~ m/^Content-Length/i ) {
1368- ($session->{attribs}->{bytes}) = $val =~ /: (\d+)/;
1369- PTDEBUG && _d('Saved Content-Length:', $session->{attribs}->{bytes});
1370- }
1371- if ( $val =~ m/Content-Encoding/i ) {
1372- ($session->{compressed}) = $val =~ /: (\w+)/;
1373- PTDEBUG && _d('Saved Content-Encoding:', $session->{compressed});
1374- }
1375- if ( $val =~ m/^Host/i ) {
1376- ($session->{attribs}->{Virtual_host}) = $val =~ /: (\S+)/;
1377- PTDEBUG && _d('Saved Host:', ($session->{attribs}->{Virtual_host}));
1378- }
1379- }
1380- return $line1, $content;
1381-}
1382-
1383-sub _d {
1384- my ($package, undef, $line) = caller 0;
1385- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
1386- map { defined $_ ? $_ : 'undef' }
1387- @_;
1388- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
1389-}
1390-
1391-1;
1392-}
1393-# ###########################################################################
1394-# End HTTPProtocolParser package
1395-# ###########################################################################
1396-
1397-# ###########################################################################
1398 # MasterSlave package
1399 # This package is a copy without comments from the original. The original
1400 # with comments and its test file can be found in the Bazaar repository at,
1401@@ -13986,10 +12646,6 @@
1402 binlog => ['BinaryLogParser'],
1403 genlog => ['GeneralLogParser'],
1404 tcpdump => ['TcpdumpParser','MySQLProtocolParser'],
1405- memcached => ['TcpdumpParser','MemcachedProtocolParser',
1406- 'MemcachedEvent'],
1407- http => ['TcpdumpParser','HTTPProtocolParser'],
1408- pglog => ['PgLogParser'],
1409 rawlog => ['RawLogParser'],
1410 );
1411 my $type = $o->get('type');
1412@@ -14543,17 +13199,6 @@
1413
1414 { # distill
1415 my %distill_args;
1416- if ( $o->get('type') eq 'memcached' || $o->get('type') eq 'http' ) {
1417- $distill_args{generic} = 1;
1418- if ( $o->get('type') eq 'http' ) {
1419- # Remove stuff after url.
1420- $distill_args{trf} = sub {
1421- my ( $query ) = @_;
1422- $query =~ s/(\S+ \S+?)(?:[?;].+)/$1/;
1423- return $query;
1424- };
1425- }
1426- }
1427 if ( grep { $_ eq 'distill' } @groupby ) {
1428 $pipeline->add(
1429 name => 'distill',
1430@@ -15282,7 +13927,7 @@
1431
1432 =head1 NAME
1433
1434-pt-query-digest - Analyze query execution logs and generate a query report, filter, replay, or transform queries for MySQL, PostgreSQL, memcached, and more.
1435+pt-query-digest - Analyze query execution logs and generate a query report, filter, replay, or transform queries for MySQL.
1436
1437 =head1 SYNOPSIS
1438
1439@@ -15387,19 +14032,6 @@
1440 Attributes created this way can be specified for L<"--order-by"> or any
1441 option that requires an attribute.
1442
1443-=head2 memcached
1444-
1445-memcached events have additional attributes related to the memcached protocol:
1446-cmd, key, res (result) and val. Also, boolean attributes are created for
1447-the various commands, misses and errors: Memc_CMD where CMD is a memcached
1448-command (get, set, delete, etc.), Memc_error and Memc_miss.
1449-
1450-These attributes are no different from slow log attributes, so you can use them
1451-with L<"--[no]report">, L<"--group-by">, in a L<"--filter">, etc.
1452-
1453-See the memcached section of L<"ATTRIBUTES REFERENCE"> for a list of
1454-memcached-specific attributes.
1455-
1456 =head1 OUTPUT
1457
1458 The default output is a query analysis report. The L<"--[no]report"> option
1459@@ -15657,12 +14289,6 @@
1460 You can also use the value C<distill>, which is a kind of super-fingerprint.
1461 See L<"--group-by"> for more.
1462
1463-When parsing memcached input (L<"--type"> memcached), the fingerprint is an
1464-abstracted version of the command and key, with placeholders removed. For
1465-example, C<get user_123_preferences> fingerprints to C<get user_?_preferences>.
1466-There is also a C<key_print> which a fingerprinted version of the key. This
1467-example's key_print is C<user_?_preferences>.
1468-
1469 Query fingerprinting accommodates a great many special cases, which have proven
1470 necessary in the real world. For example, an IN list with 5 literals is really
1471 equivalent to one with 4 literals, so lists of literals are collapsed to a
1472@@ -16027,11 +14653,6 @@
1473
1474 =back
1475
1476-If parsing memcached input (L<"--type"> memcached), there are other
1477-attributes which you can group by: key_print (see memcached section in
1478-L<"FINGERPRINTS">), cmd, key, res and val (see memcached section in
1479-L<"ATTRIBUTES">).
1480-
1481 =item --help
1482
1483 Show help and exit.
1484@@ -16761,52 +15382,6 @@
1485 notably C<Query_time>. The default L<"--order-by"> for general logs
1486 changes to C<Query_time:cnt>.
1487
1488-=item http
1489-
1490-Parse HTTP traffic from tcpdump.
1491-
1492-=item pglog
1493-
1494-Parse a log file in PostgreSQL format. The parser will automatically recognize
1495-logs sent to syslog and transparently parse the syslog format, too. The
1496-recommended configuration for logging in your postgresql.conf is as follows.
1497-
1498-The log_destination setting can be set to either syslog or stderr. Syslog has
1499-the added benefit of not interleaving log messages from several sessions
1500-concurrently, which the parser cannot handle, so this might be better than
1501-stderr. CSV-formatted logs are not supported at this time.
1502-
1503-The log_min_duration_statement setting should be set to 0 to capture all
1504-statements with their durations. Alternatively, the parser will also recognize
1505-and handle various combinations of log_duration and log_statement.
1506-
1507-You may enable log_connections and log_disconnections, but this is optional.
1508-
1509-It is highly recommended to set your log_line_prefix to the following:
1510-
1511- log_line_prefix = '%m c=%c,u=%u,D=%d '
1512-
1513-This lets the parser find timestamps with milliseconds, session IDs, users, and
1514-databases from the log. If these items are missing, you'll simply get less
1515-information to analyze. For compatibility with other log analysis tools such as
1516-PQA and pgfouine, various log line prefix formats are supported. The general
1517-format is as follows: a timestamp can be detected and extracted (the syslog
1518-timestamp is NOT parsed), and a name=value list of properties can also.
1519-Although the suggested format is as shown above, any name=value list will be
1520-captured and interpreted by using the first letter of the 'name' part,
1521-lowercased, to determine the meaning of the item. The lowercased first letter
1522-is interpreted to mean the same thing as PostgreSQL's built-in %-codes for the
1523-log_line_prefix format string. For example, u means user, so unicorn=fred
1524-will be interpreted as user=fred; d means database, so D=john will be
1525-interpreted as database=john. The pgfouine-suggested formatting is user=%u and
1526-db=%d, so it should Just Work regardless of which format you choose. The main
1527-thing is to add as much information as possible into the log_line_prefix to
1528-permit richer analysis.
1529-
1530-Currently, only English locale messages are supported, so if your server's
1531-locale is set to something else, the log won't be parsed properly. (Log
1532-messages with "duration:" and "statement:" won't be recognized.)
1533-
1534 =item slowlog
1535
1536 Parse a log file in any variation of MySQL slow-log format.
1537@@ -16872,17 +15447,6 @@
1538 Server-side prepared statements are supported. SSL-encrypted traffic cannot be
1539 inspected and decoded.
1540
1541-=item memcached
1542-
1543-Similar to tcpdump, but the expected input is memcached packets
1544-instead of MySQL packets. For example:
1545-
1546- tcpdump -i any port 11211 -s 65535 -x -nn -q -tttt \
1547- > memcached.tcp.txt
1548- pt-query-digest --type memcached memcached.tcp.txt
1549-
1550-memcached uses port 11211 by default.
1551-
1552 =back
1553
1554 =item --until
1555@@ -16962,8 +15526,8 @@
1556 type: string
1557
1558 This option tells pt-query-digest which server IP address and port (like
1559-"10.0.0.1:3306") to watch when parsing tcpdump (for L<"--type"> tcpdump and
1560-memcached); all other servers are ignored. If you don't specify it,
1561+"10.0.0.1:3306") to watch when parsing tcpdump (for L<"--type"> tcpdump);
1562+all other servers are ignored. If you don't specify it,
1563 pt-query-digest watches all servers by looking for any IP address using port
1564 3306 or "mysql". If you're watching a server with a non-standard port, this
1565 won't work, so you must specify the IP address and port to watch.
1566@@ -17156,13 +15720,12 @@
1567
1568 =item cmd
1569
1570-"Query" or "Admin" for all except memcached. For memcached it's
1571-the memcached command: get, set, etc.
1572+"Query" or "Admin".
1573
1574 =item db
1575
1576-The current database, except for memcached. The value comes from USE
1577-database statements. By default, C<Schema> is an alias which is automatically
1578+The current database. The value comes from USE database statements.
1579+By default, C<Schema> is an alias which is automatically
1580 changed to C<db>; see L<"--attribute-aliases">.
1581
1582 =item fingerprint
1583@@ -17235,75 +15798,6 @@
1584 If using L<"--processlist">, an C<id> attribute is available for
1585 the process ID, in addition to the common attributes.
1586
1587-=head2 MEMCACHED
1588-
1589-These attributes are available when parsing L<"--type"> memcached.
1590-
1591-=over
1592-
1593-=item exptime
1594-
1595-Expiration time.
1596-
1597-=item key
1598-
1599-The key used by cmd.
1600-
1601-=item key_print
1602-
1603-An abstracted form of the key.
1604-
1605-=item Memc_add
1606-
1607-Yes/No if the command is add.
1608-
1609-=item Memc_append
1610-
1611-Yes/No if the command is append.
1612-
1613-=item Memc_cas
1614-
1615-Yes/No if the command is cas.
1616-
1617-=item Memc_error
1618-
1619-Yes/No if command caused an error. Currently, the only error is when
1620-a retrieval command is interrupted.
1621-
1622-=item Memc_get
1623-
1624-Yes/No if the command is get.
1625-
1626-=item Memc_gets
1627-
1628-Yes/No if the command is gets.
1629-
1630-=item Memc_miss
1631-
1632-Yes/No if the command tried to access a nonexistent key.
1633-
1634-=item Memc_prepend
1635-
1636-Yes/No if the command is prepend.
1637-
1638-=item Memc_replace
1639-
1640-Yes/No if the command is replace.
1641-
1642-=item Memc_set
1643-
1644-Yes/No if the command is set.
1645-
1646-=item res
1647-
1648-Result of cmd.
1649-
1650-=item val
1651-
1652-The return value of cmd, if any.
1653-
1654-=back
1655-
1656 =head1 AUTHORS
1657
1658 Baron Schwartz and Daniel Nichter
1659
1660=== removed file 'lib/HTTPProtocolParser.pm'
1661--- lib/HTTPProtocolParser.pm 2013-01-03 00:19:16 +0000
1662+++ lib/HTTPProtocolParser.pm 1970-01-01 00:00:00 +0000
1663@@ -1,242 +0,0 @@
1664-# This program is copyright 2009-2011 Percona Ireland Ltd.
1665-# Feedback and improvements are welcome.
1666-#
1667-# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
1668-# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
1669-# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
1670-#
1671-# This program is free software; you can redistribute it and/or modify it under
1672-# the terms of the GNU General Public License as published by the Free Software
1673-# Foundation, version 2; OR the Perl Artistic License. On UNIX and similar
1674-# systems, you can issue `man perlgpl' or `man perlartistic' to read these
1675-# licenses.
1676-#
1677-# You should have received a copy of the GNU General Public License along with
1678-# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
1679-# Place, Suite 330, Boston, MA 02111-1307 USA.
1680-# ###########################################################################
1681-# HTTPProtocolParser package
1682-# ###########################################################################
1683-{
1684-# Package: HTTPProtocolParser
1685-# HTTPProtocolParser parses HTTP traffic from tcpdump files.
1686-package HTTPProtocolParser;
1687-use base 'ProtocolParser';
1688-
1689-use strict;
1690-use warnings FATAL => 'all';
1691-use English qw(-no_match_vars);
1692-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
1693-
1694-# server is the "host:port" of the sever being watched. It's auto-guessed if
1695-# not specified.
1696-sub new {
1697- my ( $class, %args ) = @_;
1698- my $self = $class->SUPER::new(
1699- %args,
1700- port => 80,
1701- );
1702- return $self;
1703-}
1704-
1705-# Handles a packet from the server given the state of the session. Returns an
1706-# event if one was ready to be created, otherwise returns nothing.
1707-sub _packet_from_server {
1708- my ( $self, $packet, $session, $misc ) = @_;
1709- die "I need a packet" unless $packet;
1710- die "I need a session" unless $session;
1711-
1712- PTDEBUG && _d('Packet is from server; client state:', $session->{state});
1713-
1714- # If there's no session state, then we're catching a server response
1715- # mid-stream.
1716- if ( !$session->{state} ) {
1717- PTDEBUG && _d('Ignoring mid-stream server response');
1718- return;
1719- }
1720-
1721- if ( $session->{out_of_order} ) {
1722- # We're waiting for the header so we can get the content length.
1723- # Once we know this, we can determine how many out of order packets
1724- # we need to complete the request, then order them and re-process.
1725- my ($line1, $content);
1726- if ( !$session->{have_header} ) {
1727- ($line1, $content) = $self->_parse_header(
1728- $session, $packet->{data}, $packet->{data_len});
1729- }
1730- if ( $line1 ) {
1731- $session->{have_header} = 1;
1732- $packet->{content_len} = length $content;
1733- PTDEBUG && _d('Got out of order header with',
1734- $packet->{content_len}, 'bytes of content');
1735- }
1736- my $have_len = $packet->{content_len} || $packet->{data_len};
1737- map { $have_len += $_->{data_len} }
1738- @{$session->{packets}};
1739- $session->{have_all_packets}
1740- = 1 if $session->{attribs}->{bytes}
1741- && $have_len >= $session->{attribs}->{bytes};
1742- PTDEBUG && _d('Have', $have_len, 'of', $session->{attribs}->{bytes});
1743- return;
1744- }
1745-
1746- # Assume that the server is returning only one value.
1747- # TODO: make it handle multiple.
1748- if ( $session->{state} eq 'awaiting reply' ) {
1749-
1750- # Save this early because we may return early if the packets
1751- # are being received out of order. Also, save it only once
1752- # in case we re-process packets if they're out of order.
1753- $session->{start_reply} = $packet->{ts} unless $session->{start_reply};
1754-
1755- # Get first line of header and first chunk of contents/data.
1756- my ($line1, $content) = $self->_parse_header($session, $packet->{data},
1757- $packet->{data_len});
1758-
1759- # The reponse, when in order, is text header followed by data.
1760- # If there's no line1, then we didn't get the text header first
1761- # which means we're getting the response in out of order packets.
1762- if ( !$line1 ) {
1763- $session->{out_of_order} = 1; # alert parent
1764- $session->{have_all_packets} = 0;
1765- return;
1766- }
1767-
1768- # First line should be: version code phrase
1769- # E.g.: HTTP/1.1 200 OK
1770- my ($version, $code, $phrase) = $line1 =~ m/(\S+)/g;
1771- $session->{attribs}->{Status_code} = $code;
1772- PTDEBUG && _d('Status code for last', $session->{attribs}->{arg},
1773- 'request:', $session->{attribs}->{Status_code});
1774-
1775- my $content_len = $content ? length $content : 0;
1776- PTDEBUG && _d('Got', $content_len, 'bytes of content');
1777- if ( $session->{attribs}->{bytes}
1778- && $content_len < $session->{attribs}->{bytes} ) {
1779- $session->{data_len} = $session->{attribs}->{bytes};
1780- $session->{buff} = $content;
1781- $session->{buff_left} = $session->{attribs}->{bytes} - $content_len;
1782- PTDEBUG && _d('Contents not complete,', $session->{buff_left},
1783- 'bytes left');
1784- $session->{state} = 'recving content';
1785- return;
1786- }
1787- }
1788- elsif ( $session->{state} eq 'recving content' ) {
1789- if ( $session->{buff} ) {
1790- PTDEBUG && _d('Receiving content,', $session->{buff_left},
1791- 'bytes left');
1792- return;
1793- }
1794- PTDEBUG && _d('Contents received');
1795- }
1796- else {
1797- # TODO:
1798- warn "Server response in unknown state";
1799- return;
1800- }
1801-
1802- PTDEBUG && _d('Creating event, deleting session');
1803- $session->{end_reply} = $session->{ts_max} || $packet->{ts};
1804- my $event = $self->make_event($session, $packet);
1805- delete $self->{sessions}->{$session->{client}}; # http is stateless!
1806- return $event;
1807-}
1808-
1809-# Handles a packet from the client given the state of the session.
1810-sub _packet_from_client {
1811- my ( $self, $packet, $session, $misc ) = @_;
1812- die "I need a packet" unless $packet;
1813- die "I need a session" unless $session;
1814-
1815- PTDEBUG && _d('Packet is from client; state:', $session->{state});
1816-
1817- my $event;
1818- if ( ($session->{state} || '') =~ m/awaiting / ) {
1819- PTDEBUG && _d('More client headers:', $packet->{data});
1820- return;
1821- }
1822-
1823- if ( !$session->{state} ) {
1824- $session->{state} = 'awaiting reply';
1825- my ($line1, undef) = $self->_parse_header($session, $packet->{data}, $packet->{data_len});
1826- # First line should be: request page version
1827- # E.g.: GET /foo.html HTTP/1.1
1828- my ($request, $page, $version) = $line1 =~ m/(\S+)/g;
1829- if ( !$request || !$page ) {
1830- PTDEBUG && _d("Didn't get a request or page:", $request, $page);
1831- return;
1832- }
1833- $request = lc $request;
1834- my $vh = $session->{attribs}->{Virtual_host} || '';
1835- my $arg = "$request $vh$page";
1836- PTDEBUG && _d('arg:', $arg);
1837-
1838- if ( $request eq 'get' || $request eq 'post' ) {
1839- @{$session->{attribs}}{qw(arg)} = ($arg);
1840- }
1841- else {
1842- PTDEBUG && _d("Don't know how to handle a", $request, "request");
1843- return;
1844- }
1845-
1846- $session->{start_request} = $packet->{ts};
1847- $session->{attribs}->{host} = $packet->{src_host};
1848- $session->{attribs}->{pos_in_log} = $packet->{pos_in_log};
1849- $session->{attribs}->{ts} = $packet->{ts};
1850- }
1851- else {
1852- # TODO:
1853- die "Probably multiple GETs from client before a server response?";
1854- }
1855-
1856- return $event;
1857-}
1858-
1859-sub _parse_header {
1860- my ( $self, $session, $data, $len, $no_recurse ) = @_;
1861- die "I need data" unless $data;
1862- my ($header, $content) = split(/\r\n\r\n/, $data);
1863- my ($line1, $header_vals) = $header =~ m/\A(\S+ \S+ .+?)\r\n(.+)?/s;
1864- PTDEBUG && _d('HTTP header:', $line1);
1865- return unless $line1;
1866-
1867- if ( !$header_vals ) {
1868- PTDEBUG && _d('No header vals');
1869- return $line1, undef;
1870- }
1871- my @headers;
1872- foreach my $val ( split(/\r\n/, $header_vals) ) {
1873- last unless $val;
1874- # Capture and save any useful header values.
1875- PTDEBUG && _d('HTTP header:', $val);
1876- if ( $val =~ m/^Content-Length/i ) {
1877- ($session->{attribs}->{bytes}) = $val =~ /: (\d+)/;
1878- PTDEBUG && _d('Saved Content-Length:', $session->{attribs}->{bytes});
1879- }
1880- if ( $val =~ m/Content-Encoding/i ) {
1881- ($session->{compressed}) = $val =~ /: (\w+)/;
1882- PTDEBUG && _d('Saved Content-Encoding:', $session->{compressed});
1883- }
1884- if ( $val =~ m/^Host/i ) {
1885- # The "host" attribute is already taken, so we call this "domain".
1886- ($session->{attribs}->{Virtual_host}) = $val =~ /: (\S+)/;
1887- PTDEBUG && _d('Saved Host:', ($session->{attribs}->{Virtual_host}));
1888- }
1889- }
1890- return $line1, $content;
1891-}
1892-
1893-sub _d {
1894- my ($package, undef, $line) = caller 0;
1895- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
1896- map { defined $_ ? $_ : 'undef' }
1897- @_;
1898- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
1899-}
1900-
1901-1;
1902-}
1903-# ###########################################################################
1904-# End HTTPProtocolParser package
1905-# ###########################################################################
1906
1907=== removed file 'lib/MemcachedEvent.pm'
1908--- lib/MemcachedEvent.pm 2013-01-03 00:19:16 +0000
1909+++ lib/MemcachedEvent.pm 1970-01-01 00:00:00 +0000
1910@@ -1,216 +0,0 @@
1911-# This program is copyright 2009-2011 Percona Ireland Ltd.
1912-# Feedback and improvements are welcome.
1913-#
1914-# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
1915-# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
1916-# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
1917-#
1918-# This program is free software; you can redistribute it and/or modify it under
1919-# the terms of the GNU General Public License as published by the Free Software
1920-# Foundation, version 2; OR the Perl Artistic License. On UNIX and similar
1921-# systems, you can issue `man perlgpl' or `man perlartistic' to read these
1922-# licenses.
1923-#
1924-# You should have received a copy of the GNU General Public License along with
1925-# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
1926-# Place, Suite 330, Boston, MA 02111-1307 USA.
1927-# ###########################################################################
1928-# MemcachedEvent package
1929-# ###########################################################################
1930-{
1931-# Package: MemcachedEvent
1932-# MemcachedEvent creates events from <MemcachedProtocolParser> data.
1933-# Since memcached is not strictly MySQL stuff, we have to
1934-# fabricate MySQL-like query events from memcached.
1935-#
1936-# See http://code.sixapart.com/svn/memcached/trunk/server/doc/protocol.txt
1937-# for information about the memcached protocol.
1938-package MemcachedEvent;
1939-
1940-use strict;
1941-use warnings FATAL => 'all';
1942-use English qw(-no_match_vars);
1943-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
1944-
1945-use Data::Dumper;
1946-$Data::Dumper::Indent = 1;
1947-$Data::Dumper::Sortkeys = 1;
1948-$Data::Dumper::Quotekeys = 0;
1949-
1950-# cmds that we know how to handle.
1951-my %cmds = map { $_ => 1 } qw(
1952- set
1953- add
1954- replace
1955- append
1956- prepend
1957- cas
1958- get
1959- gets
1960- delete
1961- incr
1962- decr
1963-);
1964-
1965-my %cmd_handler_for = (
1966- set => \&handle_storage_cmd,
1967- add => \&handle_storage_cmd,
1968- replace => \&handle_storage_cmd,
1969- append => \&handle_storage_cmd,
1970- prepend => \&handle_storage_cmd,
1971- cas => \&handle_storage_cmd,
1972- get => \&handle_retr_cmd,
1973- gets => \&handle_retr_cmd,
1974-);
1975-
1976-sub new {
1977- my ( $class, %args ) = @_;
1978- my $self = {};
1979- return bless $self, $class;
1980-}
1981-
1982-# Given an event from MemcachedProtocolParser, returns an event
1983-# more suitable for mk-query-digest.
1984-sub parse_event {
1985- my ( $self, %args ) = @_;
1986- my $event = $args{event};
1987- return unless $event;
1988-
1989- if ( !$event->{cmd} || !$event->{key} ) {
1990- PTDEBUG && _d('Event has no cmd or key:', Dumper($event));
1991- return;
1992- }
1993-
1994- if ( !$cmds{$event->{cmd}} ) {
1995- PTDEBUG && _d("Don't know how to handle cmd:", $event->{cmd});
1996- return;
1997- }
1998-
1999- # For a normal event, arg is the query. For memcached, the "query" is
2000- # essentially the cmd and key, so this becomes arg. E.g.: "set mk_key".
2001- $event->{arg} = "$event->{cmd} $event->{key}";
2002- $event->{fingerprint} = $self->fingerprint($event->{arg});
2003- $event->{key_print} = $self->fingerprint($event->{key});
2004-
2005- # Set every cmd so that aggregated totals will be correct. If we only
2006- # set cmd that we get, then all cmds will show as 100% in the report.
2007- # This will create a lot of 0% cmds, but --[no]zero-bool will remove them.
2008- # Think of events in a Percona-patched log: the attribs like Full_scan are
2009- # present for every event.
2010- map { $event->{"Memc_$_"} = 'No' } keys %cmds;
2011- $event->{"Memc_$event->{cmd}"} = 'Yes'; # Got this cmd.
2012- $event->{Memc_error} = 'No'; # A handler may change this.
2013- $event->{Memc_miss} = 'No';
2014- if ( $event->{res} ) {
2015- $event->{Memc_miss} = 'Yes' if $event->{res} eq 'NOT_FOUND';
2016- }
2017- else {
2018- # This normally happens with incr and decr cmds.
2019- PTDEBUG && _d('Event has no res:', Dumper($event));
2020- }
2021-
2022- # Handle special results, errors, etc. The handler should return the
2023- # event on success, or nothing on failure.
2024- if ( $cmd_handler_for{$event->{cmd}} ) {
2025- return $cmd_handler_for{$event->{cmd}}->($event);
2026- }
2027-
2028- return $event;
2029-}
2030-
2031-# Replace things that look like placeholders with a ?
2032-sub fingerprint {
2033- my ( $self, $val ) = @_;
2034- $val =~ s/[0-9A-Fa-f]{16,}|\d+/?/g;
2035- return $val;
2036-}
2037-
2038-# Possible results for storage cmds:
2039-# - "STORED\r\n", to indicate success.
2040-#
2041-# - "NOT_STORED\r\n" to indicate the data was not stored, but not
2042-# because of an error. This normally means that either that the
2043-# condition for an "add" or a "replace" command wasn't met, or that the
2044-# item is in a delete queue (see the "delete" command below).
2045-#
2046-# - "EXISTS\r\n" to indicate that the item you are trying to store with
2047-# a "cas" command has been modified since you last fetched it.
2048-#
2049-# - "NOT_FOUND\r\n" to indicate that the item you are trying to store
2050-# with a "cas" command did not exist or has been deleted.
2051-sub handle_storage_cmd {
2052- my ( $event ) = @_;
2053-
2054- # There should be a result for any storage cmd.
2055- if ( !$event->{res} ) {
2056- PTDEBUG && _d('No result for event:', Dumper($event));
2057- return;
2058- }
2059-
2060- $event->{'Memc_Not_Stored'} = $event->{res} eq 'NOT_STORED' ? 'Yes' : 'No';
2061- $event->{'Memc_Exists'} = $event->{res} eq 'EXISTS' ? 'Yes' : 'No';
2062-
2063- return $event;
2064-}
2065-
2066-# Technically, the only results for a retrieval cmd are the values requested.
2067-# "If some of the keys appearing in a retrieval request are not sent back
2068-# by the server in the item list this means that the server does not
2069-# hold items with such keys (because they were never stored, or stored
2070-# but deleted to make space for more items, or expired, or explicitly
2071-# deleted by a client)."
2072-# Contrary to this, MemcacedProtocolParser will set res='VALUE' on
2073-# success, res='NOT_FOUND' on failure, or res='INTERRUPTED' if the get
2074-# didn't finish.
2075-sub handle_retr_cmd {
2076- my ( $event ) = @_;
2077-
2078- # There should be a result for any retr cmd.
2079- if ( !$event->{res} ) {
2080- PTDEBUG && _d('No result for event:', Dumper($event));
2081- return;
2082- }
2083-
2084- $event->{'Memc_error'} = $event->{res} eq 'INTERRUPTED' ? 'Yes' : 'No';
2085-
2086- return $event;
2087-}
2088-
2089-# handle_delete() and handle_incr_decr_cmd() are stub subs in case we
2090-# need them later.
2091-
2092-# Possible results for a delete cmd:
2093-# - "DELETED\r\n" to indicate success
2094-#
2095-# - "NOT_FOUND\r\n" to indicate that the item with this key was not
2096-# found.
2097-sub handle_delete {
2098- my ( $event ) = @_;
2099- return $event;
2100-}
2101-
2102-# Possible results for an incr or decr cmd:
2103-# - "NOT_FOUND\r\n" to indicate the item with this value was not found
2104-#
2105-# - <value>\r\n , where <value> is the new value of the item's data,
2106-# after the increment/decrement operation was carried out.
2107-# On success, MemcachedProtocolParser sets res='' and val=the new val.
2108-# On failure, res=the result and val=''.
2109-sub handle_incr_decr_cmd {
2110- my ( $event ) = @_;
2111- return $event;
2112-}
2113-
2114-sub _d {
2115- my ($package, undef, $line) = caller 0;
2116- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
2117- map { defined $_ ? $_ : 'undef' }
2118- @_;
2119- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
2120-}
2121-
2122-1;
2123-}
2124-# ###########################################################################
2125-# End MemcachedEvent package
2126-# ###########################################################################
2127
2128=== removed file 'lib/MemcachedProtocolParser.pm'
2129--- lib/MemcachedProtocolParser.pm 2013-01-03 00:19:16 +0000
2130+++ lib/MemcachedProtocolParser.pm 1970-01-01 00:00:00 +0000
2131@@ -1,424 +0,0 @@
2132-# This program is copyright 2007-2011 Percona Ireland Ltd.
2133-# Feedback and improvements are welcome.
2134-#
2135-# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
2136-# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
2137-# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
2138-#
2139-# This program is free software; you can redistribute it and/or modify it under
2140-# the terms of the GNU General Public License as published by the Free Software
2141-# Foundation, version 2; OR the Perl Artistic License. On UNIX and similar
2142-# systems, you can issue `man perlgpl' or `man perlartistic' to read these
2143-# licenses.
2144-#
2145-# You should have received a copy of the GNU General Public License along with
2146-# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
2147-# Place, Suite 330, Boston, MA 02111-1307 USA.
2148-# ###########################################################################
2149-# MemcachedProtocolParser package
2150-# ###########################################################################
2151-{
2152-# Package: MemcachedProtocolParser
2153-# MemcachedProtocolParser parses memcached events from tcpdump files.
2154-package MemcachedProtocolParser;
2155-
2156-use strict;
2157-use warnings FATAL => 'all';
2158-use English qw(-no_match_vars);
2159-
2160-use Data::Dumper;
2161-$Data::Dumper::Indent = 1;
2162-$Data::Dumper::Sortkeys = 1;
2163-$Data::Dumper::Quotekeys = 0;
2164-
2165-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
2166-
2167-sub new {
2168- my ( $class, %args ) = @_;
2169-
2170- my $self = {
2171- server => $args{server},
2172- port => $args{port} || '11211',
2173- sessions => {},
2174- o => $args{o},
2175- };
2176- return bless $self, $class;
2177-}
2178-
2179-# The packet arg should be a hashref from TcpdumpParser::parse_event().
2180-# misc is a placeholder for future features.
2181-sub parse_event {
2182- my ( $self, %args ) = @_;
2183- my @required_args = qw(event);
2184- foreach my $arg ( @required_args ) {
2185- die "I need a $arg argument" unless $args{$arg};
2186- }
2187- my $packet = @args{@required_args};
2188-
2189- # Return early if there's no TCP data. These are usually ACK packets, but
2190- # they could also be FINs in which case, we should close and delete the
2191- # client's session.
2192- # TODO: It seems we don't handle FIN here? So I moved this code block here.
2193- if ( $packet->{data_len} == 0 ) {
2194- PTDEBUG && _d('No TCP data');
2195- $args{stats}->{no_tcp_data}++ if $args{stats};
2196- return;
2197- }
2198-
2199- my $src_host = "$packet->{src_host}:$packet->{src_port}";
2200- my $dst_host = "$packet->{dst_host}:$packet->{dst_port}";
2201-
2202- if ( my $server = $self->{server} ) { # Watch only the given server.
2203- $server .= ":$self->{port}";
2204- if ( $src_host ne $server && $dst_host ne $server ) {
2205- PTDEBUG && _d('Packet is not to or from', $server);
2206- $args{stats}->{not_watched_server}++ if $args{stats};
2207- return;
2208- }
2209- }
2210-
2211- # Auto-detect the server by looking for port 11211
2212- my $packet_from;
2213- my $client;
2214- if ( $src_host =~ m/:$self->{port}$/ ) {
2215- $packet_from = 'server';
2216- $client = $dst_host;
2217- }
2218- elsif ( $dst_host =~ m/:$self->{port}$/ ) {
2219- $packet_from = 'client';
2220- $client = $src_host;
2221- }
2222- else {
2223- warn 'Packet is not to or from memcached server: ', Dumper($packet);
2224- return;
2225- }
2226- PTDEBUG && _d('Client:', $client);
2227-
2228- # Get the client's session info or create a new session if the
2229- # client hasn't been seen before.
2230- if ( !exists $self->{sessions}->{$client} ) {
2231- PTDEBUG && _d('New session');
2232- $self->{sessions}->{$client} = {
2233- client => $client,
2234- state => undef,
2235- raw_packets => [],
2236- # ts -- wait for ts later.
2237- };
2238- };
2239- my $session = $self->{sessions}->{$client};
2240-
2241- # Save raw packets to dump later in case something fails.
2242- push @{$session->{raw_packets}}, $packet->{raw_packet};
2243-
2244- # Finally, parse the packet and maybe create an event.
2245- $packet->{data} = pack('H*', $packet->{data});
2246- my $event;
2247- if ( $packet_from eq 'server' ) {
2248- $event = $self->_packet_from_server($packet, $session, %args);
2249- }
2250- elsif ( $packet_from eq 'client' ) {
2251- $event = $self->_packet_from_client($packet, $session, %args);
2252- }
2253- else {
2254- # Should not get here.
2255- $args{stats}->{unknown_packet_origin}++ if $args{stats};
2256- die 'Packet origin unknown';
2257- }
2258-
2259- PTDEBUG && _d('Done with packet; event:', Dumper($event));
2260- $args{stats}->{events_parsed}++ if $args{stats};
2261- return $event;
2262-}
2263-
2264-# Handles a packet from the server given the state of the session. Returns an
2265-# event if one was ready to be created, otherwise returns nothing.
2266-sub _packet_from_server {
2267- my ( $self, $packet, $session, %args ) = @_;
2268- die "I need a packet" unless $packet;
2269- die "I need a session" unless $session;
2270-
2271- PTDEBUG && _d('Packet is from server; client state:', $session->{state});
2272-
2273- my $data = $packet->{data};
2274-
2275- # If there's no session state, then we're catching a server response
2276- # mid-stream.
2277- if ( !$session->{state} ) {
2278- PTDEBUG && _d('Ignoring mid-stream server response');
2279- $args{stats}->{ignored_midstream_server_response}++ if $args{stats};
2280- return;
2281- }
2282-
2283- # Assume that the server is returning only one value. TODO: make it
2284- # handle multi-gets.
2285- if ( $session->{state} eq 'awaiting reply' ) {
2286- PTDEBUG && _d('State is awaiting reply');
2287- # \r\n == 0d0a
2288- my ($line1, $rest) = $packet->{data} =~ m/\A(.*?)\r\n(.*)?/s;
2289- if ( !$line1 ) {
2290- $args{stats}->{unknown_server_data}++ if $args{stats};
2291- die "Unknown memcached data from server";
2292- }
2293-
2294- # Split up the first line into its parts.
2295- my @vals = $line1 =~ m/(\S+)/g;
2296- $session->{res} = shift @vals;
2297- PTDEBUG && _d('Result of last', $session->{cmd}, 'cmd:', $session->{res});
2298-
2299- if ( $session->{cmd} eq 'incr' || $session->{cmd} eq 'decr' ) {
2300- PTDEBUG && _d('It is an incr or decr');
2301- if ( $session->{res} !~ m/\D/ ) { # It's an integer, not an error
2302- PTDEBUG && _d('Got a value for the incr/decr');
2303- $session->{val} = $session->{res};
2304- $session->{res} = '';
2305- }
2306- }
2307- elsif ( $session->{res} eq 'VALUE' ) {
2308- PTDEBUG && _d('It is the result of a "get"');
2309- my ($key, $flags, $bytes) = @vals;
2310- defined $session->{flags} or $session->{flags} = $flags;
2311- defined $session->{bytes} or $session->{bytes} = $bytes;
2312-
2313- # Get the value from the $rest.
2314- # TODO: there might be multiple responses
2315- if ( $rest && $bytes ) {
2316- PTDEBUG && _d('There is a value');
2317- if ( length($rest) > $bytes ) {
2318- PTDEBUG && _d('Got complete response');
2319- $session->{val} = substr($rest, 0, $bytes);
2320- }
2321- else {
2322- PTDEBUG && _d('Got partial response, saving for later');
2323- push @{$session->{partial}}, [ $packet->{seq}, $rest ];
2324- $session->{gathered} += length($rest);
2325- $session->{state} = 'partial recv';
2326- return; # Prevent firing an event.
2327- }
2328- }
2329- }
2330- elsif ( $session->{res} eq 'END' ) {
2331- # Technically NOT_FOUND is an error, and this isn't an error it's just
2332- # a NULL, but what it really means is the value isn't found.
2333- PTDEBUG && _d('Got an END without any data, firing NOT_FOUND');
2334- $session->{res} = 'NOT_FOUND';
2335- }
2336- elsif ( $session->{res} !~ m/STORED|DELETED|NOT_FOUND/ ) {
2337- # Not really sure what else would get us here... want to make a note
2338- # and not have an uncaught condition.
2339- PTDEBUG && _d('Unknown result');
2340- }
2341- else {
2342- $args{stats}->{unknown_server_response}++ if $args{stats};
2343- }
2344- }
2345- else { # Should be 'partial recv'
2346- PTDEBUG && _d('Session state: ', $session->{state});
2347- push @{$session->{partial}}, [ $packet->{seq}, $data ];
2348- $session->{gathered} += length($data);
2349- PTDEBUG && _d('Gathered', $session->{gathered}, 'bytes in',
2350- scalar(@{$session->{partial}}), 'packets from server');
2351- if ( $session->{gathered} >= $session->{bytes} + 2 ) { # Done.
2352- PTDEBUG && _d('End of partial response, preparing event');
2353- my $val = join('',
2354- map { $_->[1] }
2355- # Sort in proper sequence because TCP might reorder them.
2356- sort { $a->[0] <=> $b->[0] }
2357- @{$session->{partial}});
2358- $session->{val} = substr($val, 0, $session->{bytes});
2359- }
2360- else {
2361- PTDEBUG && _d('Partial response continues, no action');
2362- return; # Prevent firing event.
2363- }
2364- }
2365-
2366- PTDEBUG && _d('Creating event, deleting session');
2367- my $event = make_event($session, $packet);
2368- delete $self->{sessions}->{$session->{client}}; # memcached is stateless!
2369- $session->{raw_packets} = []; # Avoid keeping forever
2370- return $event;
2371-}
2372-
2373-# Handles a packet from the client given the state of the session.
2374-sub _packet_from_client {
2375- my ( $self, $packet, $session, %args ) = @_;
2376- die "I need a packet" unless $packet;
2377- die "I need a session" unless $session;
2378-
2379- PTDEBUG && _d('Packet is from client; state:', $session->{state});
2380-
2381- my $event;
2382- if ( ($session->{state} || '') =~m/awaiting reply|partial recv/ ) {
2383- # Whoa, we expected something from the server, not the client. Fire an
2384- # INTERRUPTED with what we've got, and create a new session.
2385- PTDEBUG && _d("Expected data from the client, looks like interrupted");
2386- $session->{res} = 'INTERRUPTED';
2387- $event = make_event($session, $packet);
2388- my $client = $session->{client};
2389- delete @{$session}{keys %$session};
2390- $session->{client} = $client;
2391- }
2392-
2393- my ($line1, $val);
2394- my ($cmd, $key, $flags, $exptime, $bytes);
2395-
2396- if ( !$session->{state} ) {
2397- PTDEBUG && _d('Session state: ', $session->{state});
2398- # Split up the first line into its parts.
2399- ($line1, $val) = $packet->{data} =~ m/\A(.*?)\r\n(.+)?/s;
2400- if ( !$line1 ) {
2401- PTDEBUG && _d('Unknown memcached data from client, skipping packet');
2402- $args{stats}->{unknown_client_data}++ if $args{stats};
2403- return;
2404- }
2405-
2406- # TODO: handle <cas unique> and [noreply]
2407- my @vals = $line1 =~ m/(\S+)/g;
2408- $cmd = lc shift @vals;
2409- PTDEBUG && _d('$cmd is a ', $cmd);
2410- if ( $cmd eq 'set' || $cmd eq 'add' || $cmd eq 'replace' ) {
2411- ($key, $flags, $exptime, $bytes) = @vals;
2412- $session->{bytes} = $bytes;
2413- }
2414- elsif ( $cmd eq 'get' ) {
2415- ($key) = @vals;
2416- if ( $val ) {
2417- PTDEBUG && _d('Multiple cmds:', $val);
2418- $val = undef;
2419- }
2420- }
2421- elsif ( $cmd eq 'delete' ) {
2422- ($key) = @vals; # TODO: handle the <queue_time>
2423- if ( $val ) {
2424- PTDEBUG && _d('Multiple cmds:', $val);
2425- $val = undef;
2426- }
2427- }
2428- elsif ( $cmd eq 'incr' || $cmd eq 'decr' ) {
2429- ($key) = @vals;
2430- }
2431- else {
2432- PTDEBUG && _d("Don't know how to handle", $cmd, "command");
2433- $args{stats}->{unknown_client_command}++ if $args{stats};
2434- return;
2435- }
2436-
2437- @{$session}{qw(cmd key flags exptime)}
2438- = ($cmd, $key, $flags, $exptime);
2439- $session->{host} = $packet->{src_host};
2440- $session->{pos_in_log} = $packet->{pos_in_log};
2441- $session->{ts} = $packet->{ts};
2442- }
2443- else {
2444- PTDEBUG && _d('Session state: ', $session->{state});
2445- $val = $packet->{data};
2446- }
2447-
2448- # Handle the rest of the packet. It might not be the whole value that was
2449- # sent, for example for a big set(). We need to look at the number of bytes
2450- # and see if we got it all.
2451- $session->{state} = 'awaiting reply'; # Assume we got the whole packet
2452- if ( $val ) {
2453- if ( $session->{bytes} + 2 == length($val) ) { # +2 for the \r\n
2454- PTDEBUG && _d('Complete send');
2455- $val =~ s/\r\n\Z//; # We got the whole thing.
2456- $session->{val} = $val;
2457- }
2458- else { # We apparently did NOT get the whole thing.
2459- PTDEBUG && _d('Partial send, saving for later');
2460- push @{$session->{partial}},
2461- [ $packet->{seq}, $val ];
2462- $session->{gathered} += length($val);
2463- PTDEBUG && _d('Gathered', $session->{gathered}, 'bytes in',
2464- scalar(@{$session->{partial}}), 'packets from client');
2465- if ( $session->{gathered} >= $session->{bytes} + 2 ) { # Done.
2466- PTDEBUG && _d('Message looks complete now, saving value');
2467- $val = join('',
2468- map { $_->[1] }
2469- # Sort in proper sequence because TCP might reorder them.
2470- sort { $a->[0] <=> $b->[0] }
2471- @{$session->{partial}});
2472- $val =~ s/\r\n\Z//;
2473- $session->{val} = $val;
2474- }
2475- else {
2476- PTDEBUG && _d('Message not complete');
2477- $val = '[INCOMPLETE]';
2478- $session->{state} = 'partial send';
2479- }
2480- }
2481- }
2482-
2483- return $event;
2484-}
2485-
2486-# The event is not yet suitable for mk-query-digest. It lacks, for example,
2487-# an arg and fingerprint attribute. The event should be passed to
2488-# MemcachedEvent::make_event() to transform it.
2489-sub make_event {
2490- my ( $session, $packet ) = @_;
2491- my $event = {
2492- cmd => $session->{cmd},
2493- key => $session->{key},
2494- val => $session->{val} || '',
2495- res => $session->{res},
2496- ts => $session->{ts},
2497- host => $session->{host},
2498- flags => $session->{flags} || 0,
2499- exptime => $session->{exptime} || 0,
2500- bytes => $session->{bytes} || 0,
2501- Query_time => timestamp_diff($session->{ts}, $packet->{ts}),
2502- pos_in_log => $session->{pos_in_log},
2503- };
2504- return $event;
2505-}
2506-
2507-sub _get_errors_fh {
2508- my ( $self ) = @_;
2509- my $errors_fh = $self->{errors_fh};
2510- return $errors_fh if $errors_fh;
2511-
2512- # Errors file isn't open yet; try to open it.
2513- my $o = $self->{o};
2514- if ( $o && $o->has('tcpdump-errors') && $o->got('tcpdump-errors') ) {
2515- my $errors_file = $o->get('tcpdump-errors');
2516- PTDEBUG && _d('tcpdump-errors file:', $errors_file);
2517- open $errors_fh, '>>', $errors_file
2518- or die "Cannot open tcpdump-errors file $errors_file: $OS_ERROR";
2519- }
2520-
2521- $self->{errors_fh} = $errors_fh;
2522- return $errors_fh;
2523-}
2524-
2525-sub _d {
2526- my ($package, undef, $line) = caller 0;
2527- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
2528- map { defined $_ ? $_ : 'undef' }
2529- @_;
2530- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
2531-}
2532-
2533-# Returns the difference between two tcpdump timestamps. TODO: this is in
2534-# MySQLProtocolParser too, best to factor it out somewhere common.
2535-sub timestamp_diff {
2536- my ( $start, $end ) = @_;
2537- my $sd = substr($start, 0, 11, '');
2538- my $ed = substr($end, 0, 11, '');
2539- my ( $sh, $sm, $ss ) = split(/:/, $start);
2540- my ( $eh, $em, $es ) = split(/:/, $end);
2541- my $esecs = ($eh * 3600 + $em * 60 + $es);
2542- my $ssecs = ($sh * 3600 + $sm * 60 + $ss);
2543- if ( $sd eq $ed ) {
2544- return sprintf '%.6f', $esecs - $ssecs;
2545- }
2546- else { # Assume only one day boundary has been crossed, no DST, etc
2547- return sprintf '%.6f', ( 86_400 - $ssecs ) + $esecs;
2548- }
2549-}
2550-
2551-1;
2552-}
2553-# ###########################################################################
2554-# End MemcachedProtocolParser package
2555-# ###########################################################################
2556
2557=== removed file 'lib/PgLogParser.pm'
2558--- lib/PgLogParser.pm 2013-01-03 00:19:16 +0000
2559+++ lib/PgLogParser.pm 1970-01-01 00:00:00 +0000
2560@@ -1,669 +0,0 @@
2561-# This program is copyright 2010-2011 Baron Schwartz, 2011 Percona Ireland Ltd.
2562-# Feedback and improvements are welcome.
2563-#
2564-# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
2565-# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
2566-# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
2567-#
2568-# This program is free software; you can redistribute it and/or modify it under
2569-# the terms of the GNU General Public License as published by the Free Software
2570-# Foundation, version 2; OR the Perl Artistic License. On UNIX and similar
2571-# systems, you can issue `man perlgpl' or `man perlartistic' to read these
2572-# licenses.
2573-#
2574-# You should have received a copy of the GNU General Public License along with
2575-# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
2576-# Place, Suite 330, Boston, MA 02111-1307 USA.
2577-# ###########################################################################
2578-# PgLogParser package
2579-# ###########################################################################
2580-{
2581-# Package: PgLogParser
2582-# PgLogParser parses Postgres logs.
2583-package PgLogParser;
2584-
2585-use strict;
2586-use warnings FATAL => 'all';
2587-use English qw(-no_match_vars);
2588-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
2589-
2590-use Data::Dumper;
2591-$Data::Dumper::Indent = 1;
2592-$Data::Dumper::Sortkeys = 1;
2593-$Data::Dumper::Quotekeys = 0;
2594-
2595-# This regex is partially inspired by one from pgfouine. But there is no
2596-# documentation on the last capture in that regex, so I omit that. (TODO: that
2597-# actually seems to be for CSV logging.)
2598-# (?:[0-9XPFDBLA]{2}[0-9A-Z]{3}:[\s]+)?
2599-# Here I constrain to match at least two spaces after the severity level,
2600-# because the source code tells me to. I believe this is controlled in elog.c:
2601-# appendStringInfo(&buf, "%s: ", error_severity(edata->elevel));
2602-my $log_line_regex = qr{
2603- (LOG|DEBUG|CONTEXT|WARNING|ERROR|FATAL|PANIC|HINT
2604- |DETAIL|NOTICE|STATEMENT|INFO|LOCATION)
2605- :\s\s+
2606- }x;
2607-
2608-# The following are taken right from the comments in postgresql.conf for
2609-# log_line_prefix.
2610-my %attrib_name_for = (
2611- u => 'user',
2612- d => 'db',
2613- r => 'host', # With port
2614- h => 'host',
2615- p => 'Process_id',
2616- t => 'ts',
2617- m => 'ts', # With milliseconds
2618- i => 'Query_type',
2619- c => 'Session_id',
2620- l => 'Line_no',
2621- s => 'Session_id',
2622- v => 'Vrt_trx_id',
2623- x => 'Trx_id',
2624-);
2625-
2626-# This class's data structure is a hashref with some statefulness: pending
2627-# lines. This is necessary because we sometimes don't know whether the event is
2628-# complete until we read the next line or even several lines, so we store these.
2629-#
2630-# Another bit of data that's stored in $self is some code to automatically
2631-# translate syslog into plain log format.
2632-sub new {
2633- my ( $class ) = @_;
2634- my $self = {
2635- pending => [],
2636- is_syslog => undef,
2637- next_event => undef,
2638- 'tell' => undef,
2639- };
2640- return bless $self, $class;
2641-}
2642-
2643-# This method accepts an iterator that contains an open log filehandle. It
2644-# reads events from the filehandle by calling the iterator, and returns the
2645-# events.
2646-#
2647-# Each event is a hashref of attribute => value pairs like:
2648-# my $event = {
2649-# ts => '', # Timestamp
2650-# arg => '', # Argument to the command
2651-# other attributes...
2652-# };
2653-#
2654-# The log format is ideally prefixed with the following:
2655-#
2656-# * timestamp with microseconds
2657-# * session ID, user, database
2658-#
2659-# The format I'd like to see is something like this:
2660-#
2661-# 2010-02-08 15:31:48.685 EST c=4b7074b4.985,u=user,D=database LOG:
2662-#
2663-# However, pgfouine supports user=user, db=database format. And I think
2664-# it should be reasonable to grab pretty much any name=value properties out, and
2665-# handle them based on the lower-cased first character of $name, to match the
2666-# special values that are possible to give for log_line_prefix. For example, %u
2667-# = user, so anything starting with a 'u' should be interpreted as a user.
2668-#
2669-# In general the log format is rather flexible, and we don't know by looking at
2670-# any given line whether it's the last line in the event. So we often have to
2671-# read a line and then decide what to do with the previous line we saw. Thus we
2672-# use 'pending' when necessary but we try to do it as little as possible,
2673-# because it's double work to defer and re-parse lines; and we try to defer as
2674-# soon as possible so we don't have to do as much work.
2675-#
2676-# There are 3 categories of lines in a log file, referred to in the code as case
2677-# 1/2/3:
2678-#
2679-# - Those that start a possibly multi-line event
2680-# - Those that can continue one
2681-# - Those that are neither the start nor the continuation, and thus must be the
2682-# end.
2683-#
2684-# In cases 1 and 3, we have to check whether information from previous lines has
2685-# been accumulated. If it has, we defer the current line and create the event.
2686-# Otherwise we keep going, looking for more lines for the event that begins with
2687-# the current line. Processing the lines is easiest if we arrange the cases in
2688-# this order: 2, 1, 3.
2689-#
2690-# The term "line" is to be interpreted loosely here. Logs that are in syslog
2691-# format might have multi-line "lines" that are handled by the generated
2692-# $next_event closure and given back to the main while-loop with newlines in
2693-# them. Therefore, regexes that match "the rest of the line" generally need the
2694-# /s flag.
2695-sub parse_event {
2696- my ( $self, %args ) = @_;
2697- my @required_args = qw(next_event tell);
2698- foreach my $arg ( @required_args ) {
2699- die "I need a $arg argument" unless $args{$arg};
2700- }
2701-
2702- # The subroutine references that wrap the filehandle operations.
2703- my ( $next_event, $tell, $is_syslog ) = $self->generate_wrappers(%args);
2704-
2705- # These are the properties for the log event, which will later be used to
2706- # create an event hash ref.
2707- my @properties = ();
2708-
2709- # Holds the current line being processed, and its position in the log as a
2710- # byte offset from the beginning. In some cases we'll have to reset this
2711- # position later. We'll also have to take a wait-and-see attitude towards
2712- # the $pos_in_log, so we use $new_pos to record where we're working in the
2713- # log, and $pos_in_log to record where the beginning of the current event
2714- # started.
2715- my ($pos_in_log, $line, $was_pending) = $self->get_line();
2716- my $new_pos;
2717-
2718- # Sometimes we need to accumulate some lines and then join them together.
2719- # This is used for that.
2720- my @arg_lines;
2721-
2722- # This is used to signal that an entire event has been found, and thus exit
2723- # the while loop.
2724- my $done;
2725-
2726- # This is used to signal that an event's duration has already been found.
2727- # See the sample file pg-syslog-001.txt and the test for it.
2728- my $got_duration;
2729-
2730- # Before we start, we read and discard lines until we get one with a header.
2731- # The only thing we can really count on is that a header line should have
2732- # the header in it. But, we only do this if we aren't in the middle of an
2733- # ongoing event, whose first line was pending.
2734- if ( !$was_pending && (!defined $line || $line !~ m/$log_line_regex/o) ) {
2735- PTDEBUG && _d('Skipping lines until I find a header');
2736- my $found_header;
2737- LINE:
2738- while (
2739- eval {
2740- ($new_pos, $line) = $self->get_line();
2741- defined $line;
2742- }
2743- ) {
2744- if ( $line =~ m/$log_line_regex/o ) {
2745- $pos_in_log = $new_pos;
2746- last LINE;
2747- }
2748- else {
2749- PTDEBUG && _d('Line was not a header, will fetch another');
2750- }
2751- }
2752- PTDEBUG && _d('Found a header line, now at pos_in_line', $pos_in_log);
2753- }
2754-
2755- # We need to keep the line that begins the event we're parsing.
2756- my $first_line;
2757-
2758- # This is for holding the type of the log line, which is important for
2759- # choosing the right code to run.
2760- my $line_type;
2761-
2762- # Parse each line.
2763- LINE:
2764- while ( !$done && defined $line ) {
2765-
2766- # Throw away the newline ending.
2767- chomp $line unless $is_syslog;
2768-
2769- # This while loop works with LOG lines. Other lines, such as ERROR and
2770- # so forth, need to be handled outside this loop. The exception is when
2771- # there's nothing in progress in @arg_lines, and the non-LOG line might
2772- # just be something we can get relevant info from.
2773- if ( (($line_type) = $line =~ m/$log_line_regex/o) && $line_type ne 'LOG' ) {
2774-
2775- # There's something in progress, so we abort the loop and let it be
2776- # handled specially.
2777- if ( @arg_lines ) {
2778- PTDEBUG && _d('Found a non-LOG line, exiting loop');
2779- last LINE;
2780- }
2781-
2782- # There's nothing in @arg_lines, so we save what info we can and keep
2783- # on going.
2784- else {
2785- $first_line ||= $line;
2786-
2787- # Handle ERROR and STATEMENT lines...
2788- if ( my ($e) = $line =~ m/ERROR:\s+(\S.*)\Z/s ) {
2789- push @properties, 'Error_msg', $e;
2790- PTDEBUG && _d('Found an error msg, saving and continuing');
2791- ($new_pos, $line) = $self->get_line();
2792- next LINE;
2793- }
2794-
2795- elsif ( my ($s) = $line =~ m/STATEMENT:\s+(\S.*)\Z/s ) {
2796- push @properties, 'arg', $s, 'cmd', 'Query';
2797- PTDEBUG && _d('Found a statement, finishing up event');
2798- $done = 1;
2799- last LINE;
2800- }
2801-
2802- else {
2803- PTDEBUG && _d("I don't know what to do with this line");
2804- }
2805- }
2806-
2807- }
2808-
2809- # The log isn't just queries. It also has status and informational lines
2810- # in it. We ignore these, but if we see one that's not recognized, we
2811- # warn. These types of things are better off in mk-error-log.
2812- if (
2813- $line =~ m{
2814- Address\sfamily\snot\ssupported\sby\sprotocol
2815- |archived\stransaction\slog\sfile
2816- |autovacuum:\sprocessing\sdatabase
2817- |checkpoint\srecord\sis\sat
2818- |checkpoints\sare\soccurring\stoo\sfrequently\s\(
2819- |could\snot\sreceive\sdata\sfrom\sclient
2820- |database\ssystem\sis\sready
2821- |database\ssystem\sis\sshut\sdown
2822- |database\ssystem\swas\sshut\sdown
2823- |incomplete\sstartup\spacket
2824- |invalid\slength\sof\sstartup\spacket
2825- |next\sMultiXactId:
2826- |next\stransaction\sID:
2827- |received\ssmart\sshutdown\srequest
2828- |recycled\stransaction\slog\sfile
2829- |redo\srecord\sis\sat
2830- |removing\sfile\s"
2831- |removing\stransaction\slog\sfile\s"
2832- |shutting\sdown
2833- |transaction\sID\swrap\slimit\sis
2834- }x
2835- ) {
2836- # We get the next line to process and skip the rest of the loop.
2837- PTDEBUG && _d('Skipping this line because it matches skip-pattern');
2838- ($new_pos, $line) = $self->get_line();
2839- next LINE;
2840- }
2841-
2842- # Possibly reset $first_line, depending on whether it was determined to be
2843- # junk and unset.
2844- $first_line ||= $line;
2845-
2846- # Case 2: non-header lines, optionally starting with a TAB, are a
2847- # continuation of the previous line.
2848- if ( $line !~ m/$log_line_regex/o && @arg_lines ) {
2849-
2850- if ( !$is_syslog ) {
2851- # We need to translate tabs to newlines. Weirdly, some logs (see
2852- # samples/pg-log-005.txt) have newlines without a leading tab.
2853- # Maybe it's an older log format.
2854- $line =~ s/\A\t?/\n/;
2855- }
2856-
2857- # Save the remainder.
2858- push @arg_lines, $line;
2859- PTDEBUG && _d('This was a continuation line');
2860- }
2861-
2862- # Cases 1 and 3: These lines start with some optional meta-data, and then
2863- # the $log_line_regex followed by the line's log message. The message can be
2864- # of the form "label: text....". Examples:
2865- # LOG: duration: 1.565 ms
2866- # LOG: statement: SELECT ....
2867- # LOG: duration: 1.565 ms statement: SELECT ....
2868- # In the above examples, the $label is duration, statement, and duration.
2869- elsif (
2870- my ( $sev, $label, $rest )
2871- = $line =~ m/$log_line_regex(.+?):\s+(.*)\Z/so
2872- ) {
2873- PTDEBUG && _d('Line is case 1 or case 3');
2874-
2875- # This is either a case 1 or case 3. If there's previously gathered
2876- # data in @arg_lines, it doesn't matter which -- we have to create an
2877- # event (a Query event), and we're $done. This is case 0xdeadbeef.
2878- if ( @arg_lines ) {
2879- $done = 1;
2880- PTDEBUG && _d('There are saved @arg_lines, we are done');
2881-
2882- # We shouldn't modify @properties based on $line, because $line
2883- # doesn't have anything to do with the stuff in @properties, which
2884- # is all related to the previous line(s). However, there is one
2885- # case in which the line could be part of the event: when it's a
2886- # plain 'duration' line. This happens when the statement is logged
2887- # on one line, and then the duration is logged afterwards. If this
2888- # is true, then we alter @properties, and we do NOT defer the current
2889- # line.
2890- if ( $label eq 'duration' && $rest =~ m/[0-9.]+\s+\S+\Z/ ) {
2891- if ( $got_duration ) {
2892- # Just discard the line.
2893- PTDEBUG && _d('Discarding line, duration already found');
2894- }
2895- else {
2896- push @properties, 'Query_time', $self->duration_to_secs($rest);
2897- PTDEBUG && _d("Line's duration is for previous event:", $rest);
2898- }
2899- }
2900- else {
2901- # We'll come back to this line later.
2902- $self->pending($new_pos, $line);
2903- PTDEBUG && _d('Deferred line');
2904- }
2905- }
2906-
2907- # Here we test for case 1, lines that can start a multi-line event.
2908- elsif ( $label =~ m/\A(?:duration|statement|query)\Z/ ) {
2909- PTDEBUG && _d('Case 1: start a multi-line event');
2910-
2911- # If it's a duration, then there might be a statement later on the
2912- # same line and the duration applies to that.
2913- if ( $label eq 'duration' ) {
2914-
2915- if (
2916- (my ($dur, $stmt)
2917- = $rest =~ m/([0-9.]+ \S+)\s+(?:statement|query): *(.*)\Z/s)
2918- ) {
2919- # It does, so we'll pull out the Query_time etc now, rather
2920- # than doing it later, when we might end up in the case above
2921- # (case 0xdeadbeef).
2922- push @properties, 'Query_time', $self->duration_to_secs($dur);
2923- $got_duration = 1;
2924- push @arg_lines, $stmt;
2925- PTDEBUG && _d('Duration + statement');
2926- }
2927-
2928- else {
2929- # The duration line is just junk. It's the line after a
2930- # statement, but we never saw the statement (else we'd have
2931- # fallen into 0xdeadbeef above). Discard this line and adjust
2932- # pos_in_log. See t/samples/pg-log-002.txt for an example.
2933- $first_line = undef;
2934- ($pos_in_log, $line) = $self->get_line();
2935- PTDEBUG && _d('Line applies to event we never saw, discarding');
2936- next LINE;
2937- }
2938- }
2939- else {
2940- # This isn't a duration line, it's a statement or query. Put it
2941- # onto @arg_lines for later and keep going.
2942- push @arg_lines, $rest;
2943- PTDEBUG && _d('Putting onto @arg_lines');
2944- }
2945- }
2946-
2947- # Here is case 3, lines that can't be in case 1 or 2. These surely
2948- # terminate any event that's been accumulated, and if there isn't any
2949- # such, then we just create an event without the overhead of deferring.
2950- else {
2951- $done = 1;
2952- PTDEBUG && _d('Line is case 3, event is done');
2953-
2954- # Again, if there's previously gathered data in @arg_lines, we have
2955- # to defer the current line (not touching @properties) and revisit it.
2956- if ( @arg_lines ) {
2957- $self->pending($new_pos, $line);
2958- PTDEBUG && _d('There was @arg_lines, putting line to pending');
2959- }
2960-
2961- # Otherwise we can parse the line and put it into @properties.
2962- else {
2963- PTDEBUG && _d('No need to defer, process event from this line now');
2964- push @properties, 'cmd', 'Admin', 'arg', $label;
2965-
2966- # For some kinds of log lines, we can grab extra meta-data out of
2967- # the end of the line.
2968- # LOG: connection received: host=[local]
2969- if ( $label =~ m/\A(?:dis)?connection(?: received| authorized)?\Z/ ) {
2970- push @properties, $self->get_meta($rest);
2971- }
2972-
2973- else {
2974- die "I don't understand line $line";
2975- }
2976-
2977- }
2978- }
2979-
2980- }
2981-
2982- # If the line isn't case 1, 2, or 3 I don't know what it is.
2983- else {
2984- die "I don't understand line $line";
2985- }
2986-
2987- # We get the next line to process.
2988- if ( !$done ) {
2989- ($new_pos, $line) = $self->get_line();
2990- }
2991- } # LINE
2992-
2993- # If we're at the end of the file, we finish and tell the caller we're done.
2994- if ( !defined $line ) {
2995- PTDEBUG && _d('Line not defined, at EOF; calling oktorun(0) if exists');
2996- $args{oktorun}->(0) if $args{oktorun};
2997- if ( !@arg_lines ) {
2998- PTDEBUG && _d('No saved @arg_lines either, we are all done');
2999- return undef;
3000- }
3001- }
3002-
3003- # If we got kicked out of the while loop because of a non-LOG line, we handle
3004- # that line here.
3005- if ( $line_type && $line_type ne 'LOG' ) {
3006- PTDEBUG && _d('Line is not a LOG line');
3007-
3008- # ERROR lines come in a few flavors. See t/samples/pg-log-006.txt,
3009- # t/samples/pg-syslog-002.txt, and t/samples/pg-syslog-007.txt for some
3010- # examples. The rules seem to be this: if the ERROR is followed by a
3011- # STATEMENT, and the STATEMENT's statement matches the query in
3012- # @arg_lines, then the STATEMENT message is redundant. (This can be
3013- # caused by various combos of configuration options in postgresql.conf).
3014- # However, if the ERROR's STATEMENT line doesn't match what's in
3015- # @arg_lines, then the ERROR actually starts a new event. If the ERROR is
3016- # followed by another LOG event, then the ERROR also starts a new event.
3017- if ( $line_type eq 'ERROR' ) {
3018- PTDEBUG && _d('Line is ERROR');
3019-
3020- # If there's already a statement in processing, then put aside the
3021- # current line, and peek ahead.
3022- if ( @arg_lines ) {
3023- PTDEBUG && _d('There is @arg_lines, will peek ahead one line');
3024- my ( $temp_pos, $temp_line ) = $self->get_line();
3025- my ( $type, $msg );
3026- if (
3027- defined $temp_line
3028- && ( ($type, $msg) = $temp_line =~ m/$log_line_regex(.*)/o )
3029- && ( $type ne 'STATEMENT' || $msg eq $arg_lines[-1] )
3030- ) {
3031- # Looks like the whole thing is pertaining to the current event
3032- # in progress. Add the error message to the event.
3033- PTDEBUG && _d('Error/statement line pertain to current event');
3034- push @properties, 'Error_msg', $line =~ m/ERROR:\s*(\S.*)\Z/s;
3035- if ( $type ne 'STATEMENT' ) {
3036- PTDEBUG && _d('Must save peeked line, it is a', $type);
3037- $self->pending($temp_pos, $temp_line);
3038- }
3039- }
3040- elsif ( defined $temp_line && defined $type ) {
3041- # Looks like the current and next line are about a new event.
3042- # Put them into pending.
3043- PTDEBUG && _d('Error/statement line are a new event');
3044- $self->pending($new_pos, $line);
3045- $self->pending($temp_pos, $temp_line);
3046- }
3047- else {
3048- PTDEBUG && _d("Unknown line", $line);
3049- }
3050- }
3051- }
3052- else {
3053- PTDEBUG && _d("Unknown line", $line);
3054- }
3055- }
3056-
3057- # If $done is true, then some of the above code decided that the full
3058- # event has been found. If we reached the end of the file, then we might
3059- # also have something in @arg_lines, although we didn't find the "line after"
3060- # that signals the event was done. In either case we return an event. This
3061- # should be the only 'return' statement in this block of code.
3062- if ( $done || @arg_lines ) {
3063- PTDEBUG && _d('Making event');
3064-
3065- # Finish building the event.
3066- push @properties, 'pos_in_log', $pos_in_log;
3067-
3068- # Statement/query lines will be in @arg_lines.
3069- if ( @arg_lines ) {
3070- PTDEBUG && _d('Assembling @arg_lines: ', scalar @arg_lines);
3071- push @properties, 'arg', join('', @arg_lines), 'cmd', 'Query';
3072- }
3073-
3074- if ( $first_line ) {
3075- # Handle some meta-data: a timestamp, with optional milliseconds.
3076- if ( my ($ts) = $first_line =~ m/([0-9-]{10} [0-9:.]{8,12})/ ) {
3077- PTDEBUG && _d('Getting timestamp', $ts);
3078- push @properties, 'ts', $ts;
3079- }
3080-
3081- # Find meta-data embedded in the log line prefix, in name=value format.
3082- if ( my ($meta) = $first_line =~ m/(.*?)[A-Z]{3,}: / ) {
3083- PTDEBUG && _d('Found a meta-data chunk:', $meta);
3084- push @properties, $self->get_meta($meta);
3085- }
3086- }
3087-
3088- # Dump info about what we've found, but don't dump $event; want to see
3089- # full dump of all properties, and after it's been cast into a hash,
3090- # duplicated keys will be gone.
3091- PTDEBUG && _d('Properties of event:', Dumper(\@properties));
3092- my $event = { @properties };
3093- $event->{bytes} = length($event->{arg} || '');
3094- return $event;
3095- }
3096-
3097-}
3098-
3099-# Parses key=value meta-data from the $meta string, and returns a list of event
3100-# attribute names and values.
3101-sub get_meta {
3102- my ( $self, $meta ) = @_;
3103- my @properties;
3104- foreach my $set ( $meta =~ m/(\w+=[^, ]+)/g ) {
3105- my ($key, $val) = split(/=/, $set);
3106- if ( $key && $val ) {
3107- # The first letter of the name, lowercased, determines the
3108- # meaning of the item.
3109- if ( my $prop = $attrib_name_for{lc substr($key, 0, 1)} ) {
3110- push @properties, $prop, $val;
3111- }
3112- else {
3113- PTDEBUG && _d('Bad meta key', $set);
3114- }
3115- }
3116- else {
3117- PTDEBUG && _d("Can't figure out meta from", $set);
3118- }
3119- }
3120- return @properties;
3121-}
3122-
3123-# This subroutine abstracts the process and source of getting a line of text and
3124-# its position in the log file. It might get the line of text from the log; it
3125-# might get it from the @pending array. It also does infinite loop checking
3126-# TODO.
3127-sub get_line {
3128- my ( $self ) = @_;
3129- my ($pos, $line, $was_pending) = $self->pending;
3130- if ( ! defined $line ) {
3131- PTDEBUG && _d('Got nothing from pending, trying the $fh');
3132- my ( $next_event, $tell) = @{$self}{qw(next_event tell)};
3133- eval {
3134- $pos = $tell->();
3135- $line = $next_event->();
3136- };
3137- if ( PTDEBUG && $EVAL_ERROR ) {
3138- _d($EVAL_ERROR);
3139- }
3140- }
3141-
3142- PTDEBUG && _d('Got pos/line:', $pos, $line);
3143- return ($pos, $line);
3144-}
3145-
3146-# This subroutine defers and retrieves a line/pos pair. If you give it an
3147-# argument it'll set the stored value. If not, it'll get one if there is one
3148-# and return it.
3149-sub pending {
3150- my ( $self, $val, $pos_in_log ) = @_;
3151- my $was_pending;
3152- PTDEBUG && _d('In sub pending, val:', $val);
3153- if ( $val ) {
3154- push @{$self->{pending}}, [$val, $pos_in_log];
3155- }
3156- elsif ( @{$self->{pending}} ) {
3157- ($val, $pos_in_log) = @{ shift @{$self->{pending}} };
3158- $was_pending = 1;
3159- }
3160- PTDEBUG && _d('Return from pending:', $val, $pos_in_log);
3161- return ($val, $pos_in_log, $was_pending);
3162-}
3163-
3164-# This subroutine manufactures subroutines to automatically translate incoming
3165-# syslog format into standard log format, to keep the main parse_event free from
3166-# having to think about that. For documentation on how this works, see
3167-# SysLogParser.pm.
3168-sub generate_wrappers {
3169- my ( $self, %args ) = @_;
3170-
3171- # Reset everything, just in case some cruft was left over from a previous use
3172- # of this object. The object has stateful closures. If this isn't done,
3173- # then they'll keep reading from old filehandles. The sanity check is based
3174- # on the memory address of the closure!
3175- if ( ($self->{sanity} || '') ne "$args{next_event}" ){
3176- PTDEBUG && _d("Clearing and recreating internal state");
3177- eval { require SysLogParser; }; # Required for tests to work.
3178- my $sl = new SysLogParser();
3179-
3180- # We need a special item in %args for syslog parsing. (This might not be
3181- # a syslog log file...) See the test for t/samples/pg-syslog-002.txt for
3182- # an example of when this is needed.
3183- $args{misc}->{new_event_test} = sub {
3184- my ( $content ) = @_;
3185- return unless defined $content;
3186- return $content =~ m/$log_line_regex/o;
3187- };
3188-
3189- # The TAB at the beginning of the line indicates that there's a newline
3190- # at the end of the previous line.
3191- $args{misc}->{line_filter} = sub {
3192- my ( $content ) = @_;
3193- $content =~ s/\A\t/\n/;
3194- return $content;
3195- };
3196-
3197- @{$self}{qw(next_event tell is_syslog)} = $sl->make_closures(%args);
3198- $self->{sanity} = "$args{next_event}";
3199- }
3200-
3201- # Return the wrapper functions!
3202- return @{$self}{qw(next_event tell is_syslog)};
3203-}
3204-
3205-# This subroutine converts various formats to seconds. Examples:
3206-# 10.870 ms
3207-sub duration_to_secs {
3208- my ( $self, $str ) = @_;
3209- PTDEBUG && _d('Duration:', $str);
3210- my ( $num, $suf ) = split(/\s+/, $str);
3211- my $factor = $suf eq 'ms' ? 1000
3212- : $suf eq 'sec' ? 1
3213- : die("Unknown suffix '$suf'");
3214- return $num / $factor;
3215-}
3216-
3217-sub _d {
3218- my ($package, undef, $line) = caller 0;
3219- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
3220- map { defined $_ ? $_ : 'undef' }
3221- @_;
3222- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
3223-}
3224-
3225-1;
3226-}
3227-# ###########################################################################
3228-# End PgLogParser package
3229-# ###########################################################################
3230
3231=== modified file 'lib/QueryReportFormatter.pm'
3232--- lib/QueryReportFormatter.pm 2013-01-31 17:52:34 +0000
3233+++ lib/QueryReportFormatter.pm 2013-02-01 18:19:34 +0000
3234@@ -481,9 +481,7 @@
3235 }
3236
3237 my $log_type = $args{log_type} || '';
3238- my $mark = $log_type eq 'memcached'
3239- || $log_type eq 'http'
3240- || $log_type eq 'pglog' ? '' : '\G';
3241+ my $mark = '\G';
3242
3243 if ( $item =~ m/^(?:[\(\s]*select|insert|replace)/ ) {
3244 if ( $item =~ m/^(?:insert|replace)/ ) { # No EXPLAIN
3245
3246=== removed file 'lib/SysLogParser.pm'
3247--- lib/SysLogParser.pm 2013-01-03 00:19:16 +0000
3248+++ lib/SysLogParser.pm 1970-01-01 00:00:00 +0000
3249@@ -1,259 +0,0 @@
3250-# This program is copyright 2010-2011 Baron Schwartz, 2011 Percona Ireland Ltd.
3251-# Feedback and improvements are welcome.
3252-#
3253-# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
3254-# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
3255-# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
3256-#
3257-# This program is free software; you can redistribute it and/or modify it under
3258-# the terms of the GNU General Public License as published by the Free Software
3259-# Foundation, version 2; OR the Perl Artistic License. On UNIX and similar
3260-# systems, you can issue `man perlgpl' or `man perlartistic' to read these
3261-# licenses.
3262-#
3263-# You should have received a copy of the GNU General Public License along with
3264-# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
3265-# Place, Suite 330, Boston, MA 02111-1307 USA.
3266-# ###########################################################################
3267-# SysLogParser package
3268-# ###########################################################################
3269-{
3270-# Package: SysLogParser
3271-# SysLogParser parses events from syslogs.
3272-package SysLogParser;
3273-
3274-use strict;
3275-use warnings FATAL => 'all';
3276-use English qw(-no_match_vars);
3277-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
3278-
3279-# This regex matches the message number, line number, and content of a syslog
3280-# message:
3281-# 2008 Jan 9 16:16:34 hostname postgres[30059]: [13-2] ...content...
3282-my $syslog_regex = qr{\A.*\w+\[\d+\]: \[(\d+)-(\d+)\] (.*)\Z};
3283-
3284-# This class generates currying functions that wrap around a standard
3285-# log-parser's next_event() and tell() function pointers. The wrappers behave
3286-# the same way, except that they'll return entire syslog events, instead of
3287-# lines at a time. To use it, do the following:
3288-#
3289-# sub parse_event {
3290-# my ($self, %args) = @_;
3291-# my ($next_event, $tell, $is_syslog) = SysLogParser::make_closures(%args);
3292-# # ... write your code to use the $next_event and $tell here...
3293-# }
3294-#
3295-# If the log isn't in syslog format, $is_syslog will be false and you'll get
3296-# back simple wrappers around the $next_event and $tell functions. (They still
3297-# have to be wrapped, because to find out whether the log is in syslog format,
3298-# the first line has to be examined.)
3299-sub new {
3300- my ( $class ) = @_;
3301- my $self = {};
3302- return bless $self, $class;
3303-}
3304-
3305-# This method is here so that SysLogParser can be used and tested in its own
3306-# right. However, its ability to generate wrapper functions probably means that
3307-# it should be used as a translation layer, not directly. You can use this code
3308-# as an example of how to integrate this into other packages.
3309-sub parse_event {
3310- my ( $self, %args ) = @_;
3311- my ( $next_event, $tell, $is_syslog ) = $self->generate_wrappers(%args);
3312- return $next_event->();
3313-}
3314-
3315-# This is an example of how a class can seamlessly put a syslog translation
3316-# layer underneath itself.
3317-sub generate_wrappers {
3318- my ( $self, %args ) = @_;
3319-
3320- # Reset everything, just in case some cruft was left over from a previous use
3321- # of this object. The object has stateful closures. If this isn't done,
3322- # then they'll keep reading from old filehandles. The sanity check is based
3323- # on the memory address of the closure!
3324- if ( ($self->{sanity} || '') ne "$args{next_event}" ){
3325- PTDEBUG && _d("Clearing and recreating internal state");
3326- @{$self}{qw(next_event tell is_syslog)} = $self->make_closures(%args);
3327- $self->{sanity} = "$args{next_event}";
3328- }
3329-
3330- # Return the wrapper functions!
3331- return @{$self}{qw(next_event tell is_syslog)};
3332-}
3333-
3334-# Make the closures! The $args{misc}->{new_event_test} is an optional
3335-# subroutine reference, which tells the wrapper when to consider a line part of
3336-# a new event, in syslog format, even when it's technically the same syslog
3337-# event. See the test for samples/pg-syslog-002.txt for an example. This
3338-# argument should be passed in via the call to parse_event(). Ditto for
3339-# 'line_filter', which is some processing code to run on every line of content
3340-# in an event.
3341-sub make_closures {
3342- my ( $self, %args ) = @_;
3343-
3344- # The following variables will be referred to in the manufactured
3345- # subroutines, making them proper closures.
3346- my $next_event = $args{'next_event'};
3347- my $tell = $args{'tell'};
3348- my $new_event_test = $args{'misc'}->{'new_event_test'};
3349- my $line_filter = $args{'misc'}->{'line_filter'};
3350-
3351- # The first thing to do is get a line from the log and see if it's from
3352- # syslog.
3353- my $test_line = $next_event->();
3354- PTDEBUG && _d('Read first sample/test line:', $test_line);
3355-
3356- # If it's syslog, we have to generate a moderately elaborate wrapper
3357- # function.
3358- if ( defined $test_line && $test_line =~ m/$syslog_regex/o ) {
3359-
3360- # Within syslog-parsing subroutines, we'll use LLSP (low-level syslog
3361- # parser) as a PTDEBUG line prefix.
3362- PTDEBUG && _d('This looks like a syslog line, PTDEBUG prefix=LLSP');
3363-
3364- # Grab the interesting bits out of the test line, and save the result.
3365- my ($msg_nr, $line_nr, $content) = $test_line =~ m/$syslog_regex/o;
3366- my @pending = ($test_line);
3367- my $last_msg_nr = $msg_nr;
3368- my $pos_in_log = 0;
3369-
3370- # Generate the subroutine for getting a full log message without syslog
3371- # breaking it across multiple lines.
3372- my $new_next_event = sub {
3373- PTDEBUG && _d('LLSP: next_event()');
3374-
3375- # Keeping the pos_in_log variable right is a bit tricky! In general,
3376- # we have to tell() the filehandle before trying to read from it,
3377- # getting the position before the data we've just read. The simple
3378- # rule is that when we push something onto @pending, which we almost
3379- # always do, then $pos_in_log should point to the beginning of that
3380- # saved content in the file.
3381- PTDEBUG && _d('LLSP: Current virtual $fh position:', $pos_in_log);
3382- my $new_pos = 0;
3383-
3384- # @arg_lines is where we store up the content we're about to return.
3385- # It contains $content; @pending contains a single saved $line.
3386- my @arg_lines;
3387-
3388- # Here we actually examine lines until we have found a complete event.
3389- my $line;
3390- LINE:
3391- while (
3392- defined($line = shift @pending)
3393- || do {
3394- # Save $new_pos, because when we hit EOF we can't $tell->()
3395- # anymore.
3396- eval { $new_pos = -1; $new_pos = $tell->() };
3397- defined($line = $next_event->());
3398- }
3399- ) {
3400- PTDEBUG && _d('LLSP: Line:', $line);
3401-
3402- # Parse the line.
3403- ($msg_nr, $line_nr, $content) = $line =~ m/$syslog_regex/o;
3404- if ( !$msg_nr ) {
3405- die "Can't parse line: $line";
3406- }
3407-
3408- # The message number has changed -- thus, new message.
3409- elsif ( $msg_nr != $last_msg_nr ) {
3410- PTDEBUG && _d('LLSP: $msg_nr', $last_msg_nr, '=>', $msg_nr);
3411- $last_msg_nr = $msg_nr;
3412- last LINE;
3413- }
3414-
3415- # Or, the caller gave us a custom new_event_test and it is true --
3416- # thus, also new message.
3417- elsif ( @arg_lines && $new_event_test && $new_event_test->($content) ) {
3418- PTDEBUG && _d('LLSP: $new_event_test matches');
3419- last LINE;
3420- }
3421-
3422- # Otherwise it's part of the current message; put it onto the list
3423- # of lines pending. We have to translate characters that syslog has
3424- # munged. Some translate TAB into the literal characters '^I' and
3425- # some, rsyslog on Debian anyway, seem to translate all whitespace
3426- # control characters into an octal string representing the character
3427- # code.
3428- # Example: #011FROM pg_catalog.pg_class c
3429- $content =~ s/#(\d{3})/chr(oct($1))/ge;
3430- $content =~ s/\^I/\t/g;
3431- if ( $line_filter ) {
3432- PTDEBUG && _d('LLSP: applying $line_filter');
3433- $content = $line_filter->($content);
3434- }
3435-
3436- push @arg_lines, $content;
3437- }
3438- PTDEBUG && _d('LLSP: Exited while-loop after finding a complete entry');
3439-
3440- # Mash the pending stuff together to return it.
3441- my $psql_log_event = @arg_lines ? join('', @arg_lines) : undef;
3442- PTDEBUG && _d('LLSP: Final log entry:', $psql_log_event);
3443-
3444- # Save the new content into @pending for the next time. $pos_in_log
3445- # must also be updated to whatever $new_pos is.
3446- if ( defined $line ) {
3447- PTDEBUG && _d('LLSP: Saving $line:', $line);
3448- @pending = $line;
3449- PTDEBUG && _d('LLSP: $pos_in_log:', $pos_in_log, '=>', $new_pos);
3450- $pos_in_log = $new_pos;
3451- }
3452- else {
3453- # We hit the end of the file.
3454- PTDEBUG && _d('LLSP: EOF reached');
3455- @pending = ();
3456- $last_msg_nr = 0;
3457- }
3458-
3459- return $psql_log_event;
3460- };
3461-
3462- # Create the closure for $tell->();
3463- my $new_tell = sub {
3464- PTDEBUG && _d('LLSP: tell()', $pos_in_log);
3465- return $pos_in_log;
3466- };
3467-
3468- return ($new_next_event, $new_tell, 1);
3469- }
3470-
3471- # This is either at EOF already, or it's not syslog format.
3472- else {
3473-
3474- # Within plain-log-parsing subroutines, we'll use PLAIN as a PTDEBUG
3475- # line prefix.
3476- PTDEBUG && _d('Plain log, or we are at EOF; PTDEBUG prefix=PLAIN');
3477-
3478- # The @pending array is really only needed to return the one line we
3479- # already read as a test. Too bad we can't just push it back onto the
3480- # log. TODO: maybe we can test whether the filehandle is seekable and
3481- # seek back to the start, then just return the unwrapped functions?
3482- my @pending = defined $test_line ? ($test_line) : ();
3483-
3484- my $new_next_event = sub {
3485- PTDEBUG && _d('PLAIN: next_event(); @pending:', scalar @pending);
3486- return @pending ? shift @pending : $next_event->();
3487- };
3488- my $new_tell = sub {
3489- PTDEBUG && _d('PLAIN: tell(); @pending:', scalar @pending);
3490- return @pending ? 0 : $tell->();
3491- };
3492- return ($new_next_event, $new_tell, 0);
3493- }
3494-}
3495-
3496-sub _d {
3497- my ($package, undef, $line) = caller 0;
3498- @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
3499- map { defined $_ ? $_ : 'undef' }
3500- @_;
3501- print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
3502-}
3503-
3504-1;
3505-}
3506-# ###########################################################################
3507-# End SysLogParser package
3508-# ###########################################################################
3509
3510=== modified file 'lib/TcpdumpParser.pm'
3511--- lib/TcpdumpParser.pm 2013-01-03 00:19:16 +0000
3512+++ lib/TcpdumpParser.pm 2013-02-01 18:19:34 +0000
3513@@ -172,10 +172,7 @@
3514 sub port_number {
3515 my ( $self, $port ) = @_;
3516 return unless $port;
3517- return $port eq 'memcached' ? 11211
3518- : $port eq 'http' ? 80
3519- : $port eq 'mysql' ? 3306
3520- : $port;
3521+ return $port eq 'mysql' ? 3306 : $port;
3522 }
3523
3524 sub _d {
3525
3526=== removed file 't/lib/HTTPProtocolParser.t'
3527--- t/lib/HTTPProtocolParser.t 2012-03-06 13:56:08 +0000
3528+++ t/lib/HTTPProtocolParser.t 1970-01-01 00:00:00 +0000
3529@@ -1,286 +0,0 @@
3530-#!/usr/bin/perl
3531-
3532-BEGIN {
3533- die "The PERCONA_TOOLKIT_BRANCH environment variable is not set.\n"
3534- unless $ENV{PERCONA_TOOLKIT_BRANCH} && -d $ENV{PERCONA_TOOLKIT_BRANCH};
3535- unshift @INC, "$ENV{PERCONA_TOOLKIT_BRANCH}/lib";
3536-};
3537-
3538-use strict;
3539-use warnings FATAL => 'all';
3540-use English qw(-no_match_vars);
3541-use Test::More tests => 16;
3542-
3543-use TcpdumpParser;
3544-use ProtocolParser;
3545-use HTTPProtocolParser;
3546-use PerconaTest;
3547-
3548-my $tcpdump = new TcpdumpParser();
3549-my $protocol; # Create a new HTTPProtocolParser for each test.
3550-
3551-# GET a very simple page.
3552-$protocol = new HTTPProtocolParser();
3553-test_protocol_parser(
3554- parser => $tcpdump,
3555- protocol => $protocol,
3556- file => 't/lib/samples/http/http_tcpdump001.txt',
3557- result => [
3558- { ts => '2009-11-09 11:31:52.341907',
3559- bytes => '715',
3560- host => '10.112.2.144',
3561- pos_in_log => 0,
3562- Virtual_host => 'hackmysql.com',
3563- arg => 'get hackmysql.com/contact',
3564- Status_code => '200',
3565- Query_time => '0.651419',
3566- Transmit_time => '0.000000',
3567- },
3568- ],
3569-);
3570-
3571-# Get http://www.percona.com/about-us.html
3572-$protocol = new HTTPProtocolParser();
3573-test_protocol_parser(
3574- parser => $tcpdump,
3575- protocol => $protocol,
3576- file => 't/lib/samples/http/http_tcpdump002.txt',
3577- result => [
3578- {
3579- ts => '2009-11-09 15:31:09.074855',
3580- Query_time => '0.070097',
3581- Status_code => '200',
3582- Transmit_time => '0.000720',
3583- Virtual_host => 'www.percona.com',
3584- arg => 'get www.percona.com/about-us.html',
3585- bytes => 3832,
3586- host => '10.112.2.144',
3587- pos_in_log => 206,
3588- },
3589- {
3590- ts => '2009-11-09 15:31:09.157215',
3591- Query_time => '0.068558',
3592- Status_code => '200',
3593- Transmit_time => '0.066490',
3594- Virtual_host => 'www.percona.com',
3595- arg => 'get www.percona.com/js/jquery.js',
3596- bytes => 9921,
3597- host => '10.112.2.144',
3598- pos_in_log => 16362,
3599- },
3600- {
3601- ts => '2009-11-09 15:31:09.346763',
3602- Query_time => '0.066506',
3603- Status_code => '200',
3604- Transmit_time => '0.000000',
3605- Virtual_host => 'www.percona.com',
3606- arg => 'get www.percona.com/images/menu_team.gif',
3607- bytes => 344,
3608- host => '10.112.2.144',
3609- pos_in_log => 53100,
3610- },
3611- {
3612- ts => '2009-11-09 15:31:09.373800',
3613- Query_time => '0.045442',
3614- Status_code => '200',
3615- Transmit_time => '0.000000',
3616- Virtual_host => 'www.google-analytics.com',
3617- arg => 'get www.google-analytics.com/__utm.gif?utmwv=1.3&utmn=1710381507&utmcs=UTF-8&utmsr=1280x800&utmsc=24-bit&utmul=en-us&utmje=1&utmfl=10.0%20r22&utmdt=About%20Percona&utmhn=www.percona.com&utmhid=1947703805&utmr=0&utmp=/about-us.html&utmac=UA-343802-3&utmcc=__utma%3D154442809.1969570579.1256593671.1256825719.1257805869.3%3B%2B__utmz%3D154442809.1256593671.1.1.utmccn%3D(direct)%7Cutmcsr%3D(direct)%7Cutmcmd%3D(none)%3B%2B',
3618- bytes => 35,
3619- host => '10.112.2.144',
3620- pos_in_log => 55942,
3621- },
3622- {
3623- ts => '2009-11-09 15:31:09.411349',
3624- Query_time => '0.073882',
3625- Status_code => '200',
3626- Transmit_time => '0.000000',
3627- Virtual_host => 'www.percona.com',
3628- arg => 'get www.percona.com/images/menu_our-vision.gif',
3629- bytes => 414,
3630- host => '10.112.2.144',
3631- pos_in_log => 59213,
3632- },
3633- {
3634- ts => '2009-11-09 15:31:09.420851',
3635- Query_time => '0.067669',
3636- Status_code => '200',
3637- Transmit_time => '0.000000',
3638- Virtual_host => 'www.percona.com',
3639- arg => 'get www.percona.com/images/bg-gray-corner-top.gif',
3640- bytes => 170,
3641- host => '10.112.2.144',
3642- pos_in_log => 65644,
3643- },
3644- {
3645- ts => '2009-11-09 15:31:09.420996',
3646- Query_time => '0.067345',
3647- Status_code => '200',
3648- Transmit_time => '0.134909',
3649- Virtual_host => 'www.percona.com',
3650- arg => 'get www.percona.com/images/handshake.jpg',
3651- bytes => 20017,
3652- host => '10.112.2.144',
3653- pos_in_log => 67956,
3654- },
3655- {
3656- ts => '2009-11-09 15:31:14.536149',
3657- Query_time => '0.061528',
3658- Status_code => '200',
3659- Transmit_time => '0.059577',
3660- Virtual_host => 'hit.clickaider.com',
3661- arg => 'get hit.clickaider.com/clickaider.js',
3662- bytes => 4009,
3663- host => '10.112.2.144',
3664- pos_in_log => 147447,
3665- },
3666- {
3667- ts => '2009-11-09 15:31:14.678713',
3668- Query_time => '0.060436',
3669- Status_code => '200',
3670- Transmit_time => '0.000000',
3671- Virtual_host => 'hit.clickaider.com',
3672- arg => 'get hit.clickaider.com/pv?lng=140&&lnks=&t=About%20Percona&c=73a41b95-2926&r=http%3A%2F%2Fwww.percona.com%2F&tz=-420&loc=http%3A%2F%2Fwww.percona.com%2Fabout-us.html&rnd=3688',
3673- bytes => 43,
3674- host => '10.112.2.144',
3675- pos_in_log => 167245,
3676- },
3677- {
3678- ts => '2009-11-09 15:31:14.737890',
3679- Query_time => '0.061937',
3680- Status_code => '200',
3681- Transmit_time => '0.000000',
3682- Virtual_host => 'hit.clickaider.com',
3683- arg => 'get hit.clickaider.com/s/forms.js',
3684- bytes => 822,
3685- host => '10.112.2.144',
3686- pos_in_log => 170117,
3687- },
3688- ],
3689-);
3690-
3691-# A reponse received in out of order packet.
3692-$protocol = new HTTPProtocolParser();
3693-test_protocol_parser(
3694- parser => $tcpdump,
3695- protocol => $protocol,
3696- file => 't/lib/samples/http/http_tcpdump004.txt',
3697- result => [
3698- { ts => '2009-11-12 11:27:10.757573',
3699- Query_time => '0.327356',
3700- Status_code => '200',
3701- Transmit_time => '0.549501',
3702- Virtual_host => 'dev.mysql.com',
3703- arg => 'get dev.mysql.com/common/css/mysql.css',
3704- bytes => 11283,
3705- host => '10.67.237.92',
3706- pos_in_log => 776,
3707- },
3708- ],
3709-);
3710-
3711-# A client request broken over 2 packets.
3712-$protocol = new HTTPProtocolParser();
3713-test_protocol_parser(
3714- parser => $tcpdump,
3715- protocol => $protocol,
3716- file => 't/lib/samples/http/http_tcpdump005.txt',
3717- result => [
3718- { ts => '2009-11-13 09:20:31.041924',
3719- Query_time => '0.342166',
3720- Status_code => '200',
3721- Transmit_time => '0.012780',
3722- Virtual_host => 'dev.mysql.com',
3723- arg => 'get dev.mysql.com/doc/refman/5.0/fr/retrieving-data.html',
3724- bytes => 4382,
3725- host => '192.168.200.110',
3726- pos_in_log => 785,
3727- },
3728- ],
3729-);
3730-
3731-# Out of order header that might look like the text header
3732-# but is really data; text header arrives last.
3733-$protocol = new HTTPProtocolParser();
3734-test_protocol_parser(
3735- parser => $tcpdump,
3736- protocol => $protocol,
3737- file => 't/lib/samples/http/http_tcpdump006.txt',
3738- result => [
3739- { ts => '2009-11-13 09:50:44.432099',
3740- Query_time => '0.140878',
3741- Status_code => '200',
3742- Transmit_time => '0.237153',
3743- Virtual_host => '247wallst.files.wordpress.com',
3744- arg => 'get 247wallst.files.wordpress.com/2009/11/airplane4.jpg?w=139&h=93',
3745- bytes => 3391,
3746- host => '192.168.200.110',
3747- pos_in_log => 782,
3748- },
3749- ],
3750-);
3751-
3752-# One 2.6M image that took almost a minute to load (very slow wifi).
3753-$protocol = new HTTPProtocolParser();
3754-test_protocol_parser(
3755- parser => $tcpdump,
3756- protocol => $protocol,
3757- file => 't/lib/samples/http/http_tcpdump007.txt',
3758- result => [
3759- { ts => '2009-11-13 10:09:53.251620',
3760- Query_time => '0.121971',
3761- Status_code => '200',
3762- Transmit_time => '40.311228',
3763- Virtual_host => 'apod.nasa.gov',
3764- arg => 'get apod.nasa.gov/apod/image/0911/Ophcloud_spitzer.jpg',
3765- bytes => 2706737,
3766- host => '192.168.200.110',
3767- pos_in_log => 640,
3768- }
3769- ],
3770-);
3771-
3772-# A simple POST.
3773-$protocol = new HTTPProtocolParser();
3774-test_protocol_parser(
3775- parser => $tcpdump,
3776- protocol => $protocol,
3777- file => 't/lib/samples/http/http_tcpdump008.txt',
3778- result => [
3779- { ts => '2009-11-13 10:53:48.349465',
3780- Query_time => '0.030740',
3781- Status_code => '200',
3782- Transmit_time => '0.000000',
3783- Virtual_host => 'www.google.com',
3784- arg => 'post www.google.com/finance/qs/channel?VER=6&RID=481&CVER=1&zx=5xccsz-eg9chk&t=1',
3785- bytes => 54,
3786- host => '192.168.200.110',
3787- pos_in_log => 0,
3788- }
3789- ],
3790-);
3791-
3792-# .http instead of .80
3793-$protocol = new HTTPProtocolParser();
3794-test_protocol_parser(
3795- parser => $tcpdump,
3796- protocol => $protocol,
3797- file => 't/lib/samples/http/http_tcpdump009.txt',
3798- result => [
3799- { ts => '2009-11-09 11:31:52.341907',
3800- bytes => '715',
3801- host => '10.112.2.144',
3802- pos_in_log => 0,
3803- Virtual_host => 'hackmysql.com',
3804- arg => 'get hackmysql.com/contact',
3805- Status_code => '200',
3806- Query_time => '0.651419',
3807- Transmit_time => '0.000000',
3808- },
3809- ],
3810-);
3811-
3812-# #############################################################################
3813-# Done.
3814-# #############################################################################
3815-exit;
3816
3817=== removed file 't/lib/MemcachedEvent.t'
3818--- t/lib/MemcachedEvent.t 2012-03-06 13:56:08 +0000
3819+++ t/lib/MemcachedEvent.t 1970-01-01 00:00:00 +0000
3820@@ -1,766 +0,0 @@
3821-#!/usr/bin/perl
3822-
3823-BEGIN {
3824- die "The PERCONA_TOOLKIT_BRANCH environment variable is not set.\n"
3825- unless $ENV{PERCONA_TOOLKIT_BRANCH} && -d $ENV{PERCONA_TOOLKIT_BRANCH};
3826- unshift @INC, "$ENV{PERCONA_TOOLKIT_BRANCH}/lib";
3827-};
3828-
3829-use strict;
3830-use warnings FATAL => 'all';
3831-use English qw(-no_match_vars);
3832-use Test::More tests => 15;
3833-
3834-use MemcachedEvent;
3835-use PerconaTest;
3836-
3837-my $memce = new MemcachedEvent();
3838-isa_ok($memce, 'MemcachedEvent');
3839-
3840-sub make_events {
3841- my ( @memc_events ) = @_;
3842- my @events;
3843- push @events, map { $memce->parse_event(event=>$_) } @memc_events;
3844- return \@events;
3845-}
3846-
3847-# #############################################################################
3848-# Sanity tests.
3849-# #############################################################################
3850-my $events = make_events(
3851- {
3852- key => 'my_key',
3853- val => 'Some value',
3854- res => 'STORED',
3855- Query_time => 1,
3856- },
3857-);
3858-is_deeply(
3859- $events,
3860- [],
3861- "Doesn't die when there's no cmd"
3862-);
3863-
3864-$events = make_events(
3865- {
3866- cmd => 'unknown_cmd',
3867- val => 'Some value',
3868- res => 'STORED',
3869- Query_time => 1,
3870- },
3871-);
3872-is_deeply(
3873- $events,
3874- [],
3875- "Doesn't die when there's no key"
3876-);
3877-
3878-$events = make_events(
3879- {
3880- val => 'Some value',
3881- res => 'STORED',
3882- Query_time => 1,
3883- },
3884-);
3885-is_deeply(
3886- $events,
3887- [],
3888- "Doesn't die when there's no cmd or key"
3889-);
3890-
3891-$events = make_events(
3892- {
3893- cmd => 'unknown_cmd',
3894- key => 'my_key',
3895- val => 'Some value',
3896- res => 'STORED',
3897- Query_time => 1,
3898- },
3899-);
3900-is_deeply(
3901- $events,
3902- [],
3903- "Doesn't handle unknown cmd"
3904-);
3905-
3906-# #############################################################################
3907-# These events are copied straight from the expected results in
3908-# MemcachedProtocolParser.t.
3909-# #############################################################################
3910-
3911-# A session with a simple set().
3912-$events = make_events(
3913- { ts => '2009-07-04 21:33:39.229179',
3914- host => '127.0.0.1',
3915- cmd => 'set',
3916- key => 'my_key',
3917- val => 'Some value',
3918- flags => '0',
3919- exptime => '0',
3920- bytes => '10',
3921- res => 'STORED',
3922- Query_time => sprintf('%.6f', .229299 - .229179),
3923- pos_in_log => 0,
3924- },
3925-);
3926-is_deeply(
3927- $events,
3928- [
3929- {
3930- arg => 'set my_key',
3931- fingerprint => 'set my_key',
3932- key_print => 'my_key',
3933- cmd => 'set',
3934- key => 'my_key',
3935- res => 'STORED',
3936- Memc_add => 'No',
3937- Memc_append => 'No',
3938- Memc_cas => 'No',
3939- Memc_decr => 'No',
3940- Memc_delete => 'No',
3941- Memc_error => 'No',
3942- Memc_get => 'No',
3943- Memc_gets => 'No',
3944- Memc_incr => 'No',
3945- Memc_miss => 'No',
3946- Memc_prepend => 'No',
3947- Memc_replace => 'No',
3948- Memc_set => 'Yes',
3949- Memc_miss => 'No',
3950- Memc_error => 'No',
3951- Memc_Not_Stored => 'No',
3952- Memc_Exists => 'No',
3953- Query_time => '0.000120',
3954- bytes => '10',
3955- exptime => '0',
3956- fingerprint => 'set my_key',
3957- flags => '0',
3958- host => '127.0.0.1',
3959- pos_in_log => 0,
3960- ts => '2009-07-04 21:33:39.229179',
3961- val => 'Some value'
3962- },
3963- ],
3964- 'samples/memc_tcpdump001.txt: simple set'
3965-);
3966-
3967-# A session with a simple get().
3968-$events = make_events(
3969- { Query_time => '0.000067',
3970- cmd => 'get',
3971- key => 'my_key',
3972- val => 'Some value',
3973- bytes => 10,
3974- exptime => undef,
3975- flags => 0,
3976- host => '127.0.0.1',
3977- pos_in_log => '0',
3978- res => 'VALUE',
3979- ts => '2009-07-04 22:12:06.174390'
3980- }
3981-);
3982-is_deeply(
3983- $events,
3984- [
3985- {
3986- arg => 'get my_key',
3987- fingerprint => 'get my_key',
3988- key_print => 'my_key',
3989- cmd => 'get',
3990- key => 'my_key',
3991- res => 'VALUE',
3992- Memc_add => 'No',
3993- Memc_append => 'No',
3994- Memc_cas => 'No',
3995- Memc_decr => 'No',
3996- Memc_delete => 'No',
3997- Memc_error => 'No',
3998- Memc_get => 'Yes',
3999- Memc_gets => 'No',
4000- Memc_incr => 'No',
4001- Memc_miss => 'No',
4002- Memc_prepend => 'No',
4003- Memc_replace => 'No',
4004- Memc_set => 'No',
4005- Memc_miss => 'No',
4006- Memc_error => 'No',
4007- Query_time => '0.000067',
4008- val => 'Some value',
4009- bytes => 10,
4010- exptime => undef,
4011- flags => 0,
4012- host => '127.0.0.1',
4013- pos_in_log => '0',
4014- ts => '2009-07-04 22:12:06.174390'
4015- },
4016- ],
4017- 'samples/memc_tcpdump002.txt: simple get',
4018-);
4019-
4020-# A session with a simple incr() and decr().
4021-$events = make_events(
4022- { Query_time => '0.000073',
4023- cmd => 'incr',
4024- key => 'key',
4025- val => '8',
4026- bytes => undef,
4027- exptime => undef,
4028- flags => undef,
4029- host => '127.0.0.1',
4030- pos_in_log => '0',
4031- res => '',
4032- ts => '2009-07-04 22:12:06.175734',
4033- },
4034- { Query_time => '0.000068',
4035- cmd => 'decr',
4036- bytes => undef,
4037- exptime => undef,
4038- flags => undef,
4039- host => '127.0.0.1',
4040- key => 'key',
4041- pos_in_log => 522,
4042- res => '',
4043- ts => '2009-07-04 22:12:06.176181',
4044- val => '7',
4045- },
4046-);
4047-is_deeply(
4048- $events,
4049- [
4050- {
4051- arg => 'incr key',
4052- fingerprint => 'incr key',
4053- key_print => 'key',
4054- cmd => 'incr',
4055- key => 'key',
4056- res => '',
4057- Memc_add => 'No',
4058- Memc_append => 'No',
4059- Memc_cas => 'No',
4060- Memc_decr => 'No',
4061- Memc_delete => 'No',
4062- Memc_error => 'No',
4063- Memc_get => 'No',
4064- Memc_gets => 'No',
4065- Memc_incr => 'Yes',
4066- Memc_miss => 'No',
4067- Memc_prepend => 'No',
4068- Memc_replace => 'No',
4069- Memc_set => 'No',
4070- Memc_miss => 'No',
4071- Memc_error => 'No',
4072- Query_time => '0.000073',
4073- val => '8',
4074- bytes => undef,
4075- exptime => undef,
4076- flags => undef,
4077- host => '127.0.0.1',
4078- pos_in_log => '0',
4079- ts => '2009-07-04 22:12:06.175734',
4080- },
4081- {
4082- arg => 'decr key',
4083- fingerprint => 'decr key',
4084- key_print => 'key',
4085- cmd => 'decr',
4086- key => 'key',
4087- res => '',
4088- Memc_add => 'No',
4089- Memc_append => 'No',
4090- Memc_cas => 'No',
4091- Memc_decr => 'Yes',
4092- Memc_delete => 'No',
4093- Memc_error => 'No',
4094- Memc_get => 'No',
4095- Memc_gets => 'No',
4096- Memc_incr => 'No',
4097- Memc_miss => 'No',
4098- Memc_prepend => 'No',
4099- Memc_replace => 'No',
4100- Memc_set => 'No',
4101- Memc_miss => 'No',
4102- Memc_error => 'No',
4103- Query_time => '0.000068',
4104- bytes => undef,
4105- exptime => undef,
4106- flags => undef,
4107- host => '127.0.0.1',
4108- pos_in_log => 522,
4109- ts => '2009-07-04 22:12:06.176181',
4110- val => '7',
4111- },
4112- ],
4113- 'samples/memc_tcpdump003.txt: incr and decr'
4114-);
4115-
4116-# A session with a simple incr() and decr(), but the value doesn't exist.
4117-$events = make_events(
4118- { Query_time => '0.000131',
4119- bytes => undef,
4120- cmd => 'incr',
4121- exptime => undef,
4122- flags => undef,
4123- host => '127.0.0.1',
4124- key => 'key',
4125- pos_in_log => 764,
4126- res => 'NOT_FOUND',
4127- ts => '2009-07-06 10:37:21.668469',
4128- val => '',
4129- },
4130- {
4131- Query_time => '0.000055',
4132- bytes => undef,
4133- cmd => 'decr',
4134- exptime => undef,
4135- flags => undef,
4136- host => '127.0.0.1',
4137- key => 'key',
4138- pos_in_log => 1788,
4139- res => 'NOT_FOUND',
4140- ts => '2009-07-06 10:37:21.668851',
4141- val => '',
4142- },
4143-);
4144-is_deeply(
4145- $events,
4146- [
4147- {
4148- arg => 'incr key',
4149- fingerprint => 'incr key',
4150- key_print => 'key',
4151- cmd => 'incr',
4152- key => 'key',
4153- res => 'NOT_FOUND',
4154- Memc_add => 'No',
4155- Memc_append => 'No',
4156- Memc_cas => 'No',
4157- Memc_decr => 'No',
4158- Memc_delete => 'No',
4159- Memc_error => 'No',
4160- Memc_get => 'No',
4161- Memc_gets => 'No',
4162- Memc_incr => 'Yes',
4163- Memc_miss => 'No',
4164- Memc_prepend => 'No',
4165- Memc_replace => 'No',
4166- Memc_set => 'No',
4167- Memc_miss => 'Yes',
4168- Memc_error => 'No',
4169- Query_time => '0.000131',
4170- bytes => undef,
4171- exptime => undef,
4172- flags => undef,
4173- host => '127.0.0.1',
4174- pos_in_log => 764,
4175- ts => '2009-07-06 10:37:21.668469',
4176- val => '',
4177- },
4178- {
4179- arg => 'decr key',
4180- fingerprint => 'decr key',
4181- key_print => 'key',
4182- cmd => 'decr',
4183- key => 'key',
4184- res => 'NOT_FOUND',
4185- Memc_add => 'No',
4186- Memc_append => 'No',
4187- Memc_cas => 'No',
4188- Memc_decr => 'Yes',
4189- Memc_delete => 'No',
4190- Memc_error => 'No',
4191- Memc_get => 'No',
4192- Memc_gets => 'No',
4193- Memc_incr => 'No',
4194- Memc_miss => 'No',
4195- Memc_prepend => 'No',
4196- Memc_replace => 'No',
4197- Memc_set => 'No',
4198- Memc_miss => 'Yes',
4199- Memc_error => 'No',
4200- Query_time => '0.000055',
4201- bytes => undef,
4202- exptime => undef,
4203- flags => undef,
4204- host => '127.0.0.1',
4205- pos_in_log => 1788,
4206- ts => '2009-07-06 10:37:21.668851',
4207- val => '',
4208- },
4209- ],
4210- 'samples/memc_tcpdump004.txt: incr and decr nonexistent key'
4211-);
4212-
4213-# A session with a huge set() that will not fit into a single TCP packet.
4214-$events = make_events(
4215- { Query_time => '0.003928',
4216- bytes => 17946,
4217- cmd => 'set',
4218- exptime => 0,
4219- flags => 0,
4220- host => '127.0.0.1',
4221- key => 'my_key',
4222- pos_in_log => 764,
4223- res => 'STORED',
4224- ts => '2009-07-06 22:07:14.406827',
4225- val => ('lorem ipsum dolor sit amet' x 690) . ' fini!',
4226- },
4227-);
4228-is_deeply(
4229- $events,
4230- [
4231- {
4232- arg => 'set my_key',
4233- fingerprint => 'set my_key',
4234- key_print => 'my_key',
4235- cmd => 'set',
4236- key => 'my_key',
4237- res => 'STORED',
4238- Memc_add => 'No',
4239- Memc_append => 'No',
4240- Memc_cas => 'No',
4241- Memc_decr => 'No',
4242- Memc_delete => 'No',
4243- Memc_error => 'No',
4244- Memc_get => 'No',
4245- Memc_gets => 'No',
4246- Memc_incr => 'No',
4247- Memc_miss => 'No',
4248- Memc_prepend => 'No',
4249- Memc_replace => 'No',
4250- Memc_set => 'Yes',
4251- Memc_miss => 'No',
4252- Memc_error => 'No',
4253- Memc_Not_Stored => 'No',
4254- Memc_Exists => 'No',
4255- Query_time => '0.003928',
4256- bytes => 17946,
4257- exptime => 0,
4258- flags => 0,
4259- host => '127.0.0.1',
4260- pos_in_log => 764,
4261- ts => '2009-07-06 22:07:14.406827',
4262- val => ('lorem ipsum dolor sit amet' x 690) . ' fini!',
4263- },
4264- ],
4265- 'samples/memc_tcpdump005.txt: huge set'
4266-);
4267-
4268-# A session with a huge get() that will not fit into a single TCP packet.
4269-$events = make_events(
4270- {
4271- Query_time => '0.000196',
4272- bytes => 17946,
4273- cmd => 'get',
4274- exptime => undef,
4275- flags => 0,
4276- host => '127.0.0.1',
4277- key => 'my_key',
4278- pos_in_log => 0,
4279- res => 'VALUE',
4280- ts => '2009-07-06 22:07:14.411331',
4281- val => ('lorem ipsum dolor sit amet' x 690) . ' fini!',
4282- },
4283-);
4284-is_deeply(
4285- $events,
4286- [
4287- {
4288- arg => 'get my_key',
4289- fingerprint => 'get my_key',
4290- key_print => 'my_key',
4291- cmd => 'get',
4292- key => 'my_key',
4293- res => 'VALUE',
4294- Memc_add => 'No',
4295- Memc_append => 'No',
4296- Memc_cas => 'No',
4297- Memc_decr => 'No',
4298- Memc_delete => 'No',
4299- Memc_error => 'No',
4300- Memc_get => 'Yes',
4301- Memc_gets => 'No',
4302- Memc_incr => 'No',
4303- Memc_miss => 'No',
4304- Memc_prepend => 'No',
4305- Memc_replace => 'No',
4306- Memc_set => 'No',
4307- Memc_miss => 'No',
4308- Memc_error => 'No',
4309- Query_time => '0.000196',
4310- bytes => 17946,
4311- exptime => undef,
4312- flags => 0,
4313- host => '127.0.0.1',
4314- pos_in_log => 0,
4315- ts => '2009-07-06 22:07:14.411331',
4316- val => ('lorem ipsum dolor sit amet' x 690) . ' fini!',
4317- },
4318- ],
4319- 'samples/memc_tcpdump006.txt: huge get'
4320-);
4321-
4322-# A session with a get() that doesn't exist.
4323-$events = make_events(
4324- {
4325- Query_time => '0.000016',
4326- bytes => undef,
4327- cmd => 'get',
4328- exptime => undef,
4329- flags => undef,
4330- host => '127.0.0.1',
4331- key => 'comment_v3_482685',
4332- pos_in_log => 0,
4333- res => 'NOT_FOUND',
4334- ts => '2009-06-11 21:54:49.059144',
4335- val => '',
4336- },
4337-);
4338-is_deeply(
4339- $events,
4340- [
4341- {
4342- arg => 'get comment_v3_482685',
4343- fingerprint => 'get comment_v?_?',
4344- key_print => 'comment_v?_?',
4345- cmd => 'get',
4346- key => 'comment_v3_482685',
4347- res => 'NOT_FOUND',
4348- Memc_add => 'No',
4349- Memc_append => 'No',
4350- Memc_cas => 'No',
4351- Memc_decr => 'No',
4352- Memc_delete => 'No',
4353- Memc_error => 'No',
4354- Memc_get => 'Yes',
4355- Memc_gets => 'No',
4356- Memc_incr => 'No',
4357- Memc_miss => 'No',
4358- Memc_prepend => 'No',
4359- Memc_replace => 'No',
4360- Memc_set => 'No',
4361- Memc_miss => 'Yes',
4362- Memc_error => 'No',
4363- Query_time => '0.000016',
4364- bytes => undef,
4365- exptime => undef,
4366- flags => undef,
4367- host => '127.0.0.1',
4368- pos_in_log => 0,
4369- ts => '2009-06-11 21:54:49.059144',
4370- val => '',
4371- },
4372- ],
4373- 'samples/memc_tcpdump007.txt: get nonexistent key'
4374-);
4375-
4376-# A session with a huge get() that will not fit into a single TCP packet, but
4377-# the connection seems to be broken in the middle of the receive and then the
4378-# new client picks up and asks for something different.
4379-$events = make_events(
4380- {
4381- Query_time => '0.000003',
4382- bytes => 17946,
4383- cmd => 'get',
4384- exptime => undef,
4385- flags => 0,
4386- host => '127.0.0.1',
4387- key => 'my_key',
4388- pos_in_log => 0,
4389- res => 'INTERRUPTED',
4390- ts => '2009-07-06 22:07:14.411331',
4391- val => '',
4392- },
4393- { Query_time => '0.000001',
4394- cmd => 'get',
4395- key => 'my_key',
4396- val => 'Some value',
4397- bytes => 10,
4398- exptime => undef,
4399- flags => 0,
4400- host => '127.0.0.1',
4401- pos_in_log => 5382,
4402- res => 'VALUE',
4403- ts => '2009-07-06 22:07:14.411334',
4404- },
4405-);
4406-is_deeply(
4407- $events,
4408- [
4409- {
4410- arg => 'get my_key',
4411- fingerprint => 'get my_key',
4412- key_print => 'my_key',
4413- cmd => 'get',
4414- key => 'my_key',
4415- res => 'INTERRUPTED',
4416- Memc_add => 'No',
4417- Memc_append => 'No',
4418- Memc_cas => 'No',
4419- Memc_decr => 'No',
4420- Memc_delete => 'No',
4421- Memc_error => 'No',
4422- Memc_get => 'Yes',
4423- Memc_gets => 'No',
4424- Memc_incr => 'No',
4425- Memc_miss => 'No',
4426- Memc_prepend => 'No',
4427- Memc_replace => 'No',
4428- Memc_set => 'No',
4429- Memc_miss => 'No',
4430- Memc_error => 'Yes',
4431- Query_time => '0.000003',
4432- bytes => 17946,
4433- exptime => undef,
4434- flags => 0,
4435- host => '127.0.0.1',
4436- pos_in_log => 0,
4437- ts => '2009-07-06 22:07:14.411331',
4438- val => '',
4439- },
4440- {
4441- arg => 'get my_key',
4442- fingerprint => 'get my_key',
4443- key_print => 'my_key',
4444- cmd => 'get',
4445- key => 'my_key',
4446- res => 'VALUE',
4447- Memc_add => 'No',
4448- Memc_append => 'No',
4449- Memc_cas => 'No',
4450- Memc_decr => 'No',
4451- Memc_delete => 'No',
4452- Memc_error => 'No',
4453- Memc_get => 'Yes',
4454- Memc_gets => 'No',
4455- Memc_incr => 'No',
4456- Memc_miss => 'No',
4457- Memc_prepend => 'No',
4458- Memc_replace => 'No',
4459- Memc_set => 'No',
4460- Memc_miss => 'No',
4461- Memc_error => 'No',
4462- Query_time => '0.000001',
4463- val => 'Some value',
4464- bytes => 10,
4465- exptime => undef,
4466- flags => 0,
4467- host => '127.0.0.1',
4468- pos_in_log => 5382,
4469- ts => '2009-07-06 22:07:14.411334',
4470- },
4471- ],
4472- 'samples/memc_tcpdump008.txt: interrupted huge get'
4473-);
4474-
4475-# A session with a delete() that doesn't exist. TODO: delete takes a queue_time.
4476-$events = make_events(
4477- {
4478- Query_time => '0.000022',
4479- bytes => undef,
4480- cmd => 'delete',
4481- exptime => undef,
4482- flags => undef,
4483- host => '127.0.0.1',
4484- key => 'comment_1873527',
4485- pos_in_log => 0,
4486- res => 'NOT_FOUND',
4487- ts => '2009-06-11 21:54:52.244534',
4488- val => '',
4489- },
4490-);
4491-is_deeply(
4492- $events,
4493- [
4494- {
4495- arg => 'delete comment_1873527',
4496- fingerprint => 'delete comment_?',
4497- key_print => 'comment_?',
4498- cmd => 'delete',
4499- key => 'comment_1873527',
4500- res => 'NOT_FOUND',
4501- Memc_add => 'No',
4502- Memc_append => 'No',
4503- Memc_cas => 'No',
4504- Memc_decr => 'No',
4505- Memc_delete => 'Yes',
4506- Memc_error => 'No',
4507- Memc_get => 'No',
4508- Memc_gets => 'No',
4509- Memc_incr => 'No',
4510- Memc_miss => 'No',
4511- Memc_prepend => 'No',
4512- Memc_replace => 'No',
4513- Memc_set => 'No',
4514- Memc_miss => 'Yes',
4515- Memc_error => 'No',
4516- Query_time => '0.000022',
4517- bytes => undef,
4518- exptime => undef,
4519- flags => undef,
4520- host => '127.0.0.1',
4521- pos_in_log => 0,
4522- ts => '2009-06-11 21:54:52.244534',
4523- val => '',
4524- },
4525- ],
4526- 'samples/memc_tcpdump009.txt: delete nonexistent key'
4527-);
4528-
4529-# A session with a delete() that does exist.
4530-$events = make_events(
4531- {
4532- Query_time => '0.000120',
4533- bytes => undef,
4534- cmd => 'delete',
4535- exptime => undef,
4536- flags => undef,
4537- host => '127.0.0.1',
4538- key => 'my_key',
4539- pos_in_log => 0,
4540- res => 'DELETED',
4541- ts => '2009-07-09 22:00:29.066476',
4542- val => '',
4543- },
4544-);
4545-is_deeply(
4546- $events,
4547- [
4548- {
4549- arg => 'delete my_key',
4550- fingerprint => 'delete my_key',
4551- key_print => 'my_key',
4552- cmd => 'delete',
4553- key => 'my_key',
4554- res => 'DELETED',
4555- Memc_add => 'No',
4556- Memc_append => 'No',
4557- Memc_cas => 'No',
4558- Memc_decr => 'No',
4559- Memc_delete => 'Yes',
4560- Memc_error => 'No',
4561- Memc_get => 'No',
4562- Memc_gets => 'No',
4563- Memc_incr => 'No',
4564- Memc_miss => 'No',
4565- Memc_prepend => 'No',
4566- Memc_replace => 'No',
4567- Memc_set => 'No',
4568- Memc_miss => 'No',
4569- Memc_error => 'No',
4570- Query_time => '0.000120',
4571- bytes => undef,
4572- exptime => undef,
4573- flags => undef,
4574- host => '127.0.0.1',
4575- pos_in_log => 0,
4576- ts => '2009-07-09 22:00:29.066476',
4577- val => '',
4578- },
4579- ],
4580- 'samples/memc_tcpdump010.txt: simple delete'
4581-);
4582-
4583-# #############################################################################
4584-# Done.
4585-# #############################################################################
4586-exit;
4587
4588=== removed file 't/lib/MemcachedProtocolParser.t'
4589--- t/lib/MemcachedProtocolParser.t 2012-03-06 13:56:08 +0000
4590+++ t/lib/MemcachedProtocolParser.t 1970-01-01 00:00:00 +0000
4591@@ -1,414 +0,0 @@
4592-#!/usr/bin/perl
4593-
4594-BEGIN {
4595- die "The PERCONA_TOOLKIT_BRANCH environment variable is not set.\n"
4596- unless $ENV{PERCONA_TOOLKIT_BRANCH} && -d $ENV{PERCONA_TOOLKIT_BRANCH};
4597- unshift @INC, "$ENV{PERCONA_TOOLKIT_BRANCH}/lib";
4598-};
4599-
4600-use strict;
4601-use warnings FATAL => 'all';
4602-use English qw(-no_match_vars);
4603-use Test::More tests => 28;
4604-
4605-use MemcachedProtocolParser;
4606-use TcpdumpParser;
4607-use PerconaTest;
4608-
4609-my $tcpdump = new TcpdumpParser();
4610-my $protocol; # Create a new MemcachedProtocolParser for each test.
4611-
4612-# A session with a simple set().
4613-$protocol = new MemcachedProtocolParser();
4614-test_protocol_parser(
4615- parser => $tcpdump,
4616- protocol => $protocol,
4617- file => 't/lib/samples/memcached/memc_tcpdump001.txt',
4618- result => [
4619- { ts => '2009-07-04 21:33:39.229179',
4620- host => '127.0.0.1',
4621- cmd => 'set',
4622- key => 'my_key',
4623- val => 'Some value',
4624- flags => '0',
4625- exptime => '0',
4626- bytes => '10',
4627- res => 'STORED',
4628- Query_time => sprintf('%.6f', .229299 - .229179),
4629- pos_in_log => 0,
4630- },
4631- ],
4632-);
4633-
4634-# A session with a simple get().
4635-$protocol = new MemcachedProtocolParser();
4636-test_protocol_parser(
4637- parser => $tcpdump,
4638- protocol => $protocol,
4639- file => 't/lib/samples/memcached/memc_tcpdump002.txt',
4640- result => [
4641- { Query_time => '0.000067',
4642- cmd => 'get',
4643- key => 'my_key',
4644- val => 'Some value',
4645- bytes => 10,
4646- exptime => 0,
4647- flags => 0,
4648- host => '127.0.0.1',
4649- pos_in_log => '0',
4650- res => 'VALUE',
4651- ts => '2009-07-04 22:12:06.174390'
4652- },
4653- ],
4654-);
4655-
4656-# A session with a simple incr() and decr().
4657-$protocol = new MemcachedProtocolParser();
4658-test_protocol_parser(
4659- parser => $tcpdump,
4660- protocol => $protocol,
4661- file => 't/lib/samples/memcached/memc_tcpdump003.txt',
4662- result => [
4663- { Query_time => '0.000073',
4664- cmd => 'incr',
4665- key => 'key',
4666- val => '8',
4667- bytes => 0,
4668- exptime => 0,
4669- flags => 0,
4670- host => '127.0.0.1',
4671- pos_in_log => '0',
4672- res => '',
4673- ts => '2009-07-04 22:12:06.175734',
4674- },
4675- { Query_time => '0.000068',
4676- cmd => 'decr',
4677- bytes => 0,
4678- exptime => 0,
4679- flags => 0,
4680- host => '127.0.0.1',
4681- key => 'key',
4682- pos_in_log => 522,
4683- res => '',
4684- ts => '2009-07-04 22:12:06.176181',
4685- val => '7',
4686- },
4687- ],
4688-);
4689-
4690-# A session with a simple incr() and decr(), but the value doesn't exist.
4691-$protocol = new MemcachedProtocolParser();
4692-test_protocol_parser(
4693- parser => $tcpdump,
4694- protocol => $protocol,
4695- file => 't/lib/samples/memcached/memc_tcpdump004.txt',
4696- result => [
4697- { Query_time => '0.000131',
4698- bytes => 0,
4699- cmd => 'incr',
4700- exptime => 0,
4701- flags => 0,
4702- host => '127.0.0.1',
4703- key => 'key',
4704- pos_in_log => 764,
4705- res => 'NOT_FOUND',
4706- ts => '2009-07-06 10:37:21.668469',
4707- val => '',
4708- },
4709- {
4710- Query_time => '0.000055',
4711- bytes => 0,
4712- cmd => 'decr',
4713- exptime => 0,
4714- flags => 0,
4715- host => '127.0.0.1',
4716- key => 'key',
4717- pos_in_log => 1788,
4718- res => 'NOT_FOUND',
4719- ts => '2009-07-06 10:37:21.668851',
4720- val => '',
4721- },
4722- ],
4723-);
4724-
4725-# A session with a huge set() that will not fit into a single TCP packet.
4726-$protocol = new MemcachedProtocolParser();
4727-test_protocol_parser(
4728- parser => $tcpdump,
4729- protocol => $protocol,
4730- file => 't/lib/samples/memcached/memc_tcpdump005.txt',
4731- result => [
4732- { Query_time => '0.003928',
4733- bytes => 17946,
4734- cmd => 'set',
4735- exptime => 0,
4736- flags => 0,
4737- host => '127.0.0.1',
4738- key => 'my_key',
4739- pos_in_log => 764,
4740- res => 'STORED',
4741- ts => '2009-07-06 22:07:14.406827',
4742- val => ('lorem ipsum dolor sit amet' x 690) . ' fini!',
4743- },
4744- ],
4745-);
4746-
4747-# A session with a huge get() that will not fit into a single TCP packet.
4748-$protocol = new MemcachedProtocolParser();
4749-test_protocol_parser(
4750- parser => $tcpdump,
4751- protocol => $protocol,
4752- file => 't/lib/samples/memcached/memc_tcpdump006.txt',
4753- result => [
4754- {
4755- Query_time => '0.000196',
4756- bytes => 17946,
4757- cmd => 'get',
4758- exptime => 0,
4759- flags => 0,
4760- host => '127.0.0.1',
4761- key => 'my_key',
4762- pos_in_log => 0,
4763- res => 'VALUE',
4764- ts => '2009-07-06 22:07:14.411331',
4765- val => ('lorem ipsum dolor sit amet' x 690) . ' fini!',
4766- },
4767- ],
4768-);
4769-
4770-# A session with a get() that doesn't exist.
4771-$protocol = new MemcachedProtocolParser();
4772-test_protocol_parser(
4773- parser => $tcpdump,
4774- protocol => $protocol,
4775- file => 't/lib/samples/memcached/memc_tcpdump007.txt',
4776- result => [
4777- {
4778- Query_time => '0.000016',
4779- bytes => 0,
4780- cmd => 'get',
4781- exptime => 0,
4782- flags => 0,
4783- host => '127.0.0.1',
4784- key => 'comment_v3_482685',
4785- pos_in_log => 0,
4786- res => 'NOT_FOUND',
4787- ts => '2009-06-11 21:54:49.059144',
4788- val => '',
4789- },
4790- ],
4791-);
4792-
4793-# A session with a huge get() that will not fit into a single TCP packet, but
4794-# the connection seems to be broken in the middle of the receive and then the
4795-# new client picks up and asks for something different.
4796-$protocol = new MemcachedProtocolParser();
4797-test_protocol_parser(
4798- parser => $tcpdump,
4799- protocol => $protocol,
4800- file => 't/lib/samples/memcached/memc_tcpdump008.txt',
4801- result => [
4802- {
4803- Query_time => '0.000003',
4804- bytes => 17946,
4805- cmd => 'get',
4806- exptime => 0,
4807- flags => 0,
4808- host => '127.0.0.1',
4809- key => 'my_key',
4810- pos_in_log => 0,
4811- res => 'INTERRUPTED',
4812- ts => '2009-07-06 22:07:14.411331',
4813- val => '',
4814- },
4815- { Query_time => '0.000001',
4816- cmd => 'get',
4817- key => 'my_key',
4818- val => 'Some value',
4819- bytes => 10,
4820- exptime => 0,
4821- flags => 0,
4822- host => '127.0.0.1',
4823- pos_in_log => 5382,
4824- res => 'VALUE',
4825- ts => '2009-07-06 22:07:14.411334',
4826- },
4827- ],
4828-);
4829-
4830-# A session with a delete() that doesn't exist. TODO: delete takes a queue_time.
4831-$protocol = new MemcachedProtocolParser();
4832-test_protocol_parser(
4833- parser => $tcpdump,
4834- protocol => $protocol,
4835- file => 't/lib/samples/memcached/memc_tcpdump009.txt',
4836- result => [
4837- {
4838- Query_time => '0.000022',
4839- bytes => 0,
4840- cmd => 'delete',
4841- exptime => 0,
4842- flags => 0,
4843- host => '127.0.0.1',
4844- key => 'comment_1873527',
4845- pos_in_log => 0,
4846- res => 'NOT_FOUND',
4847- ts => '2009-06-11 21:54:52.244534',
4848- val => '',
4849- },
4850- ],
4851-);
4852-
4853-# A session with a delete() that does exist.
4854-$protocol = new MemcachedProtocolParser();
4855-test_protocol_parser(
4856- parser => $tcpdump,
4857- protocol => $protocol,
4858- file => 't/lib/samples/memcached/memc_tcpdump010.txt',
4859- result => [
4860- {
4861- Query_time => '0.000120',
4862- bytes => 0,
4863- cmd => 'delete',
4864- exptime => 0,
4865- flags => 0,
4866- host => '127.0.0.1',
4867- key => 'my_key',
4868- pos_in_log => 0,
4869- res => 'DELETED',
4870- ts => '2009-07-09 22:00:29.066476',
4871- val => '',
4872- },
4873- ],
4874-);
4875-
4876-# #############################################################################
4877-# Issue 537: MySQLProtocolParser and MemcachedProtocolParser do not handle
4878-# multiple servers.
4879-# #############################################################################
4880-$protocol = new MemcachedProtocolParser();
4881-test_protocol_parser(
4882- parser => $tcpdump,
4883- protocol => $protocol,
4884- file => 't/lib/samples/memcached/memc_tcpdump011.txt',
4885- result => [
4886- { Query_time => '0.000067',
4887- cmd => 'get',
4888- key => 'my_key',
4889- val => 'Some value',
4890- bytes => 10,
4891- exptime => 0,
4892- flags => 0,
4893- host => '127.0.0.8',
4894- pos_in_log => '0',
4895- res => 'VALUE',
4896- ts => '2009-07-04 22:12:06.174390'
4897- },
4898- { ts => '2009-07-04 21:33:39.229179',
4899- host => '127.0.0.9',
4900- cmd => 'set',
4901- key => 'my_key',
4902- val => 'Some value',
4903- flags => '0',
4904- exptime => '0',
4905- bytes => '10',
4906- res => 'STORED',
4907- Query_time => sprintf('%.6f', .229299 - .229179),
4908- pos_in_log => 638,
4909- },
4910- ],
4911-);
4912-
4913-# #############################################################################
4914-# Issue 544: memcached parse error
4915-# #############################################################################
4916-
4917-# Multiple delete in one packet.
4918-$protocol = new MemcachedProtocolParser();
4919-test_protocol_parser(
4920- parser => $tcpdump,
4921- protocol => $protocol,
4922- file => 't/lib/samples/memcached/memc_tcpdump014.txt',
4923- result => [
4924- { ts => '2009-10-06 10:31:56.323538',
4925- Query_time => '0.000024',
4926- bytes => 0,
4927- cmd => 'delete',
4928- exptime => 0,
4929- flags => 0,
4930- host => '10.0.0.5',
4931- key => 'ABBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBC',
4932- pos_in_log => 0,
4933- res => 'NOT_FOUND',
4934- val => ''
4935- },
4936- ],
4937-);
4938-
4939-# Multiple mixed commands: get delete delete
4940-$protocol = new MemcachedProtocolParser();
4941-test_protocol_parser(
4942- parser => $tcpdump,
4943- protocol => $protocol,
4944- file => 't/lib/samples/memcached/memc_tcpdump015.txt',
4945- result => [
4946- { ts => '2009-10-06 10:31:56.330709',
4947- Query_time => '0.000013',
4948- bytes => 0,
4949- cmd => 'get',
4950- exptime => 0,
4951- flags => 0,
4952- host => '10.0.0.5',
4953- key => 'ABBBBBBBBBBBBBBBBBBBBBC',
4954- pos_in_log => 0,
4955- res => 'NOT_FOUND',
4956-
4957- val => ''
4958- },
4959- ],
4960-);
4961-
4962-
4963-# #############################################################################
4964-# Issue 818: mk-query-digest: error parsing memcached dump - use of
4965-# uninitialized value in addition
4966-# #############################################################################
4967-
4968-# A replace command.
4969-$protocol = new MemcachedProtocolParser();
4970-test_protocol_parser(
4971- parser => $tcpdump,
4972- protocol => $protocol,
4973- file => 't/lib/samples/memcached/memc_tcpdump016.txt',
4974- result => [
4975- { ts => '2010-01-20 10:27:18.510727',
4976- Query_time => '0.000030',
4977- bytes => 56,
4978- cmd => 'replace',
4979- exptime => '43200',
4980- flags => '1',
4981- host => '192.168.0.3',
4982- key => 'BD_Uk_cms__20100120_095702tab_containerId_410',
4983- pos_in_log => 0,
4984- res => 'STORED',
4985- val => 'a:3:{i:0;s:6:"a:0:{}";i:1;i:1263983238;i:2;s:5:"43200";}'
4986- },
4987- { ts => '2010-01-20 10:27:18.510876',
4988- Query_time => '0.000066',
4989- bytes => '56',
4990- cmd => 'get',
4991- exptime => 0,
4992- flags => '1',
4993- host => '192.168.0.3',
4994- key => 'BD_Uk_cms__20100120_095702tab_containerId_410',
4995- pos_in_log => 893,
4996- res => 'VALUE',
4997- val => 'a:3:{i:0;s:6:"a:0:{}";i:1;i:1263983238;i:2;s:5:"43200";}'
4998- }
4999- ],
5000-);
The diff has been truncated for viewing.

Subscribers

People subscribed via source and target branches