Bug #39105 Assertion in sql_class.cc when backing up invalid merge table
Submitted: 28 Aug 2008 19:02 Modified: 24 Feb 2010 23:56
Reporter: Chuck Bell Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Backup Severity:S3 (Non-critical)
Version:6.0.7 OS:Any
Assigned to: Øystein Grøvlen CPU Architecture:Any
Triage: Triaged: D1 (Critical)

[28 Aug 2008 19:02] Chuck Bell
Description:
The server throws an assertion when restore_backup_open_tables_state() is called under the following conditons:

1) The 'use' command has been issued
2) A merge table is created whose base table(s) do not exist
3) Backup is attempted

Tracing the problem reveals the call to open_normal_and_derived_tables() in
sql_show.cc on line#3381 leaves the thd->open_tables set whereas is should be = 0. The return code for open_normal_and_derived_tables() is 1 which causes the code to enter this:

            if (res && thd->is_error() &&
                thd->main_da.sql_errno() == ER_NO_SUCH_TABLE)
            {
              /*
                Hide error for not existing table.
                This error can occur for example when we use
                where condition with db name and table name and this
                table does not exist.
              */
              res= 0;
              thd->clear_error();
            }

But the open_tables is still not cleared. So when the method restore_backup_open_tables_state() is called, the assertion in sql_class @ line#2862 is thrown.

How to repeat:
A sample test follows:

# Take out the 'use test' and test passes! Odd.
# Add the missing tables and the test passes.
use test;
DROP DATABASE IF EXISTS d3;
CREATE DATABASE d3;
CREATE TABLE d3.total (A INT NOT NULL AUTO_INCREMENT, MESSAGE CHAR(20), INDEX(A)) ENGINE=MERGE UNION=(t1,t2) INSERT_METHOD=LAST;
# Note that the following select will fail as expected.
#SELECT * FROM d3.total;
BACKUP DATABASE d1,d2,d3 TO 'd3.bak';

Suggested fix:
Correct error handling code in sql_class.cc to reset open_tables.
[28 Aug 2008 19:38] Valeriy Kravchuk
Thank you for a bug report. verified just as described with recent 6.0-bzr:

openxs@suse:/home2/openxs/dbs/6.0> bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 6.0.7-alpha-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> use test;
Database changed
mysql> DROP DATABASE IF EXISTS d3;
Query OK, 0 rows affected, 1 warning (0.07 sec)

mysql> CREATE DATABASE d3;
Query OK, 1 row affected (0.03 sec)

mysql> CREATE TABLE d3.total (A INT NOT NULL AUTO_INCREMENT, MESSAGE CHAR(20), INDEX(A))
    -> ENGINE=MERGE UNION=(t1,t2) INSERT_METHOD=LAST;
Query OK, 0 rows affected (0.10 sec)

mysql> SELECT * FROM d3.total;
ERROR 1146 (42S02): Table 'test.t2' doesn't exist
mysql> BACKUP DATABASE d3 TO 'd3.bak';
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 080803 17:01:03 mysqld_safe Number of processes running now: 0
080803 17:01:03 mysqld_safe mysqld restarted

mysql> exit
Bye
openxs@suse:/home2/openxs/dbs/6.0> tail -70 var/suse.err
080802  8:02:38  InnoDB: Shutdown completed; log sequence number 0 48117
080802  8:02:40 [Note] /home2/openxs/dbs/6.0/libexec/mysqld: Shutdown complete

080802 08:02:40 mysqld_safe mysqld from pid file /home2/openxs/dbs/6.0/var/suse.pid ended
080803 16:59:53 mysqld_safe Starting mysqld daemon with databases from /home2/openxs/dbs/6.0/var
080803 16:59:56  InnoDB: Started; log sequence number 0 48117
080803 16:59:59 [Note] Event Scheduler: Loaded 0 events
080803 16:59:59 [Note] /home2/openxs/dbs/6.0/libexec/mysqld: ready for connections.
Version: '6.0.7-alpha-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
080803 17:01:03 [Note] Backup: Starting backup process
080803 17:01:03 [Note] Backup: Backing up selected databases
mysqld: sql_class.cc:2864: void THD::restore_backup_open_tables_state(Open_tables_state*): Assertion `open_tables == 0 && temporary_tables == 0 && handler_tables == 0 && derived_tables == 0 && lock == 0 && locked_tables_mode == LTM_NONE && m_reprepare_observer == __null' failed.
/home2/openxs/dbs/6.0/libexec/mysqld(my_print_stacktrace+0x29)[0x88ec1f4]
/home2/openxs/dbs/6.0/libexec/mysqld(handle_segfault+0x271)[0x82ecf31]
[0xffffe420]
/lib/tls/libc.so.6(abort+0x1a5)[0x40180b75]
/lib/tls/libc.so.6(__assert_fail+0x103)[0x40178903]
/home2/openxs/dbs/6.0/libexec/mysqld(_ZN3THD32restore_backup_open_tables_stateEP17Open_tables_state+0xa2)[0x82db4a4]
/home2/openxs/dbs/6.0/libexec/mysqld(_Z14get_all_tablesP3THDP10TABLE_LISTP4Item+0x9f8)[0x8450f64]
/home2/openxs/dbs/6.0/libexec/mysqld(_ZN22_GLOBAL__N_DDL_blocker17open_schema_tableEP3THDP15st_schema_tableP4ListI19st_mysql_lex_stringE+0x11d)[0x84cf71b]
/home2/openxs/dbs/6.0/libexec/mysqld(_ZN3obs25InformationSchemaIterator16prepare_is_tableEP3THDPP8st_tablePP7handlerPPj18enum_schema_tables4ListI19st_mysql_lex_stringE+0xb3)[0x84cfba1]
/home2/openxs/dbs/6.0/libexec/mysqld(_ZN3obs18create_is_iteratorINS_16DbTablesIteratorEEEPT_P3THD18enum_schema_tablesPK6String+0xbe)[0x84d437e]
/home2/openxs/dbs/6.0/libexec/mysqld(_ZN3obs13get_db_tablesEP3THDPK6String+0x20)[0x84d0c34]
/home2/openxs/dbs/6.0/libexec/mysqld(_ZN11Backup_info12add_db_itemsERN6backup10Image_info2DbE+0x39)[0x899972d]
/home2/openxs/dbs/6.0/libexec/mysqld(_ZN11Backup_info7add_dbsER4ListI19st_mysql_lex_stringE+0x163)[0x899937b]
/home2/openxs/dbs/6.0/libexec/mysqld(_Z22execute_backup_commandP3THDP6st_lexP6String+0x2fb)[0x8980ae5]
/home2/openxs/dbs/6.0/libexec/mysqld(_Z21mysql_execute_commandP3THD+0xa27)[0x82fdfdd]
/home2/openxs/dbs/6.0/libexec/mysqld(_Z11mysql_parseP3THDPKcjPS2_+0x1d0)[0x83076a6]
/home2/openxs/dbs/6.0/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x871)[0x82fbceb]
/home2/openxs/dbs/6.0/libexec/mysqld(_Z10do_commandP3THD+0x229)[0x82fb271]
/home2/openxs/dbs/6.0/libexec/mysqld(handle_one_connection+0x125)[0x82f897d]
/lib/tls/libpthread.so.0[0x40050aa7]
/lib/tls/libc.so.6(__clone+0x5e)[0x40211c2e]
080803 17:01:03 - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=8388572
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 337793 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x9b27e48
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x47ebf430 thread_stack 0x30000
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x9b7ef70 = BACKUP DATABASE d3 TO 'd3.bak'
thd->thread_id=1
thd->killed=NOT_KILLED
...
[10 Nov 2008 9:43] Øystein Grøvlen
Verified that this fails on current head of backup team tree.
I got the following stack trace:

...

#11 0xfeba17f3 in _assert () from /lib/libc.so.1
#12 0x08279064 in THD::restore_backup_open_tables_state (this=0xc02dde0,
    backup=0x0) at sql_class.cc:2875
#13 0x083b5e53 in get_all_tables (thd=0xc02dde0, tables=0xfde89e50,
    cond=0xc05f050) at sql_show.cc:3460
#14 0x084252b5 in (anonymous namespace)::open_schema_table (thd=0xc02dde0,
    st=0x89ecfe8, db_list=0xfde8a0f0) at si_objects.cc:327
#15 0x084256f8 in obs::InformationSchemaIterator::prepare_is_table (
    thd=0xc02dde0, is_table=0xfde8a0dc, ha=0xfde8a0e0,
    orig_columns=0xfde8a0e4, is_table_idx=SCH_CHARSETS, db_list=Cannot access memory at address 0x0
)    at si_objects.cc:1276
#16 0x08831708 in obs::create_is_iterator<obs::DbTablesIterator> (
    thd=0xc02dde0, is_table_idx=SCH_CHARSETS, db_name=0xc052120)
    at sql_list.h:114
#17 0x084270b8 in obs::get_db_tables (thd=0x0, db_name=0x0)
    at si_objects.cc:1884
#18 0x087efeb7 in Backup_info::add_db_items (this=0xc07de88, db=@0xc052118)
    at ../../sql/backup/api_types.h:79
#19 0x087efb58 in Backup_info::add_dbs (this=0xc07de88, dbs=@0x0)
    at backup_info.cc:575
#20 0x087deaba in execute_backup_command (thd=0xc02dde0, lex=0xc02eed8,
    backupdir=0xfde8a5f0) at kernel.cc:188
#21 0x08294ac2 in mysql_execute_command (thd=0xc02dde0) at sql_parse.cc:2324
#22 0x0829cffe in mysql_parse (thd=0xc02dde0,
    inBuf=0xc05d368 "BACKUP DATABASE d3 TO 'd3.bak'", length=30,
    found_semicolon=0xfde8aaa0) at sql_parse.cc:5722
#23 0x082922b7 in dispatch_command (command=COM_QUERY, thd=0xc02dde0,
    packet=0xc04deb1 "BACKUP DATABASE d3 TO 'd3.bak'", packet_length=30)
    at sql_parse.cc:1009
#24 0x08291873 in do_command (thd=0xc02dde0) at sql_parse.cc:689
#25 0x082906dd in handle_one_connection (arg=0x0) at sql_connect.cc:1156
[16 Dec 2008 10:47] Øystein Grøvlen
With the new object service API, I do not get the same error anymore.  I executed the following test script:

use test;
DROP DATABASE IF EXISTS d3;
CREATE DATABASE d3;
CREATE TABLE d3.total (A INT NOT NULL AUTO_INCREMENT, MESSAGE CHAR(20), INDEX(A))
ENGINE=MERGE UNION=(t1,t2) INSERT_METHOD=LAST;
BACKUP DATABASE d3 TO 'd3.bak';

I now get the following error:
mysqltest: At line 8: query 'BACKUP DATABASE d3 TO 'd3.bak'' failed: 1708: Failed to obtain meta-data for table `d3`.`total`
[17 Dec 2008 10:27] 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/61848

2740 Oystein Grovlen	2008-12-17
      Bug#39105 Assertion in sql_class.cc when backing up invalid merge table
      
      Assertion no longer happens after new version of object service API
      was introduced, but error message could be improved so users are
      informed about what is actually wrong.  (That base tables are
      missing.)
      
      More information is made available by having the service interface
      copy its warnings to the THD error stack.  Main error message is still
      the same, but more information is now found on the error stack.
[2 Mar 2009 8:30] Rafal Somla
I think this bug is in a state where Oystein consults runtime team for approval of the design.
[15 Sep 2009 14:40] 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/83292

2869 Oystein Grovlen	2009-09-15
      Bug#39105 Assertion in sql_class.cc when backing up invalid merge table
        (Updated to head of backup branch)
            
      Assertion no longer happens after new version of object service API
      was introduced, but error message could be improved so users are
      informed about what is actually wrong.  (That base tables are
      missing.)
            
      More information is made available by having the service interface
      copy its warnings to the THD error stack.  Main error message is still
      the same, but more information is now found on the error stack.
     @ mysql-test/suite/backup/r/backup_nodata_driver.result
        Updated result file
     @ mysql-test/suite/backup/t/backup_nodata_driver.test
        Add test case for Bug#39105
     @ sql/si_objects.cc
        More information about errors are made available by having the service interface
        copy its warnings to the THD error stack.  Main error message is still the same, 
        but more information is now found on the error stack.
[15 Sep 2009 14:49] Øystein Grøvlen
The following responses was received on the committed version of the patch:

kostja:
Better yet, add Ed_connection::set_option(option_preserve_warnings);

alik:
if I look at the right patch, you're adding a new flag to run_service_interface_sql() and going to call copy_warnings() if it is set.

That solution is Ok, but I think, introducing something like Ed_connection::set_preserve_warnings(bool) is better: Ed_connection is doing an extra job to store warnings separately. So, basically, firstly you intentionally store things in one place, then you copy them to another place. It seems better to store things in the right place initially.

Anyway, I'm fine with employing copy_warnings() -- the patch can be treated as a "hot/small fix". Later we can do some refactoring and get rid of copy_warnings(). I'd like to make it happen now, but I don't insist.

Talking about run_service_interface_sql() parameter:

  1. if we add the parameter the could will look like:

bool run_service_interface_sql(...)
{
   ...
   bool preserve_warnings_save= ed_connection.get_preserve_warnings();
   ed_connection.set_preserve_warnings(preserve_warnings);
   ed_connection.execute_direct(...);
   ed_connection.set_preserve_warnings(preserve_warnings_save);
   ...
}

  // In this case we have to save the original value and restore it,
  // because it's better to avoid side effects in an operation.

<some operation calling run_service_interface_sql()>
{
    Ed_connection ed_connection(thd);
    ...
    if (run_service_interface_sql(thd, &ed_connection, sql_lex_string,
        TRUE))
    ...
}

  // Personally, I hate those "f(TRUE, FALSE, TRUE)" calls.
  // It's not clear what actually happens here.
  // It's better to have something like:
  //   f(PreserveWarnings, KeepHandsOut, SaveOnExit)

  2. if we set it outside run_service_interface_sql():

<some operation calling run_service_interface_sql()>
{
    Ed_connection ed_connection(thd);
    ...
    ed_connection.set_preserve_warnings(TRUE);
    if (run_service_interface_sql(thd, &ed_connection, sql_lex_string))
    ...
}

  // In this case we don't have neither to save original value,
  // nor to restore it. Also, we don't have "TRUE" in a function call.

  3. Another idea occurred to me: we can create SI_connection derived
  from Ed_connection, and encapsulate all the logic from
  run_service_interface_sql() in SI_connection::execute_direct().
  Then we would have something like:

<some operation calling "run_service_interface_sql()">
{
    SI_connection si_connection(thd);
    ...
    if (si_connection.execute_direct(sql_lex_string))
    ...
}

  I would go this way.
[16 Sep 2009 5:59] Rafal Somla
Good to push.
[9 Oct 2009 13:04] 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/86351

2880 Oystein Grovlen	2009-10-09
      Bug#39105 Assertion in sql_class.cc when backing up invalid merge table
        (Updated to head of backup branch)
            
      Assertion no longer happens after new version of object service API
      was introduced, but error message could be improved so users are
      informed about what is actually wrong.  (That base tables are
      missing.)
            
      More information is made available by having the service interface
      copy its warnings to the THD error stack.  Main error message is still
      the same, but more information is now found on the error stack.
     @ mysql-test/suite/backup/r/backup_nodata_driver.result
        Updated result file
     @ mysql-test/suite/backup/r/backup_security.result
        Change gives one additional, and more informative error message
     @ mysql-test/suite/backup/t/backup_nodata_driver.test
        Add test case for Bug#39105
     @ mysql-test/suite/backup_engines/r/backup_interruption.result
        Updated result file to reflect changes to error reporting caused by this file.
     @ sql/si_objects.cc
        More information about errors are made available by having the service interface
        copy its warnings to the THD error stack.  Main error message is still the same, 
        but more information is now found on the error stack.
[9 Oct 2009 13:16] Øystein Grøvlen
Patch pushed:
revid:oystein.grovlen@sun.com-20091009130356-dxa7demdwm0yn21j
[20 Feb 2010 9:17] Bugs System
Pushed into 6.0.14-alpha (revid:ingo.struewing@sun.com-20100218152520-s4v1ld76bif06eqn) (version source revid:ingo.struewing@sun.com-20100119103538-wtp5alpz4p2jayl5) (merge vers: 6.0.14-alpha) (pib:16)
[24 Feb 2010 23:56] Paul Dubois
Noted in 6.0.14 changelog.

BACKUP DATABASE could crash attempting to back up an invalid MERGE
table.