Bug #41845 Falcon recovery assertion (bdb->buffer->pageNumber == pageNumber) in file Cache.
Submitted: 3 Jan 2009 20:35 Modified: 4 Feb 2009 9:53
Reporter: Philip Stoev Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:6.0-falcon-team OS:Any
Assigned to: Vladislav Vaintroub
Tags: F_RECOVERY
Triage: Triaged: D1 (Critical)

[3 Jan 2009 20:35] Philip Stoev
Description:
When attempting to recover after a kill -9 on a server started with --falcon-page-size=2K , Falcon asserted as follows:

first recovery block is 107403
# 18:23:04 last recovery block is 169579
# 18:23:04 recovery read block is 141797
# 18:23:04 During recovery, fetched page 15491 tablespace 1 type 2 marked free in PIP
# 18:23:05 During recovery, fetched page 15492 tablespace 1 type 2 marked free in PIP
# 18:23:05 [Falcon] Error: assertion (bdb->buffer->pageNumber == pageNumber) failed at line 293 in file Cache.cpp
# 18:23:05
# 18:23:05 Bugcheck: assertion (bdb->buffer->pageNumber == pageNumber) failed at line 293 in file Cache.cpp
# 18:23:05
# 18:23:05 090103 18:23:05 - mysqld got signal 6 ;

#4  0x00000000008a6d88 in Error::debugBreak () at Error.cpp:94
#5  Error::error (string=<value optimized out>) at Error.cpp:71
#6  0x0000000000883f64 in Cache::fetchPage (this=0x7f5a141b6ff0, dbb=0x7f5a13f98110, pageNumber=15492, pageType=PAGE_sections, lockType=Exclusive)
    at Cache.cpp:293
#7  0x000000000089c9bb in Dbb::fetchPage (lockType=<value optimized out>, pageType=<value optimized out>, pageNumber=<value optimized out>,
    this=<value optimized out>) at Dbb.cpp:221
#8  Dbb::handoffPage (this=0x0, bdb=0x7f5a1427ee60, pageNumber=6, pageType=4294967295, lockType=19971424) at Dbb.cpp:270
#9  0x00000000008e6c9d in Section::getSectionPage (dbb=0x7f5a13f98110, root=4, sequence=1, requestedLockType=Exclusive, transId=0) at Section.cpp:251
#10 0x00000000008e6f5b in Section::getSectionPage (this=0x7f5a103216e0, sequence=1, lockType=Exclusive, transId=0) at Section.cpp:1416
#11 0x00000000008e714f in Section::redoRecordLocatorPage (this=0x3423, sequence=506, pageNumber=15493, isPostFlush=true) at Section.cpp:1278
#12 0x00000000008f2bde in SerialLog::recover (this=0x7f5a14384f48) at SerialLog.cpp:349
#13 0x0000000000897202 in Database::openDatabase (this=0x7f5a1418ebb8, filename=0x7fff1d6a7010 "/tmp/vardir/master-data_recovery/falcon_master.fts")
    at Database.cpp:733
#14 0x000000000088b463 in Connection::getDatabase (this=0x7f5a13f8d700, dbName=0x7f5a13f8d37c "FALCON_MASTER",
    dbFileName=0x7fff1d6a7010 "/tmp/vardir/master-data_recovery/falcon_master.fts", threads=0x7f5a13f8d3d8) at Connection.cpp:1651
#15 0x000000000088cab4 in Connection::openDatabase (this=0x7f5a13f8d700, dbName=0x7f5a13f8d37c "FALCON_MASTER", filename=<value optimized out>,
    account=0xba8331 "mysql", password=0xba8331 "mysql", address=0x0, parent=0x7f5a13f8d3d8) at Connection.cpp:934
#16 0x0000000000850e27 in StorageDatabase::getOpenConnection (this=0x7f5a13f8d1f0) at StorageDatabase.cpp:136
#17 0x0000000000853a06 in StorageHandler::initialize (this=0x7f5a1418e040) at StorageHandler.cpp:987
#18 0x0000000000848c76 in StorageInterface::falcon_init (p=<value optimized out>) at ha_falcon.cpp:245
#19 0x00000000007535af in ha_initialize_handlerton (plugin=0x21245c8) at handler.cc:440
#20 0x00000000007daa02 in plugin_initialize (plugin=0x3423) at sql_plugin.cc:1006
#21 0x00000000007dd974 in plugin_init (argc=0x10ac688, argv=0x2104b08, flags=<value optimized out>) at sql_plugin.cc:1213
#22 0x0000000000657f79 in init_server_components () at mysqld.cc:4112
#23 0x000000000065b008 in main (argc=<value optimized out>, argv=<value optimized out>) at mysqld.cc:4574

(gdb) list
288                                     sectorCache->readPage(bdb);
289                             else
290                                     dbb->readPage(bdb);
291                             priority.finished();
292     #ifdef HAVE_PAGE_NUMBER
293                             ASSERT(bdb->buffer->pageNumber == pageNumber);
294     #endif
295                             if (actual != lockType)
296                                     bdb->downGrade(lockType);
297                             }

(gdb) print pageNumber
$1 = 15492
(gdb) print bdb->buffer->pageNumber
$2 = 0

How to repeat:
The tablespace will be uploaded shortly.
[26 Jan 2009 15:55] Philip Stoev
This recovery failure was produced by running the following RQG command. Note that after applying the mask to the grammar, only REPLACE statements remain:

$ perl runall.pl \
  --mysqld=--falcon-page-size=2K \
  --vardir=/tmp/vardir \
  --rows=100 \
  --threads=4 \
  --mask=32 \
  --queries=1000000 \
  --duration=300 \
  --basedir=/build/bzr/6.0-falcon-team \
  --engine=Falcon \
  --grammar=conf/combinations.yy \
  --gendata=conf/combinations.zz \
  --reporter=Deadlock,ErrorLog,Backtrace,Recovery \
  --mysqld=--loose-falcon-lock-wait-timeout=1 \
  --mysqld=--log-output=none \
  --mysqld=--falcon-page-cache-size=64K

The low falcon-page-cache-size is used while the test is running, however recovery uses the default falcon-page-cache-size value.
[4 Feb 2009 9:53] Vladislav Vaintroub
Fixed with Bug#40946