pt-query-digest fails to set history columns for disk tmp tables and disk filesort
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona Toolkit moved to https://jira.percona.com/projects/PT |
Fix Released
|
Medium
|
Brian Fraser | ||
2.0 |
Fix Released
|
Medium
|
Daniel Nichter | ||
2.1 |
Fix Released
|
Medium
|
Brian Fraser |
Bug Description
Using current pt-query-digest with the history table defined as specified here:
http://
Disk_tmp_table_cnt
Disk_tmp_table_sum
Disk_filesort_cnt
Disk_filesort_sum
And if I check the slow query logs, I see many lines similar to this:
# Query_time: 18.449333 Lock_time: 0.000067 Rows_sent: 218406 Rows_examined: 16450308 Rows_affected: 0 Rows_read: 213971
# Bytes_sent: 8136552 Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: 76878912
# InnoDB_trx_id: 29DC5005A
# QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: Yes
# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 10
SET timestamp=
As you can see, this query is using the ondisk tmp tables and on disk filesorts, and yet the columns are null for the checksum
mysql> SELECT COUNT(0), Disk_tmp_table_cnt FROM query_review_
*******
COUNT(0): 34
Disk_tmp_table_cnt: NULL
1 row in set (0.00 sec)
mysql> SELECT COUNT(0), Tmp_table_cnt FROM query_review_
*******
COUNT(0): 15
Tmp_table_cnt: NULL
*******
COUNT(0): 2
Tmp_table_cnt: 1
and so on
This is very important information that is getting lost in the process
Related branches
- Daniel Nichter: Approve
-
Diff: 3493 lines (+1166/-1166)41 files modifiedbin/pt-query-digest (+8/-8)
lib/Cxn.pm (+1/-1)
lib/QueryAdvisorRules.pm (+1/-1)
lib/Schema.pm (+5/-5)
lib/SlowLogWriter.pm (+2/-2)
t/lib/SlowLogParser.t (+63/-63)
t/lib/samples/slowlogs/slow002.txt (+16/-16)
t/lib/samples/slowlogs/slow003.txt (+2/-2)
t/lib/samples/slowlogs/slow005.txt (+2/-2)
t/lib/samples/slowlogs/slow006.txt (+12/-12)
t/lib/samples/slowlogs/slow007.txt (+2/-2)
t/lib/samples/slowlogs/slow022.txt (+12/-12)
t/lib/samples/slowlogs/slow030.txt (+899/-899)
t/lib/samples/slowlogs/slow032-rewritten.txt (+2/-2)
t/lib/samples/slowlogs/slow032.txt (+2/-2)
t/lib/samples/slowlogs/slow034.txt (+18/-18)
t/lib/samples/slowlogs/slow035.txt (+2/-2)
t/pt-log-player/samples/log001.txt (+16/-16)
t/pt-query-digest/read_timeout.t (+1/-1)
t/pt-query-digest/review.t (+4/-4)
t/pt-query-digest/samples/save-results/slow002-limit-3.txt (+4/-4)
t/pt-query-digest/samples/save-results/slow002.txt (+2/-2)
t/pt-query-digest/samples/save-results/slow006.txt (+1/-1)
t/pt-query-digest/samples/slow-issue-611.txt (+2/-2)
t/pt-query-digest/samples/slow002-orderbynonexistent.txt (+6/-6)
t/pt-query-digest/samples/slow002_iters_2.txt (+1/-1)
t/pt-query-digest/samples/slow002_orderbyreport.txt (+2/-2)
t/pt-query-digest/samples/slow002_report.txt (+6/-6)
t/pt-query-digest/samples/slow002_report_filtered.txt (+1/-1)
t/pt-query-digest/samples/slow006-first2.txt (+8/-8)
t/pt-query-digest/samples/slow006-order-by-re.txt (+2/-2)
t/pt-query-digest/samples/slow006_AR_1.txt (+2/-2)
t/pt-query-digest/samples/slow006_AR_2.txt (+1/-1)
t/pt-query-digest/samples/slow006_AR_4.txt (+2/-2)
t/pt-query-digest/samples/slow006_AR_5.txt (+1/-1)
t/pt-query-digest/samples/slow006_report.txt (+2/-2)
t/pt-query-digest/samples/slow034-inheritance.txt (+18/-18)
t/pt-query-digest/samples/slow034-no-ts-inheritance.txt (+18/-18)
t/pt-query-digest/samples/slow034-order-by-Locktime-sum-with-Locktime-distro.txt (+8/-8)
t/pt-query-digest/samples/slow034-order-by-Locktime-sum.txt (+8/-8)
t/pt-query-digest/samples/slow035.txt (+1/-1)
- Daniel Nichter: Approve
-
Diff: 3487 lines (+1166/-1166)41 files modifiedbin/pt-query-digest (+8/-8)
lib/Cxn.pm (+1/-1)
lib/QueryAdvisorRules.pm (+1/-1)
lib/Schema.pm (+5/-5)
lib/SlowLogWriter.pm (+2/-2)
t/lib/SlowLogParser.t (+63/-63)
t/lib/samples/slowlogs/slow002.txt (+16/-16)
t/lib/samples/slowlogs/slow003.txt (+2/-2)
t/lib/samples/slowlogs/slow005.txt (+2/-2)
t/lib/samples/slowlogs/slow006.txt (+12/-12)
t/lib/samples/slowlogs/slow007.txt (+2/-2)
t/lib/samples/slowlogs/slow022.txt (+12/-12)
t/lib/samples/slowlogs/slow030.txt (+899/-899)
t/lib/samples/slowlogs/slow032-rewritten.txt (+2/-2)
t/lib/samples/slowlogs/slow032.txt (+2/-2)
t/lib/samples/slowlogs/slow034.txt (+18/-18)
t/lib/samples/slowlogs/slow035.txt (+2/-2)
t/pt-log-player/samples/log001.txt (+16/-16)
t/pt-query-digest/read_timeout.t (+1/-1)
t/pt-query-digest/review.t (+4/-4)
t/pt-query-digest/samples/save-results/slow002-limit-3.txt (+4/-4)
t/pt-query-digest/samples/save-results/slow002.txt (+2/-2)
t/pt-query-digest/samples/save-results/slow006.txt (+1/-1)
t/pt-query-digest/samples/slow-issue-611.txt (+2/-2)
t/pt-query-digest/samples/slow002-orderbynonexistent.txt (+6/-6)
t/pt-query-digest/samples/slow002_iters_2.txt (+1/-1)
t/pt-query-digest/samples/slow002_orderbyreport.txt (+2/-2)
t/pt-query-digest/samples/slow002_report.txt (+6/-6)
t/pt-query-digest/samples/slow002_report_filtered.txt (+1/-1)
t/pt-query-digest/samples/slow006-first2.txt (+8/-8)
t/pt-query-digest/samples/slow006-order-by-re.txt (+2/-2)
t/pt-query-digest/samples/slow006_AR_1.txt (+2/-2)
t/pt-query-digest/samples/slow006_AR_2.txt (+1/-1)
t/pt-query-digest/samples/slow006_AR_4.txt (+2/-2)
t/pt-query-digest/samples/slow006_AR_5.txt (+1/-1)
t/pt-query-digest/samples/slow006_report.txt (+2/-2)
t/pt-query-digest/samples/slow034-inheritance.txt (+18/-18)
t/pt-query-digest/samples/slow034-no-ts-inheritance.txt (+18/-18)
t/pt-query-digest/samples/slow034-order-by-Locktime-sum-with-Locktime-distro.txt (+8/-8)
t/pt-query-digest/samples/slow034-order-by-Locktime-sum.txt (+8/-8)
t/pt-query-digest/samples/slow035.txt (+1/-1)
Looking at the code it looks like perhaps the slow query output was changed? I see the code expecting this:
# QC_Hit: %s Full_scan: %s Full_join: %s Tmp_table: %s Disk_tmp_table: %s
# Filesort: %s Disk_filesort: %s Merge_passes: %d
and I have this
# QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: Yes
# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 10
Was this perhaps changed in a later version of percona server? I'm currently running 5.1.56-rel12.7, but that said, I think it is important to allow processing/ reprocessing of old slow query logs. For example, when the innodb transaction field hex bug was fixes, I went ahead and reprocessed all my slow query logs and 'found' a few dozen new queries that were masked by the bug