Bug #43106 Falcon recovery assertion (bdb->buffer->pageNumber == pageNumber) in Cache.cpp
Submitted: 23 Feb 2009 11:24 Modified: 15 May 2009 14:12
Reporter: Olav Sandstå Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:6.0.10-alpha OS:Any
Assigned to: Vladislav Vaintroub CPU Architecture:Any
Tags: F_RECOVERY

[23 Feb 2009 11:24] Olav Sandstå 
Description:
When Falcon doing recovery after running falcon_blob_recovery test it fails with the following assert:

# 11:08:17 [Falcon] Error: assertion (bdb->buffer->pageNumber == pageNumber) failed at line 294 in file Cache.cpp

The call stack looks like this:

# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(my_print_stacktrace+0x32) [0x881abf9]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(handle_segfault+0x2cd) [0x82bb32f]
# 11:08:17 [0x6f4420]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Error::debugBreak()+0x12) [0x8553530]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Error::error(char const*, ...)+0x7a) [0x85535ac]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Error::assertionFailed(char const*, char const*, int)+0x27) [0x8553651]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Cache::fetchPage(Dbb*, int, PageType, LockType)+0x394) [0x8646686]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Dbb::fetchPage(int, PageType, LockType)+0x48) [0x85acbd2]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Section::redoBlobDelete(Dbb*, int, int, int, int, bool)+0x3b) [0x8610f5f]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(SRLBlobDelete::pass2()+0xd0) [0x865a186]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(SerialLog::recover()+0xa48) [0x861c244]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Database::openDatabase(char const*)+0x324) [0x85a536e]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Connection::getDatabase(char const*, char const*, Threads*)+0x149) [0x85987a9]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(Connection::openDatabase(char const*, char const*, char const*, char const*, char const*, Threads*)+0x198) [0x8599cc4]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(StorageDatabase::getOpenConnection()+0x86) [0x855d852]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(StorageHandler::initialize()+0x9f) [0x855fefd]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(StorageInterface::falcon_init(void*)+0x23f) [0x8550fdb]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(ha_initialize_handlerton(st_plugin_int*)+0xa3) [0x840202f]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld [0x84b763e]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(plugin_init(int*, char**, int)+0x67c) [0x84b8ac8]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld [0x82bdf52]
# 11:08:17 /export/home/pb2/test/sb_1-345630-1235383462.25/mysql-6.0.10-alpha-linux-i686-test/libexec/mysqld(main+0x1de) [0x82bef04]
# 11:08:17 /lib/libc.so.6(__libc_start_main+0xdc) [0x736dec]

Note: the assert is similar to bug#41845 but the call stack is different.

How to repeat:
Seen once when running falcon_blob_recovery

Suggested fix:
Don't ask me.
[30 Mar 2009 20:24] Vladislav Vaintroub 
the page in question is all zero and has to be a DataPage.
looks like SRLDataPage is not logged.
[21 Apr 2009 11: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/72577

3133 Vladislav Vaintroub	2009-04-21
      Bug #43106 Falcon recovery assertion (bdb->buffer->pageNumber == pageNumber) in Cache.cpp 
      
      The problem is that Falcon during recovery can access a data page that can 
      be invalid. If the same transaction creates, and deletes the same blob but
      does not finish before the crash, data page s not guaranteed to be written to disk
      before delete.
      
      The fix is to update data page  only if transaction has completed, and we
      that data page is on disk. Blob update was already handled this way.
[23 Apr 2009 7:22] Bugs System 
Pushed into 6.0.11-alpha (revid:alik@sun.com-20090423071213-afmyrzvolemph7mz) (version source revid:hky@sun.com-20090421195958-j33v1cuo3yer9niu) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 14:12] MC Brown 
An entry has been added to the 6.0.11 changelog: 

Trying to recover Falcon tables after a crash when the corresponding tables and tablespaces have not been created before the crash could cause a recovery failure.