thread locks itself on btr_search_latch_part

[Aleksandr Kuzminsky]

Percona Server crashes on long wait for a latch:

--Thread 140161830381312 has waited at btr0sea.c line 1203 for 945.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x123b4b828 'btr_search_latch_part[i]'
a writer (thread id 140161830381312) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
Last time read locked in file btr0sea.c line 1105
Last time write locked in file /dev/shm/work/BUILD/Percona-Server-5.5.30-rel30.2/Percona-Server-5.5.30-rel30.2/storage/innobase/btr/btr0sea.c line 675

Thread 140161830381312 is trying to get a lock on the latch, but it was locked by the same thread before.

Version: Percona Server (GPL), Release rel30.2, Revision 508

| innodb_adaptive_hash_index | ON
| innodb_adaptive_hash_index_partitions | 1

Transactions:

---TRANSACTION 1AFDFF402A, ACTIVE 945 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1248, 1 row lock(s), undo log entries 5
MySQL thread id 4, OS thread handle 0x7f79f9657700, query id 116599319 Updating
update ....

---TRANSACTION 1AFDFF3FE8, ACTIVE 945 sec starting index read
mysql tables in use 12, locked 0
, holds adaptive hash latch
MySQL thread id 332537, OS thread handle 0x7f79f81c6700, query id 116599225 a.b.c.d user Sending data
SELECT ...

[Fernando Ipar (fipar)]

Saw this on 5.0.92-87 Today:

--Thread 140274892576512 has waited at btr0sea.c line 1399 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x14dc0f60 created in file btr0sea.c line 139
a writer (thread id 140274892576512) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file btr0sea.c line 1290
Last time write locked in file btr0sea.c line 516

[Valerii Kravchuk (valerii-kravchuk)]

Check also these upstream bug reports:

http://bugs.mysql.com/bug.php?id=68961
http://bugs.mysql.com/bug.php?id=66402
http://bugs.mysql.com/bug.php?id=59047

[Laurynas Biveinis (laurynas-biveinis)]

Valerii -

note that http://bugs.mysql.com/bug.php?id=66402 was in fact reported for Percona Server.

[Laurynas Biveinis (laurynas-biveinis)]

See bug 1218347. There is a good chance (although not a certainty) that the fix for that bug fixes this issue too. The fix is available in lp:percona-server/5.5 now and will be available in the next 5.5.33.31-2 release.

[Laurynas Biveinis (laurynas-biveinis)]

To everybody who have previously encountered this bug - does it still occur with a recent (i.e. 5.5.34-32.0 or later) Percona Server 5.5 release?

[Amol (ajkedar)]

Yes i recently faced the issue in percona xtradb cluster 5.5.34

--Thread 140004927993600 has waited at row0sel.c line 3670 for 0.0000 seconds the semaphore:
S-lock on RW-latch at 0x6653a48 '&btr_search_latch_arr[i]'
number of readers 0, waiters flag 0, lock_word: 100000
Last time read locked in file row0sel.c line 3670
Last time write locked in file /mnt/workspace/percona-xtradb-cluster-debs/label_exp/ubuntu-precise-64bit/target/Percona-XtraDB-Cluster-5.5.34/storage/innobase/btr/btr0sea.c line 674
--Thread 140005536966400 has waited at buf0buf.ic line 376 for 0.0000 seconds the semaphore:
Mutex at 0x7f55a3f645f0 '&block->mutex', lock var 0
waiters flag 0
--Thread 140005551875840 has waited at buf0buf.ic line 376 for 0.0000 seconds the semaphore:
Mutex at 0x7f55a3f645f0 '&block->mutex', lock var 0
waiters flag 0
--Thread 140005535368960 has waited at row0sel.c line 3670 for 0.0000 seconds the semaphore:
S-lock on RW-latch at 0x6653a48 '&btr_search_latch_arr[i]'
number of readers 0, waiters flag 0, lock_word: 100000
Last time read locked in file row0sel.c line 3670
Last time write locked in file /mnt/workspace/percona-xtradb-cluster-debs/label_exp/ubuntu-precise-64bit/target/Percona-XtraDB-Cluster-5.5.34/storage/innobase/btr/btr0sea.c line 674
--Thread 140005536700160 has waited at row0sel.c line 3670 for 0.0000 seconds the semaphore:
S-lock on RW-latch at 0x6653a48 '&btr_search_latch_arr[i]'
number of readers 0, waiters flag 0, lock_word: 100000
Last time read locked in file row0sel.c line 3670
Last time write locked in file /mnt/workspace/percona-xtradb-cluster-debs/label_exp/ubuntu-precise-64bit/target/Percona-XtraDB-Cluster-5.5.34/storage/innobase/btr/btr0sea.c line 674
--Thread 140005559064320 has waited at buf0buf.ic line 376 for 0.0000 seconds the semaphore:
Mutex at 0x7f55a3f645f0 '&block->mutex', lock var 0
waiters flag 0
--Thread 140005533771520 has waited at buf0buf.ic line 376 for 0.0000 seconds the semaphore:
Mutex at 0x7f55a3f645f0 '&block->mutex', lock var 1
waiters flag 0

[Amol (ajkedar)]

Thanks for updating the ticket to new, i would be eager to provide your more information if needed

[Fernando Ipar (fipar)]

I see this marked as Invalid for 5.6 but I don't see any comments. Is it confirmed that this would be resolved by upgrade to that version?

[Laurynas Biveinis (laurynas-biveinis)]

The feature did not exist in 5.6 at the time this bug was processed. This might have been not necessarily correct (e.g. an upstream bug could exist with btr_search_latch instead of btr_search_latch_part), but in any case we think we resolved the issue by fixing bug 1218347, whose fix was delivered in 5.5.34-32.0 and before the GA in 5.6. Please try upgrading to at least those, or open a new bug if you see this with a recent version.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2957