Wrong usage of mutex 'share->bitmap.bitmap_lock' and 'share->intern_lock' on Aria table update with low aria-pagecache-buffer-size

[Elena Stepanova]

The attached test case causes error messages in the server error log

safe_mutex: Found wrong usage of mutex 'share->bitmap.bitmap_lock' and 'share->intern_lock'
Mutex currently locked (in reverse order):
share->intern_lock ma_locking.c line 425
share->bitmap.bitmap_lock ma_bitmap.c line 372

or, if it's run with debug-assert-on-error, assertion failure:

mysqld: thr_mutex.c:841: print_deadlock_warning: Assertion `my_assert_on_error == 0' failed.

#8 0xb7583014 in __assert_fail () from /lib/libc.so.6
#9 0x0869ab4b in print_deadlock_warning (new_mutex=0x93062ac, parent_mutex=0x930644c) at thr_mutex.c:841
#10 0x08699975 in safe_mutex_lock (mp=0x93062ac, my_flags=0, file=0x87e6750 "ma_locking.c", line=425) at thr_mutex.c:366
#11 0x08564a06 in _ma_mark_file_changed_now (share=0x9305cf0) at ma_locking.c:425
#12 0x08553eea in maria_flush_log_for_page (page=0xb6c1e020 "\001", page_no=1, data_ptr=0x9305cf0 "\376\376\t\003\f\002\005\226") at ma_pagecrc.c:371
#13 0x08528e2b in pagecache_fwrite (pagecache=0x915f440, filedesc=0x91aa15c, buffer=0xb6c1e020 "\001", pageno=1, type=PAGECACHE_LSN_PAGE, flags=36)
    at ma_pagecache.c:658
#14 0x0852c364 in find_block (pagecache=0x915f440, file=0x9306434, pageno=0, init_hits_left=0, wrmode=1 '\001', block_is_copied=0 '\000', reg_req=1 '\001',
    page_st=0xb697e180) at ma_pagecache.c:2198
#15 0x08531931 in pagecache_write_part (pagecache=0x915f440, file=0x9306434, pageno=0, level=0, buff=0x9307088 "\001", type=PAGECACHE_PLAIN_PAGE,
    lock=PAGECACHE_LOCK_LEFT_UNLOCKED, pin=PAGECACHE_PIN_LEFT_UNPINNED, write_mode=PAGECACHE_WRITE_DELAY, page_link=0xb697e1ac, first_REDO_LSN_for_page=0, offset=0,
    size=8192) at ma_pagecache.c:4092
#16 0x084fbd05 in write_changed_bitmap (share=0x9305cf0, bitmap=0x9306408) at ma_bitmap.c:173
#17 0x084fc67f in _ma_bitmap_flush (share=0x9305cf0) at ma_bitmap.c:418
#18 0x084f6632 in _ma_scan_init_block_record (info=0x930f9e8) at ma_blockrec.c:5224
#19 0x08517a46 in maria_scan_init (info=0x930f9e8) at ma_scan.c:29
#20 0x084cdb9d in ha_maria::rnd_init (this=0x9304cd8, scan=true) at ha_maria.cc:2252
#21 0x08184bde in handler::ha_rnd_init (this=0x9304cd8, scan=true) at handler.h:1351
#22 0x0837ef69 in handler::ha_rnd_init_with_error (this=0x9304cd8, scan=true) at handler.cc:2170
#23 0x083761f5 in init_read_record (info=0xb697e6d4, thd=0x920e5d8, table=0x92f49f0, select=0x0, use_record_cache=0, print_error=true, disable_rr_cache=false)
    at records.cc:261
#24 0x0830a348 in mysql_update (thd=0x920e5d8, table_list=0x927ae38, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551615,
    handle_duplicates=DUP_ERROR, ignore=false) at sql_update.cc:559
#25 0x0826469e in mysql_execute_command (thd=0x920e5d8) at sql_parse.cc:3163
#26 0x0826d33b in mysql_parse (thd=0x920e5d8, rawbuf=0x927ad88 "UPDATE t16 SET id_board = 3", length=27, found_semicolon=0xb697f234) at sql_parse.cc:6192
#27 0x0825fe9c in dispatch_command (command=COM_QUERY, thd=0x920e5d8, packet=0x9265821 "UPDATE t16 SET id_board = 3", packet_length=27) at sql_parse.cc:1232
#28 0x0825f35d in do_command (thd=0x920e5d8) at sql_parse.cc:919
#29 0x0825d64c in handle_one_connection (arg=0x920e5d8) at sql_connect.cc:1188
#30 0xb7810b25 in start_thread () from /lib/libpthread.so.0

Reproducible on 5.2, 5.3, 5.5.

To reproduce, run the attached MTR test as

perl ./mtr --mysqld=--loose-debug-assert-on-error --mysqld=--aria-pagecache-buffer-size=512K reverse_lock_order

[Michael Widenius (monty)]

This is fixed in 5.3 (verified by Elena)
As 5.3 is now GA and this issue is not likely to happen, we will not backport the fix .2 for now.
If a lot of users or a a paying customer wants to have this fixed, lets backport the fix.
The fix is part in Revno: 3442.1.1 and 3442.1.2