Skip to content

Commit aa28d71

Browse files
VarunNagarajuinikep
VarunNagaraju
authored and
inikep
committed
PS-9220 [8.4]: Error during slow Query Log Rotation
https://perconadev.atlassian.net/browse/PS-9220 When multiple client threads are connected to the server, there can be cases where the slow log purging after rotation attempt to delete the older slow log files which don't exist anymore. In some of such cases, the error returned by my_errno() after the unlink() method call was inaccuarte causing error messages to be printed in the server error log. So, my_errno() is replcaed with errno for accurate error returned.
1 parent cee425f commit aa28d71

File tree

3 files changed

+176
-1
lines changed

3 files changed

+176
-1
lines changed

‎mysql-test/suite/percona/r/slowlog_purge_files.result‎

Lines changed: 69 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,69 @@
1+
/* Save globals to restore at the end of the test */
2+
SET @old_long_query_time = @@global.long_query_time;
3+
SET @old_max_slowlog_files = @@global.max_slowlog_files;
4+
SET @old_max_slowlog_size = @@global.max_slowlog_size;
5+
SET @old_slow_query_log_file = @@global.slow_query_log_file;
6+
SET GLOBAL slow_query_log = ON;
7+
SET GLOBAL long_query_time = 0;
8+
SET GLOBAL max_slowlog_files = 3;
9+
SET GLOBAL max_slowlog_size = 4096;
10+
SHOW GLOBAL VARIABLES WHERE VARIABLE_NAME IN ('max_slowlog_files','max_slowlog_size','slow_query_log','long_query_time');
11+
Variable_name Value
12+
long_query_time 0.000000
13+
max_slowlog_files 3
14+
max_slowlog_size 4096
15+
slow_query_log ON
16+
CREATE TABLE `tab` (
17+
`id` int NOT NULL AUTO_INCREMENT,
18+
`k` int NOT NULL DEFAULT '0',
19+
`c` char(120) COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT '',
20+
`pad` char(60) COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT '',
21+
PRIMARY KEY (`id`),
22+
KEY `k_1` (`k`)
23+
);
24+
CREATE PROCEDURE insert_10k_rows()
25+
BEGIN
26+
DECLARE i INT DEFAULT 1;
27+
START TRANSACTION;
28+
WHILE i <= 10000 DO
29+
INSERT INTO tab (k, c, pad)
30+
VALUES (
31+
i,
32+
CONCAT('c_', SUBSTRING(MD5(RAND()), 1, 20)),
33+
CONCAT('p_', SUBSTRING(MD5(RAND()), 1, 10))
34+
);
35+
SET i = i + 1;
36+
END WHILE;
37+
COMMIT;
38+
END$$
39+
CALL insert_10k_rows;
40+
SELECT COUNT(*) FROM tab;
41+
COUNT(*)
42+
10000
43+
CREATE PROCEDURE sysbench_like_write(IN duration INT)
44+
BEGIN
45+
DECLARE t_start TIMESTAMP DEFAULT NOW();
46+
DECLARE elapsed INT DEFAULT 0;
47+
WHILE elapsed < duration DO
48+
START TRANSACTION;
49+
UPDATE tab SET k = FLOOR(RAND()*10000) WHERE id = FLOOR(RAND()*10000);
50+
DELETE FROM tab WHERE id = FLOOR(RAND()*10000);
51+
INSERT INTO tab (k, c, pad)
52+
VALUES (FLOOR(RAND()*10000),
53+
SUBSTRING(MD5(RAND()),1,20),
54+
SUBSTRING(MD5(RAND()),1,10));
55+
COMMIT;
56+
SET elapsed = TIMESTAMPDIFF(SECOND, t_start, NOW());
57+
END WHILE;
58+
END$$
59+
#
60+
# Running 10 concurrent sysbench_like_write() calls
61+
#
62+
DROP PROCEDURE insert_10k_rows;
63+
DROP PROCEDURE sysbench_like_write;
64+
DROP TABLE tab;
65+
/* Restore globals */
66+
SET GLOBAL long_query_time = @old_long_query_time;
67+
SET GLOBAL max_slowlog_files = @old_max_slowlog_files;
68+
SET GLOBAL max_slowlog_size = @old_max_slowlog_size;
69+
SET GLOBAL slow_query_log_file = @old_slow_query_log_file;

‎mysql-test/suite/percona/t/slowlog_purge_files.test‎

Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,106 @@
1+
#
2+
# Test if the slow log rotation causes an error in purging older slow log files
3+
# Without the fix, the error messages in the mysqld error log will cause the test failure
4+
#
5+
6+
/* Save globals to restore at the end of the test */
7+
SET @old_long_query_time = @@global.long_query_time;
8+
SET @old_max_slowlog_files = @@global.max_slowlog_files;
9+
SET @old_max_slowlog_size = @@global.max_slowlog_size;
10+
SET @old_slow_query_log_file = @@global.slow_query_log_file;
11+
12+
13+
SET GLOBAL slow_query_log = ON;
14+
SET GLOBAL long_query_time = 0;
15+
SET GLOBAL max_slowlog_files = 3;
16+
SET GLOBAL max_slowlog_size = 4096;
17+
SHOW GLOBAL VARIABLES WHERE VARIABLE_NAME IN ('max_slowlog_files','max_slowlog_size','slow_query_log','long_query_time');
18+
19+
CREATE TABLE `tab` (
20+
`id` int NOT NULL AUTO_INCREMENT,
21+
`k` int NOT NULL DEFAULT '0',
22+
`c` char(120) COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT '',
23+
`pad` char(60) COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT '',
24+
PRIMARY KEY (`id`),
25+
KEY `k_1` (`k`)
26+
);
27+
28+
DELIMITER $$;
29+
30+
CREATE PROCEDURE insert_10k_rows()
31+
BEGIN
32+
DECLARE i INT DEFAULT 1;
33+
34+
START TRANSACTION;
35+
WHILE i <= 10000 DO
36+
INSERT INTO tab (k, c, pad)
37+
VALUES (
38+
i,
39+
CONCAT('c_', SUBSTRING(MD5(RAND()), 1, 20)),
40+
CONCAT('p_', SUBSTRING(MD5(RAND()), 1, 10))
41+
);
42+
SET i = i + 1;
43+
END WHILE;
44+
COMMIT;
45+
END$$
46+
47+
DELIMITER ;$$
48+
49+
CALL insert_10k_rows;
50+
SELECT COUNT(*) FROM tab;
51+
52+
DELIMITER $$;
53+
54+
CREATE PROCEDURE sysbench_like_write(IN duration INT)
55+
BEGIN
56+
DECLARE t_start TIMESTAMP DEFAULT NOW();
57+
DECLARE elapsed INT DEFAULT 0;
58+
WHILE elapsed < duration DO
59+
START TRANSACTION;
60+
UPDATE tab SET k = FLOOR(RAND()*10000) WHERE id = FLOOR(RAND()*10000);
61+
DELETE FROM tab WHERE id = FLOOR(RAND()*10000);
62+
INSERT INTO tab (k, c, pad)
63+
VALUES (FLOOR(RAND()*10000),
64+
SUBSTRING(MD5(RAND()),1,20),
65+
SUBSTRING(MD5(RAND()),1,10));
66+
COMMIT;
67+
SET elapsed = TIMESTAMPDIFF(SECOND, t_start, NOW());
68+
END WHILE;
69+
END$$
70+
71+
DELIMITER ;$$
72+
73+
--echo #
74+
--echo # Running 10 concurrent sysbench_like_write() calls
75+
--echo #
76+
77+
perl;
78+
use strict;
79+
use warnings;
80+
81+
my $threads = 10;
82+
my $db = 'test';
83+
my $proc = 'CALL sysbench_like_write(10);';
84+
85+
for my $i (1 .. $threads) {
86+
my $pid = fork();
87+
if ($pid == 0) {
88+
my $cmd = sprintf('$MYSQL %s -e "%s"', $db, $proc);
89+
system($cmd);
90+
exit 0;
91+
}
92+
}
93+
94+
# Wait for all children
95+
while (wait() != -1) {}
96+
EOF
97+
98+
DROP PROCEDURE insert_10k_rows;
99+
DROP PROCEDURE sysbench_like_write;
100+
DROP TABLE tab;
101+
102+
/* Restore globals */
103+
SET GLOBAL long_query_time = @old_long_query_time;
104+
SET GLOBAL max_slowlog_files = @old_max_slowlog_files;
105+
SET GLOBAL max_slowlog_size = @old_max_slowlog_size;
106+
SET GLOBAL slow_query_log_file = @old_slow_query_log_file;

‎sql/log.cc‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2264,7 +2264,7 @@ bool File_query_log::purge_logs() {
22642264
}
22652265

22662266
if ((error = (unlink(buff) != 0))) {
2267-
if (my_errno() == ENOENT) error = false;
2267+
if (errno == ENOENT) error = false;
22682268
break;
22692269
}
22702270
--iter_log_ext;

0 commit comments

Comments
 (0)