MariaDB locking

Question

I have a table W with a primary key, and a table T with a status column and an FK to W.

I am observing some random locking which I don't know where it originated:

• T1 does the following:

  • select where status=new inner join w ... for update skip locked
  • if the prev returned a row:
    • it does an select W where id=PK for update
    • it does an insert into T values... with a ref for W
    • it does an update T set status=pending where id=...
    • it does an delete from T where id=<another id>

• T2 does the following:

  • select W where id=PK for update (I don't think this is needed, because W will be implicitly locked via the FK id)
  • insert into T values... with a ref for the same PK as T1
  • the prev insert is in a loop, because apparently the foreign key requires a shared lock on W for a given PK, and T1 already requires an exclusive lock for same PK

I can have lots of T1 and T2 in several threads using different connections, but sometimes I get random locking every now and then, and all the threads running transaction of kind T2 never manage to complete. All of them sleep for the same amount, it's as if they were all locking each other in lockstep.

I get some of this:

LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
MariaDB thread id 1571679153, OS thread handle 140028721338112, query id 30769730068 <some-host> <some-ip> <some db> Statistics
select * from W where id=21230 for update
------- TRX HAS BEEN WAITING 39949099 ns FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 3498 page no 38948 n bits 16 index PRIMARY of table `xxx`.`W` trx id 19911025575 lock_mode X locks rec but not gap waiting

InnoDB engine does not report any deadlocks though.

I also observe the following:

MASTER> select trx_query, trx_mysql_thread_id from information_schema.innodb_trx where trx_rows_locked=1 ;
+-------------------------------------------+---------------------+
| trx_query                                 | trx_mysql_thread_id |
+-------------------------------------------+---------------------+
| select * from W where id=21233 for update |          1571686499 |
| select * from W where id=21233 for update |          1571685700 |
| select * from W where id=21230 for update |          1571685417 |
| select * from W where id=21233 for update |          1571685416 |
+-------------------------------------------+---------------------+

My understanding is that I'm locking W because T2 has a FK (with an index) that will require a shared lock on a row, that is also being locked by T1. But it should eventually make progress. What is going on?

---

An example of this:

---TRANSACTION 19911025577, ACTIVE 39 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
MariaDB thread id 1571679185, OS thread handle 140028719494912, query id 30769730077 <host> <ip> <user> Statistics
select * from W where id=21233 for update
------- TRX HAS BEEN WAITING 39895809 ns FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 3498 page no 38948 n bits 16 index PRIMARY of table `myschema`.`W` trx id 19911025577 lock_mode X locks rec but not gap waiting
Record lock, heap no 8 PHYSICAL RECORD: n_fields 14; compact format; info bits 0
 0: len 4; hex 800052f1; asc   R ;;
 1: len 6; hex 0004a2b9dd14; asc       ;;
 2: len 7; hex 27000029d8211b; asc '  ) ! ;;
 3: len 30; hex 38386432363934302d376363302d313165652d613838652d633138383765; asc 88d26940-7cc0-11ee-a88e-c1887e; (total 36 bytes);
 4: len 1; hex 01; asc  ;;
 5: len 7; hex 756e6b6e6f776e; asc unknown;;
 6: len 7; hex 756e6b6e6f776e; asc unknown;;
 7: len 7; hex 756e6b6e6f776e; asc unknown;;
 8: SQL NULL;
 9: len 20; hex 00000daa000091fc000000260000000000025b02; asc            &      [ ;;
 10: len 2; hex 7b7d; asc {};;
 11: len 30; hex 7b3a7363726970742d6964203a636f6e73756c2d6d61696e74656e616e63; asc {:script-id :consul-maintenanc; (total 789 bytes);
 12: len 4; hex 65491286; asc eI  ;;
 13: len 4; hex 654931c3; asc eI1 ;;

------------------
---TRANSACTION 19911025575, ACTIVE 39 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
MariaDB thread id 1571679153, OS thread handle 140028721338112, query id 30769730068 <host> <ip> <user> Statistics
select * from W where id=21230 for update
------- TRX HAS BEEN WAITING 39949099 ns FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 3498 page no 38948 n bits 16 index PRIMARY of table `myschema`.`W` trx id 19911025575 lock_mode X locks rec but not gap waiting
Record lock, heap no 5 PHYSICAL RECORD: n_fields 14; compact format; info bits 0
 0: len 4; hex 800052ee; asc   R ;;
 1: len 6; hex 0004a2bee4ea; asc       ;;
 2: len 7; hex 220000897d0794; asc "   }  ;;
 3: len 30; hex 34333739343439302d376363302d313165652d613838652d633138383765; asc 43794490-7cc0-11ee-a88e-c1887e; (total 36 bytes);
 4: len 1; hex 01; asc  ;;
 5: len 7; hex 756e6b6e6f776e; asc unknown;;
 6: len 7; hex 756e6b6e6f776e; asc unknown;;
 7: len 7; hex 756e6b6e6f776e; asc unknown;;
 8: SQL NULL;
 9: len 20; hex 00000daa0002326600000026000000000000f24b; asc       2f   &       K;;
 10: len 2; hex 7b7d; asc {};;
 11: len 30; hex 7b3a7363726970742d6964203a636f6e73756c2d6d61696e74656e616e63; asc {:script-id :consul-maintenanc; (total 789 bytes);
 12: len 4; hex 65491212; asc eI  ;;
 13: len 4; hex 654936a5; asc eI6 ;;

------------------
---TRANSACTION (0x7f5b7008d680), not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 19911025578, ACTIVE 39 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
MariaDB thread id 1571679152, OS thread handle 140028730652416, query id 30769730089 <host> <ip> <user> Statistics
select * from W where id=21233 for update
------- TRX HAS BEEN WAITING 39873684 ns FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 3498 page no 38948 n bits 16 index PRIMARY of table `myschema`.`W` trx id 19911025578 lock_mode X locks rec but not gap waiting
Record lock, heap no 8 PHYSICAL RECORD: n_fields 14; compact format; info bits 0
 0: len 4; hex 800052f1; asc   R ;;
 1: len 6; hex 0004a2b9dd14; asc       ;;
 2: len 7; hex 27000029d8211b; asc '  ) ! ;;
 3: len 30; hex 38386432363934302d376363302d313165652d613838652d633138383765; asc 88d26940-7cc0-11ee-a88e-c1887e; (total 36 bytes);
 4: len 1; hex 01; asc  ;;
 5: len 7; hex 756e6b6e6f776e; asc unknown;;
 6: len 7; hex 756e6b6e6f776e; asc unknown;;
 7: len 7; hex 756e6b6e6f776e; asc unknown;;
 8: SQL NULL;
 9: len 20; hex 00000daa000091fc000000260000000000025b02; asc            &      [ ;;
 10: len 2; hex 7b7d; asc {};;
 11: len 30; hex 7b3a7363726970742d6964203a636f6e73756c2d6d61696e74656e616e63; asc {:script-id :consul-maintenanc; (total 789 bytes);
 12: len 4; hex 65491286; asc eI  ;;
 13: len 4; hex 654931c3; asc eI1 ;;

---TRANSACTION 19911025576, ACTIVE 39 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
MariaDB thread id 1571679097, OS thread handle 140028706604800, query id 30769730069 db-proxy001.gv2.p.exoscale.net 172.20.8.30 <user> Statistics
select * from W where id=21233 for update
------- TRX HAS BEEN WAITING 39948709 ns FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 3498 page no 38948 n bits 16 index PRIMARY of table `myschema`.`W` trx id 19911025576 lock_mode X locks rec but not gap waiting
Record lock, heap no 8 PHYSICAL RECORD: n_fields 14; compact format; info bits 0
 0: len 4; hex 800052f1; asc   R ;;
 1: len 6; hex 0004a2b9dd14; asc       ;;
 2: len 7; hex 27000029d8211b; asc '  ) ! ;;
 3: len 30; hex 38386432363934302d376363302d313165652d613838652d633138383765; asc 88d26940-7cc0-11ee-a88e-c1887e; (total 36 bytes);
 4: len 1; hex 01; asc  ;;
 5: len 7; hex 756e6b6e6f776e; asc unknown;;
 6: len 7; hex 756e6b6e6f776e; asc unknown;;
 7: len 7; hex 756e6b6e6f776e; asc unknown;;
 8: SQL NULL;
 9: len 20; hex 00000daa000091fc000000260000000000025b02; asc            &      [ ;;
 10: len 2; hex 7b7d; asc {};;
 11: len 30; hex 7b3a7363726970742d6964203a636f6e73756c2d6d61696e74656e616e63; asc {:script-id :consul-maintenanc; (total 789 bytes);
 12: len 4; hex 65491286; asc eI  ;;
 13: len 4; hex 654931c3; asc eI1 ;;

---

On one experiment I did observe 4 transactions waiting for a single tx:

- waiting_query  select * from W where id=21258 for update                                       
- blocking_trx_id 19914724242
- blocking_thread 1571692338
- blocking_query NULL

---TRANSACTION 19914724242, ACTIVE 194 sec
58 lock struct(s), heap size 8312, 5 row lock(s), undo log entries 2
MariaDB thread id 1571692338, OS thread handle 140028734338816, query id 30780223733

select trx_query, trx_mysql_thread_id from information_schema.innodb_trx where trx_mysql_thread_id=1571692338 ;
<EMPTY>