[MDEV-16460] Magento randomly crashes MariaDB 10.2 on ADD CONSTRAINT Created: 2018-06-11  Updated: 2019-05-09  Resolved: 2018-06-26

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Storage Engine - InnoDB
Affects Version/s: 10.2.15
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Silver Asu Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: None
Environment:

CentOS

Attachments: Text File tables.txt    
Issue Links:
Duplicate
duplicates MDEV-16060 InnoDB: Failing assertion: ut_strcmp(... Closed
Relates
relates to MDEV-6642 Server crashed with assertion failure... Open

 Description   

I've seen many similar random crashes from different servers, but I am not able to reproduce this. I understand that this is impossible to debug, but maybe someone other has similar problem as magento is pretty popular software.

Query that causes crash is always the same (Number in table name differs):

ALTER TABLE `catalog_product_flat_1` ADD CONSTRAINT `FK_CAT_PRD_FLAT_1_ENTT_ID_CAT_PRD_ENTT_ENTT_ID` FOREIGN KEY (`entity_id`) REFERENCES `catalog_product_entity` (`entity_id`) ON DELETE CASCADE ON UPDATE CASCADE

Full log, while crash happens:

2018-06-11 13:00:21 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
...
 
2018-06-11 13:00:22 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
2018-06-11 13:00:39 139771731450176 [ERROR] InnoDB:  Index for key no 1 mysql name IDX_CATALOG_PRODUCT_FLAT_18_TYPE_ID InnoDB name IDX_CATALOG_PRODUCT_FLAT_1_TYPE_ID for table replaced_databasename/#sql-369b_504e7
 
2018-06-11 13:00:39 139771731450176 [Note] InnoDB:  Index for key no 1 mysql name IDX_CATALOG_PRODUCT_FLAT_18_TYPE_ID InnoDB name PRIMARY for table replaced_databasename/#sql-369b_504e7
 
2018-06-11 13:00:39 139771731450176 [Note] InnoDB:  Index for key no 1 mysql name IDX_CATALOG_PRODUCT_FLAT_18_TYPE_ID InnoDB name IDX_CATALOG_PRODUCT_FLAT_1_TYPE_ID for table replaced_databasename/#sql-369b_504e7
 
2018-06-11 13:00:39 139771731450176 [Note] InnoDB:  Index for key no 1 mysql name IDX_CATALOG_PRODUCT_FLAT_18_TYPE_ID InnoDB name IDX_CATALOG_PRODUCT_FLAT_1_ATTRIBUTE_SET_ID for table replaced_databasename/#sql-369b_504e7
 
2018-06-11 13:00:39 139771731450176 [Note] InnoDB:  Index for key no 1 mysql name IDX_CATALOG_PRODUCT_FLAT_18_TYPE_ID InnoDB name IDX_CATALOG_PRODUCT_FLAT_1_NAME for table replaced_databasename/#sql-369b_504e7
 
2018-06-11 13:00:39 139771731450176 [Note] InnoDB:  Index for key no 1 mysql name IDX_CATALOG_PRODUCT_FLAT_18_TYPE_ID InnoDB name IDX_CATALOG_PRODUCT_FLAT_1_PRICE for table replaced_databasename/#sql-369b_504e7
 
2018-06-11 13:00:39 0x7f1f24671940  InnoDB: Assertion failure in file /usr/src/redhat/BUILD/zone_mariadb/mariadb-10.2.15/storage/innobase/handler/ha_innodb.cc line 9609
 
InnoDB: Failing assertion: ut_strcmp(index->name, key->name) == 0
 
InnoDB: We intentionally generate a memory trap.
 
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
 
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
 
InnoDB: about forcing recovery.
 
180611 13:00:39 [ERROR] 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.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
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.
 
 
 
Server version: 10.2.15-MariaDB-log
 
key_buffer_size=4294967296
 
2018-06-11 13:00:39 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
read_buffer_size=2097152
 
max_used_connections=49
 
max_threads=1502
 
thread_count=56
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 19606762 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x14814c008
 
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 = 0x7f1f24671058 thread_stack 0x49000
 
2018-06-11 13:00:39 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
...
 
/opt/zone/sbin/mysqld(my_print_stacktrace+0x24)[0xdc2414]
 
2018-06-11 13:00:39 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
...
 
2018-06-11 13:00:39 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
/opt/zone/sbin/mysqld(handle_fatal_signal+0x513)[0x7c8ba3]
 
2018-06-11 13:00:39 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
/lib64/libpthread.so.0[0x7f2144695ca0]
 
/lib64/libc.so.6(gsignal+0x35)[0x7f21426c4fc5]
 
/lib64/libc.so.6(abort+0x110)[0x7f21426c6a70]
 
/opt/zone/sbin/mysqld[0xb3f328]
 
/opt/zone/sbin/mysqld[0x9c1b2a]
 
/opt/zone/sbin/mysqld[0x9cc419]
 
/opt/zone/sbin/mysqld[0x9d0f30]
 
/opt/zone/sbin/mysqld(_ZN7handler7ha_openEP5TABLEPKcij+0x3f)[0x7cc07f]
 
/opt/zone/sbin/mysqld(_Z21open_table_from_shareP3THDP11TABLE_SHAREPKcjjjP5TABLEb+0xa29)[0x6b1ad9]
 
/opt/zone/sbin/mysqld(_ZN3THD20open_temporary_tableEP15TMP_TABLE_SHAREPKcb+0x81)[0x763b31]
 
2018-06-11 13:00:40 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
/opt/zone/sbin/mysqld(_ZN3THD25create_and_open_tmp_tableEP10handlertonP34st_mysql_const_unsigned_lex_stringPKcS5_S5_b+0x4a)[0x7642ea]
 
2018-06-11 13:00:40 139771732965696 [ERROR] Invalid (old?) table or database name '#sql-369b_504e7'
 
/opt/zone/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x44e3)[0x68b1d3]
 
/opt/zone/sbin/mysqld(_ZN19Sql_cmd_alter_table7executeEP3THD+0x60d)[0x6dcf5d]
 
/opt/zone/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x111e)[0x5f168e]
 
/opt/zone/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x3c0)[0x5fb1b0]
 
/opt/zone/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x2ccb)[0x5fe6db]
 
/opt/zone/sbin/mysqld(_Z10do_commandP3THD+0x15b)[0x5feabb]
 
/opt/zone/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x205)[0x6d9585]
 
/opt/zone/sbin/mysqld(handle_one_connection+0x41)[0x6d9721]
 
/opt/zone/sbin/mysqld[0xd39c01]
 
/lib64/libpthread.so.0[0x7f214468d83d]
 
/lib64/libc.so.6(clone+0x6d)[0x7f2142769fdd]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x1483dc820): ALTER TABLE `catalog_product_flat_18` ADD CONSTRAINT `FK_CAT_PRD_FLAT_18_ENTT_ID_CAT_PRD_ENTT_ENTT_ID` FOREIGN KEY (`entity_id`) REFERENCES `catalog_product_entity` (`entity_id`) ON DELETE CASCADE ON UPDATE CASCADE
 
 
 
Connection ID (thread ID): 328935
 
Status: NOT_KILLED
 
 
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
 
 
 
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.
 
tcmalloc: large alloc 3511779328 bytes == 0x2b1a2000 @ 
2018-06-11 13:00:43 140229241796416 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2018-06-11 13:00:43 140229241796416 [Note] InnoDB: Uses event mutexes
 
2018-06-11 13:00:43 140229241796416 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2018-06-11 13:00:43 140229241796416 [Note] InnoDB: Using Linux native AIO
 
2018-06-11 13:00:43 140229241796416 [Note] InnoDB: Number of pools: 1
 
2018-06-11 13:00:43 140229241796416 [Note] InnoDB: Using SSE2 crc32 instructions
 
2018-06-11 13:00:43 140229241796416 [Note] InnoDB: Initializing buffer pool, total size = 8G, instances = 8, chunk size = 128M
 
2018-06-11 13:00:44 140229241796416 [Note] InnoDB: Completed initialization of buffer pool
 
2018-06-11 13:00:44 140220282665280 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2018-06-11 13:00:44 140229241796416 [Note] InnoDB: Highest supported file format is Barracuda.
 
2018-06-11 13:00:44 140229241796416 [Note] InnoDB: Starting crash recovery from checkpoint LSN=6532549241820
 
2018-06-11 13:00:48 140229241796416 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 1 row operations to undo
 
2018-06-11 13:00:48 140229241796416 [Note] InnoDB: Trx id counter is 2081980672
 
2018-06-11 13:00:48 140229241796416 [Note] InnoDB: Starting final batch to recover 2962 pages from redo log.
 
2018-06-11 13:00:51 140229241796416 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2018-06-11 13:00:51 140220249094464 [Note] InnoDB: Starting in background the rollback of recovered transactions
 
2018-06-11 13:00:51 140220249094464 [Note] InnoDB: Rolled back recovered transaction 2081980352
 
2018-06-11 13:00:51 140220249094464 [Note] InnoDB: Rollback of non-prepared transactions completed
 
2018-06-11 13:00:51 140229241796416 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
 
2018-06-11 13:00:51 140229241796416 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2018-06-11 13:00:51 140229241796416 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2018-06-11 13:00:51 140229241796416 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2018-06-11 13:00:52 140229241796416 [Note] InnoDB: Waiting for purge to start
 
2018-06-11 13:00:52 140229241796416 [Note] InnoDB: 5.7.22 started; log sequence number 6532549818501
 
2018-06-11 13:00:52 140220165167424 [Note] InnoDB: Loading buffer pool(s) from /srvdata/mysql/ib_buffer_pool
 
2018-06-11 13:00:52 140229241796416 [Note] Plugin 'FEEDBACK' is disabled.
 
180611 13:00:52 server_audit: MariaDB Audit Plugin version 1.4.4 STARTED.
 
2018-06-11 13:00:52 140229241796416 [Note] Recovering after a crash using tc.log
 
2018-06-11 13:00:52 140229241796416 [Note] Starting crash recovery...
 
2018-06-11 13:00:52 140229241796416 [Note] Crash recovery finished.
 
2018-06-11 13:00:52 140229241796416 [Note] Server socket created on IP: '::'.



 Comments   
Comment by Elena Stepanova [ 2018-06-11 ]

Could you please provide the output of 

SHOW CREATE TABLE catalog_product_flat_18;
 
SHOW INDEX IN catalog_product_flat_18;

And the same for any tables it references? (For any table with which the crash was observed, but a consistent set for such table).

Please also paste or attach your cnf file(s).

Thanks.

Comment by Elena Stepanova [ 2018-06-26 ]

It appears to be the same exact problem as MDEV-16060 (even also with Magento). Let's track further progress there.

Generated at Thu Feb 08 08:29:05 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.