pt-query-digest does not parse general log generated by PS/MySQL 5.7 instance
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona Toolkit moved to https://jira.percona.com/projects/PT |
Fix Released
|
High
|
Carlos Salguero |
Bug Description
[root@centos1 ~]# pt-query-digest --version
pt-query-digest 2.2.17
[root@centos1 ~]# rpm -qa|grep Percona-
Percona-
[root@centos1 ~]# head -n 20 /var/lib/
/usr/sbin/mysqld, Version: 5.7.11-4-log (Percona Server (GPL), Release 4, Revision 5c940e1). started with:
Tcp port: 3306 Unix socket: /var/lib/
Time Id Command Argument
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
2016-05-
[root@centos1 ~]# pt-query-digest --type genlog /var/lib/
# No events processed.
Compared to:
percona-
pt-query-digest 2.2.17
./use -e 'select @@version'
+-----------+
| @@version |
+-----------+
| 5.6.29 |
+-----------+
percona-
# 680ms user time, 30ms system time, 34.91M rss, 104.31M vsz
# Current date: Wed May 25 07:58:48 2016
# Hostname: percona
# Files: data/percona.log
# Overall: 4.03k total, 14 unique, 1.60 QPS, 0x concurrency ______________
# Time range: 2016-05-25 07:16:06 to 07:58:11
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 0 0 0 0 0 0 0
# Query size 119.08k 11 77 30.23 31.70 2.53 28.75
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ============= ===== ====== ===== ===============
# 1 0xAA353644DE4C4CB4 0.0000 0.0% 1007 0.0000 0.00 ADMIN QUIT
# 2 0xE3A3649C5FAC418D 0.0000 0.0% 1006 0.0000 0.00 SELECT
# 3 0x5D51E5F01B88B79E 0.0000 0.0% 1006 0.0000 0.00 ADMIN CONNECT
# 4 0xD63F935A9BD316B0 0.0000 0.0% 1003 0.0000 0.00 INSERT test.test?
# 5 0x389FF9DA2DF3DF62 0.0000 0.0% 2 0.0000 0.00 SELECT
# Caught SIGPIPE.
# Exiting on SIGPIPE.
head -20 data/percona.log
/data/perc/
Tcp port: 5629 Unix socket: /tmp/mysql_
Time Id Command Argument
160525 7:16:06 4 Query SELECT DATABASE()
4 Init DB test
4 Query show databases
4 Query show tables
160525 7:16:33 4 Query create table test1 (id int primary key not null auto_increment) engine=innodb
160525 7:16:42 4 Query insert into test1 values (),(),(),()
160525 7:16:45 4 Quit
160525 7:25:26 5 Connect msandbox@localhost on
5 Query select @@version_comment limit 1
5 Query select USER()
160525 7:25:31 5 Query delete from test.test1
160525 7:25:34 5 Quit
160525 7:26:50 6 Connect msandbox@localhost on
6 Query select @@version_comment limit 1
6 Query insert into test.test1 values ()
6 Quit
7 Connect msandbox@localhost on
I think this is due to the fact that the general log format on 5.7 has changed.
tags: | added: pt-query-digest |
Changed in percona-toolkit: | |
status: | New → Confirmed |
Changed in percona-toolkit: | |
status: | Confirmed → Fix Committed |
milestone: | none → 2.2.18 |
assignee: | nobody → Carlos Salguero (carlos-salguero) |
importance: | Undecided → High |
Changed in percona-toolkit: | |
status: | Fix Committed → Fix Released |
Carlos,
This appears to be broken.
Server version: 5.7.13-6-log Percona Server (GPL), Release 6, Revision e3d58bb
pt-query-digest 2.2.20
% pt-query-digest --type genlog general. log-20170328149 0716861
# No events processed.
# VersionCheck:12408 10196 0 instances to check log-20170328149 0716861 digest: 13245 10196 Reading general. log-20170328149 0716861 digest: 13246 10196 File size: 4021838570 r:9877 10196 /usr/sbin/mysqld, Version: 5.7.13-6-log (Percona Server (GPL), Release 6, Revision e3d58bb). started with: r:9880 10196 Not start of general log event r:9877 10196 Tcp port: 3306 Unix socket: /opt/mysql/ dbprod/ monty-q0. sock r:9880 10196 Not start of general log event r:9877 10196 Time Id Command Argument r:9880 10196 Not start of general log event r:9877 10196 2017-03- 28T15:02: 23.101033Z48437 638 Quit r:9880 10196 Not start of general log event r:9877 10196 2017-03- 28T15:02: 23.101712Z48436 236 Query SELECT r:9880 10196 Not start of general log event r:9877 10196 2017-03- 28T15:02: 23.101726Z48435 624 Query SELECT r:9880 10196 Not start of general log event r:9877 10196 2017-03- 28T15:02: 23.101813Z48436 720 Query SELECT r:9880 10196 Not start of general log event r:9877 10196 2017-03- 28T15:02: 23.102124Z48435 592 Query SELECT r:9880 10196 Not start of general log event r:9877 10196 2017-03- 28T15:02: 23.102185Z48436 276 Query SELECT r:9880 10196 Not start of general log event r:9877 10196 2017-03- 28T15:02: 23.102719Z48435 562 Query SELECT
# Pipeline:11562 10196 Pipeline starting at 1490998357.36695
# Pipeline:11574 10196 Pipeline process prep
# Pipeline:11574 10196 Pipeline process input
# FileIterator:11316 10196 Filename: general.
# pt_query_
# pt_query_
# Pipeline:11574 10196 Pipeline process GeneralLogParser
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse
#
# GeneralLogParse
# GeneralLogParse