[MDEV-22898] SQL query always crashes on INSERT IGNORE Created: 2020-06-15  Updated: 2020-07-29  Resolved: 2020-07-29

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Data Manipulation - Insert, Storage Engine - InnoDB
Affects Version/s: 10.4.13, 10.5
Fix Version/s: 10.4.14, 10.5.5

Type: Bug Priority: Blocker
Reporter: Db Admin BibLibre Assignee: Eugene Kosov (Inactive)
Resolution: Duplicate Votes: 0
Labels: regression, regression-10.4
Environment:

ubuntu/bionic

Issue Links:
Duplicate
duplicates MDEV-23245 Still getting assertion failure in fi... Closed
Relates
relates to MDEV-20726 InnoDB: Assertion failure in file dat... Closed
relates to MDEV-22899 Assertion `field->col->is_binary() ||... Closed

 Description   

Hello

The following SQL query always crashes MariaDB 

MariaDB [(none)]> INSERT IGNORE INTO koha.columns_settings (module, page, tablename, columnname, cannot_be_toggled, is_hidden) VALUES ("circ", "circulation", "issues-table", "collection", 0, 1), ("members", "moremember", "issues-table", "collection", 0, 1);


juin 15 14:09:29 test-server mysqld[23656]: 2020-06-15 14:09:29 0x7f71e8c58700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.4.13/storage/innobase/data/data0type.cc line 67
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: Failing assertion: !(prefix_len % mbmaxlen)
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: We intentionally generate a memory trap.
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: If you get repeated assertion failures or crashes, even
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: immediately after the mysqld startup, there may be
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: corruption in the InnoDB tablespace. Please refer to
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
 
juin 15 14:09:29 test-server mysqld[23656]: InnoDB: about forcing recovery.
 
juin 15 14:09:29 test-server mysqld[23656]: 200615 14:09:29 [ERROR] mysqld got signal 6 ;
 
juin 15 14:09:29 test-server mysqld[23656]: This could be because you hit a bug. It is also possible that this binary
 
juin 15 14:09:29 test-server mysqld[23656]: or one of the libraries it was linked against is corrupt, improperly built,
 
juin 15 14:09:29 test-server mysqld[23656]: or misconfigured. This error can also be caused by malfunctioning hardware.
 
juin 15 14:09:29 test-server mysqld[23656]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
juin 15 14:09:29 test-server mysqld[23656]: We will try our best to scrape up some info that will hopefully help
 
juin 15 14:09:29 test-server mysqld[23656]: diagnose the problem, but since we have already crashed,
 
juin 15 14:09:29 test-server mysqld[23656]: something is definitely wrong and this may fail.
 
juin 15 14:09:29 test-server mysqld[23656]: Server version: 10.4.13-MariaDB-1:10.4.13+maria~bionic
 
juin 15 14:09:29 test-server mysqld[23656]: key_buffer_size=134217728
 
juin 15 14:09:29 test-server mysqld[23656]: read_buffer_size=2097152
 
juin 15 14:09:29 test-server mysqld[23656]: max_used_connections=2
 
juin 15 14:09:29 test-server mysqld[23656]: max_threads=102
 
juin 15 14:09:29 test-server mysqld[23656]: thread_count=8
 
juin 15 14:09:29 test-server mysqld[23656]: It is possible that mysqld could use up to
 
juin 15 14:09:29 test-server mysqld[23656]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 760255 K  bytes of memory
 
juin 15 14:09:29 test-server mysqld[23656]: Hope that's ok; if not, decrease some variables in the equation.
 
juin 15 14:09:29 test-server mysqld[23656]: Thread pointer: 0x7f7180000c08
 
juin 15 14:09:29 test-server mysqld[23656]: Attempting backtrace. You can use the following information to find out
 
juin 15 14:09:29 test-server mysqld[23656]: where mysqld died. If you see no messages after this, something went
 
juin 15 14:09:29 test-server mysqld[23656]: terribly wrong...
 
juin 15 14:09:29 test-server mysqld[23656]: stack_bottom = 0x7f71e8c57dd8 thread_stack 0x49000
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55b257e3fe8e]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(handle_fatal_signal+0x515)[0x55b2578bb915]
 
juin 15 14:09:29 test-server mysqld[23656]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f7201cee890]
 
juin 15 14:09:29 test-server mysqld[23656]: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0xc7)[0x7f7200622e97]
 
juin 15 14:09:29 test-server mysqld[23656]: /lib/x86_64-linux-gnu/libc.so.6(abort+0x141)[0x7f7200624801]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(+0x57c53c)[0x55b2575c853c]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(+0xbc9f78)[0x55b257c15f78]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(+0xad02e5)[0x55b257b1c2e5]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(+0xae08e8)[0x55b257b2c8e8]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(+0xa20495)[0x55b257a6c495]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_ZN7handler12ha_write_rowEPKh+0x1a0)[0x55b2578c6990]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_Z12write_recordP3THDP5TABLEP12st_copy_info+0x1a0)[0x55b257679ac0]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0x12dc)[0x55b2576810ec]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x16d5)[0x55b2576ad315]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x1ea)[0x55b2576b3fba]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x16d5)[0x55b2576b6705]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_Z10do_commandP3THD+0x104)[0x55b2576b7bb4]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x25e)[0x55b25779423e]
 
juin 15 14:09:29 test-server mysqld[23656]: /usr/sbin/mysqld(handle_one_connection+0x3d)[0x55b2577942fd]
 
juin 15 14:09:29 test-server mysqld[23656]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7f7201ce36db]
 
juin 15 14:09:29 test-server mysqld[23656]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f720070588f]
 
juin 15 14:09:29 test-server mysqld[23656]: Trying to get some variables.
 
juin 15 14:09:29 test-server mysqld[23656]: Some pointers may be invalid and cause the dump to abort.
 
juin 15 14:09:29 test-server mysqld[23656]: Query (0x7f7180010230): INSERT IGNORE INTO columns_settings (module, page, tablename, columnname, cannot_be_toggled, is_hidden) VALUES ("circ", "circulation", "issues-table", "collection", 0, 1), ("members", "moremember", "issues-table", "collection", 0, 1)
 
juin 15 14:09:29 test-server mysqld[23656]: Connection ID (thread ID): 694
 
juin 15 14:09:29 test-server mysqld[23656]: Status: NOT_KILLED
 
juin 15 14:09:29 test-server mysqld[23656]: 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=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
 
juin 15 14:09:29 test-server mysqld[23656]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
juin 15 14:09:29 test-server mysqld[23656]: information that should help you find out what is causing the crash.
 
juin 15 14:09:29 test-server mysqld[23656]: Writing a core file...
 
juin 15 14:09:29 test-server mysqld[23656]: Working directory at /var/lib/mysql
 
juin 15 14:09:29 test-server mysqld[23656]: Resource Limits:
 
juin 15 14:09:29 test-server mysqld[23656]: Limit                     Soft Limit           Hard Limit           Units
 
juin 15 14:09:29 test-server mysqld[23656]: Max cpu time              unlimited            unlimited            seconds
 
juin 15 14:09:29 test-server mysqld[23656]: Max file size             unlimited            unlimited            bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max data size             unlimited            unlimited            bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max stack size            8388608              unlimited            bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max core file size        0                    unlimited            bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max resident set          unlimited            unlimited            bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max processes             unlimited            unlimited            processes
 
juin 15 14:09:29 test-server mysqld[23656]: Max open files            16364                16364                files
 
juin 15 14:09:29 test-server mysqld[23656]: Max locked memory         16777216             16777216             bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max address space         unlimited            unlimited            bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max file locks            unlimited            unlimited            locks
 
juin 15 14:09:29 test-server mysqld[23656]: Max pending signals       773219               773219               signals
 
juin 15 14:09:29 test-server mysqld[23656]: Max msgqueue size         819200               819200               bytes
 
juin 15 14:09:29 test-server mysqld[23656]: Max nice priority         0                    0
 
juin 15 14:09:29 test-server mysqld[23656]: Max realtime priority     0                    0
 
juin 15 14:09:29 test-server mysqld[23656]: Max realtime timeout      unlimited            unlimited            us
 
juin 15 14:09:29 test-server mysqld[23656]: Core pattern: co...
 
juin 15 14:09:29 test-server systemd[1]: mariadb.service: Main process ex

here is the show create table

columns_settings | CREATE TABLE `columns_settings` (
 
  `module` varchar(255) COLLATE utf8mb4_unicode_ci NOT NULL,
 
  `page` varchar(255) COLLATE utf8mb4_unicode_ci NOT NULL,
 
  `tablename` varchar(255) COLLATE utf8mb4_unicode_ci NOT NULL,
 
  `columnname` varchar(255) COLLATE utf8mb4_unicode_ci NOT NULL,
 
  `cannot_be_toggled` int(1) NOT NULL DEFAULT 0,
 
  `is_hidden` int(1) NOT NULL DEFAULT 0,
 
  PRIMARY KEY (`module`(191),`page`(191),`tablename`(191),`columnname`(191))
 
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci



 Comments   
Comment by Elena Stepanova [ 2020-07-26 ]

I can't reproduce it on the table created as described, but following the same logic as in MDEV-23245 and assuming that the table/columns once were utf8 and then were converted into utf8mb4, it's reproducible all right:

CREATE TABLE `columns_settings` (
 
  `module` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
 
  `page` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
 
  `tablename` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
 
  `columnname` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
 
  `cannot_be_toggled` int(1) NOT NULL DEFAULT 0,
 
  `is_hidden` int(1) NOT NULL DEFAULT 0,
 
  PRIMARY KEY (`module`(191),`page`(191),`tablename`(191),`columnname`(191))
 
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
 
 
 
ALTER TABLE columns_settings MODIFY `page` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci, MODIFY `tablename` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci, DEFAULT CHARSET utf8mb4, MODIFY `columnname` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci, COLLATE utf8mb4_unicode_ci;
 
 
 
INSERT IGNORE INTO columns_settings (module, page, tablename, columnname, cannot_be_toggled, is_hidden) VALUES ("circ", "circulation", "issues-table", "collection", 0, 1), ("members", "moremember", "issues-table", "collection", 0, 1);

10.4 non-debug 05d62518

 
2020-07-27 01:29:10 0x7fd3400b0700  InnoDB: Assertion failure in file /data/src/10.4/storage/innobase/data/data0type.cc line 67
 
InnoDB: Failing assertion: !(prefix_len % mbmaxlen)
 
 
 
#6  0x000055f196b462cf in ut_dbg_assertion_failed (expr=expr@entry=0x55f1976a642d "!(prefix_len % mbmaxlen)", file=file@entry=0x55f1976a6370 "/data/src/10.4/storage/innobase/data/data0type.cc", line=line@entry=67) at /data/src/10.4/storage/innobase/ut/ut0dbg.cc:60
 
#7  0x000055f19719c3f8 in dtype_get_at_most_n_mbchars (prtype=<optimized out>, mbminlen=<optimized out>, mbmaxlen=4, prefix_len=<optimized out>, data_len=<optimized out>, str=<optimized out>) at /data/src/10.4/storage/innobase/data/data0type.cc:67
 
#8  0x000055f1970a2c93 in row_ins_index_entry_set_vals (row=<optimized out>, entry=0x7fd2f404ed58, index=<optimized out>) at /data/src/10.4/storage/innobase/row/row0ins.cc:3430
 
#9  row_ins_index_entry_step (thr=0x7fd2f404de70, node=0x7fd2f408eb90) at /data/src/10.4/storage/innobase/row/row0ins.cc:3475
 
#10 row_ins (thr=<optimized out>, node=<optimized out>) at /data/src/10.4/storage/innobase/row/row0ins.cc:3620
 
#11 row_ins_step (thr=thr@entry=0x7fd2f404de70) at /data/src/10.4/storage/innobase/row/row0ins.cc:3759
 
#12 0x000055f1970b5f7c in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x7fd2f407f4f0 "\004", prebuilt=0x7fd2f408e568, ins_mode=<optimized out>) at /data/src/10.4/storage/innobase/row/row0mysql.cc:1422
 
#13 0x000055f196ff3b91 in ha_innobase::write_row (this=0x7fd2f40c8820, record=0x7fd2f407f4f0 "\004") at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:8021
 
#14 0x000055f196e4d53e in handler::ha_write_row (this=0x7fd2f40c8820, buf=0x7fd2f407f4f0 "\004") at /data/src/10.4/sql/handler.cc:6742
 
#15 0x000055f196bfad7d in write_record (thd=thd@entry=0x7fd2f40009a8, table=table@entry=0x7fd2f4083e98, info=info@entry=0x7fd3400ad490) at /data/src/10.4/sql/sql_insert.cc:2060
 
#16 0x000055f196c02624 in mysql_insert (thd=thd@entry=0x7fd2f40009a8, table_list=<optimized out>, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at /data/src/10.4/sql/sql_insert.cc:1078
 
#17 0x000055f196c30d7a in mysql_execute_command (thd=thd@entry=0x7fd2f40009a8) at /data/src/10.4/sql/sql_parse.cc:4519
 
#18 0x000055f196c35a9a in mysql_parse (thd=thd@entry=0x7fd2f40009a8, rawbuf=<optimized out>, length=233, parser_state=parser_state@entry=0x7fd3400af580, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.4/sql/sql_parse.cc:7896
 
#19 0x000055f196c37d59 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fd2f40009a8, packet=packet@entry=0x7fd2f4007a19 "INSERT IGNORE INTO columns_settings (module, page, tablename, columnname, cannot_be_toggled, is_hidden) VALUES (\"circ\", \"circulation\", \"issues-table\", \"collection\", 0, 1), (\"members\", \"moremember\", \"i"..., packet_length=packet_length@entry=233, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.4/sql/sql_parse.cc:1835
 
#20 0x000055f196c39516 in do_command (thd=0x7fd2f40009a8) at /data/src/10.4/sql/sql_parse.cc:1353
 
#21 0x000055f196d17902 in do_handle_one_connection (connect=connect@entry=0x55f19a8edad8) at /data/src/10.4/sql/sql_connect.cc:1412
 
#22 0x000055f196d179bd in handle_one_connection (arg=arg@entry=0x55f19a8edad8) at /data/src/10.4/sql/sql_connect.cc:1316
 
#23 0x000055f197358861 in pfs_spawn_thread (arg=0x55f19a8edb38) at /data/src/10.4/storage/perfschema/pfs.cc:1869
 
#24 0x00007fd346b5c4a4 in start_thread (arg=0x7fd3400b0700) at pthread_create.c:456
 
#25 0x00007fd345bdad0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Comment by Marko Mäkelä [ 2020-07-27 ]

I suspect that this shares a root cause with MDEV-23245.
Here is my reduced test case:

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (a VARCHAR(2) CHARACTER SET utf8mb3 COLLATE utf8mb3_unicode_ci,
 
PRIMARY KEY (a(1)))
 
ENGINE=InnoDB;
 
SHOW CREATE TABLE t1;
 
 
 
ALTER TABLE t1 MODIFY a VARCHAR(2)
 
CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci;
 
INSERT INTO t1 VALUES ('a');
 
 
 
DROP TABLE t1;

If I remove the COLLATE clause from the CREATE TABLE, then the test will avoid crash, because mysql_alter_table() would pass sensible ha_alter_info.handler_flags:

    enum_alter_inplace_result inplace_supported=
 
      table->file->check_if_supported_inplace_alter(&altered_table,
 
                                                    &ha_alter_info);

The sensible ha_alter_info.handler_flags are ALTER_CHANGE_COLUMN_DEFAULT | ALTER_RECREATE | ALTER_ADD_PK_INDEX | ALTER_DROP_PK_INDEX | ALTER_COLUMN_TYPE_CHANGE_BY_ENGINE.

If I include both COLLATE clause as in the above snippets, then we would fail to notice that the PRIMARY KEY and therefore the entire table needs to be rebuilt. The flags would only be ALTER_CHANGE_COLUMN_DEFAULT | ALTER_COLUMN_TYPE_CHANGE_BY_ENGINE.

This bug can be worked around by adding , FORCE to the ALTER TABLE statement, to force the table to be rebuilt.

Comment by Elena Stepanova [ 2020-07-27 ]

Users can't add FORCE to the original ALTER since the table has already been altered, but it appears that ALTER TABLE <table_name> FORCE works as a workaround fixing the damage and preventing further crashes. biblibreadm, could you please try?

Comment by Marko Mäkelä [ 2020-07-28 ]

I reviewed a common fix for this and MDEV-23245. It looks OK to me.

elenst, I meant that this corruption was introduced by the ALTER TABLE, and if such statement is going to be executed (it should have been tested in a staging environment first before going into production, right?), this problem can be worked around by specifying the FORCE clause.

Generated at Thu Feb 08 09:18:19 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.