From 2b40a389a5d82cfea7fabf1f34ff2737b4d65cfa Mon Sep 17 00:00:00 2001 From: Nirbhay Choubey Date: Sun, 30 Nov 2014 21:13:41 -0500 Subject: MDEV-4412 : SLOW QUERY LOG - add affected rows (UPDATE / DELETE) in slow query log Added Rows_affected to slow query log & mysql.slow_log table. --- mysql-test/r/log_slow.result | 1 + mysql-test/r/log_state.result | 8 ++--- mysql-test/r/log_tables.result | 40 +++++++++++++--------- mysql-test/r/mysqldump.result | 3 +- mysql-test/r/system_mysql_db.result | 3 +- mysql-test/suite/funcs_1/r/is_columns_mysql.result | 2 ++ .../funcs_1/r/is_columns_mysql_embedded.result | 2 ++ mysql-test/t/log_tables.test | 10 +++--- scripts/mysql_system_tables.sql | 2 +- scripts/mysql_system_tables_fix.sql | 2 ++ scripts/mysqldumpslow.sh | 19 ++++++---- sql/log.cc | 16 +++++++-- 12 files changed, 70 insertions(+), 38 deletions(-) diff --git a/mysql-test/r/log_slow.result b/mysql-test/r/log_slow.result index ca8b9e7c439..f7670f3d3db 100644 --- a/mysql-test/r/log_slow.result +++ b/mysql-test/r/log_slow.result @@ -56,6 +56,7 @@ insert_id int(11) NO NULL server_id int(10) unsigned NO NULL sql_text mediumtext NO NULL thread_id bigint(21) unsigned NO NULL +rows_affected int(11) NO NULL flush slow logs; set long_query_time=0.1; set log_slow_filter=''; diff --git a/mysql-test/r/log_state.result b/mysql-test/r/log_state.result index f157887de4b..6e3ab8a991a 100644 --- a/mysql-test/r/log_state.result +++ b/mysql-test/r/log_state.result @@ -39,7 +39,7 @@ select sleep(@long_query_time + 1); sleep(@long_query_time + 1) 0 select * from mysql.slow_log where sql_text NOT LIKE '%slow_log%'; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected # Switch to connection default set global slow_query_log= ON; set local slow_query_log= ON; @@ -49,14 +49,14 @@ select sleep(@long_query_time + 1); sleep(@long_query_time + 1) 0 select * from mysql.slow_log where sql_text NOT LIKE '%slow_log%'; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected set local slow_query_log= ON; select sleep(@long_query_time + 2); sleep(@long_query_time + 2) 0 select * from mysql.slow_log where sql_text NOT LIKE '%slow_log%'; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id -TIMESTAMP USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 select sleep(@long_query_time + 2) THREAD_ID +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected +TIMESTAMP USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 select sleep(@long_query_time + 2) THREAD_ID 0 # Switch to connection default show global variables where Variable_name = 'general_log' or Variable_name = 'slow_query_log'; diff --git a/mysql-test/r/log_tables.result b/mysql-test/r/log_tables.result index 4471c01c99b..8e39ed861bd 100644 --- a/mysql-test/r/log_tables.result +++ b/mysql-test/r/log_tables.result @@ -17,7 +17,7 @@ event_time user_host thread_id server_id command_type argument TIMESTAMP USER_HOST THREAD_ID 1 Query select * from general_log truncate table slow_log; select * from slow_log; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected truncate table general_log; select * from general_log where argument like '%general_log%'; event_time user_host thread_id server_id command_type argument @@ -82,7 +82,8 @@ slow_log CREATE TABLE `slow_log` ( `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, - `thread_id` bigint(21) unsigned NOT NULL + `thread_id` bigint(21) unsigned NOT NULL, + `rows_affected` int(11) NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' show fields from mysql.slow_log; Field Type Null Key Default Extra @@ -98,6 +99,7 @@ insert_id int(11) NO NULL server_id int(10) unsigned NO NULL sql_text mediumtext NO NULL thread_id bigint(21) unsigned NO NULL +rows_affected int(11) NO NULL flush logs; flush tables; SET GLOBAL GENERAL_LOG=ON; @@ -148,8 +150,8 @@ select sleep(2); sleep(2) 0 select * from mysql.slow_log; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id -TIMESTAMP USER_HOST QUERY_TIME 00:00:00.000000 1 0 mysql 0 0 1 select sleep(2) THREAD_ID +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected +TIMESTAMP USER_HOST QUERY_TIME 00:00:00.000000 1 0 mysql 0 0 1 select sleep(2) THREAD_ID 0 set @@session.long_query_time = @saved_long_query_time; alter table mysql.general_log engine=myisam; ERROR HY000: You cannot 'ALTER' a log table if logging is enabled @@ -187,7 +189,8 @@ slow_log CREATE TABLE `slow_log` ( `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, - `thread_id` bigint(21) unsigned NOT NULL + `thread_id` bigint(21) unsigned NOT NULL, + `rows_affected` int(11) NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' alter table mysql.general_log engine=myisam; alter table mysql.slow_log engine=myisam; @@ -215,7 +218,8 @@ slow_log CREATE TABLE `slow_log` ( `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, - `thread_id` bigint(21) unsigned NOT NULL + `thread_id` bigint(21) unsigned NOT NULL, + `rows_affected` int(11) NOT NULL ) ENGINE=MyISAM DEFAULT CHARSET=utf8 COMMENT='Slow log' set global general_log='ON'; set global slow_query_log='ON'; @@ -286,7 +290,8 @@ ON UPDATE CURRENT_TIMESTAMP, `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, -`thread_id` BIGINT(21) UNSIGNED NOT NULL +`thread_id` BIGINT(21) UNSIGNED NOT NULL, +`rows_affected` int(11) NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'; set global general_log='ON'; set global slow_query_log='ON'; @@ -313,7 +318,7 @@ event_time user_host thread_id server_id command_type argument TIMESTAMP USER_HOST THREAD_ID 1 Query select * from general_log truncate table slow_log; select * from slow_log; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected create table general_log_new like general_log; rename table general_log TO renamed_general_log, general_log_new TO general_log; create table slow_log_new like slow_log; @@ -334,9 +339,9 @@ TIMESTAMP USER_HOST THREAD_ID 1 Query select * from slow_log TIMESTAMP USER_HOST THREAD_ID 1 Query create table general_log_new like general_log TIMESTAMP USER_HOST THREAD_ID 1 Query rename table general_log TO renamed_general_log, general_log_new TO general_log select * from slow_log; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected select * from renamed_slow_log; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected set global general_log='OFF'; RENAME TABLE general_log TO general_log2; set global slow_query_log='OFF'; @@ -429,10 +434,10 @@ SELECT "My own slow query", sleep(2); My own slow query sleep(2) My own slow query 0 SELECT * FROM mysql.slow_log WHERE seq >= 2 LIMIT 3; -start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id seq -START_TIME USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 SELECT "My own slow query", sleep(2) 3 2 -START_TIME USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 SELECT "My own slow query", sleep(2) 3 3 -START_TIME USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 SELECT "My own slow query", sleep(2) 3 4 +start_time user_host query_time lock_time rows_sent rows_examined db last_insert_id insert_id server_id sql_text thread_id rows_affected seq +START_TIME USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 SELECT "My own slow query", sleep(2) 3 0 2 +START_TIME USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 SELECT "My own slow query", sleep(2) 3 0 3 +START_TIME USER_HOST QUERY_TIME 00:00:00.000000 1 0 test 0 0 1 SELECT "My own slow query", sleep(2) 3 0 4 SET GLOBAL slow_query_log = 0; SET SESSION long_query_time =@saved_long_query_time; FLUSH LOGS; @@ -550,7 +555,7 @@ CREATE procedure `db_17876.archiveSlowLog`() BEGIN DECLARE start_time, query_time, lock_time CHAR(28); DECLARE user_host MEDIUMTEXT; -DECLARE rows_set, rows_examined, last_insert_id, insert_id, server_id INT; +DECLARE rows_set, rows_examined, last_insert_id, insert_id, server_id, rows_affected INT; DECLARE thread_id BIGINT UNSIGNED; DECLARE dbname MEDIUMTEXT; DECLARE sql_text BLOB; @@ -565,14 +570,15 @@ DECLARE CONTINUE HANDLER FOR ER_SP_FETCH_NO_DATA SET done = 1; FETCH cur1 INTO start_time, user_host, query_time, lock_time, rows_set, rows_examined, dbname, last_insert_id, -insert_id, server_id, sql_text, thread_id; +insert_id, server_id, sql_text, thread_id, rows_affected; END; IF NOT done THEN BEGIN INSERT INTO `db_17876.slow_log_data` VALUES(start_time, user_host, query_time, lock_time, rows_set, rows_examined, -dbname, last_insert_id, insert_id, server_id, sql_text, thread_id); +dbname, last_insert_id, insert_id, server_id, sql_text, thread_id, +rows_affected); END; END IF; END; diff --git a/mysql-test/r/mysqldump.result b/mysql-test/r/mysqldump.result index a7ef5d4d92f..a967af77a8d 100644 --- a/mysql-test/r/mysqldump.result +++ b/mysql-test/r/mysqldump.result @@ -5264,7 +5264,8 @@ slow_log CREATE TABLE `slow_log` ( `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, - `thread_id` bigint(21) unsigned NOT NULL + `thread_id` bigint(21) unsigned NOT NULL, + `rows_affected` int(11) NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' SET @@global.log_output= @old_log_output_state; SET @@global.slow_query_log= @old_slow_query_log_state; diff --git a/mysql-test/r/system_mysql_db.result b/mysql-test/r/system_mysql_db.result index f195b0a607e..2fe6512eee3 100644 --- a/mysql-test/r/system_mysql_db.result +++ b/mysql-test/r/system_mysql_db.result @@ -273,7 +273,8 @@ slow_log CREATE TABLE `slow_log` ( `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, - `thread_id` bigint(21) unsigned NOT NULL + `thread_id` bigint(21) unsigned NOT NULL, + `rows_affected` int(11) NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' show create table table_stats; Table Create Table diff --git a/mysql-test/suite/funcs_1/r/is_columns_mysql.result b/mysql-test/suite/funcs_1/r/is_columns_mysql.result index 09adebfab1c..d1685f40314 100644 --- a/mysql-test/suite/funcs_1/r/is_columns_mysql.result +++ b/mysql-test/suite/funcs_1/r/is_columns_mysql.result @@ -172,6 +172,7 @@ def mysql slow_log insert_id 9 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) def mysql slow_log last_insert_id 8 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) select,insert,update,references def mysql slow_log lock_time 4 NULL NO time NULL NULL NULL NULL 6 NULL NULL time(6) select,insert,update,references def mysql slow_log query_time 3 NULL NO time NULL NULL NULL NULL 6 NULL NULL time(6) select,insert,update,references +def mysql slow_log rows_affected 13 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) select,insert,update,references def mysql slow_log rows_examined 6 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) select,insert,update,references def mysql slow_log rows_sent 5 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) select,insert,update,references def mysql slow_log server_id 10 NULL NO int NULL NULL 10 0 NULL NULL NULL int(10) unsigned select,insert,update,references @@ -499,6 +500,7 @@ NULL mysql slow_log insert_id int NULL NULL NULL NULL int(11) NULL mysql slow_log server_id int NULL NULL NULL NULL int(10) unsigned 1.0000 mysql slow_log sql_text mediumtext 16777215 16777215 utf8 utf8_general_ci mediumtext NULL mysql slow_log thread_id bigint NULL NULL NULL NULL bigint(21) unsigned +NULL mysql slow_log rows_affected int NULL NULL NULL NULL int(11) 3.0000 mysql tables_priv Host char 60 180 utf8 utf8_bin char(60) 3.0000 mysql tables_priv Db char 64 192 utf8 utf8_bin char(64) 3.0000 mysql tables_priv User char 80 240 utf8 utf8_bin char(80) diff --git a/mysql-test/suite/funcs_1/r/is_columns_mysql_embedded.result b/mysql-test/suite/funcs_1/r/is_columns_mysql_embedded.result index 7304f76562f..bd13bf3241f 100644 --- a/mysql-test/suite/funcs_1/r/is_columns_mysql_embedded.result +++ b/mysql-test/suite/funcs_1/r/is_columns_mysql_embedded.result @@ -172,6 +172,7 @@ def mysql slow_log insert_id 9 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) def mysql slow_log last_insert_id 8 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) def mysql slow_log lock_time 4 NULL NO time NULL NULL NULL NULL 6 NULL NULL time(6) def mysql slow_log query_time 3 NULL NO time NULL NULL NULL NULL 6 NULL NULL time(6) +def mysql slow_log rows_affected 13 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) def mysql slow_log rows_examined 6 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) def mysql slow_log rows_sent 5 NULL NO int NULL NULL 10 0 NULL NULL NULL int(11) def mysql slow_log server_id 10 NULL NO int NULL NULL 10 0 NULL NULL NULL int(10) unsigned @@ -499,6 +500,7 @@ NULL mysql slow_log insert_id int NULL NULL NULL NULL int(11) NULL mysql slow_log server_id int NULL NULL NULL NULL int(10) unsigned 1.0000 mysql slow_log sql_text mediumtext 16777215 16777215 utf8 utf8_general_ci mediumtext NULL mysql slow_log thread_id bigint NULL NULL NULL NULL bigint(21) unsigned +NULL mysql slow_log rows_affected int NULL NULL NULL NULL int(11) 3.0000 mysql tables_priv Host char 60 180 utf8 utf8_bin char(60) 3.0000 mysql tables_priv Db char 64 192 utf8 utf8_bin char(64) 3.0000 mysql tables_priv User char 80 240 utf8 utf8_bin char(80) diff --git a/mysql-test/t/log_tables.test b/mysql-test/t/log_tables.test index 64c70c039ab..69e16bc87f5 100644 --- a/mysql-test/t/log_tables.test +++ b/mysql-test/t/log_tables.test @@ -309,7 +309,8 @@ CREATE TABLE `slow_log` ( `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, - `thread_id` BIGINT(21) UNSIGNED NOT NULL + `thread_id` BIGINT(21) UNSIGNED NOT NULL, + `rows_affected` int(11) NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'; set global general_log='ON'; @@ -743,7 +744,7 @@ CREATE procedure `db_17876.archiveSlowLog`() BEGIN DECLARE start_time, query_time, lock_time CHAR(28); DECLARE user_host MEDIUMTEXT; - DECLARE rows_set, rows_examined, last_insert_id, insert_id, server_id INT; + DECLARE rows_set, rows_examined, last_insert_id, insert_id, server_id, rows_affected INT; DECLARE thread_id BIGINT UNSIGNED; DECLARE dbname MEDIUMTEXT; DECLARE sql_text BLOB; @@ -762,7 +763,7 @@ BEGIN FETCH cur1 INTO start_time, user_host, query_time, lock_time, rows_set, rows_examined, dbname, last_insert_id, - insert_id, server_id, sql_text, thread_id; + insert_id, server_id, sql_text, thread_id, rows_affected; END; IF NOT done THEN @@ -770,7 +771,8 @@ BEGIN INSERT INTO `db_17876.slow_log_data` VALUES(start_time, user_host, query_time, lock_time, rows_set, rows_examined, - dbname, last_insert_id, insert_id, server_id, sql_text, thread_id); + dbname, last_insert_id, insert_id, server_id, sql_text, thread_id, + rows_affected); END; END IF; END; diff --git a/scripts/mysql_system_tables.sql b/scripts/mysql_system_tables.sql index faad08ab6d9..eea65f285d3 100644 --- a/scripts/mysql_system_tables.sql +++ b/scripts/mysql_system_tables.sql @@ -95,7 +95,7 @@ DROP PREPARE stmt; -- Create slow_log if CSV is enabled. -SET @str = IF (@have_csv = 'YES', 'CREATE TABLE IF NOT EXISTS slow_log (start_time TIMESTAMP(6) NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, user_host MEDIUMTEXT NOT NULL, query_time TIME(6) NOT NULL, lock_time TIME(6) NOT NULL, rows_sent INTEGER NOT NULL, rows_examined INTEGER NOT NULL, db VARCHAR(512) NOT NULL, last_insert_id INTEGER NOT NULL, insert_id INTEGER NOT NULL, server_id INTEGER UNSIGNED NOT NULL, sql_text MEDIUMTEXT NOT NULL, thread_id BIGINT(21) UNSIGNED NOT NULL) engine=CSV CHARACTER SET utf8 comment="Slow log"', 'SET @dummy = 0'); +SET @str = IF (@have_csv = 'YES', 'CREATE TABLE IF NOT EXISTS slow_log (start_time TIMESTAMP(6) NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, user_host MEDIUMTEXT NOT NULL, query_time TIME(6) NOT NULL, lock_time TIME(6) NOT NULL, rows_sent INTEGER NOT NULL, rows_examined INTEGER NOT NULL, db VARCHAR(512) NOT NULL, last_insert_id INTEGER NOT NULL, insert_id INTEGER NOT NULL, server_id INTEGER UNSIGNED NOT NULL, sql_text MEDIUMTEXT NOT NULL, thread_id BIGINT(21) UNSIGNED NOT NULL, rows_affected INTEGER NOT NULL) engine=CSV CHARACTER SET utf8 comment="Slow log"', 'SET @dummy = 0'); PREPARE stmt FROM @str; EXECUTE stmt; diff --git a/scripts/mysql_system_tables_fix.sql b/scripts/mysql_system_tables_fix.sql index b9bb59cb188..dab38bbd48c 100644 --- a/scripts/mysql_system_tables_fix.sql +++ b/scripts/mysql_system_tables_fix.sql @@ -250,6 +250,8 @@ SET @old_log_state = @@global.slow_query_log; SET GLOBAL slow_query_log = 'OFF'; ALTER TABLE slow_log ADD COLUMN thread_id BIGINT(21) UNSIGNED NOT NULL AFTER sql_text; +ALTER TABLE slow_log + ADD COLUMN rows_affected INTEGER NOT NULL AFTER thread_id; ALTER TABLE slow_log MODIFY start_time TIMESTAMP(6) NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, MODIFY user_host MEDIUMTEXT NOT NULL, diff --git a/scripts/mysqldumpslow.sh b/scripts/mysqldumpslow.sh index c04ffad7457..d8b6158ecbe 100644 --- a/scripts/mysqldumpslow.sh +++ b/scripts/mysqldumpslow.sh @@ -27,8 +27,8 @@ use strict; use Getopt::Long; -# t=time, l=lock time, r=rows -# at, al, and ar are the corresponding averages +# t=time, l=lock time, r=rows, a=rows affected +# at, al, ar and aa are the corresponding averages my %opt = ( s => 'at', @@ -110,9 +110,11 @@ while ( defined($_ = shift @pending) or defined($_ = <>) ) { s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//; my ($user,$host) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+).*\n// ? ($1,$2) : ('',''); - s/^# Thread_id: [0-9]+\s+Schema: [^\n]+\n//; + s/^# Thread_id: [0-9]+\s+Schema: .*\s+QC_hit:.*[^\n]+\n//; s/^# Query_time: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+)\s+Rows_examined: ([0-9.]+).*\n//; my ($t, $l, $r, $e) = ($1, $2, $3, $4); + s/^# Rows_affected: ([0-9.]+).*\n//; + my ($a) = ($1); $t -= $l unless $opt{l}; @@ -156,6 +158,7 @@ while ( defined($_ = shift @pending) or defined($_ = <>) ) { $s->{l} += $l; $s->{r} += $r; $s->{e} += $e; + $s->{a} += $a; $s->{users}->{$user}++ if $user; $s->{hosts}->{$host}++ if $host; @@ -164,11 +167,12 @@ while ( defined($_ = shift @pending) or defined($_ = <>) ) { foreach (keys %stmt) { my $v = $stmt{$_} || die; - my ($c, $t, $l, $r, $e) = @{ $v }{qw(c t l r e)}; + my ($c, $t, $l, $r, $e, $a) = @{ $v }{qw(c t l r e a)}; $v->{at} = $t / $c; $v->{al} = $l / $c; $v->{ar} = $r / $c; $v->{ae} = $e / $c; + $v->{aa} = $a / $c; } my @sorted = sort { $stmt{$b}->{$opt{s}} <=> $stmt{$a}->{$opt{s}} } keys %stmt; @@ -177,13 +181,13 @@ my @sorted = sort { $stmt{$b}->{$opt{s}} <=> $stmt{$a}->{$opt{s}} } keys %stmt; foreach (@sorted) { my $v = $stmt{$_} || die; - my ($c, $t,$at, $l,$al, $r,$ar,$e, $ae) = @{ $v }{qw(c t at l al r ar e ae)}; + my ($c, $t, $at, $l, $al, $r, $ar, $e, $ae, $a, $aa) = @{ $v }{qw(c t at l al r ar e ae a aa)}; my @users = keys %{$v->{users}}; my $user = (@users==1) ? $users[0] : sprintf "%dusers",scalar @users; my @hosts = keys %{$v->{hosts}}; my $host = (@hosts==1) ? $hosts[0] : sprintf "%dhosts",scalar @hosts; - printf "Count: %d Time=%.2fs (%ds) Lock=%.2fs (%ds) Rows_sent=%.1f (%d), Rows_examined=%.1f (%d), $user\@$host\n%s\n\n", - $c, $at,$t, $al,$l, $ar,$r, $ae, $e, $_; + printf "Count: %d Time=%.2fs (%ds) Lock=%.2fs (%ds) Rows_sent=%.1f (%d), Rows_examined=%.1f (%d), Rows_affected=%.1f (%d), $user\@$host\n%s\n\n", + $c, $at,$t, $al,$l, $ar,$r, $ae, $e, $aa, $a, $_; } sub usage { @@ -203,6 +207,7 @@ Parse and summarize the MySQL slow query log. Options are al: average lock time ar: average rows sent at: average query time + aa: average rows affected c: count l: lock time r: rows sent diff --git a/sql/log.cc b/sql/log.cc index ff04105b43d..24e52838e47 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -837,7 +837,7 @@ bool Log_to_csv_event_handler:: restore_record(table, s->default_values); // Get empty record /* check that all columns exist */ - if (table->s->fields < 11) + if (table->s->fields < 13) goto err; /* store the time and user values */ @@ -918,6 +918,12 @@ bool Log_to_csv_event_handler:: if (table->field[11]->store((longlong) thd->thread_id, TRUE)) goto err; + /* Rows_affected */ + if (table->field[12]->store(thd->get_stmt_da()->is_ok() ? + (longlong) thd->get_stmt_da()->affected_rows() : + 0, TRUE)) + goto err; + /* log table entries are not replicated */ if (table->file->ha_write_row(table->record[0])) goto err; @@ -2918,12 +2924,16 @@ bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time, sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0); if (my_b_printf(&log_file, "# Thread_id: %lu Schema: %s QC_hit: %s\n" \ - "# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu\n", + "# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu\n" \ + "# Rows_affected: %lu\n", (ulong) thd->thread_id, (thd->db ? thd->db : ""), ((thd->query_plan_flags & QPLAN_QC) ? "Yes" : "No"), query_time_buff, lock_time_buff, (ulong) thd->get_sent_row_count(), - (ulong) thd->get_examined_row_count()) == (size_t) -1) + (ulong) thd->get_examined_row_count(), + thd->get_stmt_da()->is_ok() ? + (ulong) thd->get_stmt_da()->affected_rows() : + 0) == (size_t) -1) tmp_errno= errno; if ((thd->variables.log_slow_verbosity & LOG_SLOW_VERBOSITY_QUERY_PLAN) && (thd->query_plan_flags & -- cgit v1.2.1