1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
#
# BUG#23300: Slow query log on slave does not log slow replicated statements
#
# Description:
# The slave should log slow queries replicated from master when
# --log-slow-slave-statements is used.
#
# Test is implemented as follows:
# i) stop slave
# ii) On slave, set long_query_time to a small value.
# ii) start slave so that long_query_time variable is picked by sql thread
# iii) On master, do one short time query and one long time query, on slave
# and check that slow query is logged to slow query log but fast query
# is not.
# iv) On slave, check that slow queries go into the slow log and fast dont,
# when issued through a regular client connection
# v) On slave, check that slow queries go into the slow log and fast dont
# when we use SET TIMESTAMP= 1 on a regular client connection.
# vi) check that when setting slow_query_log= OFF in a connection 'extra2'
# prevents logging slow queries in a connection 'extra'
#
# OBS:
# This test only runs for statement and mixed binlogging firmat because on
# row format slow queries do not get slow query logged.
source include/master-slave.inc;
source include/have_binlog_format_mixed_or_statement.inc;
# Prepare slave for different long_query_time we need to stop the slave
# and restart it as long_query_time variable is dynamic and, after
# setting it, it only takes effect on new connections.
#
# Reference:
# http://dev.mysql.com/doc/refman/6.0/en/set-option.html
connection slave;
source include/stop_slave.inc;
SET @old_log_output= @@log_output;
SET GLOBAL log_output= 'TABLE';
SET @old_long_query_time= @@long_query_time;
SET GLOBAL long_query_time= 2;
TRUNCATE mysql.slow_log;
source include/start_slave.inc;
connection master;
CREATE TABLE t1 (a int, b int);
# test:
# check that slave logs the slow query to the slow log, but not the fast one.
let $slow_query= INSERT INTO t1 values(1, sleep(3));
let $fast_query= INSERT INTO t1 values(1, 1);
eval $fast_query;
eval $slow_query;
sync_slave_with_master;
let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`;
let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`;
if ($found_fast_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Fast query FOUND in slow query log. Bailing out!";
}
if (!$found_slow_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!";
}
TRUNCATE mysql.slow_log;
# regular checks for slow query log (using a new connection - 'extra' - to slave)
# test:
# when using direct connections to the slave, check that slow query is logged
# but not the fast one.
connect(extra,127.0.0.1,root,,test,$SLAVE_MYPORT);
connection extra;
let $fast_query= SELECT 1;
let $slow_query= SELECT 1, sleep(3);
eval $slow_query;
eval $fast_query;
let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`;
let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`;
if ($found_fast_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Fast query FOUND in slow query log. Bailing out!";
}
if (!$found_slow_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!";
}
TRUNCATE mysql.slow_log;
# test:
# when using direct connections to the slave, check that when setting timestamp to 1 the
# slow query is logged but the fast one is not.
let $fast_query= SELECT 2;
let $slow_query= SELECT 2, sleep(3);
SET TIMESTAMP= 1;
eval $slow_query;
eval $fast_query;
let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`;
let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`;
if ($found_fast_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Fast query FOUND in slow query log. Bailing out!";
}
if (!$found_slow_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!";
}
TRUNCATE mysql.slow_log;
# test:
# check that when setting the slow_query_log= OFF on connection 'extra2'
# prevents connection 'extra' from logging to slow query log.
let $fast_query= SELECT 3;
let $slow_query= SELECT 3, sleep(3);
connect(extra2,127.0.0.1,root,,test,$SLAVE_MYPORT);
connection extra2;
SET @old_slow_query_log= @@slow_query_log;
SET GLOBAL slow_query_log= 'OFF';
connection extra;
eval $slow_query;
eval $fast_query;
let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`;
let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`;
if ($found_fast_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Fast query FOUND in slow query log when slow_query_log= OFF. Bailing out!";
}
if ($found_slow_query)
{
SELECT * FROM mysql.slow_log;
die "Assertion failed! Slow query FOUND in slow query log when slow_query_log= OFF. Bailing out!";
}
TRUNCATE mysql.slow_log;
# clean up: drop tables, reset the variables back to the previous value,
# disconnect extra connections
connection extra2;
SET GLOBAL slow_query_log= @old_slow_query_log;
connection master;
DROP TABLE t1;
sync_slave_with_master;
source include/stop_slave.inc;
SET GLOBAL long_query_time= @old_long_query_time;
SET GLOBAL log_output= @old_log_output;
source include/start_slave.inc;
disconnect extra;
disconnect extra2;