Bug #43106 Falcon recovery assertion (bdb->buffer->pageNumber == pageNumber) in Cache.cpp
Submitted: 23 Feb 12:24 Modified: 15 May 16:12
Reporter: Olav Sandstaa
Status: Closed
Category:Server: Falcon Severity:S2 (Serious)
Version:6.0.10-alpha OS:Any
Assigned to: Vladislav Vaintroub Target Version:6.0-beta
Tags: F_RECOVERY
Triage: Triaged: D1 (Critical)

[23 Feb 12:24] Olav Sandstaa 
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 22:24] Vladislav Vaintroub 
the page in question is all zero and has to be a DataPage.
looks like SRLDataPage is not logged.
[21 Apr 13: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 9: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 16: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.