Description:
"mysqldumpslow" should collapse repeated occurrences of the same statement to one and add the various counts and times, but it currently doesn't.
This totally defeats its purpose, as users will never see the total effect of repeated statements - with this bug, the tool is nearly useless.
That is my reason to classify this report as severity 2.
How to repeat:
1) Switch on the slow query log, make sure it will log your test statement:
long_query_time = 0.0
log_queries_not_using_indexes = 1
min_examined_row_limit = 0
2) Use "mysql" to issue some statement, preferably a select with a non-empty result.
3) Use cursor-up to repeat this statement.
4) Switch off the slow query log.
5) Use "mysqldumpslow" to analyze it.
You will see several occurrences of your statement, each with "Count: 1",
while the correct result would be one occurrence with a higher count.
Suggested fix:
I asked on freenode and was told this is a problem with the changed time format in the slow query log, and it could be patched.
I tried, and this patch solved it in my test:
--- old/mysqldumpslow 2016-08-25 16:23:25.000000000 +0200
+++ new/mysqldumpslow 2016-11-10 22:19:57.197763572 +0100
@@ -99,6 +99,7 @@
}
s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//;
+ s/^#? Time: \d{4}-\d+-\d+[A-Z]+\d+:\d+:\d+.*\n//;
my ($user,$host,$dummy,$thread_id) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+)\s+\S+(\s+Id:\s+(\d+))?.*\n// ? ($1,$2,$3,$4) : ('','','','','');
s/^# Query_time: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+).*\n//;
I intentionally did not remove the old regex, so that it would work with both the old and the new format.
Description: "mysqldumpslow" should collapse repeated occurrences of the same statement to one and add the various counts and times, but it currently doesn't. This totally defeats its purpose, as users will never see the total effect of repeated statements - with this bug, the tool is nearly useless. That is my reason to classify this report as severity 2. How to repeat: 1) Switch on the slow query log, make sure it will log your test statement: long_query_time = 0.0 log_queries_not_using_indexes = 1 min_examined_row_limit = 0 2) Use "mysql" to issue some statement, preferably a select with a non-empty result. 3) Use cursor-up to repeat this statement. 4) Switch off the slow query log. 5) Use "mysqldumpslow" to analyze it. You will see several occurrences of your statement, each with "Count: 1", while the correct result would be one occurrence with a higher count. Suggested fix: I asked on freenode and was told this is a problem with the changed time format in the slow query log, and it could be patched. I tried, and this patch solved it in my test: --- old/mysqldumpslow 2016-08-25 16:23:25.000000000 +0200 +++ new/mysqldumpslow 2016-11-10 22:19:57.197763572 +0100 @@ -99,6 +99,7 @@ } s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//; + s/^#? Time: \d{4}-\d+-\d+[A-Z]+\d+:\d+:\d+.*\n//; my ($user,$host,$dummy,$thread_id) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+)\s+\S+(\s+Id:\s+(\d+))?.*\n// ? ($1,$2,$3,$4) : ('','','','',''); s/^# Query_time: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+).*\n//; I intentionally did not remove the old regex, so that it would work with both the old and the new format.