MySQL Bugs: #43384: Falcon silently doing something for a long time during startup

Bug #43384	Falcon silently doing something for a long time during startup
Submitted:	4 Mar 2009 16:57	Modified:	10 Mar 2009 12:24
Reporter:	Sergey Petrunya	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S3 (Non-critical)
Version:		OS:	Any
Assigned to:	Sergey Petrunya	CPU Architecture:	Any
Tags:	F_MEMORY

Description:
I have some tables created in Falcon - testcases from BUG#41890 and its sub-bugs, and maybe a couple more small tables (less than 1K records each, no blobs).  I'm not using the Falcon tables. However, when I start the server it looks like it hangs for noticeable amount of time. CPU usage during the hang is about 20%. 

If I start the server under gdb, I see it's doing something in Falcon: 

  #0  0xb7cba837 in memset () from /lib/libc.so.6
  #1  0x086495ed in MemMgr::allocateDebug (this=0x8d98000, size=134221824, fileName=0x8b9ce22 "Cache.cpp", line=121) at MemMgr.cpp:567
  #2  0x0864a6e1 in MemMgrAllocateDebug (s=134221824, file=0x8b9ce22 "Cache.cpp", line=121) at MemMgr.cpp:133
  #3  0x0873abba in Cache (this=0xb6848948, db=0xb6a49640, pageSz=4096, hashSz=32000, numBuffers=64000) at MemoryManager.h:62
  #4  0x086a18f9 in Dbb::init (this=0xb6a4a140, pageSz=4096, cacheSize=64000) at Dbb.cpp:182
  #5  0x086a2496 in Dbb::open (this=0xb6a4a140, fileName=0xbf942a30 "/usr/local/mysql/var/falcon_master.fts", cacheSize=262144000, transId=0) at Dbb.cpp:509
  #6  0x08698a84 in Database::openDatabase (this=0xb6a49640, filename=0xbf942a30 "/usr/local/mysql/var/falcon_master.fts") at Database.cpp:719
  #7  0x0868c08f in Connection::getDatabase (this=0xb6848548, dbName=0xb684825c "FALCON_MASTER", dbFileName=0xbf942a30 "/usr/local/mysql/var/falcon_master.fts", threads=0xb68482b8) at Connection.cpp:1650
  #8  0x0868d5a0 in Connection::openDatabase (this=0xb6848548, dbName=0xb684825c "FALCON_MASTER", filename=0xb684828c "falcon_master.fts", account=0x8b8436c "mysql", password=0x8b8436c "mysql", address=0x0, parent=0xb68482b8) at Connection.cpp:933
  #9  0x08651298 in StorageDatabase::getOpenConnection (this=0xb6848158) at StorageDatabase.cpp:136
  #10 0x086539bb in StorageHandler::initialize (this=0xb6a49028) at StorageHandler.cpp:987
  #11 0x08644c40 in StorageInterface::falcon_init (p=0x97df510) at ha_falcon.cpp:257
  #12 0x084adb2d in ha_initialize_handlerton (plugin=0x97ce0c0) at handler.cc:448
  #13 0x0856432c in plugin_initialize (plugin=0x97ce0c0) at sql_plugin.cc:1008
  #14 0x08565830 in plugin_init (argc=0x8d8b13c, argv=0x9783d18, flags=0) at sql_plugin.cc:1220
  #15 0x083659cb in init_server_components () at mysqld.cc:4136
  #16 0x0836699a in main (argc=3, argv=0xbf9431b4) at mysqld.cc:4649
(gdb) 

My problem with this has two parts:

1. What exactly is it doing for soo long when I have a rather small database:
spetrunia@pslp2 ~ $ ls -lah /usr/local/mysql/var | grep falcon
-rw-rw----  1 spetrunia spetrunia  75K Mar  3 17:19 falcon_master.fl1
-rw-rw----  1 spetrunia spetrunia 8.0K Mar  2 18:08 falcon_master.fl2
-rw-rw----  1 spetrunia spetrunia 456K Mar  3 17:15 falcon_master.fts
-rw-rw----  1 spetrunia spetrunia  16K Mar  2 18:08 falcon_temporary.fts
-rw-rw----  1 spetrunia spetrunia  16K Mar  2 18:08 falcon_user.fts

? This startup takes nearly as much as NDB storage node startup.
 
2. If it's really a necessary lengthy process, Falcon code should indicate that in stderr and print there messages indicating the progress, just like InnoDB does when it figures it needs to do some lengthy recovery.

How to repeat:
Start recent 6.0, debug build.
Load some data into Falcon tables
Stop the server
Start the server.
Compare start/stop time to that of when the server is compiled w/o Falcon.

Thank you for the bug report. Verified on Windows x64.

Sergey,  The call stack indicates that Falcon was doing this;

	cache = new Cache (database, pageSize, cacheSize / 2, cacheSize);

For about a month now, Falcon has had a default page cache size of 250 Mb.  It is now back to the 4 Mb size that it was previous.  Please check if this is still a problem.

> Kevin wrote;
> Falcon increased its default page cache size from 4Mb to 250Mb a month ago but did not add any code to make it start low and grow to to that limit.  This has caused problems on pushbuild machines that have limited memory and that run several virtual machines at a time.  Falcon should never be run with only 4 Mb of page cache so this change was logical.  But it obviously does not play well with other users of 6.0 which includes the Falcon engine by default.

> We are sorry for the inconvenience this has caused any non-Falcon users of 6.0.  It has already been changed back to 4 Mb in the main tree, mysql-6.0, but I believe that the higher default value is in the 6.0.10 clone-off.