pt-query-digest doesn't report host details

Bug #1262456 reported by Brian Lee
18
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Percona Toolkit moved to https://jira.percona.com/projects/PT
Fix Released
Medium
Frank Cizmich

Bug Description

Version being used:

# pt-query-digest --version
pt-query-digest 2.2.5

Slow log has information as follows (data has been changed):
# Time: 131218 3:35:03
# User@Host: username[username] @ [192.168.1.1]
# Thread_id: 22494547 Schema: prod Last_errno: 0 Killed: 0
# Query_time: 2.047602 Lock_time: 0.000095 Rows_sent: 0 Rows_examined: 1386373 Rows_affected: 0 Rows_read: 0
# Bytes_sent: 1541 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# InnoDB_trx_id: 547075E0F
use prod;
SET timestamp=1387337703;
select 'This is a 2 second query!'

Running pt-query-digest:
pt-query-digest --limit 100% slow-log > digested_20131218.txt

Output shows that the hosts is missing:
# Query 2: 0.00 QPS, 0.00x concurrency, ID 0x26D1C583EA2A2B3D at byte 10528
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.02
# Time range: 2013-12-18 03:35:03 to 2013-12-19 00:00:06
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 81 13
# Exec time 25 30s 2s 3s 2s 2s 195ms 2s
# Lock time 67 1ms 90us 193us 109us 113us 24us 93us
# Rows sent 0 505 0 200 38.85 192.76 67.96 3.40
# Rows examine 59 17.15M 1.32M 1.32M 1.32M 1.32M 3.23k 1.26M
# Rows affecte 0 0 0 0 0 0 0 0
# Rows read 0 505 0 200 38.85 192.76 67.96 3.40
# Bytes sent 0 77.12k 1.50k 24.31k 5.93k 23.58k 7.79k 1.87k
# Tmp tables 0 0 0 0 0 0 0 0
# Tmp disk tbl 0 0 0 0 0 0 0 0
# Tmp tbl size 0 0 0 0 0 0 0 0
# Query size 85 10.68k 841 841 841 841 0 841
# String:
# Databases prod
# Hosts
# InnoDB trxID 547075E0F (1/7%), 5471A566C (1/7%)... 11 more
# Last errno 0
# Users username
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s ################################################################
# 10s+
# Tables
# SHOW TABLE STATUS FROM `prod` LIKE 'table'\G
# SHOW CREATE TABLE `prod`.`table`\G
# EXPLAIN /*!50100 PARTITIONS*/
select 'This is a 2 second query!'

Tried overriding by using the --show-all:
pt-query-digest --limit 100% --show-all user,host,db slow-log > digested_20131218_2.txt

However, results were still the same.

Using PTDEBUG=1 shows that when the query is parsed it does indeed see the host/ip:

# Pipeline:11495 20949 Pipeline process SlowLogParser
# SlowLogParser:5028 20949 # Time: 131218 3:35:03
# SlowLogParser:5033 20949 Got ts 131218 3:35:03
# SlowLogParser:5028 20949 # User@Host: username[username] @ [192.168.1.1]
# SlowLogParser:5048 20949 Got user, host, ip username 192.168.1.1
# SlowLogParser:5028 20949 # Thread_id: 22494547 Schema: prod Last_errno: 0 Killed: 0
# SlowLogParser:5063 20949 Got some line with properties
# SlowLogParser:5028 20949 # Query_time: 2.047602 Lock_time: 0.000095 Rows_sent: 0 Rows_examined: 1386373 Rows_affected: 0 Rows_read: 0
# SlowLogParser:5063 20949 Got some line with properties
# SlowLogParser:5028 20949 # Bytes_sent: 1541 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# SlowLogParser:5063 20949 Got some line with properties
# SlowLogParser:5028 20949 # InnoDB_trx_id: 547075E0F
# SlowLogParser:5063 20949 Got some line with properties
# SlowLogParser:5028 20949 use prod;
# SlowLogParser:5076 20949 Got a default database: prod
# SlowLogParser:5028 20949 SET timestamp=1387337703;
# SlowLogParser:5082 20949 Got some setting: timestamp=1387337703
# SlowLogParser:5028 20949 select 'This is a 2 second query!'
# SlowLogParser:5116 20949 Got the query/arg line
# SlowLogParser:5128 20949 Properties of event: $VAR1 = [
# 'cmd',
# 'Query',
# 'pos_in_log',
# 0,
# 'ts',
# '131218 3:35:03',
# 'user',
# 'username',
# 'host',
# '',
# 'ip',
# '192.168.1.1',
# 'Thread_id',
# '22494547',
# 'Schema',
# 'prod',
# 'Last_errno',
# '0',
# 'Killed',
# '0',
# 'Query_time',
# '2.047602',
# 'Lock_time',
# '0.000095',
# 'Rows_sent',
# '0',
# 'Rows_examined',
# '1386373',
# 'Rows_affected',
# '0',
# 'Rows_read',
# '0',
# 'Bytes_sent',
# '1541',
# 'Tmp_tables',
# '0',
# 'Tmp_disk_tables',
# '0',
# 'Tmp_table_sizes',
# '0',
# 'InnoDB_trx_id',
# '547075E0F',
# 'db',
# 'prod',
# 'timestamp',
# '1387337703',
# 'arg',
# 'select 'This is a 2 second query!'',
# 'bytes',
# 841
# ];
#

Related branches

Revision history for this message
Olivier Fontannaud (olivier-fontannaud) wrote :

Version being used:

# pt-query-digest --version
pt-query-digest 2.2.5

# my.cnf
[mysqld]
skip-name-resolve

I have the same problem. I think it's related to --skip-name-resolve option (host is empty). I have made a dirty patch in order to fix it.

Revision history for this message
Brian Lee (chinchy) wrote :

Olivier, you're probably right. I also have skip-name-resolve on... I suspected that might have played a part in it.

Revision history for this message
Brian Lee (chinchy) wrote :

As a confirmation, Olivier's patch did fix my blank host.

Changed in percona-toolkit:
assignee: nobody → Frank Cizmich (frank-cizmich)
status: New → In Progress
importance: Undecided → Medium
Changed in percona-toolkit:
milestone: none → 2.2.11
status: In Progress → Fix Committed
Revision history for this message
Frank Cizmich (frank-cizmich) wrote :

Fixed using Olivier's approach

Also fixed in:
pt-index-usage
pt-table-usage
pt-upgrade

Revision history for this message
Frank Cizmich (frank-cizmich) wrote :

To clarify:

The fix simply involves using the IP of the host instead of it's name, when the hostname is missing.

Changed in percona-toolkit:
status: Fix Committed → In Progress
Changed in percona-toolkit:
status: In Progress → Fix Committed
Changed in percona-toolkit:
status: Fix Committed → Fix Released
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PT-634

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.