Comment 2 for bug 1431986

Hi ZhiQiang,

Tried setting synchronize_session='fetch' but did not make any difference still see database deadlock

Turned on innodb_print_all_deadlocks in mysql

Here is the deadlock log

150318 1:36:04
*** (1) TRANSACTION:
TRANSACTION 6D40E8, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 8 lock struct(s), heap size 1248, 3 row lock(s), undo log entries 45
MySQL thread id 189654, OS thread handle 0x7fa8c5aac700, query id 24912403 10.22.152.48 ceilometer update
INSERT INTO sample (meter_id, resource_id, volume, timestamp, recorded_at, message_signature, message_id) VALUES (13, 23152, 1, '1426642564.567148', '1426642564.623249', 'b73bd658f660e85614d32906aef8c0ecde48c1f0c9fe3ec0f1a826d617dd4bdf', '245609f2-cd0f-11e4-a21b-78e7d1233465\
')
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 119 page no 3 n bits 80 index `PRIMARY` of table `ceilometer`.`meter` trx id 6D40E8 lock mode S locks rec but not gap waiting
*** (2) TRANSACTION:
TRANSACTION 6D3FB7, ACTIVE 1 sec fetching rows
mysql tables in use 3, locked 3
1913 lock struct(s), heap size 227768, 229943 row lock(s)
MySQL thread id 190673, OS thread handle 0x7fa8c534f700, query id 24911810 10.xx.xx.xx ceilometer Sending data
DELETE FROM metadata_text WHERE metadata_text.id IN (SELECT resource.internal_id
FROM resource
WHERE NOT (EXISTS (SELECT 1
FROM sample
WHERE resource.internal_id = sample.resource_id)))
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 119 page no 3 n bits 80 index `PRIMARY` of table `ceilometer`.`meter` trx id 6D3FB7 lock_mode X
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 159 page no 1633 n bits 328 index `PRIMARY` of table `ceilometer`.`metadata_text` trx id 6D3FB7 lock_mode X waiting
*** WE ROLL BACK TRANSACTION (1)

1st transaction "insert into sample" is waiting for lock on ceilometer.meter primary index

2nd transaction "delete from metadata_text" has already gotten locks on several ceilometer.meter PRIMARY index rows AND is waiting for lock on ceilometer.metadata_text

1st transaction gets rollbacked

What is not clear to me from the logs why does the 2nd transaction not keep waiting for 1st to complete rather than treating it as a deadlock, unless there is some other locks that the 1st transaction grabs but are not printed in the logs.

Anyway I think that changing expirer to delete in steps each in its own transaction would avoid locking mysql indexes for a long time reducing the possibility of this happening.

Other related problem of this bug that we noticed is that Insert into sample table does not retry insert it encounters a Rollback exception, so we lose data for which transaction was rollbacked.