Bug #43048 Falcon may crash during shutdown when running it embedded
Submitted: 20 Feb 2009 8:59 Modified: 15 May 2009 15:55
Reporter: Olav Sandstå Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S3 (Non-critical)
Version:6.0.10-alpha OS:Linux
Assigned to: Olav Sandstå CPU Architecture:Any
Tags: F_SHUTDOWN

[20 Feb 2009 8:59] Olav Sandstå
Description:
I have seen the following crash happen several times for random tests when running the "embedded testsuite": 

(gdb) where
#0  0x000000302420b122 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000005852ee in my_write_core (sig=6) at stacktrace.c:309
#2  0x000000000053e859 in signal_handler (sig=6) at mysqltest.cc:7423
#3  <signal handler called>
#4  0x000000302420c888 in __lll_mutex_lock_wait () from /lib64/libpthread.so.0
#5  0x00000030242088a5 in _L_mutex_lock_107 () from /lib64/libpthread.so.0
#6  0x0000003024208333 in pthread_mutex_lock () from /lib64/libpthread.so.0
#7  0x000000000090bfc5 in Synchronize::wake (this=0x2aaaab00f210)
    at Synchronize.cpp:231
#8  0x000000000090bfa6 in Synchronize::shutdown (this=0x2aaaab00f258)
    at Synchronize.cpp:243
#9  0x000000000088f66b in Cache::shutdownThreads (this=0x2aaaaae38300)
    at Cache.cpp:1045
#10 0x000000000088fcb6 in Cache::shutdown (this=0x2aaaaae38300) at Cache.cpp:1027
#11 0x000000000089f27b in Database::shutdown (this=0x2aaaaae0dbc8)
    at Database.cpp:1632
#12 0x00000000008980c9 in Connection::shutdownDatabase (this=0x2aaaab00e7e8)
    at Connection.cpp:1803
#13 0x00000000007eed2a in StorageDatabase::close (this=0x2aaaab00e208)
    at StorageDatabase.cpp:911
#14 0x00000000007f1cc5 in StorageHandler::shutdownHandler (this=0x2aaaaae0d048)
    at StorageHandler.cpp:194
#15 0x00000000007e880c in StorageInterface::falcon_deinit (p=<value optimized out>)
    at ha_falcon.cpp:286
#16 0x00000000007e882a in StorageInterface::panic (hton=<value optimized out>, 
    flag=HA_PANIC_CLOSE) at ha_falcon.cpp:2356
#17 0x0000000000719fae in ha_finalize_handlerton (plugin=0x1931b478)
    at handler.cc:393
#18 0x000000000060078a in plugin_deinitialize (plugin=0x1931b478, ref_check=true)
    at sql_plugin.cc:821
#19 0x0000000000601c05 in reap_plugins () at sql_plugin.cc:909
#20 0x00000000006020de in plugin_shutdown () at sql_plugin.cc:1513
#21 0x00000000005591ad in end_embedded_server () at ../sql/mysqld.cc:1368
#22 0x0000000000557ba7 in mysql_server_end () at libmysql.c:202
#23 0x000000000053f46f in free_used_memory () at mysqltest.cc:1139
#24 0x000000000053f48c in cleanup_and_exit (exit_code=-1426001320)
    at mysqltest.cc:1148
#25 0x000000000054a36b in main (argc=0, argv=<value optimized out>)
    at mysqltest.cc:8040

This seems to happen only during shutdown of tests.

How to repeat:
I see this failing sometimes when running the following test with Falcon built from the mysql-6.0-falcon-team tree:

./mysql-test-run.pl --embedded --mem

I see the crash both when running a debug and optimized builds.

Suggested fix:
Falcon should not crash with a segmentation fault during shutdown.
[20 Feb 2009 13:20] Olav Sandstå
The cause for pthread_mutex_lock to crash is that the Thread object and the mutex object seems to be overwritten when calling pthread_mutex_lock. The content of the ioThread object looks like this:

(dbx) print -r *ioThreads[0]
*ioThreads[0] = {
    Thread::Synchronize::shutdownInProgress = true
    Thread::Synchronize::sleeping           = true
    Thread::Synchronize::wakeup             = true
    Thread::Synchronize::waitTime           = -1229782938247303442LL
    Thread::Synchronize::condition          = {
        Thread::Synchronize::__pthread_cond_flags = {
            Thread::Synchronize::__pthread_cond_flag  = "îîîî"
            Thread::Synchronize::__pthread_cond_type  = 61166U
            Thread::Synchronize::__pthread_cond_magic = 61166U
        }
        Thread::Synchronize::__pthread_cond_data  = 17216961135462248174U
    }
    Thread::Synchronize::mutex              = {
        Thread::Synchronize::_pthread_mutex::__pthread_mutex_flags = {
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_flag1   = 61166U
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_flag2   = 'î'
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_ceiling = 'î'
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_type    = 61166U
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_magic   = 61166U
        }
        Thread::Synchronize::_pthread_mutex::__pthread_mutex_lock  = {
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_lock64  = {
                Thread::Synchronize::_pthread_mutex::__pthread_mutex_pad = "îîîîîîîî"
            }
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_lock32  = {
                Thread::Synchronize::_pthread_mutex::__pthread_ownerpid = 4008636142U
                Thread::Synchronize::_pthread_mutex::__pthread_lockword = 4008636142U
            }
            Thread::Synchronize::_pthread_mutex::__pthread_mutex_owner64 = 17216961135462248174U
        }
        Thread::Synchronize::_pthread_mutex::__pthread_mutex_data  = 17216961135462248174U
    }
    Thread::argument          = 0xeeeeeeeeeeeeeeee
    Thread::function          = 0xeeeeeeeeeeeeeeee
    Thread::threadHandle      = 0xeeeeeeeeeeeeeeee
    Thread::threadId          = 4008636142U
    Thread::threadBarn        = 0xeeeeeeeeeeeeeeee
    Thread::next              = 0xeeeeeeeeeeeeeeee
    Thread::prior             = 0xeeeeeeeeeeeeeeee
    Thread::queue             = 0xeeeeeeeeeeeeeeee
    Thread::srlQueue          = 0xeeeeeeeeeeeeeeee
    Thread::lockType          = -286331154
    Thread::wakeupType        = -286331154
    Thread::lockGranted       = true
    Thread::licenseWakeup     = true
    Thread::activeLocks       = -286331154
    Thread::locks             = 0xeeeeeeeeeeeeeeee
    Thread::lockPending       = 0xeeeeeeeeeeeeeeee
    Thread::marked            = true
    Thread::pageMarks         = -286331154
    Thread::eventNumber       = -286331154
    Thread::random            = -286331154
    Thread::backoff           = -286331154
    Thread::description       = 0xeeeeeeeeeeeeeeee "<bad address 0xeeeeeeee>"
    Thread::where             = 0xeeeeeeeeeeeeeeee "<bad address 0xeeeeeeee>"
    Thread::defaultTimeZone   = 0xeeeeeeeeeeeeeeee
    Thread::javaThread        = 0xeeeeeeeeeeeeeeee
    Thread::commitBlockNumber = 17216961135462248174ULL
    Thread::useCount          = -286331154
}
[20 Feb 2009 14:23] Olav Sandstå
The code that causes this is the following:

void Synchronize::wake()
{
#ifdef _WIN32
	SetEvent (event);
#endif

#ifdef _PTHREADS
	int ret = pthread_mutex_lock (&mutex);
	CHECK_RET ("pthread_mutex_lock failed, errno %d", errno);
	wakeup = true;
	pthread_cond_broadcast (&condition);
	ret = pthread_mutex_unlock (&mutex);
	CHECK_RET ("pthread_mutex_unlock failed, errno %d", errno);
#endif
}

void Synchronize::shutdown()
{
	shutdownInProgress = true;
	wake();
}

What seems to happen is that:

1. The thread shutting down the Cache is calling Synchronize::shutdown() to shut down the IO threads. This makes the shutdownInProgress set to true. Then it calls Synchronize::wake() but before that get executed, the thread we try to shutdown is running:

2. The thread to be shutdown sees the shutdownInProgess flag set to true. It shuts down and as part of this the Thread object is destroyed (and the memory overwritten).

3. The thread in (1) continues and calls pthread_mutex_lock (in Synchronize::wake()) with an "overwritten mutex" - and crashes....
[23 Feb 2009 18:58] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/67250

3032 Olav Sandstaa	2009-02-23
      Bug #43048 Falcon may crash during shutdown when running it embedded
      
      Calling shutdown() directly on a Thread object is not thread safe. If the
      thread we want to shutdown wake's up during the call to shutdown() it might
      shutdown and delete the thread object before the call to shutdown() has 
      completed. This might result in shutdown() accessing free and overwritten
      memory.
      
      Instead of calling shutdown() directly, use the thread barn's
      shutdown() method which has the neccessary locking for concurrent
      threads.
[2 Mar 2009 14:13] Bugs System
Pushed into 6.0.11-alpha (revid:alik@sun.com-20090302140208-lfdejjbcyezlhhjt) (version source revid:olav@sun.com-20090223185739-u9wvhrnajjqv8sct) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 15:55] MC Brown
A note has been added to the 6.0.11 changelog: 

mysqld would crash when using Falcon tables during shutdown if the server was running in embedded mode.