pt-deadlock-logger logs incorrect ts

Bug #1295667 reported by Roman Vynar on 2014-03-21
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Percona Toolkit moved to
Fix Released
Frank Cizmich

Bug Description

Let's go through the example:

mysql> show variables like '%zone%';
| Variable_name | Value |
| system_time_zone | UTC |
| time_zone | America/Chicago |
2 rows in set (0.00 sec)

"SHOW ENGINE INNODB STATUS" reflects the time in SYSTEM time zone.
In our case it's UTC which corresponds to system_time_zone:

mysql> pager grep 1403;
PAGER set to 'grep 1403'
mysql> show engine innodb status\G
140316 18:05:07 >> this entry is related to LATEST DETECTED DEADLOCK section
1 row in set (0.00 sec)

mysql> select now();
| now() |
| 2014-03-21 07:18:35 |
1 row in set (0.00 sec)

The table "percona.deadlocks" has the following field:
  `ts` datetime NOT NULL,

datetime is not TZ aware and inserting UTC time of the latest deadlock (140316 18:05:07) into the table is incorrect as during the next selection from it, you will get ts displayed "as is" with the ongoing TZ America/Chicago.
Say if you insert the current INNODB time "12:18" with the ongoing now() "07:18" and then select it, you will get "12:18" which is in the future and no way to figure out what was the TZ on that time.

This means that if a deadlock occurs right now, its time would be say "140321 12:18:35" UTC, it will be inserted "as is", then the query "SELECT ts FROM deadlocks WHERE ts >= NOW() - INTERVAL 300 second" will return deadlocks within the last 5 min. but for the next 5 hours, which is the TZ diff (Chicago == UTC+5).
This query is used by the monitoring plugin. So we would like to be aware / alerted with the most recent deadlocks but with the current implementation, ts is not TZ aware, which makes it impossible.

We suggest to:
1. alter `ts` to timestamp NOT NULL (without DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP as it's not a time of a record but the date and time of the last detected deadlock);
2. use "SET time_zone=SYSTEM" prior inserting a record into percona.deadlocks table. Potentially, it can be also "SET time_zone=@@system_time_zone" but SYSTEM is better as when DST changes SYSTEM will report correctly, while system_time_zone will report w/o DST change until MySQL restart it seems.

Changed in percona-toolkit:
assignee: nobody → Frank Cizmich (frank-cizmich)
status: New → In Progress
importance: Undecided → Medium
milestone: none → 2.2.8
Changed in percona-toolkit:
status: In Progress → Fix Committed
Changed in percona-toolkit:
status: Fix Committed → Fix Released

Percona now uses JIRA for bug reports so this bug report is migrated to:

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

Other bug subscribers