summaryrefslogtreecommitdiffstats
path: root/mysql-test/main/log_slow.test
blob: 39467e7e800137e0a5e3a6f6158ae45edce70785 (plain)
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
188
189
190
191
192
--source include/no_valgrind_without_big.inc

#
# Testing of slow log query options
#

set @@log_slow_verbosity="";

select @@log_slow_filter;
select @@log_slow_rate_limit;
select @@log_slow_verbosity;
--replace_regex /\S+mysqld-slow.log/$PATH\/mysqld-slow.log/
show variables like "log_slow%";
set @org_slow_query_log= @@global.slow_query_log;

# Some simple test to set log_slow_filter
set @@log_slow_filter= "filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk,admin";
select @@log_slow_filter;
set @@log_slow_filter="admin,admin";
select @@log_slow_filter;
set @@log_slow_filter=7;
select @@log_slow_filter;

# Test of wrong values
--error 1231
set @@log_slow_filter= "filesort,impossible,impossible2,admin";
--error 1231
set @@log_slow_filter= "filesort, admin";
--error 1231
set @@log_slow_filter= 1<<31;
select @@log_slow_filter;

# Some simple test to set log_slow_verbosity
set @@log_slow_verbosity= "query_plan,innodb";
select @@log_slow_verbosity;
set @@log_slow_verbosity=1;
select @@log_slow_verbosity;

#
# Check which fields are in slow_log table
#

show fields from mysql.slow_log;

#
# Check flush command
#
--disable_ps2_protocol

flush slow logs;

# MDEV-4206 (empty filter should be no filter)
set long_query_time=0.1;
set log_slow_filter='';
set slow_query_log=1;
set global log_output='TABLE';
select sleep(0.5);
select count(*) FROM mysql.slow_log;

# Reset used variables
set @@long_query_time=default;
set @@slow_query_log=default;
set @@log_slow_filter=default;
set @@log_slow_verbosity=default;
set global log_output= default;
truncate mysql.slow_log;

--echo #
--echo # MDEV-18333 Slow_queries count doesn't increase when slow_query_log is turned off
--echo #

SET SESSION slow_query_log=OFF;
SET GLOBAL slow_query_log=OFF;
SET long_query_time=0.1;

--echo # Although this query is disallowed by slow_query_log, it should still increment Slow_queries

SELECT VARIABLE_VALUE INTO @global_slow_queries
  FROM INFORMATION_SCHEMA.GLOBAL_STATUS
  WHERE VARIABLE_NAME='SLOW_QUERIES';
SELECT sleep(0.2) INTO @tmp FROM DUAL;
SELECT
    CAST(VARIABLE_VALUE AS UNSIGNED)-@global_slow_queries AS Slow_queries_increment
  FROM
    INFORMATION_SCHEMA.GLOBAL_STATUS
  WHERE
    VARIABLE_NAME='SLOW_QUERIES';

--echo # Although this query is disallowed by log_slow_filter, it should still increment Slow_queries

SET log_slow_filter=filesort;
SELECT sleep(0.2) INTO @tmp FROM DUAL;
SELECT VARIABLE_VALUE INTO @global_slow_queries
  FROM INFORMATION_SCHEMA.GLOBAL_STATUS
  WHERE VARIABLE_NAME='SLOW_QUERIES';
SELECT sleep(0.2) INTO @tmp FROM DUAL;
SELECT
    CAST(VARIABLE_VALUE AS UNSIGNED)-@global_slow_queries AS Slow_queries_increment
  FROM
    INFORMATION_SCHEMA.GLOBAL_STATUS
  WHERE
    VARIABLE_NAME='SLOW_QUERIES';
SET log_slow_filter=DEFAULT;

SET @@long_query_time=default;
SET GLOBAL slow_query_log= @org_slow_query_log;

--echo #
--echo # MDEV-21187: log_slow_filter="" logs queries not using indexes
--echo #

flush status;
create table t (id int);
insert into t values (1),(4);
set log_slow_filter='';
select * from t;
show session status like 'Slow_queries';

drop table t;
--enable_ps2_protocol

--echo #
--echo # End of 10.3 tests
--echo #


--echo #
--echo # MDEV-31742: incorrect examined rows in case of stored function usage
--echo #


CREATE TABLE `tab_MDEV_30820` (
`ID` int(11) NOT NULL AUTO_INCREMENT,
`NAME_F` varchar(50) DEFAULT NULL,
  PRIMARY KEY (`ID`)
);

 CREATE TABLE `tab2` (
  `ID` int(11) NOT NULL AUTO_INCREMENT,
  `TAB1_ID` int(11) DEFAULT NULL,
  PRIMARY KEY (`id`)
);

--disable_ps2_protocol
--disable_view_protocol

--delimiter //
CREATE FUNCTION `get_zero`() RETURNS int(11)
BEGIN
    RETURN(0) ;
END
//

for i in 1..100 do insert into tab_MDEV_30820 values (i,'qwerty'); end for ; //
for i in 1..1000 do insert into tab2 values (i,i+300); end for ; //

--delimiter ;

SET @old_slow_query_log= @@global.slow_query_log;
SET @old_log_output= @@global.log_output;
SET @old_long_query_time= @@long_query_time;
SET GLOBAL log_output= "TABLE";
SET GLOBAL slow_query_log= ON;

SET SESSION slow_query_log=ON;
SET SESSION long_query_time= 0;

SELECT 0 as zero, (SELECT ID FROM tab2 where tab2.TAB1_ID =
tab_MDEV_30820.ID ORDER BY 1 LIMIT 1 ) AS F1 FROM tab_MDEV_30820 ORDER BY 2 DESC LIMIT 2;

SELECT get_zero() as zero, (SELECT ID FROM tab2 where tab2.TAB1_ID =
tab_MDEV_30820.ID ORDER BY 1 LIMIT 1) AS F1 FROM tab_MDEV_30820 ORDER BY 2 DESC LIMIT 2;

--echo # should be the same rows_examined
SELECT rows_examined FROM mysql.slow_log WHERE sql_text LIKE '%SELECT%tab_MDEV_30820%';

## Reset to initial values
SET @@long_query_time= @old_long_query_time;
SET @@global.log_output= @old_log_output;
SET @@global.slow_query_log= @old_slow_query_log;
SET SESSION slow_query_log=default;

drop table tab_MDEV_30820, tab2;
drop function get_zero;

--enable_view_protocol
--enable_ps2_protocol
--enable_view_protocol

--echo #
--echo # End of 10.4 tests
--echo #