Add lock information to lock timeout error message

Summary:
Currently, on lock timeout, we only give
  ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
 which has no information on what type of lock timed out.

This change augments the message with the lock type to say something like
  ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction: Timeout on index: test/t1.GEN_CLUST_INDEX
which shows which type of lock timed out as well as the associated object.

There two cases to handle here. For error messages coming from the storage engine, the error is stored onto the transaction, which will get forwarded to the SQL layer for display through `handler::get_error_message`.. For MDL locks in the SQL layer, we are directly using the information in the MDL lock to display the error message.

I didn't touch NDB because I didn't bother getting that to build.

Test Plan: mtr

Reviewers: jkedgar, jtolmer

Reviewed By: jtolmer

Subscribers: ebergen, webscalesql-eng

Differential Revision: https://reviews.facebook.net/D47613

include/thr_lock.h

@@ -25,6 +25,7 @@ extern "C" {
 #include <my_list.h>
 
 struct st_thr_lock;
+struct TABLE;
 extern ulong locks_immediate,locks_waited ;
 
 /*
@@ -99,7 +100,7 @@ typedef struct st_thr_lock_data {
   mysql_cond_t *cond;
   enum thr_lock_type type;
   void *status_param;			/* Param to status functions */
-  void *debug_print_param;
+  struct TABLE *table;
   struct PSI_table *m_psi;
 } THR_LOCK_DATA;
 
@@ -141,7 +142,8 @@ enum enum_thr_lock_result thr_lock(THR_LOCK_DATA *data,
 void thr_unlock(THR_LOCK_DATA *data);
 enum enum_thr_lock_result thr_multi_lock(THR_LOCK_DATA **data,
                                          uint count, THR_LOCK_INFO *owner,
-                                         ulong lock_wait_timeout);
+                                         ulong lock_wait_timeout,
+                                         THR_LOCK_DATA **error_pos);
 void thr_multi_unlock(THR_LOCK_DATA **data,uint count);
 void
 thr_lock_merge_status(THR_LOCK_DATA **data, uint count);

mysql-test/r/check.result

@@ -38,7 +38,7 @@ LOCK TABLE t1 WRITE;
 SET lock_wait_timeout= 1;
 CHECK TABLE t1;
 Table	Op	Msg_type	Msg_text
-test.t1	check	Error	Lock wait timeout exceeded; try restarting transaction
+test.t1	check	Error	Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 test.t1	check	status	Operation failed
 # Connection default
 UNLOCK TABLES;

mysql-test/r/concurrent_innodb_safelog.result

@@ -46,7 +46,7 @@ begin;
 ** Not so if innodb_locks_unsafe_for_binlog is set. The locks that
 ** do not match the WHERE condition are released.
 update t1 set eta=2 where tipo=22;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 ** Release user level name lock from thread 1. This will cause the ULL
 ** on thread 2 to end its wait.
 DO release_lock("hello");
@@ -186,7 +186,7 @@ begin;
 ** Not so if innodb_locks_unsafe_for_binlog is set. The locks that
 ** do not match the WHERE condition are released.
 update t1 set tipo=1 where tipo=2;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 ** Release ULL. This will release the next waiting ULL on thread 2.
 DO release_lock("hello");
 ** The table should still be updated with updates for thread 1 only:
@@ -368,7 +368,7 @@ begin;
 ** Update the same range which is marked for update on thread 2; this
 ** will hang because of row locks.
 update t1 set tipo=1 where tipo=2;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 ** After the update the table will be unmodified because the previous
 ** transaction failed and was rolled back.
 select * from t1;
@@ -475,7 +475,7 @@ begin;
 ** Not so if innodb_locks_unsafe_for_binlog is set. The locks that
 ** do not match the WHERE condition are released.
 update t1 set tipo=11 where tipo=22;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 ** After the time out the transaction is aborted; no rows should
 ** have changed.
 select * from t1;
@@ -574,7 +574,7 @@ begin;
 ** Selecting a range for update by table scan will be blocked
 ** because of on-going transaction on thread 2.
 select * from t1 where tipo=1 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 ** connection thread2
 ** Table will be unchanged and the select command will not be
 ** blocked:
@@ -653,7 +653,7 @@ delete from t1 where tipo=2;
 ** connection thread1
 begin;
 update t1 set tipo=1 where tipo=2;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 select * from t1;
 eta	tipo	c
 7	7	aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
@@ -735,7 +735,7 @@ begin;
 ** Not so if innodb_locks_unsafe_for_binlog is set. The locks that
 ** do not match the WHERE condition are released.
 update t1 set tipo=1 where tipo=22;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 select * from t1;
 eta	tipo	c
 7	7	aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa

mysql-test/r/concurrent_innodb_unsafelog.result

@@ -366,7 +366,7 @@ begin;
 ** Update the same range which is marked for update on thread 2; this
 ** will hang because of row locks.
 update t1 set tipo=1 where tipo=2;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 ** After the update the table will be unmodified because the previous
 ** transaction failed and was rolled back.
 select * from t1;
@@ -571,7 +571,7 @@ begin;
 ** Selecting a range for update by table scan will be blocked
 ** because of on-going transaction on thread 2.
 select * from t1 where tipo=1 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 ** connection thread2
 ** Table will be unchanged and the select command will not be
 ** blocked:
@@ -650,7 +650,7 @@ delete from t1 where tipo=2;
 ** connection thread1
 begin;
 update t1 set tipo=1 where tipo=2;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.GEN_CLUST_INDEX
 select * from t1;
 eta	tipo	c
 7	7	aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa

mysql-test/r/innodb_mrr.result

@@ -700,7 +700,7 @@ dummy	a	b
 SET AUTOCOMMIT=0;
 START TRANSACTION;
 INSERT INTO t1 VALUES (2,2,2);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;
@@ -717,7 +717,7 @@ COMMIT;
 INSERT INTO t1 VALUES (1,1,1),(3,3,3),(5,5,5);
 SET AUTOCOMMIT=0;
 SELECT * FROM t1 WHERE a > 2 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;

mysql-test/r/innodb_mrr_all.result

@@ -700,7 +700,7 @@ dummy	a	b
 SET AUTOCOMMIT=0;
 START TRANSACTION;
 INSERT INTO t1 VALUES (2,2,2);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;
@@ -717,7 +717,7 @@ COMMIT;
 INSERT INTO t1 VALUES (1,1,1),(3,3,3),(5,5,5);
 SET AUTOCOMMIT=0;
 SELECT * FROM t1 WHERE a > 2 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;

mysql-test/r/innodb_mrr_cost.result

@@ -700,7 +700,7 @@ dummy	a	b
 SET AUTOCOMMIT=0;
 START TRANSACTION;
 INSERT INTO t1 VALUES (2,2,2);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;
@@ -717,7 +717,7 @@ COMMIT;
 INSERT INTO t1 VALUES (1,1,1),(3,3,3),(5,5,5);
 SET AUTOCOMMIT=0;
 SELECT * FROM t1 WHERE a > 2 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;

mysql-test/r/innodb_mrr_cost_all.result

@@ -700,7 +700,7 @@ dummy	a	b
 SET AUTOCOMMIT=0;
 START TRANSACTION;
 INSERT INTO t1 VALUES (2,2,2);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;
@@ -717,7 +717,7 @@ COMMIT;
 INSERT INTO t1 VALUES (1,1,1),(3,3,3),(5,5,5);
 SET AUTOCOMMIT=0;
 SELECT * FROM t1 WHERE a > 2 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;

mysql-test/r/innodb_mrr_cost_icp.result

@@ -700,7 +700,7 @@ dummy	a	b
 SET AUTOCOMMIT=0;
 START TRANSACTION;
 INSERT INTO t1 VALUES (2,2,2);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;
@@ -717,7 +717,7 @@ COMMIT;
 INSERT INTO t1 VALUES (1,1,1),(3,3,3),(5,5,5);
 SET AUTOCOMMIT=0;
 SELECT * FROM t1 WHERE a > 2 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;

mysql-test/r/innodb_mrr_icp.result

@@ -700,7 +700,7 @@ dummy	a	b
 SET AUTOCOMMIT=0;
 START TRANSACTION;
 INSERT INTO t1 VALUES (2,2,2);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;
@@ -717,7 +717,7 @@ COMMIT;
 INSERT INTO t1 VALUES (1,1,1),(3,3,3),(5,5,5);
 SET AUTOCOMMIT=0;
 SELECT * FROM t1 WHERE a > 2 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;

mysql-test/r/innodb_mrr_none.result

@@ -699,7 +699,7 @@ dummy	a	b
 SET AUTOCOMMIT=0;
 START TRANSACTION;
 INSERT INTO t1 VALUES (2,2,2);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;
@@ -716,7 +716,7 @@ COMMIT;
 INSERT INTO t1 VALUES (1,1,1),(3,3,3),(5,5,5);
 SET AUTOCOMMIT=0;
 SELECT * FROM t1 WHERE a > 2 FOR UPDATE;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.a
 ROLLBACK;
 ROLLBACK;
 DROP TABLE t1;

mysql-test/r/innodb_mysql_lock.result

@@ -164,9 +164,9 @@ id	value
 # Connection con1
 SET lock_wait_timeout=1;
 ALTER TABLE t1 ADD INDEX idx(value);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 ALTER TABLE t1 ADD INDEX idx(value);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 # Connection default
 SELECT * FROM t1;
 id	value

mysql-test/r/innodb_mysql_sync.result

@@ -246,23 +246,23 @@ SET DEBUG_SYNC= 'now SIGNAL continue1';
 SET DEBUG_SYNC= 'now WAIT_FOR upgraded';
 # Now both reads and writes should be blocked
 SELECT * FROM t1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 INSERT INTO t1 VALUES (4,4);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue2';
 SET DEBUG_SYNC= 'now WAIT_FOR beforecommit';
 # Still both reads and writes should be blocked.
 SELECT * FROM t1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 INSERT INTO t1 VALUES (5,5);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue3';
 SET DEBUG_SYNC= 'now WAIT_FOR binlog';
 # Same here.
 SELECT * FROM t1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 INSERT INTO t1 VALUES (6,6);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue4';
 # Connection default
 # Reaping ALTER TABLE ...
@@ -293,14 +293,14 @@ a	b
 2	2
 3	3
 INSERT INTO t1 VALUES (4,4);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue2';
 SET DEBUG_SYNC= 'now WAIT_FOR binlog';
 # Now both reads and writes should be blocked.
 SELECT * FROM t1 limit 1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 INSERT INTO t1 VALUES (5,5);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue3';
 # Connection default
 # Reaping ALTER TABLE ...
@@ -334,23 +334,23 @@ SET DEBUG_SYNC= 'now SIGNAL continue1';
 SET DEBUG_SYNC= 'now WAIT_FOR upgraded';
 # Now both reads and writes should be blocked.
 SELECT * FROM t1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 INSERT INTO t1 VALUES (4,4);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue2';
 SET DEBUG_SYNC= 'now WAIT_FOR beforecommit';
 # Same here.
 SELECT * FROM t1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 INSERT INTO t1 VALUES (5,5);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue3';
 SET DEBUG_SYNC= 'now WAIT_FOR binlog';
 # Same here.
 SELECT * FROM t1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 INSERT INTO t1 VALUES (6,6);
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1
 SET DEBUG_SYNC= 'now SIGNAL continue4';
 # Connection default
 # Reaping ALTER TABLE ...

mysql-test/r/innodb_trx_count.result

@@ -8,7 +8,7 @@ i
 1
 begin;
 update t1 set i=2 where i=1;
-ERROR HY000: Lock wait timeout exceeded; try restarting transaction
+ERROR HY000: Lock wait timeout exceeded; try restarting transaction: Timeout on record in index: test/t1.PRIMARY
 rollback;
 commit_all_diff
 0