Merged fix-1082104-pt-deadlock-logger-username-dash

bin/pt-deadlock-logger

@@ -3757,7 +3757,8 @@ my $d = qr/(\d+)/;                    # Digit
 my $t  = qr/((?:\d+ \d+)|(?:[A-Fa-f0-9]+))/;                # Transaction ID
 my $i = qr/((?:\d{1,3}\.){3}\d+)/;    # IP address
 my $n = qr/([^`\s]+)/;                # MySQL object name
-my $w = qr/(\w+)/;                    # Words
+my $u = qr/(\S+)/;                    # Username. This is somewhat wrong, but
+                                      # usernames with spaces are rare enough.
 my $s = qr/(\d{6} .\d:\d\d:\d\d)/;    # InnoDB timestamp
 
 # A thread's proc_info can be at least 98 different things I've found in the
@@ -4082,7 +4083,7 @@ sub parse_deadlocks {
                # the most useful marker for where I have to start guessing.
                ( $hostname, $ip ) = $thread_line =~ m/query id \d+(?: ([A-Za-z]\S+))? $i/m;
                if ( defined $ip ) {
-                  ($user, $query_status) = $thread_line =~ m/$ip $w(?: (.*))?$/;
+                  ($user, $query_status) = $thread_line =~ m/$ip $u(?: (.*))?$/;
                }
                else {
                   # OK, there wasn't an IP address.
@@ -4094,7 +4095,7 @@ sub parse_deadlocks {
                      # query_status.
                      # It's basically impossible to know which is which.
                      ( $hostname, $user, $query_status ) = $thread_line
-                        =~ m/query id \d+(?: ([A-Za-z]\S+))?(?: $w(?: (.*))?)?$/m;
+                        =~ m/query id \d+(?: ([A-Za-z]\S+))?(?: $u(?: (.*))?)?$/m;
                   }
                   else {
                      $user = 'system user';
@@ -4387,6 +4388,10 @@ held lock, you're looking at the same lock, so of course you'd prefer to see
 both wait-for locks and get more information.  If the two waited-for locks are
 not on the same table, more than two transactions were involved in the deadlock.
 
+Finally, keep in mind that, because usernames with spaces are not quoted by
+InnoDB, the tool will generally misreport the second word of these usernames
+as the hostname.
+
 =head1 OPTIONS
 
 This tool accepts additional command-line arguments.  Refer to the

t/pt-deadlock-logger/bugs.t

@@ -9,7 +9,7 @@ BEGIN {
 use strict;
 use warnings FATAL => 'all';
 use English qw(-no_match_vars);
-use Test::More tests => 1;
+use Test::More;
 
 use PerconaTest;
 use Sandbox;
@@ -67,7 +67,60 @@ is_deeply(
    "Bug 903443: pt-deadlock-logger parses the thread id incorrectly for MySQL 5.5",
 );
 
+# #############################################################################
+# https://bugs.launchpad.net/percona-toolkit/+bug/1082104
+# pt-deadlock-logger problem when the user have a dash in the name
+# #############################################################################
+
+$innodb_status_sample = load_file("t/pt-deadlock-logger/samples/bug_1082104.txt");
+
+is_deeply(
+   pt_deadlock_logger::parse_deadlocks($innodb_status_sample),
+   {
+      '1' => {
+          db => 'test',
+          hostname => 'localhost',
+          id => 1,
+          idx => 'PRIMARY',
+          ip => '',
+          lock_mode => 'X',
+          lock_type => 'RECORD',
+          query => 'update a set movie_id=96 where id =2',
+          server => '',
+          tbl => 'a',
+          thread => '19',
+          ts => '2011-12-12T22:52:42',
+          txn_id => 0,
+          txn_time => '161',
+          user => 'ro-ot',
+          victim => 0,
+          wait_hold => 'w'
+      },
+      '2' => {
+          db => 'test',
+          hostname => 'localhost',
+          id => 2,
+          idx => 'PRIMARY',
+          ip => '',
+          lock_mode => 'X',
+          lock_type => 'RECORD',
+          query => 'update a set movie_id=98 where id =4',
+          server => '',
+          tbl => 'a',
+          thread => '18',
+          ts => '2011-12-12T22:52:42',
+          txn_id => 0,
+          txn_time => '1026',
+          user => 'ro-ot',
+          victim => 1,
+          wait_hold => 'w'
+      }
+   },
+   "Bug 1082104: pt-deadlock-logger shows host as user when the username has a dash in the name",
+);
+
 # #############################################################################
 # Done.
 # #############################################################################
+done_testing;
 exit;

t/pt-deadlock-logger/samples/bug_1082104.txt

@@ -0,0 +1,53 @@
+=====================================
+070915 15:34:37 INNODB MONITOR OUTPUT
+=====================================
+Per second averages calculated from the last 24 seconds
+------------------------
+LATEST DETECTED DEADLOCK
+------------------------
+111212 22:52:42
+*** (1) TRANSACTION:
+TRANSACTION 3405, ACTIVE 161 sec starting index read
+mysql tables in use 1, locked 1
+LOCK WAIT 3 lock struct(s), heap size 376, 3 row lock(s), undo log entries 2
+MySQL thread id 19, OS thread handle 0x7fac301e4700, query id 180 localhost ro-ot Updating
+update a set movie_id=96 where id =2
+*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
+RECORD LOCKS space id 0 page no 307 n bits 72 index `PRIMARY` of table `test`.`a` trx id 3405 lock_mode X locks rec but not gap waiting
+Record lock, heap no 3 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
+ 0: len 4; hex 80000002; asc ;;
+ 1: len 6; hex 000000003404; asc 4 ;;
+ 2: len 7; hex 040000163b2515; asc ;% ;;
+ 3: len 4; hex 80000063; asc c;;
+ 4: len 1; hex 01; asc ;;
+ 5: len 8; hex 8000124a7c1acb8c; asc J| ;;
+
+*** (2) TRANSACTION:
+TRANSACTION 3404, ACTIVE 1026 sec starting index read
+mysql tables in use 1, locked 1
+3 lock struct(s), heap size 376, 2 row lock(s), undo log entries 1
+MySQL thread id 18, OS thread handle 0x7fac30225700, query id 181 localhost ro-ot Updating
+update a set movie_id=98 where id =4
+*** (2) HOLDS THE LOCK(S):
+RECORD LOCKS space id 0 page no 307 n bits 72 index `PRIMARY` of table `test`.`a` trx id 3404 lock_mode X locks rec but not gap
+Record lock, heap no 3 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
+ 0: len 4; hex 80000002; asc ;;
+ 1: len 6; hex 000000003404; asc 4 ;;
+ 2: len 7; hex 040000163b2515; asc ;% ;;
+ 3: len 4; hex 80000063; asc c;;
+ 4: len 1; hex 01; asc ;;
+ 5: len 8; hex 8000124a7c1acb8c; asc J| ;;
+
+*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
+RECORD LOCKS space id 0 page no 307 n bits 72 index `PRIMARY` of table `test`.`a` trx id 3404 lock_mode X locks rec but not gap waiting
+Record lock, heap no 5 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
+ 0: len 4; hex 80000004; asc ;;
+ 1: len 6; hex 000000003405; asc 4 ;;
+ 2: len 7; hex 0500000e7017e8; asc p ;;
+ 3: len 4; hex 80000062; asc b;;
+ 4: len 1; hex 01; asc ;;
+ 5: len 8; hex 8000124a7c1acbb6; asc J| ;;
+
+*** WE ROLL BACK TRANSACTION (2)
+END OF INNODB MONITOR OUTPUT
+============================