Bug #73910 | InnoDB: Opened table is not incrementing counter | ||
---|---|---|---|
Submitted: | 12 Sep 2014 22:46 | Modified: | 2 Mar 2017 18:33 |
Reporter: | Mike Willbanks | Email Updates: | |
Status: | No Feedback | Impact on me: | |
Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
Version: | 5.5.39 | OS: | Linux (Ubuntu 14.04 amd64) |
Assigned to: | CPU Architecture: | Any | |
Tags: | crash, dict0dict, innodb |
[12 Sep 2014 22:46]
Mike Willbanks
[12 Sep 2014 23:57]
Mike Willbanks
Yet another one came in today: 140912 23:41:56 InnoDB: Assertion failure in thread 140303325800192 in file dict0dict.c line 355 InnoDB: Failing assertion: table->n_mysql_handles_opened > 0 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. 23:41:56 UTC - mysqld got signal 6 ; Thread pointer: 0x7f9dc6856f60 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 = 7f9ae9e51e90 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x20)[0x7f9db55615a0] /usr/sbin/mysqld(handle_fatal_signal+0x3d5)[0x7f9db5426805] /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f9db418a340] /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7f9db37e0bb9] /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f9db37e3fc8] /usr/sbin/mysqld(+0x62e053)[0x7f9db564d053] /usr/sbin/mysqld(+0x5bddbe)[0x7f9db55dcdbe] /usr/sbin/mysqld(+0x5a2205)[0x7f9db55c1205] /usr/sbin/mysqld(_ZN12ha_partition5closeEv+0x7c)[0x7f9db56dc67c] /usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x12d)[0x7f9db53a80cd] /usr/sbin/mysqld(+0x2c39a7)[0x7f9db52e29a7] /usr/sbin/mysqld(_Z18close_thread_tableP3THDPP5TABLE+0x2ad)[0x7f9db52e501d] /usr/sbin/mysqld(_Z19close_thread_tablesP3THD+0x16b)[0x7f9db52e51cb] /usr/sbin/mysqld(+0x3509ef)[0x7f9db536f9ef] /usr/sbin/mysqld(_Z14get_all_tablesP3THDP10TABLE_LISTP4Item+0x16a)[0x7f9db537bcba] /usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x220)[0x7f9db5381570] /usr/sbin/mysqld(_ZN4JOIN4execEv+0x4c5)[0x7f9db536afe5] /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1de)[0x7f9db536cf8e] /usr/sbin/mysqld(+0x300ac0)[0x7f9db531fac0] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x3c9a)[0x7f9db532b01a] /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0xed)[0x7f9db532d80d] /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1ed4)[0x7f9db532ff14] /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x105)[0x7f9db53cd605] /usr/sbin/mysqld(handle_one_connection+0x41)[0x7f9db53cd711] /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f9db4182182] /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f9db38a4fbd] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (7f9abc35f1f0): is an invalid pointer Connection ID (thread ID): 5608 Status: NOT_KILLED
[15 Sep 2014 14:22]
Mike Willbanks
And another... 140915 14:06:35 InnoDB: Assertion failure in thread 139813452723968 in file dict0dict.c line 355 InnoDB: Failing assertion: table->n_mysql_handles_opened > 0 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:06:35 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. key_buffer_size=536870912 read_buffer_size=65536 max_used_connections=15 max_threads=100 thread_count=14 connection_count=13 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 557440 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7f2bb82d4500 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 = 7f28db2f2e90 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x20)[0x7f2ba6a015a0] /usr/sbin/mysqld(handle_fatal_signal+0x3d5)[0x7f2ba68c6805] /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f2ba562a340] /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7f2ba4c80bb9] /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f2ba4c83fc8] /usr/sbin/mysqld(+0x62e053)[0x7f2ba6aed053] /usr/sbin/mysqld(+0x5bddbe)[0x7f2ba6a7cdbe] /usr/sbin/mysqld(+0x5a2205)[0x7f2ba6a61205] /usr/sbin/mysqld(_ZN12ha_partition5closeEv+0x7c)[0x7f2ba6b7c67c] /usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x12d)[0x7f2ba68480cd] /usr/sbin/mysqld(+0x2c39a7)[0x7f2ba67829a7] /usr/sbin/mysqld(_Z18close_thread_tableP3THDPP5TABLE+0x2ad)[0x7f2ba678501d] /usr/sbin/mysqld(_Z19close_thread_tablesP3THD+0x16b)[0x7f2ba67851cb] /usr/sbin/mysqld(+0x3509ef)[0x7f2ba680f9ef] /usr/sbin/mysqld(_Z14get_all_tablesP3THDP10TABLE_LISTP4Item+0x16a)[0x7f2ba681bcba] /usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x220)[0x7f2ba6821570] /usr/sbin/mysqld(_ZN4JOIN4execEv+0x4c5)[0x7f2ba680afe5] /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1de)[0x7f2ba680cf8e] /usr/sbin/mysqld(+0x300ac0)[0x7f2ba67bfac0] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x3c9a)[0x7f2ba67cb01a] /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0xed)[0x7f2ba67cd80d] /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1ed4)[0x7f2ba67cff14] /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x105)[0x7f2ba686d605] /usr/sbin/mysqld(handle_one_connection+0x41)[0x7f2ba686d711] /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f2ba5622182] /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f2ba4d44fbd] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (7f28a408b840): is an invalid pointer Connection ID (thread ID): 31778 Status: NOT_KILLED
[15 Sep 2014 21:54]
Mike Willbanks
Another one with a dump of transactions, deadlocks, etc just prior to the crash: InnoDB: transactions deadlock detected, dumping detailed information. 140915 21:07:52 *** (1) TRANSACTION: TRANSACTION A5A174703, ACTIVE 1 sec inserting mysql tables in use 1, locked 1 LOCK WAIT 65 lock struct(s), heap size 14776, 2 row lock(s) MySQL thread id 39, OS thread handle 0x7f13886cb700, query id 2006078 ec2-107-22-220-149.compute-1.amazonaws.com 107.22.220.149 root update insert into node_comm_cube set nodeId='0', hostId='3669870885048719226', ts5min='0', pldCount='68', mrrTs='0' on duplicate key update pldCount=pldCount+'68', mrrTs='0' *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 0 page no 5686804 n bits 336 index `PRIMARY` of table `p2production1`.`node_comm_cube` trx id A5A174703 lock_mode X locks gap before rec insert intention waiting Record lock, heap no 130 PHYSICAL RECORD: n_fields 8; compact format; info bits 32 0: len 8; hex 0000000000000000; asc ;; 1: len 8; hex e8ee0080a391516d; asc Qm;; 2: len 8; hex 8000000000000000; asc ;; 3: len 6; hex 000a5a174691; asc Z F ;; 4: len 7; hex 3b009d00122c11; asc ; , ;; 5: len 4; hex 80000000; asc ;; 6: len 8; hex 8000000000000000; asc ;; 7: len 4; hex 8000005e; asc ^;; *** (2) TRANSACTION: TRANSACTION A5A1746E7, ACTIVE 1 sec inserting, thread declared inside InnoDB 1 mysql tables in use 1, locked 1 4 lock struct(s), heap size 1248, 2 row lock(s) MySQL thread id 42, OS thread handle 0x7f13885c7700, query id 2006048 ec2-107-22-220-149.compute-1.amazonaws.com 107.22.220.149 root update insert into node_comm_cube set nodeId='0', hostId='16207894308402233486', ts5min='0', pldCount='10', mrrTs='0' on duplicate key update pldCount=pldCount+'10', mrrTs='0' *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 0 page no 5686804 n bits 336 index `PRIMARY` of table `p2production1`.`node_comm_cube` trx id A5A1746E7 lock_mode X locks gap before rec Record lock, heap no 130 PHYSICAL RECORD: n_fields 8; compact format; info bits 32 0: len 8; hex 0000000000000000; asc ;; 1: len 8; hex e8ee0080a391516d; asc Qm;; 2: len 8; hex 8000000000000000; asc ;; 3: len 6; hex 000a5a174691; asc Z F ;; 4: len 7; hex 3b009d00122c11; asc ; , ;; 5: len 4; hex 80000000; asc ;; 6: len 8; hex 8000000000000000; asc ;; 7: len 4; hex 8000005e; asc ^;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 0 page no 5686804 n bits 336 index `PRIMARY` of table `p2production1`.`node_comm_cube` trx id A5A1746E7 lock_mode X locks gap before rec insert intention waiting Record lock, heap no 130 PHYSICAL RECORD: n_fields 8; compact format; info bits 32 0: len 8; hex 0000000000000000; asc ;; 1: len 8; hex e8ee0080a391516d; asc Qm;; 2: len 8; hex 8000000000000000; asc ;; 3: len 6; hex 000a5a174691; asc Z F ;; 4: len 7; hex 3b009d00122c11; asc ; , ;; 5: len 4; hex 80000000; asc ;; 6: len 8; hex 8000000000000000; asc ;; 7: len 4; hex 8000005e; asc ^;; *** WE ROLL BACK TRANSACTION (2) 140915 21:16:27 InnoDB: Assertion failure in thread 139721869399808 in file dict0dict.c line 355 InnoDB: Failing assertion: table->n_mysql_handles_opened > 0 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. 21:16:27 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. key_buffer_size=536870912 read_buffer_size=65536 max_used_connections=19 max_threads=100 thread_count=12 connection_count=11 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 557440 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7f13a073dfe0 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 = 7f1388648e90 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x20)[0x7f138db0f5a0] /usr/sbin/mysqld(handle_fatal_signal+0x3d5)[0x7f138d9d4805] /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f138c738340] /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7f138bd8ebb9] /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f138bd91fc8] /usr/sbin/mysqld(+0x62e053)[0x7f138dbfb053] /usr/sbin/mysqld(+0x5bddbe)[0x7f138db8adbe] /usr/sbin/mysqld(+0x5a2205)[0x7f138db6f205] /usr/sbin/mysqld(_ZN12ha_partition5closeEv+0x7c)[0x7f138dc8a67c] /usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x12d)[0x7f138d9560cd] /usr/sbin/mysqld(+0x2c39a7)[0x7f138d8909a7] /usr/sbin/mysqld(_Z18close_thread_tableP3THDPP5TABLE+0x2ad)[0x7f138d89301d] /usr/sbin/mysqld(_Z19close_thread_tablesP3THD+0x16b)[0x7f138d8931cb] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x30b)[0x7f138d8d568b] /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0xed)[0x7f138d8db80d] /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1ed4)[0x7f138d8ddf14] /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x105)[0x7f138d97b605] /usr/sbin/mysqld(handle_one_connection+0x41)[0x7f138d97b711] /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f138c730182] /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f138be52fbd] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (7f10940008d0): is an invalid pointer Connection ID (thread ID): 41 Status: NOT_KILLED
[16 Sep 2014 1:55]
Mike Willbanks
I've changed the title of this to see where this is happening. It seems that there is a situation where partitioned tables do not properly increment the table counter; when this happens and the table counter is to be decremented and all items have been decremented as there is no additional counters left thus failing the assertion.
[15 Oct 2014 20:14]
Mike Willbanks
Latest ability to reproduce this use case: https://gist.github.com/mwillbanks/c9b13cd75eaaceadc2c5 Including items here for ease of reading: == error.log == 141015 16:25:43 InnoDB: Assertion failure in thread 140072888116992 in file dict0dict.c line 353 InnoDB: Failing assertion: table->n_mysql_handles_opened > 0 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. 16:25:43 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. key_buffer_size=536870912 read_buffer_size=65536 max_used_connections=9 max_threads=100 thread_count=8 connection_count=7 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 557440 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7f6820f40ed0 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 = 7f6542bd1e98 thread_stack 0x80000 /usr/sbin/mysqld(my_print_stacktrace+0x20)[0x7f680e51ff20] /usr/sbin/mysqld(handle_fatal_signal+0x3d5)[0x7f680e40a8d5] /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f680d19c340] /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7f680c7f2bb9] /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f680c7f5fc8] /usr/sbin/mysqld(+0x5d9993)[0x7f680e60a993] /usr/sbin/mysqld(+0x56990e)[0x7f680e59a90e] /usr/sbin/mysqld(+0x551df5)[0x7f680e582df5] /usr/sbin/mysqld(_ZN12ha_partition5closeEv+0x54)[0x7f680e694394] /usr/sbin/mysqld(_ZN18QUICK_RANGE_SELECTD1Ev+0xfc)[0x7f680e4b194c] /usr/sbin/mysqld(_ZN18QUICK_RANGE_SELECTD0Ev+0x9)[0x7f680e4b19b9] /usr/sbin/mysqld(_ZN26QUICK_ROR_INTERSECT_SELECTD1Ev+0x45)[0x7f680e4b1cf5] /usr/sbin/mysqld(_ZN26QUICK_ROR_INTERSECT_SELECTD0Ev+0x9)[0x7f680e4b1d89] /usr/sbin/mysqld(_ZN10SQL_SELECT7cleanupEv+0x12)[0x7f680e4b5a62] /usr/sbin/mysqld(_ZN13st_join_table7cleanupEv+0x12)[0x7f680e34d772] /usr/sbin/mysqld(_ZN4JOIN7cleanupEb+0xdf)[0x7f680e34d92f] /usr/sbin/mysqld(_ZN4JOIN9join_freeEv+0x43)[0x7f680e34dbc3] /usr/sbin/mysqld(+0x322388)[0x7f680e353388] /usr/sbin/mysqld(_ZN4JOIN4execEv+0x77e)[0x7f680e36259e] /usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0xcb)[0x7f680e35e06b] /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x144)[0x7f680e35e894] /usr/sbin/mysqld(+0x2ef7f0)[0x7f680e3207f0] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x2860)[0x7f680e3280e0] /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x160)[0x7f680e32c5a0] /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1df2)[0x7f680e32eb32] /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x176)[0x7f680e3baa96] /usr/sbin/mysqld(handle_one_connection+0x41)[0x7f680e3baaf1] /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f680d194182] /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f680c8b6fbd] == query.sql == SELECT `nfvn`.`channelId` , `nfvnp`.`maxValue` as `pMaxValue` , `nfvn`.`minValue` , `nfvn`.`avgValue` , `nfvn`.`maxValue` , `nfvnn`.`minValue` as `nMinValue` FROM `node_filtered_values_new` `nfvn` LEFT JOIN `node_filtered_values_new` `nfvnp` ON ( `nfvnp`.`nodeId` = `nfvn`.`nodeId` AND `nfvnp`.`timeStamp` = `nfvn`.`timeStamp` - 3600 AND `nfvnp`.`timePeriod` = 3600 AND `nfvnp`.`channelId` = `nfvn`.`channelId` ) LEFT JOIN `node_filtered_values_new` `nfvnn` ON ( `nfvnn`.`nodeId` = `nfvn`.`nodeId` AND `nfvnn`.`timeStamp` = `nfvn`.`timeStamp` + 3600 AND `nfvnn`.`timePeriod` = 3600 AND `nfvnn`.`channelId` = `nfvn`.`channelId` ) WHERE `nfvn`.`nodeId` = 72057594037945360 AND `nfvn`.`timeStamp` = 1412164800 AND `nfvn`.`timePeriod` = 3600; == table.sql == CREATE TABLE `node_filtered_values_new` ( `channelId` int(11) unsigned NOT NULL DEFAULT '0', `nodeId` bigint(20) unsigned NOT NULL DEFAULT '0', `timeStamp` bigint(20) NOT NULL DEFAULT '0', `timePeriod` int(10) unsigned NOT NULL, `minValue` double DEFAULT NULL, `avgValue` double DEFAULT NULL, `maxValue` double DEFAULT NULL, `countValue` int(11) DEFAULT NULL, PRIMARY KEY (`channelId`,`nodeId`,`timeStamp`), KEY `nfvn_nodeIndex` (`nodeId`), KEY `nfvn_tsIndex` (`timeStamp`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 /*!50100 PARTITION BY KEY (channelId) PARTITIONS 50 */
[2 Feb 2017 18:33]
MySQL Verification Team
Please try version 5.5.54: https://dev.mysql.com/downloads/mysql/5.5.html#downloads
[3 Mar 2017 1:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".