pt-index-usage multiple warnings

[Sergey Onanchenko]

Dear Colleagues,

Percona-Server-server-57-5.7.18-16.1.el7.x86_64
percona-toolkit-3.0.4-1.el7.x86_64

pt-index-usage ./mysql-log-slow-queries.log --host localhost > mysql_slow_query_index_usage.log
Use of uninitialized value $query in pattern match (m//) at /usr/bin/pt-index-usage line 4573, <> line 4.
DBD::mysql::db selectall_arrayref failed: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'from `products` p where s.`id` = p.`sid`), 0),
    IFNULL((SELECT `days` FROM `' at line 3 [for Statement "EXPLAIN select `delivery_speed` = IF(
  GREATEST(
    IFNULL((SELECT `delivery_speed` FROM `suppliers` s from `products` p where s.`id` = p.`sid`), 0),
    IFNULL((SELECT `days` FROM `suppliers_delivery_speed` sds WHERE p.`cid` = sds.`cid` AND p.`sid` = sds.`sid`), 0)
  ) = 0,
  NULL,
  GREATEST(
    IFNULL((SELECT `delivery_speed` FROM `suppliers` s WHERE s.`id` = p.`sid`), 0),
    IFNULL((SELECT `days` FROM `suppliers_delivery_speed` sds WHERE p.`cid` = sds.`cid` AND p.`sid` = sds.`sid`), 0)
  )
)
WHERE `outdated` = 0"] at /usr/bin/pt-index-usage line 4580, <> line 9.
DBD::mysql::db selectall_arrayref failed: Table 'compservice.temp_products_orig_names' doesn't exist [for Statement "EXPLAIN select p.`name` = tpon. name from `products` p, `temp_products_orig_names` tpon where p.`id` = tpon.`product_id`"] at /usr/bin/pt-index-usage line 4580, <> line 444.
DBD::mysql::db selectall_arrayref failed: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'from `products` p where `relation` = 'PRODUCTS' AND `relation_id` = p.`id`)
  +' at line 3 [for Statement "EXPLAIN select `rating` = IF(
  `in_stock` = 0, -1,
  `rating` + (SELECT IF(COUNT(*) > 0, 1, 0) FROM `images` from `products` p where `relation` = 'PRODUCTS' AND `relation_id` = p.`id`)
  + IF(`available` > 0, 10000, 0)
)"] at /usr/bin/pt-index-usage line 4580, <> line 719.
./mysql-log-slow-queries.log: 45% 00:36 remain
Use of uninitialized value $query in pattern match (m//) at /usr/bin/pt-index-usage line 4573, <> line 11993.

Input files were 300MB and I'm not sure which exactly statement is needed - can extract on demand.

About debug - 800MB output. I not sure if it is useful - can extract on demand too.

Do not hesitate to ask if any additional information is needed.

[Carlos Salguero (carlos-salguero)]

According to the error I see, the problem is there are references to a non-existing table in the slow.log file and pt-index-usage is failing in this situation. Could you confirm that's the issue?

[Sergey Onanchenko (osadmin)]

You are right.

This was exactly temporary table:

    $table = 'temp_products_orig_names';
    $this->db->query("
    CREATE TEMPORARY TABLE IF NOT EXISTS ?# (
      `product_id` bigint(20) NOT NULL,
      `name` varchar(512) NOT NULL
    ) ENGINE=MyISAM DEFAULT CHARSET=utf8;
    ", $table)

But this was only for second statement.

What about first one ? suppliers_delivery_speed is permanent table.

[Carlos Salguero (carlos-salguero)]

Could you run the program using PTDEBUG=1 pt-index-usage ... and paste the output please?

[Sergey Onanchenko (osadmin)]

Hi,

with debug (2 problematic parts as 3rd one is clarified (temp table))

1.
```
# SlowLogParser:2872 10413 # Time: 2017-08-13T18:30:33.940076+02:00
# SlowLogParser:2877 10413 Got ts 2017-08-13T18:30:33
# SlowLogParser:2872 10413 # User@Host: compservice[compservice] @ localhost [] Id: 27937
# SlowLogParser:2896 10413 Got user, host, ip compservice localhost
# SlowLogParser:2872 10413 # Schema: compservice Last_errno: 0 Killed: 0
# SlowLogParser:2915 10413 Got some line with properties
# SlowLogParser:2872 10413 # Query_time: 21.636984 Lock_time: 0.000090 Rows_sent: 0 Rows_examined: 3764653 Rows_affected: 137
# SlowLogParser:2915 10413 Got some line with properties
# SlowLogParser:2872 10413 # Bytes_sent: 60 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# SlowLogParser:2915 10413 Got some line with properties
# SlowLogParser:2872 10413 # QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No
# SlowLogParser:2915 10413 Got some line with properties
# SlowLogParser:2872 10413 # Filesort: No Filesort_on_disk: No Merge_passes: 0
# SlowLogParser:2915 10413 Got some line with properties
# SlowLogParser:2872 10413 # No InnoDB statistics available for this query
# SlowLogParser:2872 10413 SET timestamp=1502638233;
# SlowLogParser:2934 10413 Got some setting: timestamp=1502638233
# SlowLogParser:2872 10413 UPDATE `products` p SET
# SlowLogParser:2968 10413 Got the query/arg line
# SlowLogParser:2980 10413 Properties of event: $VAR1 = [
# 'cmd',
# 'Query',
# 'pos_in_log',
# 2238,
# 'ts',
# '2017-08-13T18:30:33',
# 'user',
# 'compservice',
# 'host',
# 'localhost',
# 'ip',
# '',
# 'Thread_id',
# '27937',
# 'Schema',
# 'compservice',
# 'Last_errno',
# '0',
# 'Killed',
# '0',
# 'Query_time',
# '21.636984',
# 'Lock_time',
# '0.000090',
# 'Rows_sent',
# '0',
# 'Rows_examined',
# '3764653',
# 'Rows_affected',
# '137',
# 'Bytes_sent',
# '60',
# 'Tmp_tables',
# '0',
# 'Tmp_disk_tables',
# '0',
# 'Tmp_table_sizes',
# '0',
# 'QC_Hit',
# 'No',
# 'Full_scan',
# 'No',
# 'Full_join',
# 'No',
# 'Tmp_table',
# 'No',
# 'Tmp_table_on_disk',
# 'No',
# 'Filesort',
# 'No',
# 'Filesort_on_disk',
# 'No',
# 'Merge_passes',
# '0',
# 'timestamp',
# '1502638233',
# 'arg',
# 'UPDATE `products` p SET
# `in_stock` = (SELECT IFNULL(SUM(`in_stock`), 0) FROM `products_all` WHERE `product_id` = p.`id`),
# `outdated` = IF(`in_stock` = 0 AND `available` = 0 AND `in_stock_date` < DATE_SUB(NOW(), INTERVAL 3 DAY), 1,
# (SELECT IF(COUNT(*) = SUM(`outdated`), 1, 0) FROM `products_all` WHERE `product_id` = p.`id`))',
# 'bytes',
# 338
# ];
#
# Transformers:3658 10413 12E96E71A6F1820E checksum for UPDATE `products` p SET
# `in_stock` = (SELECT IFNULL(SUM(`in_stock`), 0) FROM `products_all` WHERE `product_id` = p.`id`),
# `outdated` = IF(`in_stock` = 0 AND `available` = 0 AND `in_stock_date` < DATE_SUB(NOW(), INTERVAL 3 DAY), 1,
# (SELECT IF(COUNT(*) = SUM(`outdated`), 1, 0) FROM `products_all` WHERE `product_id` = p.`id`))
# Transformers:3658 10413 B2D2A19048A5540A checksum for update `products` p set `in_stock`...

[Shahriyar Rzayev (rzayev-sehriyar)]

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