1#!/usr/bin/perl 2 3BEGIN { 4 die "The PERCONA_TOOLKIT_BRANCH environment variable is not set.\n" 5 unless $ENV{PERCONA_TOOLKIT_BRANCH} && -d $ENV{PERCONA_TOOLKIT_BRANCH}; 6 unshift @INC, "$ENV{PERCONA_TOOLKIT_BRANCH}/lib"; 7}; 8 9use strict; 10use warnings FATAL => 'all'; 11use English qw(-no_match_vars); 12use Test::More; 13 14use Processlist; 15use PerconaTest; 16use TextResultSetParser; 17use Transformers; 18use MasterSlave; 19use PerconaTest; 20 21use Data::Dumper; 22$Data::Dumper::Indent = 1; 23$Data::Dumper::Sortkeys = 1; 24$Data::Dumper::Quotekeys = 0; 25 26my $ms = new MasterSlave(OptionParser=>1,DSNParser=>1,Quoter=>1); 27my $rsp = new TextResultSetParser(); 28my $pl; 29my $procs; 30my @events; 31 32sub parse_n_times { 33 my ( $n, %args ) = @_; 34 @events = (); 35 for ( 1..$n ) { 36 my $event = $pl->parse_event(%args); 37 push @events, $event if $event; 38 } 39} 40 41# ########################################################################### 42# A cxn that's connecting should be seen but ignored until it begins 43# to execute a query. 44# ########################################################################### 45$pl = new Processlist(MasterSlave=>$ms); 46 47$procs = [ 48 [ [1, 'unauthenticated user', 'localhost', undef, 'Connect', undef, 49 'Reading from net', undef] ], 50 [],[], 51], 52 53parse_n_times( 54 3, 55 code => sub { 56 return shift @$procs; 57 }, 58 time => Transformers::unix_timestamp('2001-01-01 00:05:00'), 59); 60 61is( 62 scalar @events, 63 0, 64 "No events for new cxn still connecting" 65); 66 67is_deeply( 68 $pl->_get_active_cxn(), 69 {}, 70 "Cxn not saved because it's not executing a query" 71); 72 73# ########################################################################### 74# A sleeping cxn that goes aways should be safely ignored. 75# ########################################################################### 76$pl = Processlist->new(MasterSlave=>$ms); 77 78parse_n_times( 79 1, 80 code => sub { 81 return [ [1, 'root', 'localhost', undef, 'Sleep', 7, '', undef], ]; 82 }, 83 time => Transformers::unix_timestamp('2001-01-01 00:05:00'), 84); 85 86# And now the connection goes away... 87parse_n_times( 88 1, 89 code => sub { return []; }, 90 time => Transformers::unix_timestamp('2001-01-01 00:05:01'), 91); 92 93is( 94 scalar @events, 95 0, 96 "No events for sleep cxn that went away" 97); 98 99is_deeply( 100 $pl->_get_active_cxn(), 101 {}, 102 "Sleeping cxn not saved" 103); 104 105# ########################################################################### 106# A more life-like test with multiple queries that come, execute and go away. 107# ########################################################################### 108$pl = Processlist->new(MasterSlave=>$ms); 109 110# The initial processlist shows a query in progress. 111parse_n_times( 112 1, 113 code => sub { 114 return [ 115 [1, 'root', 'localhost', 'test', 'Query', 2, 'executing', 'query1_1'], 116 ], 117 }, 118 time => Transformers::unix_timestamp('2001-01-01 00:05:00'), 119 etime => .05, 120); 121 122is( 123 scalar @events, 124 0, 125 'No events fired' 126); 127 128# The should now be active cxn with a query that started 2 seconds ago. 129is_deeply( 130 $pl->_get_active_cxn(), 131 { 132 1 => [ 133 1, 'root', 'localhost', 'test', 'Query', 2, 'executing', 'query1_1', 134 Transformers::unix_timestamp('2001-01-01 00:04:58'), # START 135 0.05, # ETIME 136 Transformers::unix_timestamp('2001-01-01 00:05:00'), # FSEEN 137 { executing => 0 }, 138 ], 139 }, 140 "Cxn 1 is active" 141); 142 143# The next processlist shows a new cxn/query in progress and the first 144# one (above) has ended. 145$procs = [ 146 [ [2, 'root', 'localhost', 'test', 'Query', 1, 'executing', 'query2_1'] ], 147]; 148 149parse_n_times( 150 1, 151 code => sub { 152 return shift @$procs, 153 }, 154 time => Transformers::unix_timestamp('2001-01-01 00:05:01'), 155 etime => .03, 156); 157 158# Event should have been made for the first query. 159is_deeply( 160 \@events, 161 [ { db => 'test', 162 user => 'root', 163 host => 'localhost', 164 arg => 'query1_1', 165 bytes => 8, 166 ts => '2001-01-01T00:05:00', 167 Query_time => 2, 168 Lock_time => 0, 169 id => 1, 170 }, 171 ], 172 'query1_1 fired', 173) or print Dumper(\@events); 174 175# Only the 2nd cxn/query should be active now. 176is_deeply( 177 $pl->_get_active_cxn(), 178 { 179 2 => [ 180 2, 'root', 'localhost', 'test', 'Query', 1, 'executing', 'query2_1', 181 Transformers::unix_timestamp('2001-01-01 00:05:00'), # START 182 .03, # ETIME 183 Transformers::unix_timestamp('2001-01-01 00:05:01'), # FSEEN 184 { executing => 0 }, 185 ], 186 }, 187 "Only cxn 2 is active" 188); 189 190# The query on cxn 2 is finished, but the connection is still open. 191parse_n_times( 192 1, 193 code => sub { 194 return [ 195 [ 2, 'root', 'localhost', 'test', 'Sleep', 0, '', undef], 196 ], 197 }, 198 time => Transformers::unix_timestamp('2001-01-01 00:05:02'), 199); 200 201# And so as a result, query2_1 has fired... 202is_deeply( 203 \@events, 204 [ { db => 'test', 205 user => 'root', 206 host => 'localhost', 207 arg => 'query2_1', 208 bytes => 8, 209 ts => '2001-01-01T00:05:01', 210 Query_time => 1, 211 Lock_time => 0, 212 id => 2, 213 }, 214 ], 215 'query2_1 fired', 216); 217 218# ...and there's no more active cxn. 219is_deeply( 220 $pl->_get_active_cxn(), 221 {}, 222 "No active cxn" 223); 224 225# In this sample, cxn 2 is running a query, with a start time at the current 226# time of 3 secs later 227parse_n_times( 228 1, 229 code => sub { 230 return [ 231 [ 2, 'root', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2'], 232 ], 233 }, 234 time => Transformers::unix_timestamp('2001-01-01 00:05:03'), 235 etime => 3.14159, 236); 237 238is_deeply( 239 $pl->_get_active_cxn(), 240 { 241 2 => [ 242 2, 'root', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2', 243 Transformers::unix_timestamp('2001-01-01 00:05:03'), # START 244 3.14159, # ETIME 245 Transformers::unix_timestamp('2001-01-01 00:05:03'), # FSEEN 246 { executing => 0 }, 247 ], 248 }, 249 'query2_2 just started', 250); 251 252# And there is no event on cxn 2. 253is( 254 scalar @events, 255 0, 256 'query2_2 has not fired yet', 257); 258 259# In this sample, the "same" query is running one second later and this time it 260# seems to have a start time of 5 secs later, which is not enough to be a new 261# query. 262parse_n_times( 263 1, 264 code => sub { 265 return [ 266 [ 2, 'root', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2'], 267 ], 268 }, 269 time => Transformers::unix_timestamp('2001-01-01 00:05:05'), 270 etime => 2.718, 271); 272 273is( 274 scalar @events, 275 0, 276 'query2_2 has not fired yet', 277); 278 279# And so as a result, query2_2 has NOT fired, but the query is still active. 280is_deeply( 281 $pl->_get_active_cxn(), 282 { 283 2 => [ 284 2, 'root', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2', 285 Transformers::unix_timestamp('2001-01-01 00:05:03'), 286 3.14159, 287 Transformers::unix_timestamp('2001-01-01 00:05:03'), 288 { executing => 2 }, 289 ], 290 }, 291 'Cxn 2 still active with query starting at 05:03', 292); 293 294# But wait! There's another! And this time we catch it! 295parse_n_times( 296 1, 297 code => sub { 298 return [ 299 [ 2, 'root', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2'], 300 ], 301 }, 302 time => Transformers::unix_timestamp('2001-01-01 00:05:08.500'), 303 etime => 0.123, 304); 305 306is_deeply( 307 \@events, 308 [ { db => 'test', 309 user => 'root', 310 host => 'localhost', 311 arg => 'query2_2', 312 bytes => 8, 313 ts => '2001-01-01T00:05:03', 314 Query_time => 5.5, 315 Lock_time => 0, 316 id => 2, 317 }, 318 ], 319 'Original query2_2 fired', 320); 321 322# And so as a result, query2_2 has fired and the prev array contains the "new" 323# query2_2. 324is_deeply( 325 $pl->_get_active_cxn(), 326 { 327 2 => [ 328 2, 'root', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2', 329 Transformers::unix_timestamp('2001-01-01 00:05:08'), 330 0.123, 331 Transformers::unix_timestamp('2001-01-01 00:05:08.500'), 332 { executing => 0 }, 333 ], 334 }, 335 "New query2_2 is active, starting at 05:08" 336); 337 338 339# ########################################################################### 340# pt-query-digest --processlist: Duplicate entries for replication thread 341# https://bugs.launchpad.net/percona-toolkit/+bug/1156901 342# ########################################################################### 343 344# This is basically the same thing as above, but we're pretending to 345# be a repl thread, so it should behave differently. 346 347$pl = Processlist->new(MasterSlave=>$ms); 348 349parse_n_times( 350 1, 351 code => sub { 352 return [ 353 [ 2, 'system user', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2'], 354 ], 355 }, 356 time => Transformers::unix_timestamp('2001-01-01 00:05:03'), 357 etime => 3.14159, 358); 359 360is_deeply( 361 $pl->_get_active_cxn(), 362 { 363 2 => [ 364 2, 'system user', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2', 365 Transformers::unix_timestamp('2001-01-01 00:05:03'), # START 366 3.14159, # ETIME 367 Transformers::unix_timestamp('2001-01-01 00:05:03'), # FSEEN 368 { executing => 0 }, 369 ], 370 }, 371 'query2_2 just started', 372); 373 374# And there is no event on cxn 2. 375is( 376 scalar @events, 377 0, 378 'query2_2 has not fired yet', 379); 380 381parse_n_times( 382 1, 383 code => sub { 384 return [ 385 [ 2, 'system user', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2'], 386 ], 387 }, 388 time => Transformers::unix_timestamp('2001-01-01 00:05:05'), 389 etime => 2.718, 390); 391 392is( 393 scalar @events, 394 0, 395 'query2_2 has not fired yet, same as with normal queries', 396); 397 398is_deeply( 399 $pl->_get_active_cxn(), 400 { 401 2 => [ 402 2, 'system user', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2', 403 Transformers::unix_timestamp('2001-01-01 00:05:03'), 404 3.14159, 405 Transformers::unix_timestamp('2001-01-01 00:05:03'), 406 { executing => 2 }, 407 ], 408 }, 409 'Cxn 2 still active with query starting at 05:03', 410); 411 412# Same as above but five seconds and a half later 413parse_n_times( 414 1, 415 code => sub { 416 return [ 417 [ 2, 'system user', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2'], 418 ], 419 }, 420 time => Transformers::unix_timestamp('2001-01-01 00:05:08.500'), 421 etime => 0.123, 422); 423 424is_deeply( 425 \@events, 426 [], 427 'Original query2_2 not fired because we are a repl thrad', 428); 429 430is_deeply( 431 $pl->_get_active_cxn(), 432 { 433 2 => [ 434 2, 'system user', 'localhost', 'test', 'Query', 0, 'executing', 'query2_2', 435 Transformers::unix_timestamp('2001-01-01 00:05:03'), # START 436 3.14159, # ETIME 437 Transformers::unix_timestamp('2001-01-01 00:05:03'), # FSEEN 438 { executing => 5.5 }, 439 ], 440 }, 441 "Old query2_2 is active because we're a repl thread, but executing has updated" 442); 443 444# ########################################################################### 445# Issue 867: Make mk-query-digest detect Lock_time from processlist 446# ########################################################################### 447$ms = new MasterSlave(OptionParser=>1,DSNParser=>1,Quoter=>1); 448$pl = Processlist->new(MasterSlave=>$ms); 449 450# For 2/10ths of a second, the query is Locked. First time we see this 451# cxn and query, we don't/can't know how much of it's execution Time was 452# Locked or something else, so the first 1/10th second of Locked time is 453# ignored and the 2nd tenth is counted. Then... 454parse_n_times( 455 1, 456 code => sub { 457 return [ 458 [1, 'root', 'localhost', 'test', 'Query', 0, 'Locked', 'query1_1'], 459 ], 460 }, 461 time => Transformers::unix_timestamp('2011-01-01 00:00:00.2'), 462 etime => .1, 463); 464parse_n_times( 465 1, 466 code => sub { 467 return [ 468 [1, 'root', 'localhost', 'test', 'Query', 0, 'Locked', 'query1_1'], 469 ], 470 }, 471 time => Transformers::unix_timestamp('2011-01-01 00:00:00.4'), 472 etime => .1, 473); 474 475# ...when the query changes states, we guesstimate that half the poll time 476# between state changes was in the previous state, and the other half in 477# the new/current state. So Locked picks up 0.05 (1/2 of 1/10), bringing 478# its total to 0.15. 479parse_n_times( 480 1, 481 code => sub { 482 return [ 483 [1, 'root', 'localhost', 'test', 'Query', 0, 'executing', 'query1_1'], 484 ], 485 }, 486 time => Transformers::unix_timestamp('2011-01-01 00:00:00.6'), 487 etime => .1, 488); 489 490parse_n_times( 491 1, 492 code => sub { 493 return [ 494 [1, 'root', 'localhost', 'test', 'Sleep', 0, '', undef], 495 ], 496 }, 497 time => Transformers::unix_timestamp('2011-01-01 00:00:00.8'), 498 etime => .1, 499); 500 501$events[0]->{Lock_time} = sprintf '%.1f', $events[0]->{Lock_time}; 502is( 503 $events[0]->{Lock_time}, 504 0.3, 505 "Detects Lock_time from Locked state" 506); 507 508# Query_time should be 0.6 because it it was first seen at :00.2 and 509# then ends at :00.8. So .8 - .2 = .6. 510ok( 511 $events[0]->{Query_time} >= 0.58 512 && $events[0]->{Query_time} <= 0.69, 513 "Query_time is accurate (0.58 <= t <= 0.69)" 514); 515 516# ########################################################################### 517# Issue 1252: mk-query-digest --processlist does not work well 518# ########################################################################### 519$pl = Processlist->new(MasterSlave=>$ms); 520 521# @ :10.0 522# First call we have 3 queries, none of which are finished. This poll 523# actually started at :10.0 but took .5s to complete so time=:10.5. 524parse_n_times( 525 1, 526 code => sub { 527 return [ 528 [1, 'root', 'localhost', 'test', 'Query', 1, 'Locked', 'query1'], 529 [2, 'root', 'localhost', 'test', 'Query', 2, 'executing', 'query2'], 530 [3, 'root', 'localhost', 'test', 'Query', 3, 'executing', 'query3'], 531 ], 532 }, 533 time => Transformers::unix_timestamp('2011-01-01 00:00:10.5'), 534 etime => 0.5, 535); 536is_deeply( 537 \@events, 538 [], 539 "No events yet (issue 1252)" 540) or print Dumper(\@events); 541 542is_deeply( 543 $pl->_get_active_cxn(), 544 { 545 1 => [ 546 1, 'root', 'localhost', 'test', 'Query', 1, 'Locked', 'query1', 547 Transformers::unix_timestamp('2011-01-01 00:00:09'), # START 548 0.5, # ETIME 549 Transformers::unix_timestamp('2011-01-01 00:00:10.5'), # FSEEN 550 { Locked => 0 }, 551 ], 552 2 => [ 553 2, 'root', 'localhost', 'test', 'Query', 2, 'executing', 'query2', 554 Transformers::unix_timestamp('2011-01-01 00:00:08'), # START 555 0.5, # ETIME 556 Transformers::unix_timestamp('2011-01-01 00:00:10.5'), # FSEEN 557 { executing => 0 }, 558 ], 559 3 => [ 560 3, 'root', 'localhost', 'test', 'Query', 3, 'executing', 'query3', 561 Transformers::unix_timestamp('2011-01-01 00:00:07'), # START 562 0.5, # ETIME 563 Transformers::unix_timestamp('2011-01-01 00:00:10.5'), # FSEEN 564 { executing => 0 }, 565 ], 566 }, 567 "All three cxn are active (issue 1252)" 568); 569 570# @ :11.0 571# Second call queries 3 & 2 have finished, so we should get an event for 572# one of them and the other will be cached. Also note: query 1 has changed 573# from Locked to executing. -- This poll actually started at :11.0 but took 574# 0.1s to complete so time=:11.1. 575parse_n_times( 576 1, 577 code => sub { 578 return [ 579 [1, 'root', 'localhost', 'test', 'Query', 1, 'executing', 'query1'], 580 ], 581 }, 582 time => Transformers::unix_timestamp('2011-01-01 00:00:11.1'), 583 etime => 0.1, 584); 585 586# Processlist uses hashes so the returns may be unpredictable due to 587# keys/values %$hash being unpredictable. So we save the returns, then 588# sort them later by cxn ID. 589my @event_q; 590push @event_q, @events; 591 592is( 593 scalar @events, 594 1, 595 "2nd call, an event returned (issue 1252)" 596); 597 598# @ :11.0 599# Third call finishes query 1 but should returned cached event first 600# since it finished at 2nd call. -- No poll happens until all cached 601# events are returned. 602parse_n_times( 603 1, 604 code => sub { return []; }, 605 time => Transformers::unix_timestamp('2011-01-01 00:00:11.1'), 606 etime => 0.5, 607); 608 609is( 610 scalar @events, 611 1, 612 "3rd call, another event returned (issue 1252)" 613) or print Dumper(\@events); 614 615push @event_q, @events; 616@event_q = sort { $a->{id} <=> $b->{id} } @event_q; 617is_deeply( 618 \@event_q, 619 [ { 620 Lock_time => 0, 621 Query_time => 2, 622 arg => 'query2', 623 bytes => 6, 624 db => 'test', 625 host => 'localhost', 626 id => 2, 627 ts => '2011-01-01T00:00:10', 628 user => 'root' 629 }, 630 { 631 Lock_time => 0, 632 Query_time => 3, 633 arg => 'query3', 634 bytes => 6, 635 db => 'test', 636 host => 'localhost', 637 id => 3, 638 ts => '2011-01-01T00:00:10', 639 user => 'root' 640 } ], 641 "Cxn 2 and 3 finished (issue 1252)", 642) or print Dumper(\@event_q); 643 644# @ :11.5 645# Fourth call returns query1 that finished last call. -- This poll 646# actually happens at :11.5 and took 0.2s to complete so time=:11.7. 647parse_n_times( 648 1, 649 code => sub { return []; }, 650 time => Transformers::unix_timestamp('2011-01-01 00:00:11.7'), 651 etime => 0.2, 652); 653 654# This query was first seen at :10.5 and then was done and gone by :11.7. 655# Thus we observed it for 1.2s. Actually, the query was last seen at :11.1, 656# so between then and :11.7 is .6s, i.e. one poll interval. So the query 657# really ended sometime during the poll interval :11.1-:11.7. 658$events[0]->{Query_time} = sprintf '%.6f', $events[0]->{Query_time}; 659$events[0]->{Lock_time} = sprintf '%.2f', $events[0]->{Lock_time}; 660is_deeply( 661 \@events, 662 [ { 663 Lock_time => '0.30', 664 Query_time => '1.200000', 665 arg => 'query1', 666 bytes => 6, 667 db => 'test', 668 host => 'localhost', 669 id => 1, 670 ts => '2011-01-01T00:00:10', 671 user => 'root' 672 } ], 673 "4th call, last finished event (issue 1252)" 674) or print Dumper(\@events); 675 676# @ :12.0 677# Fifth call returns nothing because there's no events. 678parse_n_times( 679 1, 680 code => sub { return []; }, 681 time => Transformers::unix_timestamp('2011-01-01 00:00:12.0'), 682 etime => 0.1, 683); 684 685is( 686 scalar @events, 687 0, 688 "No events (issue 1252)" 689) or print Dumper(\@events); 690 691# ########################################################################### 692# Tests for "find" functionality. 693# ########################################################################### 694 695my %find_spec = ( 696 busy_time => 60, 697 idle_time => 0, 698 ignore => { 699 Id => 5, 700 User => qr/^system.user$/, 701 State => qr/Locked/, 702 Command => qr/Binlog Dump/, 703 }, 704 match => { 705 Command => qr/Query/, 706 Info => qr/^(?i:select)/, 707 }, 708); 709 710my $matching_query = 711 { 'Time' => '91', 712 'Command' => 'Query', 713 'db' => undef, 714 'Id' => '43', 715 'Info' => 'select * from foo', 716 'User' => 'msandbox', 717 'State' => 'executing', 718 'Host' => 'localhost' 719 }; 720 721my @queries = $pl->find( 722 [ { 'Time' => '488', 723 'Command' => 'Connect', 724 'db' => undef, 725 'Id' => '4', 726 'Info' => undef, 727 'User' => 'system user', 728 'State' => 'Waiting for master to send event', 729 'Host' => '' 730 }, 731 { 'Time' => '488', 732 'Command' => 'Connect', 733 'db' => undef, 734 'Id' => '5', 735 'Info' => undef, 736 'User' => 'system user', 737 'State' => 738 'Has read all relay log; waiting for the slave I/O thread to update it', 739 'Host' => '' 740 }, 741 { 'Time' => '416', 742 'Command' => 'Sleep', 743 'db' => undef, 744 'Id' => '7', 745 'Info' => undef, 746 'User' => 'msandbox', 747 'State' => '', 748 'Host' => 'localhost' 749 }, 750 { 'Time' => '0', 751 'Command' => 'Query', 752 'db' => undef, 753 'Id' => '8', 754 'Info' => 'show full processlist', 755 'User' => 'msandbox', 756 'State' => undef, 757 'Host' => 'localhost:41655' 758 }, 759 { 'Time' => '467', 760 'Command' => 'Binlog Dump', 761 'db' => undef, 762 'Id' => '2', 763 'Info' => undef, 764 'User' => 'msandbox', 765 'State' => 766 'Has sent all binlog to slave; waiting for binlog to be updated', 767 'Host' => 'localhost:56246' 768 }, 769 { 'Time' => '91', 770 'Command' => 'Sleep', 771 'db' => undef, 772 'Id' => '40', 773 'Info' => undef, 774 'User' => 'msandbox', 775 'State' => '', 776 'Host' => 'localhost' 777 }, 778 { 'Time' => '91', 779 'Command' => 'Query', 780 'db' => undef, 781 'Id' => '41', 782 'Info' => 'optimize table foo', 783 'User' => 'msandbox', 784 'State' => 'Query', 785 'Host' => 'localhost' 786 }, 787 { 'Time' => '91', 788 'Command' => 'Query', 789 'db' => undef, 790 'Id' => '42', 791 'Info' => 'select * from foo', 792 'User' => 'msandbox', 793 'State' => 'Locked', 794 'Host' => 'localhost' 795 }, 796 $matching_query, 797 ], 798 %find_spec, 799); 800 801my $expected = [ $matching_query ]; 802 803is_deeply(\@queries, $expected, 'Basic find()'); 804 805{ 806 # Internal, fragile test! 807 is_deeply( 808 $pl->{_reasons_for_matching}->{$matching_query}, 809 [ 'Exceeds busy time', 'Query matches Command spec', 'Query matches Info spec', ], 810 "_reasons_for_matching works" 811 ); 812} 813 814%find_spec = ( 815 busy_time => 1, 816 ignore => { 817 User => qr/^system.user$/, 818 State => qr/Locked/, 819 Command => qr/Binlog Dump/, 820 }, 821 match => { 822 }, 823); 824 825@queries = $pl->find( 826 [ { 'Time' => '488', 827 'Command' => 'Sleep', 828 'db' => undef, 829 'Id' => '7', 830 'Info' => undef, 831 'User' => 'msandbox', 832 'State' => '', 833 'Host' => 'localhost' 834 }, 835 ], 836 %find_spec, 837); 838 839is(scalar(@queries), 0, 'Did not find any query'); 840 841%find_spec = ( 842 busy_time => undef, 843 idle_time => 15, 844 ignore => { 845 }, 846 match => { 847 }, 848); 849is_deeply( 850 [ 851 $pl->find( 852 $rsp->parse(load_file('t/lib/samples/pl/recset003.txt')), 853 %find_spec, 854 ) 855 ], 856 [ 857 { 858 Id => '29392005', 859 User => 'remote', 860 Host => '1.2.3.148:49718', 861 db => 'happy', 862 Command => 'Sleep', 863 Time => '17', 864 State => undef, 865 Info => undef, 866 } 867 ], 868 'idle_time' 869); 870 871%find_spec = ( 872 match => { User => 'msandbox' }, 873); 874@queries = $pl->find( 875 $rsp->parse(load_file('t/lib/samples/pl/recset008.txt')), 876 %find_spec, 877); 878ok( 879 @queries == 0, 880 "Doesn't match replication thread by default" 881); 882 883%find_spec = ( 884 replication_threads => 1, 885 match => { User => 'msandbox' }, 886); 887@queries = $pl->find( 888 $rsp->parse(load_file('t/lib/samples/pl/recset008.txt')), 889 %find_spec, 890); 891ok( 892 @queries == 1, 893 "Matches replication thread" 894); 895 896# ########################################################################### 897# Find "all". 898# ########################################################################### 899%find_spec = ( 900 all => 1, 901); 902@queries = $pl->find( 903 $rsp->parse(load_file('t/lib/samples/pl/recset002.txt')), 904 %find_spec, 905); 906 907is_deeply( 908 \@queries, 909 $rsp->parse(load_file('t/lib/samples/pl/recset002.txt')), 910 "Find all queries" 911); 912 913%find_spec = ( 914 all => 1, 915 ignore => { Info => 'foo1' }, 916); 917@queries = $pl->find( 918 $rsp->parse(load_file('t/lib/samples/pl/recset002.txt')), 919 %find_spec, 920); 921 922is_deeply( 923 \@queries, 924 [ 925 { 926 Id => '2', 927 User => 'user1', 928 Host => '1.2.3.4:5455', 929 db => 'foo', 930 Command => 'Query', 931 Time => '5', 932 State => 'Locked', 933 Info => 'select * from foo2;', 934 } 935 ], 936 "Find all queries that aren't ignored" 937); 938 939# ############################################################################# 940# https://bugs.launchpad.net/percona-toolkit/+bug/923896 941# ############################################################################# 942 943%find_spec = ( 944 busy_time => 1, 945 ignore => {}, 946 match => {}, 947); 948my $proc = { 'Time' => undef, 949 'Command' => 'Query', 950 'db' => undef, 951 'Id' => '7', 952 'Info' => undef, 953 'User' => 'msandbox', 954 'State' => '', 955 'Host' => 'localhost' 956 }; 957 958local $@; 959eval { $pl->find([$proc], %find_spec) }; 960ok !$@, 961 "Bug 923896: NULL Time in processlist doesn't fail for busy_time+Command=Query"; 962 963delete $find_spec{busy_time}; 964$find_spec{idle_time} = 1; 965$proc->{Command} = 'Sleep'; 966 967local $@; 968eval { $pl->find([$proc], %find_spec) }; 969ok !$@, 970 "Bug 923896: NULL Time in processlist doesn't fail for idle_time+Command=Sleep"; 971 972# ############################################################################# 973# NULL STATE doesn't generate warnings 974# https://bugs.launchpad.net/percona-toolkit/+bug/821703 975# ############################################################################# 976 977$procs = [ 978 [ [1, 'unauthenticated user', 'localhost', undef, 'Connect', 7, 979 'some state', 1] ], 980 [ [1, 'unauthenticated user', 'localhost', undef, 'Connect', 8, 981 undef, 2] ], 982], 983 984eval { 985 parse_n_times( 986 2, 987 code => sub { 988 return shift @$procs; 989 }, 990 time => Transformers::unix_timestamp('2001-01-01 00:05:00'), 991 ); 992}; 993 994is( 995 $EVAL_ERROR, 996 '', 997 "NULL STATE shouldn't cause warnings" 998); 999 1000# ############################################################################# 1001# Extra processlist fields are ignored and don't cause errors 1002# https://bugs.launchpad.net/percona-toolkit/+bug/883098 1003# ############################################################################# 1004 1005$procs = [ 1006 [ [1, 'unauthenticated user', 'localhost', undef, 'Connect', 7, 1007 'some state', 1, 0, 0, 1] ], 1008 [ [1, 'unauthenticated user', 'localhost', undef, 'Connect', 8, 1009 undef, 2, 1, 2, 0] ], 1010], 1011 1012eval { 1013 parse_n_times( 1014 2, 1015 code => sub { 1016 return shift @$procs; 1017 }, 1018 time => Transformers::unix_timestamp('2001-01-01 00:05:00'), 1019 ); 1020}; 1021 1022is( 1023 $EVAL_ERROR, 1024 '', 1025 "Extra processlist fields don't cause errors" 1026); 1027# ############################################################################# 1028# Done. 1029# ############################################################################# 1030done_testing; 1031