2
use warnings FATAL => 'all';
6
# This program is copyright (c) 2006 Baron Schwartz, baron at xaprb dot com.
7
# Feedback and improvements are gratefully received.
9
# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
10
# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
11
# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
13
# This program is free software; you can redistribute it and/or modify it under
14
# the terms of the GNU General Public License as published by the Free Software
15
# Foundation, version 2; OR the Perl Artistic License. On UNIX and similar
16
# systems, you can issue `man perlgpl' or `man perlartistic' to read these
18
# You should have received a copy of the GNU General Public License along with
19
# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
20
# Place, Suite 330, Boston, MA 02111-1307 USA
22
our $VERSION = '1.6.0';
25
$Data::Dumper::Sortkeys = 1;
26
use English qw(-no_match_vars);
27
use List::Util qw(max);
29
# Some common patterns
30
my $d = qr/(\d+)/; # Digit
31
my $f = qr/(\d+\.\d+)/; # Float
32
my $t = qr/(\d+ \d+)/; # Transaction ID
33
my $i = qr/((?:\d{1,3}\.){3}\d+)/; # IP address
34
my $n = qr/([^`\s]+)/; # MySQL object name
35
my $w = qr/(\w+)/; # Words
36
my $fl = qr/([\w\.\/]+) line $d/; # Filename and line number
37
my $h = qr/((?:0x)?[0-9a-f]*)/; # Hex
38
my $s = qr/(\d{6} .\d:\d\d:\d\d)/; # InnoDB timestamp
40
# If you update this variable, also update the SYNOPSIS in the pod.
41
my %innodb_section_headers = (
42
"TRANSACTIONS" => "tx",
43
"BUFFER POOL AND MEMORY" => "bp",
46
"ROW OPERATIONS" => "ro",
47
"INSERT BUFFER AND ADAPTIVE HASH INDEX" => "ib",
49
"LATEST DETECTED DEADLOCK" => "dl",
50
"LATEST FOREIGN KEY ERROR" => "fk",
54
tx => \&parse_tx_section,
55
bp => \&parse_bp_section,
56
sm => \&parse_sm_section,
57
lg => \&parse_lg_section,
58
ro => \&parse_ro_section,
59
ib => \&parse_ib_section,
60
io => \&parse_io_section,
61
dl => \&parse_dl_section,
62
fk => \&parse_fk_section,
66
Transaction => \&parse_fk_transaction_error,
67
Error => \&parse_fk_bad_constraint_error,
68
Cannot => \&parse_fk_cant_drop_parent_error,
71
# A thread's proc_info can be at least 98 different things I've found in the
72
# source. Fortunately, most of them begin with a gerunded verb. These are
73
# the ones that don't.
76
'Execution of init_command' => 1,
77
'FULLTEXT initialization' => 1,
80
'Repair with keycache' => 1,
83
'Thread initialized' => 1,
85
'copy to tmp table' => 1,
86
'discard_or_import_tablespace' => 1,
88
'got handler lock' => 1,
95
'rename result table' => 1,
108
# Parse the status and return it.
109
# See srv_printf_innodb_monitor in innobase/srv/srv0srv.c
110
# Pass in the text to parse, whether to be in debugging mode, which sections
111
# to parse (hashref; if empty, parse all), and whether to parse full info from
112
# locks and such (probably shouldn't unless you need to).
113
sub parse_status_text {
114
my ( $self, $fulltext, $debug, $sections, $full ) = @_;
116
die "I can't parse undef" unless defined $fulltext;
117
$fulltext =~ s/[\r\n]+/\n/g;
120
die '$sections must be a hashref' unless ref($sections) eq 'HASH';
123
got_all => 0, # Whether I was able to get the whole thing
124
ts => '', # Timestamp the server put on it
125
last_secs => 0, # Num seconds the averages are over
126
sections => {}, # Parsed values from each section
130
$innodb_data{'fulltext'} = $fulltext;
133
# Get the most basic info about the status: beginning and end, and whether
134
# I got the whole thing (if there has been a big deadlock and there are
135
# too many locks to print, the output might be truncated)
136
my ( $time_text ) = $fulltext =~ m/^$s INNODB MONITOR OUTPUT$/m;
137
$innodb_data{'ts'} = [ parse_innodb_timestamp( $time_text ) ];
138
$innodb_data{'timestring'} = ts_to_string($innodb_data{'ts'});
139
( $innodb_data{'last_secs'} ) = $fulltext
140
=~ m/Per second averages calculated from the last $d seconds/;
142
( my $got_all ) = $fulltext =~ m/END OF INNODB MONITOR OUTPUT/;
143
$innodb_data{'got_all'} = $got_all || 0;
145
# Split it into sections. Each section begins with
150
my @matches = $fulltext
151
=~ m#\n(---+)\n([A-Z /]+)\n\1\n(.*?)(?=\n(---+)\n[A-Z /]+\n\4\n|$)#gs;
152
while ( my ( $start, $name, $text, $end ) = splice(@matches, 0, 4) ) {
153
$innodb_sections{$name} = [ $text, $end ? 1 : 0 ];
155
# The Row Operations section is a special case, because instead of ending
156
# with the beginning of another section, it ends with the end of the file.
157
# So this section is complete if the entire file is complete.
158
$innodb_sections{'ROW OPERATIONS'}->[1] ||= $innodb_data{'got_all'};
160
# Just for sanity's sake, make sure I understand what to do with each
163
foreach my $section ( keys %innodb_sections ) {
164
my $header = $innodb_section_headers{$section};
165
die "Unknown section $section in $fulltext\n"
167
$innodb_data{'sections'}->{ $header }
168
->{'fulltext'} = $innodb_sections{$section}->[0];
169
$innodb_data{'sections'}->{ $header }
170
->{'complete'} = $innodb_sections{$section}->[1];
174
_debug( $debug, $EVAL_ERROR);
177
# ################################################################
178
# Parse the detailed data out of the sections.
179
# ################################################################
181
foreach my $section ( keys %parser_for ) {
182
if ( defined $innodb_data{'sections'}->{$section}
183
&& (!%$sections || (defined($sections->{$section} && $sections->{$section})) )) {
184
$parser_for{$section}->(
185
$innodb_data{'sections'}->{$section},
186
$innodb_data{'sections'}->{$section}->{'complete'},
189
or delete $innodb_data{'sections'}->{$section};
192
delete $innodb_data{'sections'}->{$section};
197
_debug( $debug, $EVAL_ERROR);
200
return \%innodb_data;
203
# Parses the status text and returns it flattened out as a single hash.
204
sub get_status_hash {
205
my ( $self, $fulltext, $debug, $sections, $full ) = @_;
207
# Parse the status text...
209
= $self->parse_status_text($fulltext, $debug, $sections, $full );
211
# Flatten the hierarchical structure into a single list by grabbing desired
214
(map { 'IB_' . $_ => $innodb_status->{$_} } qw(timestring last_secs got_all)),
215
(map { 'IB_bp_' . $_ => $innodb_status->{'sections'}->{'bp'}->{$_} }
216
qw( writes_pending buf_pool_hit_rate total_mem_alloc buf_pool_reads
217
awe_mem_alloc pages_modified writes_pending_lru page_creates_sec
218
reads_pending pages_total buf_pool_hits writes_pending_single_page
219
page_writes_sec pages_read pages_written page_reads_sec
220
writes_pending_flush_list buf_pool_size add_pool_alloc
221
dict_mem_alloc pages_created buf_free complete )),
222
(map { 'IB_tx_' . $_ => $innodb_status->{'sections'}->{'tx'}->{$_} }
223
qw( num_lock_structs history_list_len purge_done_for transactions
224
purge_undo_for is_truncated trx_id_counter complete )),
225
(map { 'IB_ib_' . $_ => $innodb_status->{'sections'}->{'ib'}->{$_} }
226
qw( hash_table_size hash_searches_s non_hash_searches_s
227
bufs_in_node_heap used_cells size free_list_len seg_size inserts
228
merged_recs merges complete )),
229
(map { 'IB_lg_' . $_ => $innodb_status->{'sections'}->{'lg'}->{$_} }
230
qw( log_ios_done pending_chkp_writes last_chkp log_ios_s
231
log_flushed_to log_seq_no pending_log_writes complete )),
232
(map { 'IB_sm_' . $_ => $innodb_status->{'sections'}->{'sm'}->{$_} }
233
qw( wait_array_size rw_shared_spins rw_excl_os_waits mutex_os_waits
234
mutex_spin_rounds mutex_spin_waits rw_excl_spins rw_shared_os_waits
235
waits signal_count reservation_count complete )),
236
(map { 'IB_ro_' . $_ => $innodb_status->{'sections'}->{'ro'}->{$_} }
237
qw( queries_in_queue n_reserved_extents main_thread_state
238
main_thread_proc_no main_thread_id read_sec del_sec upd_sec ins_sec
239
read_views_open num_rows_upd num_rows_ins num_rows_read
240
queries_inside num_rows_del complete )),
241
(map { 'IB_fk_' . $_ => $innodb_status->{'sections'}->{'fk'}->{$_} }
242
qw( trigger parent_table child_index parent_index attempted_op
243
child_db timestring fk_name records col_name reason txn parent_db
244
type child_table parent_col complete )),
245
(map { 'IB_io_' . $_ => $innodb_status->{'sections'}->{'io'}->{$_} }
246
qw( pending_buffer_pool_flushes pending_pwrites pending_preads
247
pending_normal_aio_reads fsyncs_s os_file_writes pending_sync_ios
248
reads_s flush_type avg_bytes_s pending_ibuf_aio_reads writes_s
249
threads os_file_reads pending_aio_writes pending_log_ios os_fsyncs
250
pending_log_flushes complete )),
251
(map { 'IB_dl_' . $_ => $innodb_status->{'sections'}->{'dl'}->{$_} }
252
qw( timestring rolled_back txns complete ));
258
return sprintf('%02d-%02d-%02d %02d:%02d:%02d', @$parts);
261
sub parse_innodb_timestamp {
263
my ( $y, $m, $d, $h, $i, $s )
264
= $text =~ m/^(\d\d)(\d\d)(\d\d) +(\d+):(\d+):(\d+)$/;
265
die("Can't get timestamp from $text\n") unless $y;
267
return ( $y, $m, $d, $h, $i, $s );
270
sub parse_fk_section {
271
my ( $section, $complete, $debug, $full ) = @_;
272
my $fulltext = $section->{'fulltext'};
274
return 0 unless $fulltext;
276
my ( $ts, $type ) = $fulltext =~ m/^$s\s+(\w+)/m;
277
$section->{'ts'} = [ parse_innodb_timestamp( $ts ) ];
278
$section->{'timestring'} = ts_to_string($section->{'ts'});
279
$section->{'type'} = $type;
281
# Decide which type of FK error happened, and dispatch to the right parser.
282
if ( $type && $fk_parser_for{$type} ) {
283
$fk_parser_for{$type}->( $section, $complete, $debug, $fulltext, $full );
286
delete $section->{'fulltext'} unless $debug;
291
sub parse_fk_cant_drop_parent_error {
292
my ( $section, $complete, $debug, $fulltext, $full ) = @_;
294
# Parse the parent/child table info out
295
@{$section}{ qw(attempted_op parent_db parent_table) } = $fulltext
296
=~ m{Cannot $w table `(.*)/(.*)`}m;
297
@{$section}{ qw(child_db child_table) } = $fulltext
298
=~ m{because it is referenced by `(.*)/(.*)`}m;
300
( $section->{'reason'} ) = $fulltext =~ m/(Cannot .*)/s;
301
$section->{'reason'} =~ s/\n(?:InnoDB: )?/ /gm
302
if $section->{'reason'};
304
# Certain data may not be present. Make them '' if not present.
305
map { $section->{$_} ||= "" }
306
qw(child_index fk_name col_name parent_col);
309
# See dict/dict0dict.c, function dict_foreign_error_report
310
# I don't care much about these. There are lots of different messages, and
311
# they come from someone trying to create a foreign key, or similar
312
# statements. They aren't indicative of some transaction trying to insert,
313
# delete or update data. Sometimes it is possible to parse out a lot of
314
# information about the tables and indexes involved, but often the message
315
# contains the DDL string the user entered, which is way too much for this
316
# module to try to handle.
317
sub parse_fk_bad_constraint_error {
318
my ( $section, $complete, $debug, $fulltext, $full ) = @_;
320
# Parse the parent/child table and index info out
321
@{$section}{ qw(child_db child_table) } = $fulltext
322
=~ m{Error in foreign key constraint of table (.*)/(.*):$}m;
323
$section->{'attempted_op'} = 'DDL';
325
# FK name, parent info... if possible.
326
@{$section}{ qw(fk_name col_name parent_db parent_table parent_col) }
328
=~ m/CONSTRAINT `?$n`? FOREIGN KEY \(`?$n`?\) REFERENCES (?:`?$n`?\.)?`?$n`? \(`?$n`?\)/;
330
if ( !defined($section->{'fk_name'}) ) {
331
# Try to parse SQL a user might have typed in a CREATE statement or such
332
@{$section}{ qw(col_name parent_db parent_table parent_col) }
334
=~ m/FOREIGN\s+KEY\s*\(`?$n`?\)\s+REFERENCES\s+(?:`?$n`?\.)?`?$n`?\s*\(`?$n`?\)/i;
336
$section->{'parent_db'} ||= $section->{'child_db'};
338
# Name of the child index (index in the same table where the FK is, see
339
# definition of dict_foreign_struct in include/dict0mem.h, where it is
340
# called foreign_index, as opposed to referenced_index which is in the
341
# parent table. This may not be possible to find.
342
@{$section}{ qw(child_index) } = $fulltext
343
=~ m/^The index in the foreign key in table is $n$/m;
345
@{$section}{ qw(reason) } = $fulltext =~ m/:\s*([^:]+)(?= Constraint:|$)/ms;
346
$section->{'reason'} =~ s/\s+/ /g
347
if $section->{'reason'};
349
# Certain data may not be present. Make them '' if not present.
350
map { $section->{$_} ||= "" }
351
qw(child_index fk_name col_name parent_table parent_col);
354
# see source file row/row0ins.c
355
sub parse_fk_transaction_error {
356
my ( $section, $complete, $debug, $fulltext, $full ) = @_;
358
# Parse the txn info out
359
my ( $txn ) = $fulltext
360
=~ m/Transaction:\n(TRANSACTION.*)\nForeign key constraint fails/s;
362
$section->{'txn'} = parse_tx_text( $txn, $complete, $debug, $full );
365
# Parse the parent/child table and index info out. There are two types: an
366
# update or a delete of a parent record leaves a child orphaned
367
# (row_ins_foreign_report_err), and an insert or update of a child record has
368
# no matching parent record (row_ins_foreign_report_add_err).
370
@{$section}{ qw(reason child_db child_table) }
371
= $fulltext =~ m{^(Foreign key constraint fails for table `(.*)/(.*)`:)$}m;
373
@{$section}{ qw(fk_name col_name parent_db parent_table parent_col) }
375
=~ m/CONSTRAINT `$n` FOREIGN KEY \(`$n`\) REFERENCES (?:`$n`\.)?`$n` \(`$n`\)/;
376
$section->{'parent_db'} ||= $section->{'child_db'};
378
# Special case, which I don't know how to trigger, but see
379
# innobase/row/row0ins.c row_ins_check_foreign_constraint
380
if ( $fulltext =~ m/ibd file does not currently exist!/ ) {
381
my ( $attempted_op, $index, $records )
382
= $fulltext =~ m/^Trying to (add to index) `$n` tuple:\n(.*))?/sm;
383
$section->{'child_index'} = $index;
384
$section->{'attempted_op'} = $attempted_op || '';
385
if ( $records && $full ) {
386
( $section->{'records'} )
387
= parse_innodb_record_dump( $records, $complete, $debug );
389
@{$section}{qw(parent_db parent_table)}
390
=~ m/^But the parent table `$n`\.`$n`$/m;
393
my ( $attempted_op, $which, $index )
394
= $fulltext =~ m/^Trying to ([\w ]*) in (child|parent) table, in index `$n` tuple:$/m;
396
$section->{$which . '_index'} = $index;
397
$section->{'attempted_op'} = $attempted_op || '';
399
# Parse out the related records in the other table.
400
my ( $search_index, $records );
401
if ( $which eq 'child' ) {
402
( $search_index, $records ) = $fulltext
403
=~ m/^But in parent table [^,]*, in index `$n`,\nthe closest match we can find is record:\n(.*)/ms;
404
$section->{'parent_index'} = $search_index;
407
( $search_index, $records ) = $fulltext
408
=~ m/^But in child table [^,]*, in index `$n`, (?:the record is not available|there is a record:\n(.*))?/ms;
409
$section->{'child_index'} = $search_index;
411
if ( $records && $full ) {
412
$section->{'records'}
413
= parse_innodb_record_dump( $records, $complete, $debug );
416
$section->{'records'} = '';
421
# Parse out the tuple trying to be updated, deleted or inserted.
422
my ( $trigger ) = $fulltext =~ m/^(DATA TUPLE: \d+ fields;\n.*)$/m;
424
$section->{'trigger'} = parse_innodb_record_dump( $trigger, $complete, $debug );
427
# Certain data may not be present. Make them '' if not present.
428
map { $section->{$_} ||= "" }
429
qw(child_index fk_name col_name parent_table parent_col);
432
# There are new-style and old-style record formats. See rem/rem0rec.c
433
# TODO: write some tests for this
434
sub parse_innodb_record_dump {
435
my ( $dump, $complete, $debug ) = @_;
436
return undef unless $dump;
440
if ( $dump =~ m/PHYSICAL RECORD/ ) {
441
my $style = $dump =~ m/compact format/ ? 'new' : 'old';
442
$result->{'style'} = $style;
444
# This is a new-style record.
445
if ( $style eq 'new' ) {
446
@{$result}{qw( heap_no type num_fields info_bits )}
448
=~ m/^(?:Record lock, heap no $d )?([A-Z ]+): n_fields $d; compact format; info bits $d$/m;
451
# OK, it's old-style. Unfortunately there are variations here too.
452
elsif ( $dump =~ m/-byte offs / ) {
454
@{$result}{qw( heap_no type num_fields byte_offset info_bits )}
456
=~ m/^(?:Record lock, heap no $d )?([A-Z ]+): n_fields $d; $d-byte offs [A-Z]+; info bits $d$/m;
457
if ( $dump !~ m/-byte offs TRUE/ ) {
458
$result->{'byte_offset'} = 0;
463
@{$result}{qw( heap_no type num_fields byte_offset info_bits )}
465
=~ m/^(?:Record lock, heap no $d )?([A-Z ]+): n_fields $d; $d-byte offsets; info bits $d$/m;
470
$result->{'style'} = 'tuple';
471
@{$result}{qw( type num_fields )}
472
= $dump =~ m/^(DATA TUPLE): $d fields;$/m;
475
# Fill in default values for things that couldn't be parsed.
476
map { $result->{$_} ||= 0 }
477
qw(heap_no num_fields byte_offset info_bits);
478
map { $result->{$_} ||= '' }
481
my @fields = $dump =~ m/ (\d+:.*?;?);(?=$| \d+:)/gm;
482
$result->{'fields'} = [ map { parse_field($_, $complete, $debug ) } @fields ];
487
# New/old-style applies here. See rem/rem0rec.c
488
# $text should not include the leading space or the second trailing semicolon.
490
my ( $text, $complete, $debug ) = @_;
493
# '4: SQL NULL, size 4 '
494
# '1: len 6; hex 000000005601; asc V ;'
496
# '5: len 30; hex 687474703a2f2f7777772e737765657477617465722e636f6d2f73746f72; asc http://www.sweetwater.com/stor;...(truncated)'
497
my ( $id, $nullsize, $len, $hex, $asc, $truncated );
498
( $id, $nullsize ) = $text =~ m/^$d: SQL NULL, size $d $/;
499
if ( !defined($id) ) {
500
( $id ) = $text =~ m/^$d: SQL NULL$/;
502
if ( !defined($id) ) {
503
( $id, $len, $hex, $asc, $truncated )
504
= $text =~ m/^$d: len $d; hex $h; asc (.*);(\.\.\.\(truncated\))?$/;
507
die "Could not parse this field: '$text'" unless defined $id;
510
len => defined($len) ? $len : defined($nullsize) ? $nullsize : 0,
511
'hex' => defined($hex) ? $hex : '',
512
asc => defined($asc) ? $asc : '',
513
trunc => $truncated ? 1 : 0,
518
sub parse_dl_section {
519
my ( $dl, $complete, $debug, $full ) = @_;
521
my $fulltext = $dl->{'fulltext'};
522
return 0 unless $fulltext;
524
my ( $ts ) = $fulltext =~ m/^$s$/m;
527
$dl->{'ts'} = [ parse_innodb_timestamp( $ts ) ];
528
$dl->{'timestring'} = ts_to_string($dl->{'ts'});
534
^\*{3}\s([^\n]*) # *** (1) WAITING FOR THIS...
535
(.*?) # Followed by anything, non-greedy
536
(?=(?:^\*{3})|\z) # Followed by another three stars or EOF
540
# Loop through each section. There are no assumptions about how many
541
# there are, who holds and wants what locks, and who gets rolled back.
542
while ( my ($header, $body) = splice(@sections, 0, 2) ) {
543
my ( $txn_id, $what ) = $header =~ m/^\($d\) (.*):$/;
545
$dl->{'txns'}->{$txn_id} ||= {};
546
my $txn = $dl->{'txns'}->{$txn_id};
548
if ( $what eq 'TRANSACTION' ) {
549
$txn->{'tx'} = parse_tx_text( $body, $complete, $debug, $full );
552
push @{$txn->{'locks'}}, parse_innodb_record_locks( $body, $complete, $debug, $full );
556
@{ $dl }{ qw(rolled_back) }
557
= $fulltext =~ m/^\*\*\* WE ROLL BACK TRANSACTION \($d\)$/m;
559
# Make sure certain values aren't undef
560
map { $dl->{$_} ||= '' } qw(rolled_back);
562
delete $dl->{'fulltext'} unless $debug;
566
sub parse_innodb_record_locks {
567
my ( $text, $complete, $debug, $full ) = @_;
570
foreach my $lock ( $text =~ m/(^(?:RECORD|TABLE) LOCKS?.*$)/gm ) {
572
@{$hash}{ qw(lock_type space_id page_no n_bits index db table txn_id lock_mode) }
574
=~ m{^(RECORD|TABLE) LOCKS? (?:space id $d page no $d n bits $d index `?$n`? of )?table `$n(?:/|`\.`)$n` trx id $t lock.mode (\S+)}m;
575
( $hash->{'special'} )
576
= $lock =~ m/^(?:RECORD|TABLE) .*? locks (rec but not gap|gap before rec)/m;
577
$hash->{'insert_intention'}
578
= $lock =~ m/^(?:RECORD|TABLE) .*? insert intention/m ? 1 : 0;
580
= $lock =~ m/^(?:RECORD|TABLE) .*? waiting/m ? 1 : 0;
582
# Some things may not be in the text, so make sure they are not
584
map { $hash->{$_} ||= 0 } qw(n_bits page_no space_id);
585
map { $hash->{$_} ||= "" } qw(index special);
593
my ( $txn, $complete, $debug, $full ) = @_;
595
my ( $txn_id, $txn_status, $active_secs, $proc_no, $os_thread_id )
597
=~ m/^(?:---)?TRANSACTION $t, (\D*?)(?: $d sec)?, (?:process no $d, )?OS thread id $d/m;
598
my ( $thread_status, $thread_decl_inside )
600
=~ m/OS thread id \d+(?: ([^,]+?))?(?:, thread declared inside InnoDB $d)?$/m;
602
# Parsing the line that begins 'MySQL thread id' is complicated. The only
603
# thing always in the line is the thread and query id. See function
604
# innobase_mysql_print_thd in InnoDB source file sql/ha_innodb.cc.
605
my ( $thread_line ) = $txn =~ m/^(MySQL thread id .*)$/m;
606
my ( $mysql_thread_id, $query_id, $hostname, $ip, $user, $query_status );
608
if ( $thread_line ) {
609
# These parts can always be gotten.
610
( $mysql_thread_id, $query_id ) = $thread_line =~ m/^MySQL thread id $d, query id $d/m;
612
# If it's a master/slave thread, "Has (read|sent) all" may be the thread's
613
# proc_info. In these cases, there won't be any host/ip/user info
614
( $query_status ) = $thread_line =~ m/(Has (?:read|sent) all .*$)/m;
615
if ( defined($query_status) ) {
616
$user = 'system user';
619
# It may be the case that the query id is the last thing in the line.
620
elsif ( $thread_line =~ m/query id \d+ / ) {
621
# The IP address is the only non-word thing left, so it's the most
622
# useful marker for where I have to start guessing.
623
( $hostname, $ip ) = $thread_line =~ m/query id \d+(?: ([A-Za-z]\S+))? $i/m;
625
( $user, $query_status ) = $thread_line =~ m/$ip $w(?: (.*))?$/;
627
else { # OK, there wasn't an IP address.
628
# There might not be ANYTHING except the query status.
629
( $query_status ) = $thread_line =~ m/query id \d+ (.*)$/;
630
if ( $query_status !~ m/^\w+ing/ && !exists($is_proc_info{$query_status}) ) {
631
# The remaining tokens are, in order: hostname, user, query_status.
632
# It's basically impossible to know which is which.
633
( $hostname, $user, $query_status ) = $thread_line
634
=~ m/query id \d+(?: ([A-Za-z]\S+))?(?: $w(?: (.*))?)?$/m;
637
$user = 'system user';
643
my ( $lock_wait_status, $lock_structs, $heap_size, $row_locks, $undo_log_entries )
645
=~ m/^(?:(\D*) )?$d lock struct\(s\), heap size $d(?:, $d row lock\(s\))?(?:, undo log entries $d)?$/m;
646
my ( $lock_wait_time )
648
=~ m/^------- TRX HAS BEEN WAITING $d SEC/m;
651
# If the transaction has locks, grab the locks.
652
if ( $txn =~ m/^TABLE LOCK|RECORD LOCKS/ ) {
653
$locks = [parse_innodb_record_locks($txn, $complete, $debug, $full)];
656
my ( $tables_in_use, $tables_locked )
658
=~ m/^mysql tables in use $d, locked $d$/m;
659
my ( $txn_doesnt_see_ge, $txn_sees_lt )
661
=~ m/^Trx read view will not see trx with id >= $t, sees < $t$/m;
662
my $has_read_view = defined($txn_doesnt_see_ge);
663
# Only a certain number of bytes of the query text are included here, at least
664
# under some circumstances. Some versions include 300, some 600.
668
^MySQL\sthread\sid\s[^\n]+\n # This comes before the query text
669
(.*?) # The query text
670
(?= # Followed by any of...
672
|^-------\sTRX\sHAS\sBEEN\sWAITING
674
|^RECORD\sLOCKS\sspace\sid
675
|^(?:---)?TRANSACTION
681
$query_text =~ s/\s+$//;
688
active_secs => $active_secs,
689
has_read_view => $has_read_view,
690
heap_size => $heap_size,
691
hostname => $hostname,
693
lock_structs => $lock_structs,
694
lock_wait_status => $lock_wait_status,
695
lock_wait_time => $lock_wait_time,
696
mysql_thread_id => $mysql_thread_id,
697
os_thread_id => $os_thread_id,
699
query_id => $query_id,
700
query_status => $query_status,
701
query_text => $query_text,
702
row_locks => $row_locks,
703
tables_in_use => $tables_in_use,
704
tables_locked => $tables_locked,
705
thread_decl_inside => $thread_decl_inside,
706
thread_status => $thread_status,
707
txn_doesnt_see_ge => $txn_doesnt_see_ge,
709
txn_sees_lt => $txn_sees_lt,
710
txn_status => $txn_status,
711
undo_log_entries => $undo_log_entries,
714
$stuff{'fulltext'} = $txn if $debug;
715
$stuff{'locks'} = $locks if $locks;
717
# Some things may not be in the txn text, so make sure they are not
719
map { $stuff{$_} ||= 0 } qw(active_secs heap_size lock_structs
720
tables_in_use undo_log_entries tables_locked has_read_view
721
thread_decl_inside lock_wait_time proc_no row_locks);
722
map { $stuff{$_} ||= "" } qw(thread_status txn_doesnt_see_ge
723
txn_sees_lt query_status ip query_text lock_wait_status user);
724
$stuff{'hostname'} ||= $stuff{'ip'};
729
sub parse_tx_section {
730
my ( $section, $complete, $debug, $full ) = @_;
731
return unless $section && $section->{'fulltext'};
732
my $fulltext = $section->{'fulltext'};
733
$section->{'transactions'} = [];
735
# Handle the individual transactions
736
my @transactions = $fulltext =~ m/(---TRANSACTION \d.*?)(?=\n---TRANSACTION|$)/gs;
737
foreach my $txn ( @transactions ) {
738
my $stuff = parse_tx_text( $txn, $complete, $debug, $full );
739
delete $stuff->{'fulltext'} unless $debug;
740
push @{$section->{'transactions'}}, $stuff;
743
# Handle the general info
744
@{$section}{ 'trx_id_counter' }
745
= $fulltext =~ m/^Trx id counter $t$/m;
746
@{$section}{ 'purge_done_for', 'purge_undo_for' }
747
= $fulltext =~ m/^Purge done for trx's n:o < $t undo n:o < $t$/m;
748
@{$section}{ 'history_list_len' } # This isn't present in some 4.x versions
749
= $fulltext =~ m/^History list length $d$/m;
750
@{$section}{ 'num_lock_structs' }
751
= $fulltext =~ m/^Total number of lock structs in row lock hash table $d$/m;
752
@{$section}{ 'is_truncated' }
753
= $fulltext =~ m/^\.\.\. truncated\.\.\.$/m ? 1 : 0;
755
# Fill in things that might not be present
756
foreach ( qw(history_list_len) ) {
757
$section->{$_} ||= 0;
760
delete $section->{'fulltext'} unless $debug;
764
# I've read the source for this section.
765
sub parse_ro_section {
766
my ( $section, $complete, $debug, $full ) = @_;
767
return unless $section && $section->{'fulltext'};
768
my $fulltext = $section->{'fulltext'};
771
@{$section}{ 'queries_inside', 'queries_in_queue' }
772
= $fulltext =~ m/^$d queries inside InnoDB, $d queries in queue$/m;
773
( $section->{ 'read_views_open' } )
774
= $fulltext =~ m/^$d read views open inside InnoDB$/m;
775
( $section->{ 'n_reserved_extents' } )
776
= $fulltext =~ m/^$d tablespace extents now reserved for B-tree/m;
777
@{$section}{ 'main_thread_proc_no', 'main_thread_id', 'main_thread_state' }
778
= $fulltext =~ m/^Main thread (?:process no. $d, )?id $d, state: (.*)$/m;
779
@{$section}{ 'num_rows_ins', 'num_rows_upd', 'num_rows_del', 'num_rows_read' }
780
= $fulltext =~ m/^Number of rows inserted $d, updated $d, deleted $d, read $d$/m;
781
@{$section}{ 'ins_sec', 'upd_sec', 'del_sec', 'read_sec' }
782
= $fulltext =~ m#^$f inserts/s, $f updates/s, $f deletes/s, $f reads/s$#m;
783
$section->{'main_thread_proc_no'} ||= 0;
785
map { $section->{$_} ||= 0 } qw(read_views_open n_reserved_extents);
786
delete $section->{'fulltext'} unless $debug;
790
sub parse_lg_section {
791
my ( $section, $complete, $debug, $full ) = @_;
792
return unless $section;
793
my $fulltext = $section->{'fulltext'};
796
( $section->{ 'log_seq_no' } )
797
= $fulltext =~ m/Log sequence number \s*(\d.*)$/m;
798
( $section->{ 'log_flushed_to' } )
799
= $fulltext =~ m/Log flushed up to \s*(\d.*)$/m;
800
( $section->{ 'last_chkp' } )
801
= $fulltext =~ m/Last checkpoint at \s*(\d.*)$/m;
802
@{$section}{ 'pending_log_writes', 'pending_chkp_writes' }
803
= $fulltext =~ m/$d pending log writes, $d pending chkp writes/;
804
@{$section}{ 'log_ios_done', 'log_ios_s' }
805
= $fulltext =~ m#$d log i/o's done, $f log i/o's/second#;
807
delete $section->{'fulltext'} unless $debug;
811
sub parse_ib_section {
812
my ( $section, $complete, $debug, $full ) = @_;
813
return unless $section && $section->{'fulltext'};
814
my $fulltext = $section->{'fulltext'};
816
# Some servers will output ibuf information for tablespace 0, as though there
817
# might be many tablespaces with insert buffers. (In practice I believe
818
# the source code shows there will only ever be one). I have to parse both
819
# cases here, but I assume there will only be one.
820
@{$section}{ 'size', 'free_list_len', 'seg_size' }
821
= $fulltext =~ m/^Ibuf(?: for space 0)?: size $d, free list len $d, seg size $d,$/m;
822
@{$section}{ 'inserts', 'merged_recs', 'merges' }
823
= $fulltext =~ m/^$d inserts, $d merged recs, $d merges$/m;
825
@{$section}{ 'hash_table_size', 'used_cells', 'bufs_in_node_heap' }
826
= $fulltext =~ m/^Hash table size $d, used cells $d, node heap has $d buffer\(s\)$/m;
827
@{$section}{ 'hash_searches_s', 'non_hash_searches_s' }
828
= $fulltext =~ m{^$f hash searches/s, $f non-hash searches/s$}m;
830
delete $section->{'fulltext'} unless $debug;
834
sub parse_wait_array {
835
my ( $text, $complete, $debug, $full ) = @_;
838
@result{ qw(thread waited_at_filename waited_at_line waited_secs) }
839
= $text =~ m/^--Thread $d has waited at $fl for $f seconds/m;
841
# Depending on whether it's a SYNC_MUTEX,RW_LOCK_EX,RW_LOCK_SHARED,
842
# there will be different text output
843
if ( $text =~ m/^Mutex at/m ) {
844
$result{'request_type'} = 'M';
845
@result{ qw( lock_mem_addr lock_cfile_name lock_cline lock_var) }
846
= $text =~ m/^Mutex at $h created file $fl, lock var $d$/m;
847
@result{ qw( waiters_flag )}
848
= $text =~ m/^waiters flag $d$/m;
851
@result{ qw( request_type lock_mem_addr lock_cfile_name lock_cline) }
852
= $text =~ m/^(.)-lock on RW-latch at $h created in file $fl$/m;
853
@result{ qw( writer_thread writer_lock_mode ) }
854
= $text =~ m/^a writer \(thread id $d\) has reserved it in mode (.*)$/m;
855
@result{ qw( num_readers waiters_flag )}
856
= $text =~ m/^number of readers $d, waiters flag $d$/m;
857
@result{ qw(last_s_file_name last_s_line ) }
858
= $text =~ m/Last time read locked in file $fl$/m;
859
@result{ qw(last_x_file_name last_x_line ) }
860
= $text =~ m/Last time write locked in file $fl$/m;
863
$result{'cell_waiting'} = $text =~ m/^wait has ended$/m ? 0 : 1;
864
$result{'cell_event_set'} = $text =~ m/^wait is ending$/m ? 1 : 0;
866
# Because there are two code paths, some things won't get set.
867
map { $result{$_} ||= '' }
868
qw(last_s_file_name last_x_file_name writer_lock_mode);
869
map { $result{$_} ||= 0 }
870
qw(num_readers lock_var last_s_line last_x_line writer_thread);
875
sub parse_sm_section {
876
my ( $section, $complete, $debug, $full ) = @_;
877
return 0 unless $section && $section->{'fulltext'};
878
my $fulltext = $section->{'fulltext'};
881
@{$section}{ 'reservation_count', 'signal_count' }
882
= $fulltext =~ m/^OS WAIT ARRAY INFO: reservation count $d, signal count $d$/m;
883
@{$section}{ 'mutex_spin_waits', 'mutex_spin_rounds', 'mutex_os_waits' }
884
= $fulltext =~ m/^Mutex spin waits $d, rounds $d, OS waits $d$/m;
885
@{$section}{ 'rw_shared_spins', 'rw_shared_os_waits', 'rw_excl_spins', 'rw_excl_os_waits' }
886
= $fulltext =~ m/^RW-shared spins $d, OS waits $d; RW-excl spins $d, OS waits $d$/m;
888
# Look for info on waits.
889
my @waits = $fulltext =~ m/^(--Thread.*?)^(?=Mutex spin|--Thread)/gms;
890
$section->{'waits'} = [ map { parse_wait_array($_, $complete, $debug) } @waits ];
891
$section->{'wait_array_size'} = scalar(@waits);
893
delete $section->{'fulltext'} unless $debug;
897
# I've read the source for this section.
898
sub parse_bp_section {
899
my ( $section, $complete, $debug, $full ) = @_;
900
return unless $section && $section->{'fulltext'};
901
my $fulltext = $section->{'fulltext'};
904
@{$section}{ 'total_mem_alloc', 'add_pool_alloc' }
905
= $fulltext =~ m/^Total memory allocated $d; in additional pool allocated $d$/m;
906
@{$section}{'dict_mem_alloc'} = $fulltext =~ m/Dictionary memory allocated $d/;
907
@{$section}{'awe_mem_alloc'} = $fulltext =~ m/$d MB of AWE memory/;
908
@{$section}{'buf_pool_size'} = $fulltext =~ m/^Buffer pool size\s*$d$/m;
909
@{$section}{'buf_free'} = $fulltext =~ m/^Free buffers\s*$d$/m;
910
@{$section}{'pages_total'} = $fulltext =~ m/^Database pages\s*$d$/m;
911
@{$section}{'pages_modified'} = $fulltext =~ m/^Modified db pages\s*$d$/m;
912
@{$section}{'pages_read', 'pages_created', 'pages_written'}
913
= $fulltext =~ m/^Pages read $d, created $d, written $d$/m;
914
@{$section}{'page_reads_sec', 'page_creates_sec', 'page_writes_sec'}
915
= $fulltext =~ m{^$f reads/s, $f creates/s, $f writes/s$}m;
916
@{$section}{'buf_pool_hits', 'buf_pool_reads'}
917
= $fulltext =~ m{Buffer pool hit rate $d / $d$}m;
918
if ($fulltext =~ m/^No buffer pool page gets since the last printout$/m) {
919
@{$section}{'buf_pool_hits', 'buf_pool_reads'} = (0, 0);
920
@{$section}{'buf_pool_hit_rate'} = '--';
923
@{$section}{'buf_pool_hit_rate'}
924
= $fulltext =~ m{Buffer pool hit rate (\d+ / \d+)$}m;
926
@{$section}{'reads_pending'} = $fulltext =~ m/^Pending reads $d/m;
927
@{$section}{'writes_pending_lru', 'writes_pending_flush_list', 'writes_pending_single_page' }
928
= $fulltext =~ m/^Pending writes: LRU $d, flush list $d, single page $d$/m;
930
map { $section->{$_} ||= 0 }
931
qw(writes_pending_lru writes_pending_flush_list writes_pending_single_page
932
awe_mem_alloc dict_mem_alloc);
933
@{$section}{'writes_pending'} = List::Util::sum(
934
@{$section}{ qw(writes_pending_lru writes_pending_flush_list writes_pending_single_page) });
936
delete $section->{'fulltext'} unless $debug;
940
# I've read the source for this.
941
sub parse_io_section {
942
my ( $section, $complete, $debug, $full ) = @_;
943
return unless $section && $section->{'fulltext'};
944
my $fulltext = $section->{'fulltext'};
945
$section->{'threads'} = {};
947
# Grab the I/O thread info
948
my @threads = $fulltext =~ m<^(I/O thread \d+ .*)$>gm;
949
foreach my $thread (@threads) {
950
my ( $tid, $state, $purpose, $event_set )
951
= $thread =~ m{I/O thread $d state: (.+?) \((.*)\)(?: ev set)?$}m;
952
if ( defined $tid ) {
953
$section->{'threads'}->{$tid} = {
957
event_set => $event_set ? 1 : 0,
962
# Grab the reads/writes/flushes info
963
@{$section}{ 'pending_normal_aio_reads', 'pending_aio_writes' }
964
= $fulltext =~ m/^Pending normal aio reads: $d, aio writes: $d,$/m;
965
@{$section}{ 'pending_ibuf_aio_reads', 'pending_log_ios', 'pending_sync_ios' }
966
= $fulltext =~ m{^ ibuf aio reads: $d, log i/o's: $d, sync i/o's: $d$}m;
967
@{$section}{ 'flush_type', 'pending_log_flushes', 'pending_buffer_pool_flushes' }
968
= $fulltext =~ m/^Pending flushes \($w\) log: $d; buffer pool: $d$/m;
969
@{$section}{ 'os_file_reads', 'os_file_writes', 'os_fsyncs' }
970
= $fulltext =~ m/^$d OS file reads, $d OS file writes, $d OS fsyncs$/m;
971
@{$section}{ 'reads_s', 'avg_bytes_s', 'writes_s', 'fsyncs_s' }
972
= $fulltext =~ m{^$f reads/s, $d avg bytes/read, $f writes/s, $f fsyncs/s$}m;
973
@{$section}{ 'pending_preads', 'pending_pwrites' }
974
= $fulltext =~ m/$d pending preads, $d pending pwrites$/m;
975
@{$section}{ 'pending_preads', 'pending_pwrites' } = (0, 0)
976
unless defined($section->{'pending_preads'});
978
delete $section->{'fulltext'} unless $debug;
983
my ( $debug, $msg ) = @_;
996
# ############################################################################
997
# Perldoc section. I put this last as per the Dog book.
998
# ############################################################################
1003
InnoDBParser - Parse InnoDB monitor text.
1007
InnoDBParser tries to parse the output of the InnoDB monitor. One way to get
1008
this output is to connect to a MySQL server and issue the command SHOW ENGINE
1009
INNODB STATUS (omit 'ENGINE' on earlier versions of MySQL). The goal is to
1010
turn text into data that something else (e.g. innotop) can use.
1012
The output comes from all over, but the place to start in the source is
1013
innobase/srv/srv0srv.c.
1020
# Get the status text.
1021
my $dbh = DBI->connect(
1022
"DBI::mysql:test;host=localhost",
1026
my $query = 'SHOW /*!5 ENGINE */ INNODB STATUS';
1027
my $text = $dbh->selectcol_arrayref($query)->[0];
1032
# Choose sections of the monitor text you want. Possible values:
1033
# TRANSACTIONS => tx
1034
# BUFFER POOL AND MEMORY => bp
1037
# ROW OPERATIONS => ro
1038
# INSERT BUFFER AND ADAPTIVE HASH INDEX => ib
1040
# LATEST DETECTED DEADLOCK => dl
1041
# LATEST FOREIGN KEY ERROR => fk
1043
my $required_sections = {
1047
# Parse the status text.
1048
my $parser = InnoDBParser->new;
1049
$innodb_status = $parser->parse_status_text(
1052
# Omit the following parameter to get all sections.
1056
=head1 COPYRIGHT, LICENSE AND WARRANTY
1058
This package is copyright (c) 2006 Baron Schwartz, baron at xaprb dot com.
1059
Feedback and improvements are gratefully received.
1061
THIS PACKAGE IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
1062
WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
1063
MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
1065
This program is free software; you can redistribute it and/or modify it under
1066
the terms of the GNU General Public License as published by the Free Software
1067
Foundation, version 2; OR the Perl Artistic License. On UNIX and similar
1068
systems, you can issue `man perlgpl' or `man perlartistic' to read these
1071
You should have received a copy of the GNU General Public License along with
1072
this program; if not, write to the Free Software Foundation, Inc., 59 Temple
1073
Place, Suite 330, Boston, MA 02111-1307 USA
1077
Baron Schwartz, baron at xaprb dot com.
1081
None known, but I bet there are some. The InnoDB monitor text wasn't really
1082
designed to be parsable.
1086
innotop - a program that can format the parsed status information for humans
added
removed
build/debian/additions/innotop/InnoDBParser.pm
