Bug #41836 Falcon assertion assertion (state != None) failed at line 79 in file Sync.cpp
Submitted: 3 Jan 2009 12:25 Modified: 15 May 2009 10:36
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S3 (Non-critical)
Version:6.0-falcon-team OS:Any
Assigned to: Vladislav Vaintroub CPU Architecture:Any
Tags: F_SYNCHRONIZATION

[3 Jan 2009 12:25] Philip Stoev
Description:
When recovery is initiated soon after server takeoff, it fails as follows:

# 14:22:17 Recovering database /tmp/vardir/master-data_recovery/falcon_master.fts ...
# 14:22:18 first recovery block is 1
# 14:22:18 last recovery block is 483
# 14:22:18 recovery read block is 2
# 14:22:18 Recovery complete
# 14:22:18 0: Commit System Transaction 2
# 14:22:18 0: Commit System Transaction 4
# 14:22:18 0: Commit System Transaction 6
# 14:22:18 [Falcon] Error: assertion (state != None) failed at line 79 in file Sync.cpp
# 14:22:18
# 14:22:18 Bugcheck: assertion (state != None) failed at line 79 in file Sync.cpp
# 14:22:18
# 14:22:18 090103 14:22:18 - mysqld got signal 6 ;
# 14:22:18 This could be because you hit a bug. It is also possible that this binary
# 14:22:18 or one of the libraries it was linked against is corrupt, improperly built,
# 14:22:18 or misconfigured. This error can also be caused by malfunctioning hardware.
# 14:22:18 We will try our best to scrape up some info that will hopefully help diagnose
# 14:22:18 the problem, but since we have already crashed, something is definitely wrong
# 14:22:18 and this may fail.
# 14:22:18
# 14:22:18 key_buffer_size=8384512
# 14:22:18 read_buffer_size=131072
# 14:22:18 max_used_connections=0
# 14:22:18 max_threads=151
# 14:22:18 thread_count=0
# 14:22:18 connection_count=0
# 14:22:18 It is possible that mysqld could use up to
# 14:22:18 key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338364 K
# 14:22:18 bytes of memory
# 14:22:18 Hope that's ok; if not, decrease some variables in the equation.
# 14:22:18
# 14:22:18 thd: 0x0
# 14:22:18 Attempting backtrace. You can use the following information to find out
# 14:22:18 where mysqld died. If you see no messages after this, something went
# 14:22:18 terribly wrong...
# 14:22:18 stack_bottom = (nil) thread_stack 0x40000
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(my_print_stacktrace+0x2e) [0xaba2ce]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(handle_segfault+0x32a) [0x6563aa]
# 14:22:18 /lib64/libpthread.so.0 [0x315b00f0f0]
# 14:22:18 /lib64/libpthread.so.0(raise+0x2b) [0x315b00efab]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(Error::error(char const*, ...)+0xe8) [0x8a6d88]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(Sync::unlock()+0x2c) [0x85aa5c]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(TableSpaceManager::initialize()+0x92) [0x869052]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(Database::openDatabase(char const*)+0x328) [0x8973c8]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(Connection::getDatabase(char const*, char const*, Threads*)+0xe3) [0x88b463]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(Connection::openDatabase(char const*, char const*, char const*, char const*, char const*, Threads*)+0xa4) [0x88cab4]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(StorageDatabase::getOpenConnection()+0x77) [0x850e27]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(StorageHandler::initialize()+0x96) [0x853a06]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(StorageInterface::falcon_init(void*)+0x186) [0x848c76]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(ha_initialize_handlerton(st_plugin_int*)+0x3f) [0x7535af]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld [0x7daa02]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(plugin_init(int*, char**, int)+0x824) [0x7dd974]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld [0x657f79]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld(main+0x198) [0x65b008]
# 14:22:18 /lib64/libc.so.6(__libc_start_main+0xe6) [0x315a41e546]
# 14:22:18 /build/bzr/6.0-falcon-team/mysql-test/../sql/mysqld [0x584379]
# 14:22:18 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
# 14:22:18 information that should help you find out what is causing the crash.
# 14:22:18 Writing a core file

How to repeat:
It appears that this crash is almost certain if recovery is initiated before checkpointing or serial log rotation has been performed.

To repeat:

$ perl runall.pl \
  --rows=1000 \
  --threads=4 \
  --queries=1000000 \
  --duration=10 \
  --basedir=/build/bzr/6.0-falcon-team \
  --engine=Falcon \
  --grammar=conf/combinations.yy \
  --gendata=conf/combinations.zz \
  --reporter=Recovery \
  --mysqld=--loose-falcon-lock-wait-timeout=1 \
  --mysqld=--log-output=none
[8 Jan 2009 17:33] 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/62727

2961 Vladislav Vaintroub	2009-01-08
       Bug#41836 : crash in TableSpaceManager::initialize.
      The reason for the crash  are multiple invokations of SyncObject::unlock))=. 
      First unlock() unlocked syncSysDDL, second call into assertion (object must be locked for unlock)
      
      Solution: do not unlock syncSysDDL, lock is automatically released after function returns.
[13 Feb 2009 7:25] Bugs System
Pushed into 6.0.10-alpha (revid:alik@sun.com-20090211182317-uagkyj01fk30p1f8) (version source revid:olav@sun.com-20090113103017-41jbad7qlvlwpwxh) (merge vers: 6.0.10-alpha) (pib:6)
[15 May 2009 10:37] MC Brown
Internal change, no changelog entry required.