Bug #59682 SIGSEGV while running ibtests + SHOW INNODB STATUS with UNIV_SYNC_DEBUG enabled

• Submitted: 23 Jan 2011 21:49
• Modified: 13 Feb 2012 3:39
• Reporter: Sunny Bains
• Status: Closed
• Category: MySQL Server: InnoDB storage engine
• Severity: S3 (Non-critical)
• Version: 5.1-plugin+
• OS: Any
• Assigned to: Sunny Bains
• CPU Architecture: Any
• Tags: debug

[23 Jan 2011 21:49] Sunny Bains

Description:
The rw lock debug list should be covered by the debug list mutex when traversing
the lock debug info.

Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: 13 at address: 0x0000000000000000
[Switching to process 22314]
0x00000001004511d1 in rw_lock_debug_print (f=0x7fff7064cf40, info=0xb000000000000) at /Users/sunny/innodb/bzr/5.5/storage/innobase/sync/sync0rw.c:1004
1004		rwt	  = info->lock_type;
(gdb) bt
#0  0x00000001004511d1 in rw_lock_debug_print (f=0x7fff7064cf40, info=0xb000000000000) at /Users/sunny/innodb/bzr/5.5/storage/innobase/sync/sync0rw.c:1004
#1  0x000000010045109c in rw_lock_list_print_info (file=0x7fff7064cf40) at /Users/sunny/innodb/bzr/5.5/storage/innobase/sync/sync0rw.c:939
#2  0x0000000100453f4a in sync_print (file=0x7fff7064cf40) at /Users/sunny/innodb/bzr/5.5/storage/innobase/sync/sync0sync.c:1542
#3  0x0000000100447378 in srv_printf_innodb_monitor (file=0x7fff7064cf40, nowait=0, trx_start=0x128c4a998, trx_end=0x128c4a990) at /Users/sunny/innodb/bzr/5.5/storage/innobase/srv/srv0srv.c:1859
#4  0x000000010040ceb1 in innodb_show_status (hton=0x100f031b0, thd=0x101161400, stat_print=0x10004a6ca <stat_print(THD*, char const*, unsigned int, char const*, unsigned int, char const*, unsigned int)>) at /Users/sunny/innodb/bzr/5.5/storage/innobase/handler/ha_innodb.cc:9149
#5  0x000000010040d129 in innobase_show_status (hton=0x100f031b0, thd=0x101161400, stat_print=0x10004a6ca <stat_print(THD*, char const*, unsigned int, char const*, unsigned int, char const*, unsigned int)>, stat_type=HA_ENGINE_STATUS) at /Users/sunny/innodb/bzr/5.5/storage/innobase/handler/ha_innodb.cc:9390
#6  0x000000010004b457 in ha_show_status (thd=0x101161400, db_type=0x100f031b0, stat=HA_ENGINE_STATUS) at /Users/sunny/innodb/bzr/5.5/sql/handler.cc:4509
#7  0x00000001001ea2c1 in mysql_execute_command (thd=0x101161400) at /Users/sunny/innodb/bzr/5.5/sql/sql_parse.cc:2245
#8  0x00000001001f013c in mysql_parse (thd=0x101161400, rawbuf=0x12689dc10 "SHOW ENGINE INNODB STATUS", length=25, parser_state=0x128c4c180) at /Users/sunny/innodb/bzr/5.5/sql/sql_parse.cc:5509
#9  0x00000001001f0d05 in dispatch_command (command=COM_QUERY, thd=0x101161400, packet=0x101121e01 "", packet_length=25) at /Users/sunny/innodb/bzr/5.5/sql/sql_parse.cc:1035
#10 0x00000001001f2164 in do_command (thd=0x101161400) at /Users/sunny/innodb/bzr/5.5/sql/sql_parse.cc:772
#11 0x00000001002c3db2 in do_handle_one_connection (thd_arg=0x101161400) at /Users/sunny/innodb/bzr/5.5/sql/sql_connect.cc:748
#12 0x00000001002c3eab in handle_one_connection (arg=0x101161400) at 
/Users/sunny/innodb/bzr/5.5/sql/sql_connect.cc:684
#13 0x00007fff839ad536 in _pthread_start ()
#14 0x00007fff839ad3e9 in thread_start ()
Current language:  auto; currently c
(gdb) 

How to repeat:
for i in 3 3a 5 5a 7 7a 9 9a 9a 9a 12 12a 12a 12a; do perl ibtest$i>$i.out& done
Start another client that does "SHOW INNODB STATUS" at 1 second intervals

Suggested fix:
There is a comment at the top of sync0rw.c that suggests the above requirement too.

=== modified file 'storage/innobase/sync/sync0rw.c'
--- storage/innobase/sync/sync0rw.c	revid:[e-mail]-20110118103033-7u1t8xpumnzyzeb4
+++ storage/innobase/sync/sync0rw.c	2011-01-23 11:12:19 +0000
@@ -934,11 +934,16 @@
				putc('\n', file);
			}

-			info = UT_LIST_GET_FIRST(lock->debug_list);
-			while (info != NULL) {
+			rw_lock_debug_mutex_enter();
+
+			for (info = UT_LIST_GET_FIRST(lock->debug_list);
+			     info != NULL;
+			     info = UT_LIST_GET_NEXT(list, info)) {
+
				rw_lock_debug_print(file, info);
-				info = UT_LIST_GET_NEXT(list, info);
			}
+
+			rw_lock_debug_mutex_exit();
		}
#ifndef INNODB_RW_LOCKS_USE_ATOMICS
		mutex_exit(&(lock->mutex));

[24 Jan 2011 9:15] Marko Mäkelä

This looks OK to me.

I was about to suggest adding a rw_lock_own() assertion to rw_lock_debug_print(), but then I saw the comments about doing dirty reads on purpose in rw_lock_print(). Could you perhaps fix that one as well?

[12 Oct 2012 23:50] John Russell

Added to changelog for 5.1.60: 

A timing issue could cause a crash while processing the SHOW ENGINE 
INNODB STATUS command. This issue only affected debug builds of the 
server.