pt-query-digest results are empty

Question

I have a slow log generated by MySQL 5.1.71-log, that I've copied onto another machine. It appears I'm not getting any results from pt-query-digest.

$> pt-query-digest slow.log

# 2.1s user time, 910ms system time, 506.36M rss, 687.04M vsz
# Current date: Fri Sep 12 10:39:50 2014
# Hostname: util.ultralinq.net
# Files: slow.log
# Overall: 0 total, 1 unique, 0 QPS, 0x concurrency ______________________
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Query size        66.26M  66.26M  66.26M  66.26M  66.26M       0  66.26M

# Profile
# Rank        Query ID    Response time Calls       R/Call      V/M   Item
# =========== =========== =========== =========== =========== ===== ======

$> head -n 1 slow.log
"2014-07-10 17:02:48","XXX[XXX] @  [A.B.C.D.]","00:00:18","00:00:00",4,1817425,"echo",0,0,3,"(SELECT 'readCount' AS var, COUNT(id) AS data FROM study\n                WHERE ctime > '2014-07-09 21:02:29' AND status='read') union (SELECT 'unreadCount' AS var, COUNT(id) AS data FROM study\n                WHERE ctime > '2014-07-09 21:02:29' AND status in ('unread', 'upload')) union (SELECT 'avgStudySize' AS var, SUM(size)/COUNT(distinct study_id) AS data FROM echo\n                WHERE ctime > '2014-07-09 21:02:29') union (SELECT 'procDelay' AS var, TIME_TO_SEC(TIMEDIFF('2014-07-09 21:02:29', MIN(ctime))) AS data FROM echo\n                WHERE ctime > '2014-07-09 21:02:29' and post_process_status = 'unprocessed')"

$> wc -l slow.log 
144973 slow.log

$> pt-query-digest --version
pt-query-digest 2.2.10

Why am I not getting more interesting results?

score 1 · Answer 1 · answered Sep 12 '14 at 16:27

Alan, the format you are showing does not seem to correspond with one of the compatible ones expected by pt-query-digest.

This one is the one expected:

$ cat slow.log
/usr/sbin/mysqld, Version: 5.6.20-68.0-log (Percona Server (GPL), Release 68.0, Revision 656). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 140912 16:10:36
# User@Host: root[root] @ localhost []  Id: 116621
# Schema:   Last_errno: 0  Killed: 0
# Query_time: 11.000250  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0  Rows_affected: 0
# Bytes_sent: 64
SET timestamp=1410538236;
SELECT sleep(11);

Yours looks like the CSV export of the slow query log as written into table (not file) -log_output = TABLE:

mysql> desc slow_log;
+----------------+---------------------+------+-----+-------------------+-----------------------------+
| Field          | Type                | Null | Key | Default           | Extra                       |
+----------------+---------------------+------+-----+-------------------+-----------------------------+
| start_time     | timestamp           | NO   |     | CURRENT_TIMESTAMP | on update CURRENT_TIMESTAMP |
| user_host      | mediumtext          | NO   |     | NULL              |                             |
| query_time     | time                | NO   |     | NULL              |                             |
| lock_time      | time                | NO   |     | NULL              |                             |
| rows_sent      | int(11)             | NO   |     | NULL              |                             |
| rows_examined  | int(11)             | NO   |     | NULL              |                             |
| db             | varchar(512)        | NO   |     | NULL              |                             |
| last_insert_id | int(11)             | NO   |     | NULL              |                             |
| insert_id      | int(11)             | NO   |     | NULL              |                             |
| server_id      | int(10) unsigned    | NO   |     | NULL              |                             |
| sql_text       | mediumtext          | NO   |     | NULL              |                             |
| thread_id      | bigint(21) unsigned | NO   |     | NULL              |                             |
+----------------+---------------------+------+-----+-------------------+-----------------------------+
12 rows in set (0.00 sec)

I may be wrong, but as far as I know, that format is not available to be parsed (the only formats available are: slowlog, binlog, genlog, rawlog and tcpdump).

However, it is feasible to transform your format to the slow log format, as all the info is there.

In the future, You may want to export the table doing the conversion indicated here:

mysql -u user -p -h host.rds.amazonaws.com -D mysql -s -r -e "SELECT CONCAT( '# Time: ', DATE_FORMAT(start_time, '%y%m%d %H%i%s'), '\n', '# User@Host: ', user_host, '\n', '# Query_time: ', TIME_TO_SEC(query_time),  '  Lock_time: ', TIME_TO_SEC(lock_time), '  Rows_sent: ', rows_sent, '  Rows_examined: ', rows_examined, '\n', sql_text, ';' ) FROM mysql.slow_log" > /tmp/mysql.slow_log.log

(This is because I assume that you are logging into a table because you are using RDS. if not, just use the log_output = FILE option)

pt-query-digest results are empty

1 Answers1