Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.3.7, 10.4.2, 10.1.37, 10.2.21
-
None
Description
As per the manual,
Slow_queries
Description: Number of queries which took longer than long_query_time to run. The slow query log does not need to be active for this to be recorded.
https://mariadb.com/kb/en/library/server-status-variables/#slow_queries
But in real scenario, we have to active slow query log otherwise, it will not be recoded.
MariaDB [test]> select @@long_query_time, @@slow_query_log;
|
+-------------------+------------------+
|
| @@long_query_time | @@slow_query_log |
|
+-------------------+------------------+
|
| 10.000000 | 0 |
|
+-------------------+------------------+
|
1 row in set (0.029 sec)
|
|
|
MariaDB [test]> show global status like 'slow_queries';
|
+---------------+-------+
|
| Variable_name | Value |
|
+---------------+-------+
|
| Slow_queries | 0 |
|
+---------------+-------+
|
1 row in set (0.005 sec)
|
|
|
MariaDB [test]> set global long_query_time=0.1;
|
Query OK, 0 rows affected (0.027 sec)
|
|
|
MariaDB [test]> \r
|
Connection id: 10
|
Current database: test
|
|
|
MariaDB [test]> select sleep(1) from mysql.user limit 2;
|
+----------+
|
| sleep(1) |
|
+----------+
|
| 0 |
|
| 0 |
|
+----------+
|
2 rows in set (2.079 sec)
|
|
|
MariaDB [test]> show global status like 'slow_queries';
|
+---------------+-------+
|
| Variable_name | Value |
|
+---------------+-------+
|
| Slow_queries | 0 |
|
+---------------+-------+
|
1 row in set (0.005 sec)
|
|
|
MariaDB [test]> set global slow_query_log=ON;
|
Query OK, 0 rows affected (0.038 sec)
|
|
|
MariaDB [test]> \r
|
Connection id: 11
|
Current database: test
|
|
|
MariaDB [test]> select @@long_query_time, @@slow_query_log;
|
+-------------------+------------------+
|
| @@long_query_time | @@slow_query_log |
|
+-------------------+------------------+
|
| 0.100000 | 1 |
|
+-------------------+------------------+
|
1 row in set (0.001 sec)
|
|
|
MariaDB [test]> select sleep(1) from mysql.user limit 2;
|
+----------+
|
| sleep(1) |
|
+----------+
|
| 0 |
|
| 0 |
|
+----------+
|
2 rows in set (1.996 sec)
|
|
|
MariaDB [test]> show global status like 'slow_queries';
|
+---------------+-------+
|
| Variable_name | Value |
|
+---------------+-------+
|
| Slow_queries | 1 |
|
+---------------+-------+
|
1 row in set (0.005 sec)
|
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Closed
-
Activity
A smaller script demonstrating the same problem:
SET GLOBAL slow_query_log=OFF; |
SET long_query_time=0.1; |
SELECT VARIABLE_VALUE INTO @global_slow_queries |
FROM INFORMATION_SCHEMA.GLOBAL_STATUS |
WHERE VARIABLE_NAME='SLOW_QUERIES'; |
SELECT sleep(0.2) 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'; |
+------------------------+
|
| Slow_queries_increment |
|
+------------------------+
|
| 0 |
|
+------------------------+
|
The expected Slow_queries_increment is 0.
Discussed with Monty, agreed that it should work as follows:
- Inside stored routines logging and Slow_queries increment are always disabled. Values of @@GLOBAL.slow_query_log and @@SESSION.slow_query_log are not important in this case.
- Otherwise, when outside of stored routines:
- @@GLOBAL.slow_query_log and @@SESSION.slow_query_log set to FALSE disable only logging! They do not affect Slow_queries increment.
- If @@GLOBAL.slow_query_log is set to FALSE, it disables logging globally. The value of @@SESSION.slow_query_log does not matter in this case.
- If @@GLOBAL.slow_query_log is TRUE, the logging is allowed globally, but an individual thread can disable logging by setting @@SESSION.slow_query_log to FALSE. This is needed for mysqldump.
In 10.3, there are conflicts between this and MDEV-7742/MDEV-8305 due to the removal of opt_log_slow_admin_statements in 10.3.1.
I was unable to resolve these conflicts, and I recorded a wrong result for main.log_slow in my merge.
bar, please fix 10.3 and close this ticket once done.
Made a cleanup:
commit 26f0d72a3f9b92574b16fc0348f79f16ed8021d0
A cleanup for MDEV-18333 Slow_queries count doesn't increase when slow_query_log is turned off
thd->lex->m_sql_cmd was not cleared between queries.
log_slow_query() could crash (when running mtr --ps) because of this.
The difference was introduced by this commit:
commit e2b2bde358f434d945e9730acfbc6eedeb9ab8a2Author: MontyDate: Sun Aug 3 15:26:47 2014 +0300Made sql_log_slow a session variablemysqldump:- Added --log-queries to allow one to disable logging for the dumpsql/log_event.cc:- Removed setting of enable_slow_log as it's not required anymore.sql/sql_parse.cc:- Set enable_slow_log to value of thd->variables.sql_log_slow as this will speed up tests if slow log is disabled.- opt_log_slow_admin_statements can now only disable slow log, not enable it.sql/sql_explain.cc:- Minor cleanupOther things:- Added sql_log_slow to system variables.- Changed opt_slow_log to global_system_variables.sql_log_slow in all files- Updated tests to reflect changesIf we want to keep it this way, documentation needs to be updated.