InnoDB: Assertion failure in thread 140616411674384 in file dict/dict0dict.c line 1821

[Dave Juntgen]

I think this issue may have to with the innodb_lazy_drop_table flag.

InnoDB: Error: Waited for 5 secs for hash index ref_count (12) to drop to 0.
index: "PRIMARY" table: "webchart_pepperson/variable_tree"
InnoDB: Error: Waited for 10 secs for hash index ref_count (12) to drop to 0.
index: "PRIMARY" table: "webchart_pepperson/variable_tree"

[...]

InnoDB: Error: Waited for 595 secs for hash index ref_count (12) to drop to 0.
index: "PRIMARY" table: "webchart_pepperson/variable_tree"
InnoDB: Error: Waited for 600 secs for hash index ref_count (12) to drop to 0.
index: "PRIMARY" table: "webchart_pepperson/variable_tree"
110615 18:54:11 InnoDB: Assertion failure in thread 140616411674384 in file dict/dict0dict.c line 1821
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. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
110615 18:54:11 - 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=4294967296
read_buffer_size=131072
max_used_connections=15
max_threads=100
threads_connected=32
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4412991 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0xbbe22d0
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 = 0x7fe3cf446e98 thread_stack 0x40000
/usr/local/mysql/libexec/mysqld(my_print_stacktrace+0x39)[0x87a309]
/usr/local/mysql/libexec/mysqld(handle_segfault+0x34e)[0x5ae1ee]
/lib64/libpthread.so.0(+0xf0f0)[0x7fe3d181d0f0]
/lib64/libc.so.6(gsignal+0x35)[0x7fe3d09e76c5]
/lib64/libc.so.6(abort+0x175)[0x7fe3d09e8ea5]
/usr/local/mysql/libexec/mysqld[0x7e7d6c]
/usr/local/mysql/libexec/mysqld[0x7ed00a]
/usr/local/mysql/libexec/mysqld[0x774c29]
/usr/local/mysql/libexec/mysqld[0x71af3d]
/usr/local/mysql/libexec/mysqld(_Z15ha_delete_tableP3THDP10handlertonPKcS4_S4_b+0xd4)[0x691994]
/usr/local/mysql/libexec/mysqld(_Z20mysql_rm_table_part2P3THDP10TABLE_LISTbbbb+0x516)[0x698826]
/usr/local/mysql/libexec/mysqld(_Z14mysql_rm_tableP3THDP10TABLE_LISTcc+0x77)[0x698d57]
/usr/local/mysql/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x2abe)[0x5bcb6e]
/usr/local/mysql/libexec/mysqld(_Z11mysql_parseP3THDPcjPPKc+0x51b)[0x5c067b]
/usr/local/mysql/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x9f1)[0x5c1071]
/usr/local/mysql/libexec/mysqld(_Z10do_commandP3THD+0x128)[0x5c1cb8]
/usr/local/mysql/libexec/mysqld(handle_one_connection+0x7b1)[0x5b3ca1]
/lib64/libpthread.so.0(+0x6a3a)[0x7fe3d1814a3a]
/lib64/libc.so.6(clone+0x6d)[0x7fe3d0a9367d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7fe108007aa0): drop table variable_tree
Connection ID (thread ID): 65842
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
110615 18:54:11 mysqld_safe Number of processes running now: 0
110615 18:54:11 mysqld_safe mysqld restarted

Config:

[client]port = 3306
socket = /tmp/mysql.sock

[mysqld]
myisam_recover

server-id = 1
port = 3306
socket = /tmp/mysql.sock
basedir = /usr/local/mysql
tmpdir = /usr/local/mysql_data/data/tmp
datadir = /usr/local/mysql_data/data
pid-file = /usr/local/mysql_data/mysql.pid
log-bin = /usr/local/mysql_data/bin-logs/mysql-bin
slow_query_log = 1
slow_query_log_file = /usr/local/mysql_data/slow-queries.log
log-error = /usr/local/mysql_data/mysql.err
default-table-type = InnoDB
concurrent_insert = 2

loose_handlersocket_port = 9998
loose_handlersocket_port_wr = 9999
loose_handlersocket_threads = 16
loose_handlersocket_threads_wr = 1
open_files_limit = 65535

innodb_file_per_table = 1
innodb_lazy_drop_table = 1

innodb_data_home_dir = /usr/local/mysql_data/ibd
innodb_log_group_home_dir = /usr/local/mysql_data/ibd/log
innodb_data_file_path = ibdata1:10M:autoextend
innodb_buffer_pool_size = 5G
innodb_log_buffer_size = 8M
innodb_additional_mem_pool_size = 4M
innodb_log_files_in_group = 2
innodb_log_file_size = 100M

innodb_open_files = 1000
innodb_flush_method = O_DIRECT
innodb_flush_log_at_trx_commit = 2
innodb_lock_wait_timeout = 300
innodb_read_io_threads=4
innodb_write_io_threads=4

max_connections = 100
table_cache = 10000
open-files-limit = 20000

thread_cache_size = 20
key_buffer_size = 4G
max_heap_table_size = 50M
tmp_table_size = 50M
expire_logs_days = 30
max_binlog_size = 200M
max_allowed_packet = 1G
query_cache_size = 0
query_cache_type = 0
long_query_time = 1

[mysql]
no-auto-rehash

[Dave Juntgen (djuntgen)]

As request in i17014, here is the stack strace:

See attached symbol and stack file.

MySQL Version:

Ver 5.1.56-rel12.7-log for unknown-linux-gnu on x86_64 (Percona Server with XtraDB (GPL), Release 12.7, Revision 224)

[xxx]# resolve_stack_dump -s mysqld.sym -n mysql.stack
0x87a309 my_print_stacktrace + 57
0x5ae1ee handle_segfault + 846
0x7fe3d181d0f0 _end + -794604856
0x7fe3d09e76c5 _end + -809504611
0x7fe3d09e8ea5 _end + -809498499
0x7e7d6c dict_index_remove_from_cache + 252
0x7ed00a dict_table_remove_from_cache + 106
0x774c29 row_drop_table_for_mysql + 2009
0x71af3d ha_innobase::delete_table(char const*) + 205
0x691994 ha_delete_table(THD*, handlerton*, char const*, char const*, char const*, bool) + 212
0x698826 mysql_rm_table_part2(THD*, TABLE_LIST*, bool, bool, bool, bool) + 1302
0x698d57 mysql_rm_table(THD*, TABLE_LIST*, char, char) + 119
0x5bcb6e mysql_execute_command(THD*) + 10942
0x5c067b mysql_parse(THD*, char*, unsigned int, char const**) + 1307
0x5c1071 dispatch_command(enum_server_command, THD*, char*, unsigned int) + 2545
0x5c1cb8 do_command(THD*) + 296
0x5b3ca1 handle_one_connection + 1969
0x7fe3d1814a3a _end + -794639342
0x7fe3d0a9367d _end + -808800171

[Dave Juntgen (djuntgen)]

Symbol's created with command:

nm -n --demangle /usr/local/mysql/libexec/mysqld > mysqld.sym

then resolved with:

resolve_stack_dump -s mysqld.sym -n mysqld.stack

[Yasufumi Kinoshita (yasufumi-kinoshita)]

Can I ask a question?

The table "webchart_pepperson/variable_tree" has experienced "DISCARD TABLESPACE" and "IMPORT TABLESPACE" with the option innodb_lazy_drop_table was enabled, before the crash?

[Yasufumi Kinoshita (yasufumi-kinoshita)]

The essence of this bug might be
"incompatibility between DISCARD/IMPORT TABLESPACE and innodb_lazy_drop_table".

[Dave Juntgen (djuntgen)]

Hi Yasufumi -

the table "webchart_pepperson/variable_tree" was not discarded and reimported. However - I believe the developer ran several "TRUNCATE TABLE" commands before trying to drop it.

[Yasufumi Kinoshita (yasufumi-kinoshita)]

Thank you.
It my be good information to focus the scope.

[Dave Drager (ddrager)]

Hello,

Looks like this bug might still be present in latest versions. At least it looks like it is the same bug. Just received the same message/crash on the latest version of Percona-Server, using Percona repositories:

Percona-Server-shared-55-5.5.28-rel29.2.360.rhel6.x86_64
Percona-Server-client-55-5.5.28-rel29.2.360.rhel6.x86_64
Percona-Server-server-55-5.5.28-rel29.2.360.rhel6.x86_64

[root@xxx mysql]# mysqladmin version
mysqladmin Ver 8.42 Distrib 5.5.28, for Linux on x86_64
Copyright (c) 2000, 2012, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Server version 5.5.28-29.2-log
Protocol version 10
Connection Localhost via UNIX socket
UNIX socket /var/lib/mysql/mysql.sock
Uptime: 21 min 46 sec

Threads: 2 Questions: 65 Slow queries: 0 Opens: 34 Flush tables: 1 Open tables: 27 Queries per second avg: 0.049

** I do have innodb_lazy_drop_table enabled. **

Log follows:

InnoDB: Error: Waited for 570 secs for hash index ref_count (516) to drop to 0.
index: "threadid" table: "forum/threadviews"
InnoDB: Error: Waited for 575 secs for hash index ref_count (516) to drop to 0.
index: "threadid" table: "forum/threadviews"
...
InnoDB: Error: Waited for 590 secs for hash index ref_count (516) to drop to 0.
index: "threadid" table: "forum/threadviews"
InnoDB: Error: Waited for 595 secs for hash index ref_count (516) to drop to 0.
index: "threadid" table: "forum/threadviews"
InnoDB: Error: Waited for 600 secs for hash index ref_count (516) to drop to 0.
index: "threadid" table: "forum/threadviews"
121219 6:42:38 InnoDB: Assertion failure in thread 139966688274176 in file dict0dict.c line 1883
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. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
12:42:38 UTC - 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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=6291456000
read_buffer_size=262144
max_used_connections=17
max_threads=1100
thread_count=2
connection_count=2
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6720683 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x31ad0080
Attempting backtrace. You can use the following information to find out
where mysqld...

[Roel Van de Paar (roel11)]

Ref bug 1086269 | bug 897258

[SingerWang (wang)]

We are running the latest Percona-5.5 and saw this issue again.. I think we have regressed..

root@db6:/data/mysql_ssd# mysql -uroot -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 171
Server version: 5.5.30-30.1-log Percona Server (GPL), Release 30.1

Copyright (c) 2000, 2013, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> \s
--------------
mysql Ver 14.14 Distrib 5.5.30, for Linux (x86_64) using readline 5.1

Connection id: 171
Current database:
Current user: root@localhost
SSL: Not in use
Current pager: stdout
Using outfile: ''
Using delimiter: ;
Server version: 5.5.30-30.1-log Percona Server (GPL), Release 30.1
Protocol version: 10
Connection: Localhost via UNIX socket
Server characterset: utf8
Db characterset: utf8
Client characterset: utf8
Conn. characterset: utf8
UNIX socket: /var/run/mysqld/mysqld.sock
Uptime: 12 min 59 sec

Threads: 4 Questions: 300214 Slow queries: 8 Opens: 147 Flush tables: 1 Open tables: 140 Queries per second avg: 385.383
--------------

mysql>

TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS
----------------------------
END OF INNODB MONITOR OUTPUT
============================
130402 14:18:18 [Warning] Too many connections
InnoDB: Error: Waited for 595 secs for hash index ref_count (16) to drop to 0.
index: "index_stored_assets_on_updated_at" table: "shopify/lhma_1364875984728_stored_assets"
InnoDB: Error: Waited for 600 secs for hash index ref_count (16) to drop to 0.
index: "index_stored_assets_on_updated_at" table: "shopify/lhma_1364875984728_stored_assets"
130402 14:18:23 InnoDB: Assertion failure in thread 139539545208576 in file dict0dict.c line 1900
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. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
14:18:23 UTC - 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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=4001
max_threads=4002
thread_count=4001
connection_count=4001
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 8773810 K bytes of memory
Hope that's ok; if not, decrease some variables in t...

[Laurynas Biveinis (laurynas-biveinis)]

For any recent re-occurrences of this bug, please follow bug 1086227.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-484