MySQL Bugs: #4047: mysqldump loses connection on InnoDB tables

Bug #4047	mysqldump loses connection on InnoDB tables
Submitted:	8 Jun 2004 0:03	Modified:	29 Sep 2004 11:38
Reporter:	Dean Ellis	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: mysqldump Command-line Client	Severity:	S2 (Serious)
Version:	4.1.3	OS:	Linux (Linux)
Assigned to:	Assigned Account	CPU Architecture:	Any

Description:
mysqldump loses connection to server when dumping InnoDB tables, reporting:

mysqldump: Can't get CREATE TABLE for table `t1` (Lost connection to MySQL server during query)

SHOW CREATE TABLE within mysql client works.

How to repeat:
USE test;
DROP TABLE IF EXISTS t1;
CREATE TABLE t1 ( a int ) ENGINE=InnoDB;

mysqldump test t1

Suggested fix:
n/a

Dean,

I assume that the mysqld server does not crash? Then it is a client problem.

Regards,

Heikki

Hi!

I was able to repeat this with 4.1.3 on Linux, and mysqld does crash.

The bug is a result of the improvement I made recently to ::start_stmt() in ha_innodb.cc. In 4.0, mysqldump seems to internally use TL_READ_NO_INSERT, or a similar non-TL_READ mode, while in 4.1 it uses TL_READ. The code that stores the old select_lock_type in ::start_stmt() does not work because the claim below does not hold.

"
                /* When we first come here after LOCK TABLES,
                select_lock_type is set to LOCK_S or LOCK_X. Store the value
                in case we run also consistent reads and need to restore the
                value later. */

                if (prebuilt->select_lock_type != LOCK_NONE) {
                        prebuilt->stored_select_lock_type =
                                        prebuilt->select_lock_type;
                }

                if (prebuilt->stored_select_lock_type != LOCK_S
                    && prebuilt->stored_select_lock_type != LOCK_X) {
                        fprintf(stderr,
"InnoDB: Error: select_lock_type is %lu inside ::start_stmt()!\n",
                        prebuilt->stored_select_lock_type);

                        ut_error;
                }
"

I have now fixed the bug by removing the improvement from 4.1.

Still open questions: should we backport the bug fix to 4.0? Can we somehow fix the improvement so that we still would be able to remember the original select_lock_type, and put it back after a consistent read performed inside LOCK TABLES?

Regards,

Heikki

(gdb) run
Starting program: /home/heikki/mysql-4.1/sql/mysqld
[New Thread 16384 (LWP 26102)]
040608  9:17:39  Warning: You have enabled the binary log, but you haven't set s
erver-id to a non-zero value: we force server id to 1; updates will be logged to
 the binary log, but connections from slaves will not be accepted.
[New Thread 32769 (LWP 26104)]
[New Thread 16386 (LWP 26105)]
[New Thread 32771 (LWP 26106)]
[New Thread 49156 (LWP 26107)]
[New Thread 65541 (LWP 26108)]
040608  9:17:40  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
040608  9:17:40  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 0 1904263765.
InnoDB: Doing recovery: scanned up to log sequence number 0 1904263765
InnoDB: Last MySQL binlog file position 0 680048, file name ./binlog.000009
040608  9:17:40  InnoDB: Flushing modified pages from the buffer pool...
[New Thread 81926 (LWP 26109)]
[New Thread 98311 (LWP 26110)]
[New Thread 114696 (LWP 26111)]
040608  9:17:40  InnoDB: Started; log sequence number 0 1904263765
[New Thread 131081 (LWP 26112)]
040608  9:17:40  mysql.user table is not updated to new password format; Disabli
ng new password usage until mysql_fix_privilege_tables is run
/home/heikki/mysql-4.1/sql/mysqld: ready for connections.
Version: '4.1.3-beta-debug-log'  socket: '/home/heikki/bugsocket'  port: 3307
[New Thread 147466 (LWP 26155)]
InnoDB: Error: select_lock_type is 99999999 inside ::start_stmt()!
040608  9:18:20InnoDB: Assertion failure in thread 147466 in file ha_innodb.cc l
ine 4682
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. See section 6.1 of
InnoDB: http://www.innodb.com/ibman.php about forcing recovery.

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 147466 (LWP 26155)]
0x081f8596 in ha_innobase::start_stmt(THD*) (this=0x85d8380, thd=0x85db380)
    at ha_innodb.cc:4682
4682                            ut_error;
(gdb) bt
#0  0x081f8596 in ha_innobase::start_stmt(THD*) (this=0x85d8380, thd=0x85db380)
    at ha_innodb.cc:4682
#1  0x08192818 in check_lock_and_start_stmt (thd=0x16b, table=0x85e4d60,
    lock_type=TL_UNLOCK) at sql_base.cc:1549
#2  0x0819296a in open_ltable(THD*, st_table_list*, thr_lock_type) (
    thd=0x85db380, table_list=0x85e9990, lock_type=TL_UNLOCK)
    at sql_base.cc:1602
#3  0x0820bc7e in mysqld_show_create(THD*, st_table_list*) (thd=0x85db380,
    table_list=0x85e9990) at sql_show.cc:800
#4  0x081722e6 in mysql_execute_command(THD*) (thd=0x85db380)
    at sql_parse.cc:2443
#5  0x08176251 in mysql_parse(THD*, char*, unsigned) (thd=0x85db380,
    inBuf=0x85e9930 "show create table `alex1`", length=140358544)
    at sql_parse.cc:3926
#6  0x0816fa13 in dispatch_command(enum_server_command, THD*, char*, unsigned)
    (command=COM_QUERY, thd=0x85db380,
    packet=0x85e0761 "show create table `alex1`", packet_length=26)
    at sql_parse.cc:1457
#7  0x0816f31d in do_command(THD*) (thd=0x85db380) at sql_parse.cc:1272
#8  0x0816e7de in handle_one_connection (arg=0x0) at sql_parse.cc:1016
#9  0x40053f60 in pthread_start_thread () from /lib/i686/libpthread.so.0
#10 0x400540fe in pthread_start_thread_event () from /lib/i686/libpthread.so.0
#11 0x401f5327 in clone () from /lib/i686/libc.so.6
(gdb) frame 1
#1  0x08192818 in check_lock_and_start_stmt (thd=0x16b, table=0x85e4d60,
    lock_type=TL_UNLOCK) at sql_base.cc:1549
1549      if ((error=table->file->start_stmt(thd)))
(gdb) list
1544        my_printf_error(ER_TABLE_NOT_LOCKED_FOR_WRITE,
1545                        ER(ER_TABLE_NOT_LOCKED_FOR_WRITE),
1546                        MYF(0),table->table_name);
1547        DBUG_RETURN(1);
1548      }
1549      if ((error=table->file->start_stmt(thd)))
1550      {
1551        table->file->print_error(error,MYF(0));
1552        DBUG_RETURN(1);
1553      }
(gdb) list 1500
1495                }
1496                else
1497                {
1498                  *prev_table= tmp->table;          // Relink open list
1499                  prev_table= &tmp->table->next;
1500                }
1501              }
1502            }
1503            *prev_table=0;
1504            pthread_mutex_unlock(&LOCK_open);

Hi!

I have now fixed this bug and other similar LOCK TABLES + mysqldump bugs in 4.0.22.

This specific bug was probably fixed already in 4.0.21.

I still have to port the bug fixes to 4.1.5.

Regards,

Heikki

I got this crash with 4.0.21 using the official MySQL RPMS on RHEL 3.0U2. The command I believe triggered it is a regularly schedule mysqldump.

mysqldump -A -a --opt -uroot -p ...

root@auratus: /root >rpm -qa |grep MySQL
MySQL-server-4.0.21-0
MySQL-shared-4.0.21-0
MySQL-client-4.0.21-0
MySQL-devel-4.0.21-0
MySQL-shared-compat-4.0.21-0
MySQL-Max-4.0.21-0

/usr/sbin/mysqld-max: ready for connections.
Version: '4.0.21-Max-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 Official MySQL RPM
InnoDB: Error: select_lock_type is 99999999 inside ::start_stmt()!
040922 11:41:52InnoDB: Assertion failure in thread 2862439344 in file ha_innodb.cc line 4581
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. See section 6.1 of
InnoDB: http://www.innodb.com/ibman.php about forcing recovery.
mysqld got signal 11;
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=67108864
read_buffer_size=131072
max_used_connections=0
max_connections=100
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 129535 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x87c7188
InnoDB: Thread 2990828464 stopped in file ut0mem.c line 163
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...
Cannot determine thread, fp=0xaa9d4eec, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x80db854
0xb75b6d28
0xaa9d52bc
0x80fb310
0x814db24
0x80e7b63
0x80ea5e5
0x80e5d23
0x80e576e
0x80e4f98
0xb75b0dec
0xb74dce8a
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://www.mysql.com/doc/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x87de7a8 = show create table `client`
thd->thread_id=1
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.

Number of processes running now: 0
040922 11:41:52 mysqld restarted
...

This is a very serious bug and one that should never have slipped into so-called "stable" release code.

We just converted one entire database to Innodb and I just lost the whole thing and needed to restore from the hourly backup. When we checked we found this bug had made all of our backups since the conversion non-functional. We are using Fedora Core2 for x86_64 and had planned on standardizing on MySQL and Innodb tables. This incident puts that decision on hold. The "stable" versions of MySQL obviously aren't :-(

Hi!

I agree that this is the most serious bug that has slipped into the stable InnoDB-4.0 this year. The modification was itself a bug fix, that is how it got in the stable branch. Fortunately, the workaround is simple, and actually --quick --single-transaction is the most consistent way of dumping InnoDB tables. Normally, you should not use the -l option at all for InnoDB tables.

Regards,

Heikki

Changes in release 4.0.22 (not released yet)

InnoDB: Fixed a bug introduced in 4.0.21. An assertion failed if one used mysqldump with the option -l or --opt, or if one used LOCK TABLES ... LOCAL. (Workaround in 4.0.21: use --quick and --single-transaction. (Bug #5538)