Skip to content

Commit 602492e

Browse files
author
Tatiana Azundris Nuernberg
committed
Bug#33732907: Slow query log logs password in plain text on syntax error
If a statement could not be parsed, it would not be included in the general log (unless --log-raw was used, in which case the statement would be logged before parsing). By contrast, the slow query log would include such a query, which in theory could expose sensitive credentials. This patch changes the behaviour so that unparseable queries are not slow-logged. This aligns it with the default behaviour of the general log. The slow query log will not observe --log-raw or align its behaviour with the performance schema's, as it is not the correct tool to debug malformed queries or hunt down possible attempts at SQL injection. Backport from 8.x Change-Id: I2395bc853b8c66a60ab6e1578dceffbb48de2c05
1 parent a74028d commit 602492e

File tree

3 files changed

+135
-1
lines changed

3 files changed

+135
-1
lines changed

‎mysql-test/r/slow_log.result‎

Lines changed: 53 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,53 @@
1+
#
2+
# Bug#33732907: Slow query log logs password in plain text on syntax error
3+
#
4+
5+
SET @save_sqlf=@@global.slow_query_log_file;
6+
SET @save_sql=@@global.slow_query_log;
7+
SET @save_lo=@@global.log_output;
8+
SET @save_lqt=@@session.long_query_time;
9+
SET GLOBAL slow_query_log_file= '.../slow33732907.log';
10+
SET @@global.slow_query_log=1;
11+
SET @@global.log_output='file,table';
12+
SET @@session.long_query_time=0;
13+
14+
# This succeeds, and the password is correctly obfuscated.
15+
CREATE USER 'duplicate_user'@'%' IDENTIFIED BY 'mypassword';
16+
# This fails, but the password is still correctly obfuscated.
17+
CREATE USER 'duplicate_user'@'%' IDENTIFIED BY 'mypassword';
18+
ERROR HY000: Operation CREATE USER failed for 'duplicate_user'@'%'
19+
20+
# Since we throw an error during the parse stage, we don't know which
21+
# part of the statement is the password (or whether there even is one),
22+
# so we cannot obfuscate it. In that case, the statement should not be
23+
# logged, either. The general log also behaves like this by default.
24+
CREATE USER ‘bad_characters’@’%’ IDENTIFIED BY 'mypassword';
25+
ERROR 42000: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '��bad_characters’@’%’ IDENTIFIED BY 'mypassword'' at line 1
26+
# Expected: 1 OK stmt, 1 failed stmt, 0 unparseable stmts
27+
SELECT "general table>",argument
28+
FROM mysql.general_log
29+
WHERE INSTR(argument,"CREATE USER")=1
30+
ORDER BY event_time;
31+
general table> argument
32+
general table> CREATE USER 'duplicate_user'@'%' IDENTIFIED WITH 'mysql_native_password' AS '<secret>'
33+
general table> CREATE USER 'duplicate_user'@'%' IDENTIFIED WITH 'mysql_native_password' AS '<secret>'
34+
# Expected: 1 OK stmt, 1 failed stmt, 0 unparseable stmts
35+
SELECT "slow table>",sql_text
36+
FROM mysql.slow_log
37+
WHERE INSTR(sql_text,"CREATE USER")=1
38+
ORDER BY start_time;
39+
slow table> sql_text
40+
slow table> CREATE USER 'duplicate_user'@'%' IDENTIFIED WITH 'mysql_native_password' AS '*FABE5482D5AADF36D028AC443D117BE1180B9725'
41+
slow table> CREATE USER 'duplicate_user'@'%' IDENTIFIED WITH 'mysql_native_password' AS '<secret>'
42+
SET @@global.slow_query_log_file=@save_sqlf;
43+
SET @@global.slow_query_log=@save_sql;
44+
SET @@global.log_output=@save_lo;
45+
SET @@session.long_query_time=@save_lqt;
46+
DROP USER 'duplicate_user'@'%';
47+
# Expected: 1 OK stmt, 1 failed stmt, 0 unparseable stmts
48+
slow file>CREATE USER 'duplicate_user'@'%' IDENTIFIED WITH 'mysql_native_password' AS '*FABE5482D5AADF36D028AC443D117BE1180B9725';
49+
slow file>CREATE USER 'duplicate_user'@'%' IDENTIFIED WITH 'mysql_native_password' AS '<secret>';
50+
TRUNCATE mysql.slow_log;
51+
TRUNCATE mysql.general_log;
52+
#
53+
# Done.

‎mysql-test/t/slow_log.test‎

Lines changed: 77 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,77 @@
1+
--echo #
2+
--echo # Bug#33732907: Slow query log logs password in plain text on syntax error
3+
--echo #
4+
--echo
5+
6+
--source include/not_parallel.inc
7+
--source include/not_valgrind.inc
8+
9+
SET @save_sqlf=@@global.slow_query_log_file;
10+
SET @save_sql=@@global.slow_query_log;
11+
SET @save_lo=@@global.log_output;
12+
SET @save_lqt=@@session.long_query_time;
13+
14+
--replace_result $MYSQL_TMP_DIR ...
15+
eval SET GLOBAL slow_query_log_file= '$MYSQL_TMP_DIR/slow33732907.log';
16+
SET @@global.slow_query_log=1;
17+
SET @@global.log_output='file,table';
18+
SET @@session.long_query_time=0;
19+
20+
let SLOW_LOG= `SELECT @@global.slow_query_log_file`;
21+
22+
--echo
23+
--echo # This succeeds, and the password is correctly obfuscated.
24+
CREATE USER 'duplicate_user'@'%' IDENTIFIED BY 'mypassword';
25+
--echo # This fails, but the password is still correctly obfuscated.
26+
--error ER_CANNOT_USER
27+
CREATE USER 'duplicate_user'@'%' IDENTIFIED BY 'mypassword';
28+
29+
--echo
30+
--echo # Since we throw an error during the parse stage, we don't know which
31+
--echo # part of the statement is the password (or whether there even is one),
32+
--echo # so we cannot obfuscate it. In that case, the statement should not be
33+
--echo # logged, either. The general log also behaves like this by default.
34+
--error ER_PARSE_ERROR
35+
CREATE USER ‘bad_characters’@’%’ IDENTIFIED BY 'mypassword';
36+
37+
--echo # Expected: 1 OK stmt, 1 failed stmt, 0 unparseable stmts
38+
SELECT "general table>",argument
39+
FROM mysql.general_log
40+
WHERE INSTR(argument,"CREATE USER")=1
41+
ORDER BY event_time;
42+
43+
--echo # Expected: 1 OK stmt, 1 failed stmt, 0 unparseable stmts
44+
SELECT "slow table>",sql_text
45+
FROM mysql.slow_log
46+
WHERE INSTR(sql_text,"CREATE USER")=1
47+
ORDER BY start_time;
48+
49+
SET @@global.slow_query_log_file=@save_sqlf;
50+
SET @@global.slow_query_log=@save_sql;
51+
SET @@global.log_output=@save_lo;
52+
SET @@session.long_query_time=@save_lqt;
53+
54+
DROP USER 'duplicate_user'@'%';
55+
56+
--echo # Expected: 1 OK stmt, 1 failed stmt, 0 unparseable stmts
57+
--perl
58+
use strict;
59+
60+
my $file= $ENV{'SLOW_LOG'} or die("slow log not set");
61+
62+
open(FILE, "$file") or die("Unable to open $file: $!");
63+
while (<FILE>) {
64+
my $line = $_;
65+
if ($line =~ /CREATE USER /) {
66+
print "slow file>".$line; }
67+
}
68+
close(FILE);
69+
EOF
70+
71+
--remove_file $MYSQL_TMP_DIR/slow33732907.log
72+
TRUNCATE mysql.slow_log;
73+
TRUNCATE mysql.general_log;
74+
75+
76+
--echo #
77+
--echo # Done.

‎sql/log.cc‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
/* Copyright (c) 2000, 2021, Oracle and/or its affiliates.
1+
/* Copyright (c) 2000, 2022, Oracle and/or its affiliates.
22
33
This program is free software; you can redistribute it and/or modify
44
it under the terms of the GNU General Public License, version 2.0,
@@ -1686,6 +1686,10 @@ bool log_slow_applicable(THD *thd)
16861686
if (unlikely(thd->in_sub_stmt))
16871687
DBUG_RETURN(false); // Don't set time for sub stmt
16881688

1689+
if (unlikely(thd->is_error()) &&
1690+
(unlikely(thd->get_stmt_da()->mysql_errno() == ER_PARSE_ERROR)))
1691+
DBUG_RETURN(false);
1692+
16891693
/*
16901694
Do not log administrative statements unless the appropriate option is
16911695
set.

0 commit comments

Comments
 (0)