From b3776a25a8907a03b96260bade9ca55c4de7a2e8 Mon Sep 17 00:00:00 2001 From: Carlos Salguero Date: Thu, 23 Feb 2017 18:00:00 -0300 Subject: [PATCH 1/5] PT-81 Collect information about locks and transactions using P_S --- bin/pt-stalk | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) diff --git a/bin/pt-stalk b/bin/pt-stalk index c0b07dc8..f0e6b8b2 100755 --- a/bin/pt-stalk +++ b/bin/pt-stalk @@ -832,6 +832,8 @@ collect() { log "Could not find the MySQL error log" fi + ps_locks_transactions "$d/$p-ps-locks-transactions" + if [ "${mysql_version}" '>' "5.1" ]; then local mutex="SHOW ENGINE INNODB MUTEX" else @@ -1062,6 +1064,29 @@ tokudb_status() { >> "$d/$p-tokudbstatus$n" || rm -f "$d/$p-tokudbstatus$n" } +ps_locks_transactions() { + local outfile=$1 + + mysql -e 'select @@performance_schema' | grep "1" &>/dev/null + + if [ $? -eq 0 ]; then + local status="select t.processlist_id, ml.* from performance_schema.metadata_locks ml join performance_schema.threads t on (ml.owner_thread_id=t.thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + + local status="select t.processlist_id, et.* from performance_schema.events_transactions_current et join performance_schema.threads t using(thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + + local status="select t.processlist_id, et.* from performance_schema.events_transactions_history_long et join performance_schema.threads t using(thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + else + echo "Performance schema is not enabled" >> outfile + fi + +} + innodb_status() { local n=$1 From f88f74d5cf0cd0534ee21d2c3a0e6b8cd0bbb6ad Mon Sep 17 00:00:00 2001 From: Carlos Salguero Date: Thu, 23 Feb 2017 18:03:05 -0300 Subject: [PATCH 2/5] PT-81 Fixed typo --- bin/pt-stalk | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bin/pt-stalk b/bin/pt-stalk index f0e6b8b2..7e066c8a 100755 --- a/bin/pt-stalk +++ b/bin/pt-stalk @@ -1082,7 +1082,7 @@ ps_locks_transactions() { echo -e "\n$status\n" >> $outfile $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile else - echo "Performance schema is not enabled" >> outfile + echo "Performance schema is not enabled" >> $outfile fi } From 173d04b8b6ed56b25eb23d5b46c92ab09ddf864e Mon Sep 17 00:00:00 2001 From: Carlos Salguero Date: Thu, 23 Feb 2017 23:19:09 -0300 Subject: [PATCH 3/5] PT-81 Added missing query --- bin/pt-stalk | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/bin/pt-stalk b/bin/pt-stalk index 7e066c8a..9118b13b 100755 --- a/bin/pt-stalk +++ b/bin/pt-stalk @@ -1074,6 +1074,10 @@ ps_locks_transactions() { echo -e "\n$status\n" >> $outfile $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + local status="select t.processlist_id, th.* from performance_schema.table_handles th left join performance_schema.threads t on (th.owner_thread_id=t.thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + local status="select t.processlist_id, et.* from performance_schema.events_transactions_current et join performance_schema.threads t using(thread_id)\G" echo -e "\n$status\n" >> $outfile $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile From 90e1e9cf1eed7ebb249654e5bce00c52cab98cb8 Mon Sep 17 00:00:00 2001 From: Carlos Salguero Date: Sat, 25 Feb 2017 10:41:07 -0300 Subject: [PATCH 4/5] PT-81 Moved functions to the collect module --- bin/pt-stalk | 42 +++++++++++++++++++++--------------------- lib/bash/collect.sh | 29 +++++++++++++++++++++++++++++ 2 files changed, 50 insertions(+), 21 deletions(-) diff --git a/bin/pt-stalk b/bin/pt-stalk index 9118b13b..c6d72ec4 100755 --- a/bin/pt-stalk +++ b/bin/pt-stalk @@ -1064,6 +1064,27 @@ tokudb_status() { >> "$d/$p-tokudbstatus$n" || rm -f "$d/$p-tokudbstatus$n" } +innodb_status() { + local n=$1 + + local innostat="" + + $CMD_MYSQL $EXT_ARGV -e "SHOW /*!40100 ENGINE*/ INNODB STATUS\G" \ + >> "$d/$p-innodbstatus$n" + grep "END OF INNODB" "$d/$p-innodbstatus$n" >/dev/null || { + if [ -d /proc -a -d /proc/$mysqld_pid ]; then + for fd in /proc/$mysqld_pid/fd/*; do + file $fd | grep deleted >/dev/null && { + grep 'INNODB' $fd >/dev/null && { + cat $fd > "$d/$p-innodbstatus$n" + break + } + } + done + fi + } +} + ps_locks_transactions() { local outfile=$1 @@ -1091,27 +1112,6 @@ ps_locks_transactions() { } -innodb_status() { - local n=$1 - - local innostat="" - - $CMD_MYSQL $EXT_ARGV -e "SHOW /*!40100 ENGINE*/ INNODB STATUS\G" \ - >> "$d/$p-innodbstatus$n" - grep "END OF INNODB" "$d/$p-innodbstatus$n" >/dev/null || { - if [ -d /proc -a -d /proc/$mysqld_pid ]; then - for fd in /proc/$mysqld_pid/fd/*; do - file $fd | grep deleted >/dev/null && { - grep 'INNODB' $fd >/dev/null && { - cat $fd > "$d/$p-innodbstatus$n" - break - } - } - done - fi - } -} - # ########################################################################### # End collect package # ########################################################################### diff --git a/lib/bash/collect.sh b/lib/bash/collect.sh index 85b9c141..45dbc1f9 100644 --- a/lib/bash/collect.sh +++ b/lib/bash/collect.sh @@ -102,6 +102,8 @@ collect() { log "Could not find the MySQL error log" fi + ps_locks_transactions "$d/$p-ps-locks-transactions" + # Get a sample of these right away, so we can get these without interaction # with the other commands we're about to run. if [ "${mysql_version}" '>' "5.1" ]; then @@ -389,6 +391,33 @@ innodb_status() { } } +ps_locks_transactions() { + local outfile=$1 + + mysql -e 'select @@performance_schema' | grep "1" &>/dev/null + + if [ $? -eq 0 ]; then + local status="select t.processlist_id, ml.* from performance_schema.metadata_locks ml join performance_schema.threads t on (ml.owner_thread_id=t.thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + + local status="select t.processlist_id, th.* from performance_schema.table_handles th left join performance_schema.threads t on (th.owner_thread_id=t.thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + + local status="select t.processlist_id, et.* from performance_schema.events_transactions_current et join performance_schema.threads t using(thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + + local status="select t.processlist_id, et.* from performance_schema.events_transactions_history_long et join performance_schema.threads t using(thread_id)\G" + echo -e "\n$status\n" >> $outfile + $CMD_MYSQL $EXT_ARGV -e "$status" >> $outfile + else + echo "Performance schema is not enabled" >> $outfile + fi + +} + # ########################################################################### # End collect package # ########################################################################### From 4a056cf3b012ac58b55dd7b3e2ea65c578316ce1 Mon Sep 17 00:00:00 2001 From: Carlos Salguero Date: Tue, 21 Mar 2017 13:45:59 -0300 Subject: [PATCH 5/5] PT-81 Collect information about locks and transactions using P_S --- bin/pt-stalk | 11 ++++++- lib/bash/collect.sh | 11 ++++++- sandbox/servers/5.7/my.sandbox.cnf | 3 ++ t/pt-stalk/pt-stalk.t | 43 ++++++++++++++++++++++++++++ t/pt-stalk/samples/issue-1642751.sql | 29 +++++++++++++++++++ 5 files changed, 95 insertions(+), 2 deletions(-) create mode 100644 t/pt-stalk/samples/issue-1642751.sql diff --git a/bin/pt-stalk b/bin/pt-stalk index c6d72ec4..6a2c28ca 100755 --- a/bin/pt-stalk +++ b/bin/pt-stalk @@ -832,7 +832,6 @@ collect() { log "Could not find the MySQL error log" fi - ps_locks_transactions "$d/$p-ps-locks-transactions" if [ "${mysql_version}" '>' "5.1" ]; then local mutex="SHOW ENGINE INNODB MUTEX" @@ -906,6 +905,12 @@ collect() { log "Loop start: $(date +'TS %s.%N %F %T')" local start_time=$(date +'%s') local curr_time=$start_time + local ps_instrumentation_enabled=$($CMD_MYSQL $EXT_ARGV -e 'SELECT ENABLED FROM performance_schema.setup_instruments WHERE NAME = "transaction";' \ + | sed "2q;d" | sed 'y/ABCDEFGHIJKLMNOPQRSTUVWXYZ/abcdefghijklmnopqrstuvwxyz/') + if [ $ps_instrumentation_enabled != "yes" ]; then + log "Performance Schema instrumentation is disabled" + fi + while [ $((curr_time - start_time)) -lt $OPT_RUN_TIME ]; do disk_space $d > $d/$p-disk-space @@ -948,6 +953,10 @@ collect() { (echo $ts; transactions) >>"$d/$p-transactions" & fi + if [ $ps_instrumentation_enabled == "yes" ]; then + ps_locks_transactions "$d/$p-ps-locks-transactions" + fi + curr_time=$(date +'%s') done log "Loop end: $(date +'TS %s.%N %F %T')" diff --git a/lib/bash/collect.sh b/lib/bash/collect.sh index 45dbc1f9..960199d1 100644 --- a/lib/bash/collect.sh +++ b/lib/bash/collect.sh @@ -102,7 +102,6 @@ collect() { log "Could not find the MySQL error log" fi - ps_locks_transactions "$d/$p-ps-locks-transactions" # Get a sample of these right away, so we can get these without interaction # with the other commands we're about to run. @@ -193,6 +192,12 @@ collect() { log "Loop start: $(date +'TS %s.%N %F %T')" local start_time=$(date +'%s') local curr_time=$start_time + local ps_instrumentation_enabled=$($CMD_MYSQL $EXT_ARGV -e 'SELECT ENABLED FROM performance_schema.setup_instruments WHERE NAME = "transaction";' \ + | sed "2q;d" | sed 'y/ABCDEFGHIJKLMNOPQRSTUVWXYZ/abcdefghijklmnopqrstuvwxyz/') + if [ $ps_instrumentation_enabled != "yes" ]; then + log "Performance Schema instrumentation is disabled" + fi + while [ $((curr_time - start_time)) -lt $OPT_RUN_TIME ]; do # We check the disk, but don't exit, because we need to stop jobs if we @@ -242,6 +247,10 @@ collect() { (echo $ts; transactions) >>"$d/$p-transactions" & fi + if [ $ps_instrumentation_enabled == "yes" ]; then + ps_locks_transactions "$d/$p-ps-locks-transactions" + fi + curr_time=$(date +'%s') done log "Loop end: $(date +'TS %s.%N %F %T')" diff --git a/sandbox/servers/5.7/my.sandbox.cnf b/sandbox/servers/5.7/my.sandbox.cnf index 44796ef2..c5d9452e 100644 --- a/sandbox/servers/5.7/my.sandbox.cnf +++ b/sandbox/servers/5.7/my.sandbox.cnf @@ -30,3 +30,6 @@ lower_case_table_names = 0 # fkc test binlog_format = STATEMENT +performance_schema = ON +performance-schema-instrument='wait/lock/metadata/sql/mdl=ON' +performance-schema-instrument='transaction=ON' diff --git a/t/pt-stalk/pt-stalk.t b/t/pt-stalk/pt-stalk.t index 6ee5ee05..32d6c203 100644 --- a/t/pt-stalk/pt-stalk.t +++ b/t/pt-stalk/pt-stalk.t @@ -8,6 +8,7 @@ BEGIN { use strict; use warnings FATAL => 'all'; +use threads; use English qw(-no_match_vars); use Test::More; use Time::HiRes qw(sleep); @@ -421,7 +422,49 @@ like( qr/matched=yes/, "Accepts floating point values as treshold variable" ); + +# ########################################################################### +# Test report about performance schema transactions in MySQL 5.7+ +# ########################################################################### +cleanup(); + +SKIP: { + + skip "Only test on mysql 5.7" if ( $sandbox_version lt '5.7' ); + + sub start_thread { + # this must run in a thread because we need to have an uncommitted transaction + my ($dsn_opts) = @_; + my $dp = new DSNParser(opts=>$dsn_opts); + my $sb = new Sandbox(basedir => '/tmp', DSNParser => $dp); + my $dbh = $sb->get_dbh_for('master'); + $sb->load_file('master', "t/pt-stalk/samples/issue-1642751.sql"); + } + my $thr = threads->create('start_thread', $dsn_opts); + $thr->detach(); + threads->yield(); + + my $cmd = "$trunk/bin/pt-stalk --no-stalk --iterations=1 --host=127.0.0.1 --port=12345 --user=msandbox " + . "--password=msandbox --sleep 0 --run-time=10 --dest $dest --log $log_file --iterations=1 " + . "--run-time=2 --pid $pid_file --defaults-file=$cnf >$log_file 2>&1"; + system($cmd); + sleep 15; + PerconaTest::kill_program(pid_file => $pid_file); + + $output = `cat $dest/*-ps-locks-transactions 2>/dev/null`; + like( + $output, + qr/ STATE: ACTIVE/, + "MySQL 5.7 ACTIVE transactions" + ); + + like( + $output, + qr/ STATE: COMMITTED/, + "MySQL 5.7 COMMITTED transactions" + ); +} # ############################################################################# # Done. diff --git a/t/pt-stalk/samples/issue-1642751.sql b/t/pt-stalk/samples/issue-1642751.sql new file mode 100644 index 00000000..087792c4 --- /dev/null +++ b/t/pt-stalk/samples/issue-1642751.sql @@ -0,0 +1,29 @@ +/* This enables perfomance schema without a server restart */ +UPDATE performance_schema.setup_consumers SET enabled='YES' WHERE NAME = 'events_waits_current'; + +/* Enable instrumentation */ +UPDATE performance_schema.setup_consumers SET ENABLED='YES' WHERE NAME LIKE '%events_transactions%'; +UPDATE performance_schema.setup_consumers SET ENABLED='YES' WHERE NAME LIKE '%events_transactions%'; +UPDATE performance_schema.setup_instruments SET ENABLED='YES' WHERE NAME = 'wait/lock/metadata/sql/mdl'; + +CREATE SCHEMA IF NOT EXISTS test; + +USE test; +DROP TABLE IF EXISTS t1; +CREATE TABLE t1 (id int) ENGINE=INNODB; + +/* Successfuly finished transaction */ +SET autocommit=0; +START TRANSACTION; +INSERT INTO t1 VALUES (CEIL(RAND()*10000)); +COMMIT; + +/* Ongoing transaction */ +SET autocommit=0; +START TRANSACTION; +INSERT INTO t1 VALUES (CEIL(RAND()*10000)); +/* Wait to let pt-stalk to collect the data and find an ACTIVE transaction */ +SELECT SLEEP(11); +COMMIT; + +DROP DATABASE IF EXISTS test;