| Bug #55935 | crash when printing deadlock information... | ||
|---|---|---|---|
| Submitted: | 12 Aug 2010 7:24 | Modified: | 30 Apr 2012 11:53 |
| Reporter: | Shane Bester (Platinum Quality Contributor) | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
| Version: | 5.0.72,5.1.49, 5.1.56 | OS: | Windows |
| Assigned to: | CPU Architecture: | Any | |
[12 Aug 2010 7:24]
Shane Bester
[12 Aug 2010 7:27]
MySQL Verification Team
some infos
Attachment: bug55935_5.1.49_crash_info.txt (text/plain), 17.17 KiB.
[18 Aug 2010 22:19]
MySQL Verification Team
while trying to reproduce this, I got another crash, in the middle of printing lock info when the innodb_lock_monitor was running: 5.1.49: mysqld-debug.exe!mach_read_from_1()[mach0data.ic:37] mysqld-debug.exe!rec_get_bit_field_1()[rem0rec.ic:189] mysqld-debug.exe!rec_get_status()[rem0rec.ic:407] mysqld-debug.exe!rec_get_offsets_func()[rem0rec.c:324] mysqld-debug.exe!lock_rec_print()[lock0lock.c:4176] mysqld-debug.exe!lock_print_info_all_transactions()[lock0lock.c:4425] mysqld-debug.exe!srv_printf_innodb_monitor()[srv0srv.c:1719] mysqld-debug.exe!srv_monitor_thread()[srv0srv.c:1972] other running threads against the table in question include truncate, insert, update. still no solidly repeatable testcase..
[7 Oct 2010 10:17]
MySQL Verification Team
seen on 5.0.72 also: mysqld-nt.exe!rec_get_offsets_func()[rem0rec.c:326] mysqld-nt.exe!lock_rec_print()[lock0lock.c:4183] mysqld-nt.exe!lock_deadlock_recursive()[lock0lock.c:3331] mysqld-nt.exe!lock_deadlock_recursive()[lock0lock.c:3401] mysqld-nt.exe!lock_deadlock_recursive()[lock0lock.c:3401] mysqld-nt.exe!lock_deadlock_recursive()[lock0lock.c:3401] mysqld-nt.exe!lock_deadlock_occurs()[lock0lock.c:3190] mysqld-nt.exe!lock_rec_enqueue_waiting()[lock0lock.c:1844] mysqld-nt.exe!lock_rec_insert_check_and_lock()[lock0lock.c:4834] mysqld-nt.exe!btr_cur_ins_lock_and_undo()[btr0cur.c:860] mysqld-nt.exe!btr_cur_optimistic_insert()[btr0cur.c:1022] mysqld-nt.exe!row_ins_index_entry_low()[row0ins.c:2085] mysqld-nt.exe!row_ins()[row0ins.c:2378] mysqld-nt.exe!row_ins_step()[row0ins.c:2482] mysqld-nt.exe!row_insert_for_mysql()[row0mysql.c:1152] mysqld-nt.exe!ha_innobase::write_row()[ha_innodb.cc:3289] mysqld-nt.exe!write_record()[sql_insert.cc:1351] mysqld-nt.exe!mysql_insert()[sql_insert.cc:826] mysqld-nt.exe!wait_if_global_read_lock()[lock.cc:1269] mysqld-nt.exe!List<Item>::push_back()[sql_list.h:400] mysqld-nt.exe!MYSQLparse()[sql_yacc.cc:29358] mysqld-nt.exe!dispatch_command()[sql_parse.cc:1940] mysqld-nt.exe!do_command()[sql_parse.cc:1628] mysqld-nt.exe!handle_one_connection()[sql_parse.cc:1234] mysqld-nt.exe!pthread_start()[my_winthread.c:85] mysqld-nt.exe!_threadstart()[thread.c:196] kernel32.dll!FlsSetValue()
[7 Oct 2010 10:55]
MySQL Verification Team
in 5.0.72 crash is in rec_get_offsets_func:
if (UNIV_LIKELY(index->table->comp)) {
switch (UNIV_EXPECT(rec_get_status(rec), <------------------ crash
REC_STATUS_ORDINARY)) {
rec was a NULL value.
Calling function, lock_rec_print, called page_find_rec_with_heap_no but forgot to check if result is null, and therefore passes the incorrect 'rec' :
if (page) {
rec_t* rec
= page_find_rec_with_heap_no(page, i);
offsets = rec_get_offsets(rec, lock->index,
offsets, ULINT_UNDEFINED, &heap);
rec_print_new(file, rec, offsets);
}
[7 Oct 2010 11:05]
MySQL Verification Team
some infos.
Attachment: 5.0.72_some_crash_infos.txt (text/plain), 13.83 KiB.
[14 Mar 2011 8:10]
MySQL Verification Team
oh, I just hit this again on 5.1.49 builtin with innodb_lock_monitor enabled: 00604854 mysqld.exe!mach_read_from_1()[mach0data.ic:37] 0060E58E mysqld.exe!rec_get_bit_field_1()[rem0rec.ic:189] 0060E710 mysqld.exe!rec_get_status()[rem0rec.ic:407] 0060F400 mysqld.exe!rec_get_offsets_func()[rem0rec.c:324] 005D1C5A mysqld.exe!lock_rec_print()[lock0lock.c:4177] 005D20FC mysqld.exe!lock_print_info_all_transactions()[lock0lock.c:4426] 005B4544 mysqld.exe!srv_printf_innodb_monitor()[srv0srv.c:1720] 005B4B4A mysqld.exe!srv_monitor_thread()[srv0srv.c:1972] I'll rerun identical test on 5.1.56 shortly.
[14 Mar 2011 8:41]
MySQL Verification Team
crashed 5.1.56 also. now i support i'll upload a testcase sometime soon. mysqld.exe!mach_read_from_1()[mach0data.ic:37] mysqld.exe!rec_get_bit_field_1()[rem0rec.ic:186] mysqld.exe!rec_get_status()[rem0rec.ic:404] mysqld.exe!rec_get_offsets_func()[rem0rec.c:324] mysqld.exe!lock_rec_print()[lock0lock.c:4177] mysqld.exe!lock_print_info_all_transactions()[lock0lock.c:4424] mysqld.exe!srv_printf_innodb_monitor()[srv0srv.c:1725] mysqld.exe!srv_monitor_thread()[srv0srv.c:1977] kernel32.dll!FlsSetValue() I'll try 5.5.9 first and post results.
[14 Mar 2011 17:57]
MySQL Verification Team
note tos elf: 15 threads, shuffled for about 30 minutes is enough to see a crash on 5.1 builtin.
Attachment: dml.sql (, text), 1.27 KiB.
[26 Apr 2012 14:49]
MySQL Verification Team
I repeated this on 5.1.42 + plugin today: ha_innodb_plugin.dll!lock_deadlock_recursive()[lock0lock.c:3342] ha_innodb_plugin.dll!lock_deadlock_recursive()[lock0lock.c:3495] ha_innodb_plugin.dll!lock_deadlock_recursive()[lock0lock.c:3495] ha_innodb_plugin.dll!lock_deadlock_recursive()[lock0lock.c:3495] ha_innodb_plugin.dll!lock_deadlock_occurs()[lock0lock.c:3285] ha_innodb_plugin.dll!lock_rec_enqueue_waiting()[lock0lock.c:1797] ha_innodb_plugin.dll!lock_rec_lock_slow()[lock0lock.c:2052] ha_innodb_plugin.dll!lock_rec_lock()[lock0lock.c:2112] ha_innodb_plugin.dll!lock_clust_rec_read_check_and_lock()[lock0lock.c:5311] ha_innodb_plugin.dll!sel_set_rec_lock()[row0sel.c:971] ha_innodb_plugin.dll!row_search_for_mysql()[row0sel.c:4044] ha_innodb_plugin.dll!ha_innodb::general_fetch()[ha_innodb.cc:5299] ha_innodb_plugin.dll!ha_innodb::rnd_next()[ha_innodb.cc:5491] mysqld.exe!rr_sequential()[records.cc:385] mysqld.exe!mysql_delete()[sql_delete.cc:343] mysqld.exe!mysql_execute_command()[sql_parse.cc:3308] mysqld.exe!init_available_charsets()[charset.c:447] mysqld.exe!get_charset_by_csname()[charset.c:591] mysqld.exe!MYSQLparse()[sql_yacc.cc:15748] mysqld.exe!parse_sql()[sql_parse.cc:7844] mysqld.exe!mysql_parse()[sql_parse.cc:5974] mysqld.exe!dispatch_command()[sql_parse.cc:1233] mysqld.exe!do_command()[sql_parse.cc:876] mysqld.exe!handle_one_connection()[sql_connect.cc:1127] mysqld.exe!pthread_start()[my_winthread.c:85] mysqld.exe!_callthreadstart()[thread.c:293]
[30 Apr 2012 8:02]
MySQL Verification Team
There maybe multiple bugs reported in this bug. I have made progress on this. I get a crash in minutes instead of 12 hours with a better testcase. For this crash in lock_rec_enqueue_waiting: ha_innodb_plugin.dll!lock_rec_enqueue_waiting()[lock0lock.c:1767] ha_innodb_plugin.dll!lock_rec_lock_slow()[lock0lock.c:2052] ha_innodb_plugin.dll!lock_rec_lock()[lock0lock.c:2112] ha_innodb_plugin.dll!lock_clust_rec_read_check_and_lock()[lock0lock.c:5311] ha_innodb_plugin.dll!sel_set_rec_lock()[row0sel.c:971] ha_innodb_plugin.dll!row_search_for_mysql()[row0sel.c:4044] ha_innodb_plugin.dll!os_fast_mutex_lock()[os0sync.c:666] ha_innodb_plugin.dll!srv_conc_enter_innodb()[srv0srv.c:1086] ha_innodb_plugin.dll!ha_innodb::index_first()[ha_innodb.cc:5387] ha_innodb_plugin.dll!ha_innodb::rnd_next()[ha_innodb.cc:5482] mysqld.exe!rr_sequential()[records.cc:385] mysqld.exe!mysql_delete()[sql_delete.cc:297] mysqld.exe!mysql_execute_command()[sql_parse.cc:3312] 5.1.42 + plugin : crash 5.1.44 + plugin : crash 5.1.45 + plugin : crash 5.1.46 + plugin : no crash 5.1.62 + plugin : no crash It seems to me this crash in lock_rec_enqueue_waiting might be a duplicate of http://bugs.mysql.com/bug.php?id=49001 which is fixed in 5.1.46 plugin 1.0.7.
[3 May 2012 5:08]
MySQL Verification Team
Also, another improvement maybe have led to the non-repeatability of this bug: http://bugs.mysql.com/bug.php?id=49047
