Description:
sys schema lock wait view reports invalid times if db time zone is not utc, because now() and the info schema info are in different time zones
mysql> select * from x$innodb_lock_waits\G
*************************** 1. row ***************************
wait_started: 2019-10-21 22:14:29
wait_age: -06:59:23
wait_age_secs: -25163
locked_table: `ops`.`ops_settings`
locked_index: PRIMARY
locked_type: RECORD
waiting_trx_id: 27820096424
waiting_trx_started: 2019-10-21 22:14:29
waiting_trx_age: -06:59:23
waiting_trx_rows_locked: 1
waiting_trx_rows_modified: 0
waiting_pid: 65694006
waiting_query: select * from ops_settings for update
waiting_lock_id: 27820096424:177700:3:3
waiting_lock_mode: X
blocking_trx_id: 27820095928
blocking_pid: 65693981
blocking_query: NULL
blocking_lock_id: 27820095928:177700:3:3
blocking_lock_mode: X
blocking_trx_started: 2019-10-21 22:14:24
blocking_trx_age: -06:59:18
blocking_trx_rows_locked: 3
blocking_trx_rows_modified: 0
sql_kill_blocking_query: KILL QUERY 65693981
sql_kill_blocking_connection: KILL 65693981
1 row in set, 3 warnings (0.00 sec)
mysql> select @@time_zone;
+-------------+
| @@time_zone |
+-------------+
| US/Pacific |
+-------------+
1 row in set (0.00 sec)
How to repeat:
select a row for update in two separate transactions, look at the view results
Suggested fix:
use convert_tz, we have many monitoring queries of this form, one example (not this exact view but shows the pattern):
select unix_timestamp()-unix_timestamp(ifnull(convert_tz(min(t.trx_started),'UTC',if(\@\@global.time_zone='SYSTEM',\@\@global.system_time_zone,\@\@global.time_zone)),now())) from information_schema.INNODB_TRX t where t.trx_rows_locked>0
Description: sys schema lock wait view reports invalid times if db time zone is not utc, because now() and the info schema info are in different time zones mysql> select * from x$innodb_lock_waits\G *************************** 1. row *************************** wait_started: 2019-10-21 22:14:29 wait_age: -06:59:23 wait_age_secs: -25163 locked_table: `ops`.`ops_settings` locked_index: PRIMARY locked_type: RECORD waiting_trx_id: 27820096424 waiting_trx_started: 2019-10-21 22:14:29 waiting_trx_age: -06:59:23 waiting_trx_rows_locked: 1 waiting_trx_rows_modified: 0 waiting_pid: 65694006 waiting_query: select * from ops_settings for update waiting_lock_id: 27820096424:177700:3:3 waiting_lock_mode: X blocking_trx_id: 27820095928 blocking_pid: 65693981 blocking_query: NULL blocking_lock_id: 27820095928:177700:3:3 blocking_lock_mode: X blocking_trx_started: 2019-10-21 22:14:24 blocking_trx_age: -06:59:18 blocking_trx_rows_locked: 3 blocking_trx_rows_modified: 0 sql_kill_blocking_query: KILL QUERY 65693981 sql_kill_blocking_connection: KILL 65693981 1 row in set, 3 warnings (0.00 sec) mysql> select @@time_zone; +-------------+ | @@time_zone | +-------------+ | US/Pacific | +-------------+ 1 row in set (0.00 sec) How to repeat: select a row for update in two separate transactions, look at the view results Suggested fix: use convert_tz, we have many monitoring queries of this form, one example (not this exact view but shows the pattern): select unix_timestamp()-unix_timestamp(ifnull(convert_tz(min(t.trx_started),'UTC',if(\@\@global.time_zone='SYSTEM',\@\@global.system_time_zone,\@\@global.time_zone)),now())) from information_schema.INNODB_TRX t where t.trx_rows_locked>0