Skip to content

Commit 0a4a78a

Browse files
author
Alexey Botchkov
committed
MDEV-6058 MySQL Bug #11766693: LOG-SLOW-ADMIN-STATEMENTS AND
 LOG-SLOW-SLAVE-STATEMENTS NOT DISPLAYED. These parameters were moved from the command line options to the system variables section. Treatment of the opt_log_slow_slave_statements changed to let the dynamic change of the variable.
1 parent fd6c588 commit 0a4a78a

9 files changed

+207
-8
lines changed

‎mysql-test/r/log_slow.result

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,8 +9,10 @@ select @@log_slow_verbosity;
99

1010
show variables like "log_slow%";
1111
Variable_name Value
12+
log_slow_admin_statements OFF
1213
log_slow_filter admin,filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk
1314
log_slow_rate_limit 1
15+
log_slow_slave_statements OFF
1416
log_slow_verbosity
1517
set @org_slow_query_log= @@global.slow_query_log;
1618
set @@log_slow_filter= "filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk,admin";

‎mysql-test/suite/rpl/r/rpl_slow_query_log.result

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -76,6 +76,21 @@ ALTER TABLE t1 ADD INDEX id1(a);
7676
INSERT INTO t1 values(1, sleep(3));
7777
### Assertion is good. Both Master and Slave exhibit the
7878
### same number of queries in slow log: 1
79+
********************************************************************
80+
**** TRUNCATE the slow log then check whether runtime changes of
81+
**** log_slow_slave_statements work without slave restart.
82+
********************************************************************
83+
SET @old_log_slow_slave_statements= @@global.log_slow_slave_statements;
84+
SET @@global.log_slow_slave_statements = off;
85+
TRUNCATE mysql.slow_log;
86+
INSERT INTO t1 values(1, sleep(3));;
87+
SELECT sql_text FROM mysql.slow_log WHERE sql_text like 'INSERT INTO t1 values(1, sleep(3))';
88+
sql_text
89+
SET @@global.log_slow_slave_statements = on;
90+
INSERT INTO t1 values(1, sleep(3));;
91+
SELECT sql_text FROM mysql.slow_log WHERE sql_text like 'INSERT INTO t1 values(1, sleep(3))';
92+
sql_text
93+
INSERT INTO t1 values(1, sleep(3))
7994
SET @@global.log_output= @old_log_output;
8095
SET @@global.long_query_time= @old_long_query_time;
8196
DROP TABLE t1;

‎mysql-test/suite/rpl/t/rpl_slow_query_log.test

Lines changed: 33 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -299,6 +299,39 @@ if ($master_slow_query == $slave_slow_query)
299299
-- echo ### same number of queries in slow log: $master_slow_query
300300
}
301301

302+
-- echo ********************************************************************
303+
-- echo **** TRUNCATE the slow log then check whether runtime changes of
304+
-- echo **** log_slow_slave_statements work without slave restart.
305+
-- echo ********************************************************************
306+
307+
SET @old_log_slow_slave_statements= @@global.log_slow_slave_statements;
308+
SET @@global.log_slow_slave_statements = off;
309+
TRUNCATE mysql.slow_log;
310+
311+
-- connection master
312+
313+
--disable_warnings
314+
-- eval $slow_query;
315+
--enable_warnings
316+
sync_slave_with_master;
317+
318+
-- connection slave
319+
320+
eval SELECT sql_text FROM mysql.slow_log WHERE sql_text like '$slow_query';
321+
322+
SET @@global.log_slow_slave_statements = on;
323+
324+
-- connection master
325+
326+
--disable_warnings
327+
-- eval $slow_query;
328+
--enable_warnings
329+
sync_slave_with_master;
330+
331+
-- connection slave
332+
333+
eval SELECT sql_text FROM mysql.slow_log WHERE sql_text like '$slow_query';
334+
302335
-- connection master
303336
SET @@global.log_output= @old_log_output;
304337
SET @@global.long_query_time= @old_long_query_time;

‎mysql-test/suite/sys_vars/r/log_slow_admin_statements_func.result

Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
1+
SET @old_log_output= @@global.log_output;
2+
SET @old_slow_query_log= @@global.slow_query_log;
3+
SET @old_long_query_time= @@session.long_query_time;
4+
SET @old_log_slow_admin_statements= @@global.log_slow_admin_statements;
5+
USE test;
6+
CREATE TABLE log_slow_admin_statements (
7+
i INT PRIMARY KEY AUTO_INCREMENT,
8+
j VARCHAR(255)
9+
) ENGINE=InnoDB;
10+
SET GLOBAL log_output = 'file,table';
11+
SET GLOBAL slow_query_log = on;
12+
SET SESSION long_query_time = 0;
13+
SET GLOBAL log_slow_admin_statements = on;
14+
ALTER TABLE log_slow_admin_statements ADD COLUMN k INT DEFAULT 17;
15+
CREATE PROCEDURE add_rows()
16+
BEGIN
17+
DECLARE count INT;
18+
SET count = 1;
19+
INSERT INTO log_slow_admin_statements(j) values (REPEAT('A', 255));
20+
WHILE count <= 15 DO
21+
INSERT INTO log_slow_admin_statements(j) SELECT j FROM log_slow_admin_statements;
22+
SET count = count + 1;
23+
END WHILE;
24+
END
25+
$
26+
CALL add_rows();
27+
OPTIMIZE TABLE log_slow_admin_statements;
28+
Table Op Msg_type Msg_text
29+
test.log_slow_admin_statements optimize note Table does not support optimize, doing recreate + analyze instead
30+
test.log_slow_admin_statements optimize status OK
31+
CHECK TABLE log_slow_admin_statements EXTENDED;
32+
Table Op Msg_type Msg_text
33+
test.log_slow_admin_statements check status OK
34+
DROP TABLE log_slow_admin_statements;
35+
SELECT sql_text FROM mysql.slow_log WHERE sql_text LIKE '%TABLE log_slow_admin_statements%';
36+
sql_text
37+
ALTER TABLE log_slow_admin_statements ADD COLUMN k INT DEFAULT 17
38+
OPTIMIZE TABLE log_slow_admin_statements
39+
CHECK TABLE log_slow_admin_statements EXTENDED
40+
DROP TABLE log_slow_admin_statements
41+
SET @@global.log_output= @old_log_output;
42+
SET @@global.slow_query_log= @old_slow_query_log;
43+
SET @@session.long_query_time= @old_long_query_time;
44+
SET @@global.log_slow_admin_statements= @old_log_slow_admin_statements;
45+
DROP PROCEDURE add_rows;
46+
TRUNCATE TABLE mysql.slow_log;

‎mysql-test/suite/sys_vars/r/sysvars_server_notembedded.result

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1829,6 +1829,20 @@ NUMERIC_BLOCK_SIZE NULL
18291829
ENUM_VALUE_LIST OFF,ON
18301830
READ_ONLY YES
18311831
COMMAND_LINE_ARGUMENT OPTIONAL
1832+
VARIABLE_NAME LOG_SLOW_ADMIN_STATEMENTS
1833+
SESSION_VALUE NULL
1834+
GLOBAL_VALUE OFF
1835+
GLOBAL_VALUE_ORIGIN COMPILE-TIME
1836+
DEFAULT_VALUE OFF
1837+
VARIABLE_SCOPE GLOBAL
1838+
VARIABLE_TYPE BOOLEAN
1839+
VARIABLE_COMMENT Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to the slow log if it is open.
1840+
NUMERIC_MIN_VALUE NULL
1841+
NUMERIC_MAX_VALUE NULL
1842+
NUMERIC_BLOCK_SIZE NULL
1843+
ENUM_VALUE_LIST OFF,ON
1844+
READ_ONLY NO
1845+
COMMAND_LINE_ARGUMENT OPTIONAL
18321846
VARIABLE_NAME LOG_SLOW_FILTER
18331847
SESSION_VALUE admin,filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk
18341848
GLOBAL_VALUE admin,filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk
@@ -1857,6 +1871,20 @@ NUMERIC_BLOCK_SIZE 1
18571871
ENUM_VALUE_LIST NULL
18581872
READ_ONLY NO
18591873
COMMAND_LINE_ARGUMENT REQUIRED
1874+
VARIABLE_NAME LOG_SLOW_SLAVE_STATEMENTS
1875+
SESSION_VALUE NULL
1876+
GLOBAL_VALUE OFF
1877+
GLOBAL_VALUE_ORIGIN COMPILE-TIME
1878+
DEFAULT_VALUE OFF
1879+
VARIABLE_SCOPE GLOBAL
1880+
VARIABLE_TYPE BOOLEAN
1881+
VARIABLE_COMMENT Log slow statements executed by slave thread to the slow log if it is open.
1882+
NUMERIC_MIN_VALUE NULL
1883+
NUMERIC_MAX_VALUE NULL
1884+
NUMERIC_BLOCK_SIZE NULL
1885+
ENUM_VALUE_LIST OFF,ON
1886+
READ_ONLY NO
1887+
COMMAND_LINE_ARGUMENT OPTIONAL
18601888
VARIABLE_NAME LOG_SLOW_VERBOSITY
18611889
SESSION_VALUE
18621890
GLOBAL_VALUE

‎mysql-test/suite/sys_vars/t/log_slow_admin_statements_func.test

Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,61 @@
1+
--source include/no_valgrind_without_big.inc
2+
-- source include/have_innodb.inc
3+
4+
SET @old_log_output= @@global.log_output;
5+
SET @old_slow_query_log= @@global.slow_query_log;
6+
SET @old_long_query_time= @@session.long_query_time;
7+
SET @old_log_slow_admin_statements= @@global.log_slow_admin_statements;
8+
9+
USE test;
10+
CREATE TABLE log_slow_admin_statements (
11+
i INT PRIMARY KEY AUTO_INCREMENT,
12+
j VARCHAR(255)
13+
) ENGINE=InnoDB;
14+
15+
# enable slow logging to table
16+
SET GLOBAL log_output = 'file,table';
17+
SET GLOBAL slow_query_log = on;
18+
SET SESSION long_query_time = 0;
19+
SET GLOBAL log_slow_admin_statements = on;
20+
21+
# test ALTER, OPTIMIZE and CHECK against the table shown up
22+
ALTER TABLE log_slow_admin_statements ADD COLUMN k INT DEFAULT 17;
23+
24+
# add rows so OPTIMIZE and CHECK runs
25+
DELIMITER $;
26+
27+
CREATE PROCEDURE add_rows()
28+
BEGIN
29+
DECLARE count INT;
30+
SET count = 1;
31+
INSERT INTO log_slow_admin_statements(j) values (REPEAT('A', 255));
32+
WHILE count <= 15 DO
33+
INSERT INTO log_slow_admin_statements(j) SELECT j FROM log_slow_admin_statements;
34+
SET count = count + 1;
35+
END WHILE;
36+
END
37+
$
38+
39+
DELIMITER ;$
40+
41+
CALL add_rows();
42+
43+
# OPTIMIZE TABLE
44+
OPTIMIZE TABLE log_slow_admin_statements;
45+
46+
# CHECK TABLE
47+
CHECK TABLE log_slow_admin_statements EXTENDED;
48+
49+
# DROP TABLE
50+
DROP TABLE log_slow_admin_statements;
51+
52+
# ALTER, OPTIMIZE, CHECK and DROP operations should be logged in slow query log.
53+
SELECT sql_text FROM mysql.slow_log WHERE sql_text LIKE '%TABLE log_slow_admin_statements%';
54+
55+
SET @@global.log_output= @old_log_output;
56+
SET @@global.slow_query_log= @old_slow_query_log;
57+
SET @@session.long_query_time= @old_long_query_time;
58+
SET @@global.log_slow_admin_statements= @old_log_slow_admin_statements;
59+
60+
DROP PROCEDURE add_rows;
61+
TRUNCATE TABLE mysql.slow_log;

‎sql/log_event.cc

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4428,6 +4428,15 @@ int Query_log_event::do_apply_event(rpl_group_info *rgi,
44284428
if (thd->m_digest != NULL)
44294429
thd->m_digest->reset(thd->m_token_array, max_digest_length);
44304430

4431+
if (thd->slave_thread)
4432+
{
4433+
/*
4434+
The opt_log_slow_slave_statements variable can be changed
4435+
dynamically, so we have to set the sql_log_slow respectively.
4436+
*/
4437+
thd->variables.sql_log_slow= opt_log_slow_slave_statements;
4438+
}
4439+
44314440
thd->enable_slow_log= thd->variables.sql_log_slow;
44324441
mysql_parse(thd, thd->query(), thd->query_length(), &parser_state);
44334442
/* Finalize server status flags after executing a statement. */

‎sql/mysqld.cc

Lines changed: 0 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -7372,14 +7372,6 @@ struct my_option my_long_options[]=
73727372
"Don't log extra information to update and slow-query logs.",
73737373
&opt_short_log_format, &opt_short_log_format,
73747374
0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
7375-
{"log-slow-admin-statements", 0,
7376-
"Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to "
7377-
"the slow log if it is open.", &opt_log_slow_admin_statements,
7378-
&opt_log_slow_admin_statements, 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
7379-
{"log-slow-slave-statements", 0,
7380-
"Log slow statements executed by slave thread to the slow log if it is open.",
7381-
&opt_log_slow_slave_statements, &opt_log_slow_slave_statements,
7382-
0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
73837375
{"log-tc", 0,
73847376
"Path to transaction coordinator log (used for transactions that affect "
73857377
"more than one storage engine, when binary log is disabled).",

‎sql/sys_vars.cc

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1183,6 +1183,19 @@ static Sys_var_mybool Sys_log_queries_not_using_indexes(
11831183
GLOBAL_VAR(opt_log_queries_not_using_indexes),
11841184
CMD_LINE(OPT_ARG), DEFAULT(FALSE));
11851185

1186+
static Sys_var_mybool Sys_log_slow_admin_statements(
1187+
"log_slow_admin_statements",
1188+
"Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to "
1189+
"the slow log if it is open.",
1190+
GLOBAL_VAR(opt_log_slow_admin_statements),
1191+
CMD_LINE(OPT_ARG), DEFAULT(FALSE));
1192+
1193+
static Sys_var_mybool Sys_log_slow_slave_statements(
1194+
"log_slow_slave_statements",
1195+
"Log slow statements executed by slave thread to the slow log if it is open.",
1196+
GLOBAL_VAR(opt_log_slow_slave_statements),
1197+
CMD_LINE(OPT_ARG), DEFAULT(FALSE));
1198+
11861199
static Sys_var_ulong Sys_log_warnings(
11871200
"log_warnings",
11881201
"Log some not critical warnings to the general log file."

0 commit comments

Comments
 (0)