maria-discuss team mailing list archive

[AskMonty KB <noreply@xxxxxxxxxxxx>]

Hello,

A new question has been asked in "Slow Query Log" by yu.d.sun_32615. Please answer it at http://mariadb.com/kb/en/slow-query-log-and-long_query_time/ as the person asking the question may not be subscribed to the mailing list.

--------------------------------
In my understanding if we enable slow query log, MySQL will capture all SQL statements that take more than long_query_time seconds to execute into the log. 


If so below testing puzzled me:

Server version: 10.0.21-MariaDB-wsrep-log MariaDB Server, wsrep_25.10.r4144


=== in the mysql CLI  ==================

ip-10-74-2-218$ root@localhost[galeratest] MYSQL> select now();
+---------------------+
| now()               |
+---------------------+
| 2015-12-18 11:12:50 |
+---------------------+
1 row in set (0.00 sec)

ip-10-74-2-218$ root@localhost[galeratest] MYSQL> show variables like 'long%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)

ip-10-74-2-218$ root@localhost[galeratest] MYSQL> select count(*) from test_table;
+----------+
| count(*) |
+----------+
|       13 |
+----------+
1 row in set (0.00 sec)

ip-10-74-2-218$ root@localhost[galeratest] MYSQL> select sleep(5);
+----------+
| sleep(5) |
+----------+
|        0 |
+----------+
1 row in set (5.00 sec)

ip-10-74-2-218$ root@localhost[galeratest] MYSQL> select sleep(11);
+-----------+
| sleep(11) |
+-----------+
|         0 |
+-----------+
1 row in set (11.00 sec)

ip-10-74-2-218$ root@localhost[galeratest] MYSQL> select count(*) from test_table;
+----------+
| count(*) |
+----------+
|       13 |
+----------+
1 row in set (0.00 sec)

ip-10-74-2-218$ root@localhost[galeratest] MYSQL>




==== from the slow query log ==================

# Time: 151218 11:13:12
# User@Host: root[root] @ localhost []
# Thread_id: 125  Schema: galeratest  QC_hit: No
# Query_time: 0.000163  Lock_time: 0.000075  Rows_sent: 1  Rows_examined: 13
SET timestamp=1450465992;
select count(*) from test_table;
# Time: 151218 11:13:48
# User@Host: root[root] @ localhost []
# Thread_id: 125  Schema: galeratest  QC_hit: No
# Query_time: 11.002494  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
SET timestamp=1450466028;
select sleep(11);
# Time: 151218 11:14:10
# User@Host: root[root] @ localhost []
# Thread_id: 125  Schema: galeratest  QC_hit: No
# Query_time: 0.000159  Lock_time: 0.000073  Rows_sent: 1  Rows_examined: 13
SET timestamp=1450466050;
select count(*) from test_table;



================

Question - why the 'select count(*) from test_table' statement is captured while it seems right that select sleep(11) got captured and sleep(5) did not? 






--------------------------------

To view or answer this question please visit: http://mariadb.com/kb/en/slow-query-log-and-long_query_time/