Bug #42725 Exception when filling I_S.TABLESPACES by Falcon (backup.backup_timeout failure)
Submitted: 10 Feb 2009 9:30 Modified: 15 May 2009 15:58
Reporter: Rafal Somla Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:6.0 OS:Any
Assigned to: Christopher Powers
Tags: F_ERROR HANDLING, pushbuild, server crash, sporadic, Tablespace, test failure, widespread
Triage: Triaged: D1 (Critical)

[10 Feb 2009 9:30] Rafal Somla
Description:
A server crash due to unexpected exception has been observed in PB for main 6.0 tree on debx86-b platform.

The stack trace is shown below. This is what happens:

1. BACKUP DATABASE bup_ddl_blocker TO "bup_ddl_blocker.bak" is being executed.

2. When filling backup catalogue, function obs::find_tablespace_for_table() is called (this is part of object services API).

3. This function internally executes select on I_S.TABLESPACES table:

SELECT t1.tablespace_name, t1.engine, t1.tablespace_comment, t2.file_name FROM INFORMATION_SCHEMA.TABLESPACES AS t1, INFORMATION_SCHEMA.FILES AS t2, INFORMATION_SCHEMA.TABLES AS t3 WHERE t1.tablespace"...

4. When processing the SELECT, control is passed to Falcon code: 

#15 0x085d027a in StorageInterface::fill_is_table (hton=0x97c6e70,
    thd=0x9efc678, tables=0xa0d0208, cond=0x0,
    schema_table_idx=SCH_TABLESPACES) at ha_falcon.cpp:2305

5. eventually ResultSet::next method is called which throws exception in this place:

bool ResultSet::next()
{
	if (!statement)
		throw SQLEXCEPTION (RUNTIME_ERROR, "ResultSet has been closed");
...

Exception is thrown because this->statement is NULL (checked with gdb).

6. The std::set_unexpected() call suggests that the exception, which was passed up the call stack, reached a function which declares a list of allowable exceptions with "throw()" declaration and this declaration does not include SQLEXCEPTION.

How to repeat:
Look at this PB page, debx86-b platform:

https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0&order=123
[10 Feb 2009 9:31] Rafal Somla
Stack trace from the crash.

#3  <signal handler called>
#4  0x401bd947 in raise () from /lib/tls/libc.so.6
#5  0x401bf0c9 in abort () from /lib/tls/libc.so.6
#6  0x400e9994 in __gnu_cxx::__verbose_terminate_handler ()
   from /usr/lib/libstdc++.so.6
#7  0x400e73b5 in std::set_unexpected () from /usr/lib/libstdc++.so.6
#8  0x400e73f2 in std::terminate () from /usr/lib/libstdc++.so.6
#9  0x400e752a in __cxa_throw () from /usr/lib/libstdc++.so.6
#10 0x0867e288 in ResultSet::next (this=0x40e1b8d0) at ResultSet.cpp:127
#11 0x085f848c in TableSpaceManager::getTableSpaceInfo (this=0x40dadeb0,
    infoTable=0x4d625610) at TableSpaceManager.cpp:476
#12 0x08625a98 in Database::getTableSpaceInfo (this=0x40bab640,
    infoTable=0x4d625610) at Database.cpp:2387
#13 0x085da27e in StorageDatabase::getTableSpaceInfo (this=0x40dac158,
    infoTable=0x4d625610) at StorageDatabase.cpp:1260
#14 0x085de393 in StorageHandler::getTableSpaceInfo (this=0x40bab028,
    infoTable=0x4d625610) at StorageHandler.cpp:957
#15 0x085d027a in StorageInterface::fill_is_table (hton=0x97c6e70,
    thd=0x9efc678, tables=0xa0d0208, cond=0x0,
    schema_table_idx=SCH_TABLESPACES) at ha_falcon.cpp:2305
#16 0x08479f5b in run_hton_fill_schema_table (thd=0x9efc678,
    plugin=0x4d6256fc, arg=0x4d625740) at sql_show.cc:6489
#17 0x084f9332 in plugin_foreach_with_mask (thd=0x9efc678,
    func=0x8479ef2 <run_hton_fill_schema_table>, type=1,
    state_mask=4294967287, arg=0x4d625740) at sql_plugin.cc:1819
#18 0x0847c4dd in hton_fill_schema_table (thd=0x9efc678, tables=0xa0d0208,
    cond=0x0) at sql_show.cc:6501
#19 0x0847c9ae in get_schema_tables_result (join=0xa0b3738,
    executed_place=PROCESSED_BY_JOIN_EXEC) at sql_show.cc:6458
#20 0x083a9f22 in JOIN::exec (this=0xa0b3738) at sql_select.cc:2394
#21 0x083a64e1 in mysql_select (thd=0x9efc678, rref_pointer_array=0xa0cf6b8,
    tables=0xa0d0208, wild_num=0, fields=@0xa0cf648, conds=0xa050478,
    og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
    select_options=2684635648, result=0xa0e2e70, unit=0xa0cf31c,
    select_lex=0xa0cf5b4) at sql_select.cc:3058
#22 0x083abd22 in handle_select (thd=0x9efc678, lex=0xa0cf2c0,
    result=0xa0e2e70, setup_tables_done_option=0) at sql_select.cc:315
#23 0x083102af in execute_sqlcom_select (thd=0x9efc678, all_tables=0xa0d0208)
    at sql_parse.cc:4756
#24 0x083112da in mysql_execute_command (thd=0x9efc678) at sql_parse.cc:2063
#25 0x083beae6 in Execute_sql_statement::execute_server_code (
    this=0x4d626bf8, thd=0x9efc678) at sql_prepare.cc:2946
#26 0x083bc195 in Prepared_statement::execute_server_runnable (
    this=0x4d6268ac, server_runnable=0x4d626bf8) at sql_prepare.cc:3426
#27 0x083c0064 in Ed_connection::execute_direct (this=0x4d626ca0,
    server_runnable=0x4d626bf8) at sql_prepare.cc:3957
#28 0x083c0134 in Ed_connection::execute_direct (this=0x4d626ca0, sql_text=
      {str = 0xa005840 "SELECT t1.tablespace_name, t1.engine, t1.tablespace_comment, t2.file_name FROM INFORMATION_SCHEMA.TABLESPACES AS t1, INFORMATION_SCHEMA.FILES AS t2, INFORMATION_SCHEMA.TABLES AS t3 WHERE t1.tablespace"..., length = 335}) at sql_prepare.cc:3923
#29 0x08508ab8 in (anonymous namespace)::run_service_interface_sql (
    thd=0x9efc678, ed_connection=0x4d626ca0, query=0x4d626f30)
    at si_objects.cc:192
#30 0x0850911f in obs::find_tablespace_for_table (thd=0x9efc678,
    db_name=0xa071b68, table_name=0xa071bd8) at si_objects.cc:2776
#31 0x08a29722 in Backup_info::add_db_items (this=0xa0028c0, db=@0xa071b60)
    at backup_info.cc:813
#32 0x08a29f55 in Backup_info::add_dbs (this=0xa0028c0, thd=0x9efc678,
    dbs=@0x9efdbc0) at backup_info.cc:654
#33 0x08a14b3b in execute_backup_command (thd=0x9efc678, lex=0x9efd5a8,
    backupdir=0x4d627894, overwrite=false) at kernel.cc:184
#34 0x08311ba1 in mysql_execute_command (thd=0x9efc678) at sql_parse.cc:2347
#35 0x08319a09 in mysql_parse (thd=0x9efc678,
    inBuf=0x9f1ae68 "BACKUP DATABASE bup_ddl_blocker TO \"bup_ddl_blocker.bak\"", length=56, found_semicolon=0x4d627f20) at sql_parse.cc:5751
[19 Feb 2009 17:15] Kevin Lewis
Chris, Vlad suggests that this may be similar to Bug#42830.  These bugs may be seen now because the scavenger is running more often.  Please investigate whether the scavenger needs to coordinate access to ResultSets before clearing them.
[23 Feb 2009 20:17] 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/67254

3032 Christopher Powers	2009-02-23
      Bug#42725 "Exception when filling I_S.TABLESPACES by Falcon"
      Bug#42830 "Falcon Exception: ResultSet has been closed after recovery"
      
      The exception occurs because the system transaction is committed
      while the result set is being accessed. The commit closes the
      statement and clears the associated result sets.
      
      To prevent this, the tablespace getinfo methods now get a
      shared lock on syncSysDDL before executing queries.
      
      Database::openDatabase also gets a shared lock on syncSysDDL
      prior to executing query and processing the result set. Note that
      this issue was indirectly addressed by disabling scavenging during
      recovery: http://lists.mysql.com/commits/66823.
[23 Feb 2009 22:47] 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/67268

3034 Christopher Powers	2009-02-23
      Bug#42725 "Exception when filling I_S.TABLESPACES by Falcon"
      Bug#42830 "Falcon Exception: ResultSet has been closed after recovery"
      
      Missed a spot: SequenceManager::initialize()
[23 Feb 2009 23:03] Kevin Lewis
Patch looks good.  OK to push.
[2 Mar 2009 14:12] Bugs System
Pushed into 6.0.11-alpha (revid:alik@sun.com-20090302140208-lfdejjbcyezlhhjt) (version source revid:olav@sun.com-20090224081308-fcszc3gg5r9gykao) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 15:58] MC Brown
An entry has been added to the 6.0.11 changelog: 

When Falcon is populating the INFORMATION_SCHEMA.TABLESPACES table, an exception can be raised because required result set has been closed before the resultset has been completed. This can happen during a BACKUP operation.