[MDEV-27145] Failing assertion: !cursor->index->is_committed() in row0ins.cc Created: 2021-11-30  Updated: 2023-11-23  Resolved: 2023-06-02

Status: Closed
Project: MariaDB Server
Component/s: Data Manipulation - Insert, Storage Engine - InnoDB
Affects Version/s: 10.4.18
Fix Version/s: 10.6.15, 10.9.8, 10.10.6, 10.11.5, 11.0.3, 11.1.2

Type: Bug Priority: Major
Reporter: lilei Assignee: Marko Mäkelä
Resolution: Duplicate Votes: 2
Labels: innodb
Environment:

linux


Attachments: File 10.6.5 crash     HTML File table info    
Issue Links:
Duplicate
duplicates MDEV-22739 !cursor->index->is_committed() in row... Closed
Relates
relates to MDEV-23713 Replication stops with "Index for tab... Stalled
relates to MDEV-27751 InnoDB: Failing assertion: !cursor->i... Closed
relates to MDEV-27744 LPAD in vcol created in ORACLE mode m... Closed

 Description   

2021-11-30 17:52:47 0x7fedbc6ec640  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.4.18/storage/innobase/row/row0ins.cc line 218
InnoDB: Failing assertion: !cursor->index->is_committed()
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/innodb-recovery-modes/
InnoDB: about forcing recovery.
211130 17:52:47 [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.4.18-MariaDB-1:10.4.18+maria~focal-log
key_buffer_size=134217728
read_buffer_size=2097152
max_used_connections=2
max_threads=508
thread_count=24
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3499843 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7fed40000c48
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 = 0x7fedbc6ebd68 thread_stack 0x80000
mysqld(my_print_stacktrace+0x32)[0x55c5291aa192]
mysqld(handle_fatal_signal+0x55d)[0x55c528c6154d]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x14bb0)[0x7ff14857bbb0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcb)[0x7ff147c5f8cb]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x116)[0x7ff147c44864]
2021-11-30 17:52:47 3959 [Warning] Aborted connection 3959 to db: 'unconnected' user: 'unauthenticated' host: '192.192.192.21' (Got an error reading communication packets)
 
mysqld(+0x5b0d47)[0x55c52892ed47]
mysqld(+0x59dcf4)[0x55c52891bcf4]
mysqld(+0xb5dadb)[0x55c528edbadb]
mysqld(+0xb5ff71)[0x55c528eddf71]
mysqld(+0xb712a0)[0x55c528eef2a0]
mysqld(+0xab52ba)[0x55c528e332ba]
mysqld(_ZN7handler12ha_write_rowEPKh+0x13a)[0x55c528c6f22a]
mysqld(_ZN14Rows_log_event9write_rowEP14rpl_group_infob+0x184)[0x55c528d7bdf4]
mysqld(_ZN20Write_rows_log_event11do_exec_rowEP14rpl_group_info+0x81)[0x55c528d7c3f1]
mysqld(_ZN14Rows_log_event14do_apply_eventEP14rpl_group_info+0x23f)[0x55c528d7031f]
mysqld(_Z18wsrep_apply_eventsP3THDP14Relay_log_infoPKvm+0x1b9)[0x55c528bdb779]
mysqld(_ZN21Wsrep_applier_service15apply_write_setERKN5wsrep7ws_metaERKNS0_12const_bufferERNS0_14mutable_bufferE+0xa3)[0x55c528bc3a03]
mysqld(+0xe99ca0)[0x55c529217ca0]
mysqld(_ZN5wsrep12server_state8on_applyERNS_21high_priority_serviceERKNS_9ws_handleERKNS_7ws_metaERKNS_12const_bufferE+0xc1)[0x55c529218cf1]
mysqld(+0xeac04c)[0x55c52922a04c]
/usr/lib/galera/libgalera_smm.so(+0x6241b)[0x7ff146e7e41b]
/usr/lib/galera/libgalera_smm.so(+0x7426e)[0x7ff146e9026e]
/usr/lib/galera/libgalera_smm.so(+0x76dd8)[0x7ff146e92dd8]
/usr/lib/galera/libgalera_smm.so(+0xaaa82)[0x7ff146ec6a82]
/usr/lib/galera/libgalera_smm.so(+0xaac0b)[0x7ff146ec6c0b]
 
/usr/lib/galera/libgalera_smm.so(+0xaae02)[0x7ff146ec6e02]
/usr/lib/galera/libgalera_smm.so(+0x777d0)[0x7ff146e937d0]
/usr/lib/galera/libgalera_smm.so(+0x4cdf1)[0x7ff146e68df1]
mysqld(_ZN5wsrep18wsrep_provider_v2611run_applierEPNS_21high_priority_serviceE+0x12)[0x55c52922a592]
mysqld(+0x85f5f3)[0x55c528bdd5f3]
mysqld(_Z15start_wsrep_THDPv+0x2ec)[0x55c528bce89c]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x9590)[0x7ff148570590]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7ff147d37223]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7ff1275a7edb): replace INTO `tb_6` (`id`, `parentid`, `name`, `size`, `manage_id`, `toindex`) VALUES ('BC2431B654A3403E939BC04EBCDBFD26', '0688233D1FAF4F8EB0C01EF658B68E29', '109521141068-0110', -1, '6AA84E63AC9349F5ACCFB35F9C6DB511', 'company_0_2')
 
Connection ID (thread ID): 19
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=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
 
The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
information that should help you find out what is causing the crash.
Writing a core file...
Working directory at /var/lib/rds-mariadb/mariadb_data
Resource Limits:
Limit                     Soft Limit           Hard Limit           Units
Max cpu time              unlimited            unlimited            seconds
Max file size             unlimited            unlimited            bytes
Max data size             unlimited            unlimited            bytes
Max stack size            8388608              unlimited            bytes
Max core file size        unlimited            unlimited            bytes
Max resident set          unlimited            unlimited            bytes
Max processes             unlimited            unlimited            processes
Max open files            1048576              1048576              files
Max locked memory         65536                65536                bytes
Max address space         unlimited            unlimited            bytes
Max file locks            unlimited            unlimited            locks
Max pending signals       1028617              1028617              signals
Max msgqueue size         819200               819200               bytes
Max nice priority         0                    0
Max realtime priority     0                    0
Max realtime timeout      unlimited            unlimited            us
Core pattern: core
 
Fatal signal 11 while backtracing



 Comments   
Comment by Roy Bellingan [ 2021-11-30 ]

Running on a 10.6.5
I too started to encounter this bug a few minutes ago, what I did is change the master from which I am reading the replication log, as you know is an imperfect task and I had to put a
set global slave_exec_mode = "IDEMPOTENT";
After restarting the slave, at most 5 second and the error is triggered, I will now try to truncate the table that is giving me problem, and see if other table trigger the error.
This happened already 5 times (i updated from 10.6.4 but same error still)
I attached the relevant stack trace.

We just had now another crash in another table (I think I can not update attachment)

2021-11-30 18:47:39 386370 [ERROR] InnoDB: Record in index `dateCET` of table `turboProp`.`expenditureRollup` was not found on update: TUPLE (info_bits=0, 2 fields):

{NULL,[4] *(0x800FB02A)}

at: COMPACT RECORD(info_bits=0, 2 fields):

{NULL,[4] )(0x800FB029)}

2021-11-30 18:47:39 0x7f1198186700
InnoDB: Assertion failure in file /home/buildbot/buildbot/build/storage/innobase/row/row0ins.cc line 221
InnoDB: Failing assertion: !cursor->index->is_committed()

Comment by Alice Sherepa [ 2021-11-30 ]

Could you please add the output of SHOW CREATE TABLE ?

Comment by Roy Bellingan [ 2021-11-30 ]

Some table where failing, I will attach all of them with a brief description of what the usual traffic is about (table info).
I am sorry for not having more stack trace and crash info, as the error log file grow immensely and in the hurry I just truncated it

Comment by lilei [ 2021-12-01 ]

CREATE TABLE `tb_6` (
`id` varchar(40) COLLATE utf8mb4_unicode_ci NOT NULL,
`parentid` varchar(40) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
`otag` varchar(40) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
`name` varchar(2048) COLLATE utf8mb4_unicode_ci NOT NULL,
`size` bigint(20) DEFAULT NULL,
`filetype` varchar(250) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
`manage_id` varchar(40) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
`toindex` varchar(32) COLLATE utf8mb4_unicode_ci NOT NULL COMMENT '???????',
PRIMARY KEY (`id`),
KEY `id_tb_6` (`id`),
KEY `parentId_tb_6` (`parentid`),
KEY `manage_id_tb_6` (`manage_id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci;

----------------- 原始邮件 -----------------
发件人: "Alice Sherepa (Jira)" <jira@mariadb.org>;
发送时间: 2021年12月1日(星期三) 凌晨4:48
收件人: ""<781747824@qq.com>;

主题: [JIRA] (MDEV-27145) 数据库崩溃

    [ https://jira.mariadb.org/browse/MDEV-27145?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&amp;focusedCommentId=207259#comment-207259 ]

Alice Sherepa 在 MDEV-27145中留言:
--------------------------------------

Could you please add the output of SHOW CREATE TABLE ?

> 数据库崩溃
> -----
>
>                 关键字: MDEV-27145
>                 URL: https://jira.mariadb.org/browse/MDEV-27145
>                  项目: MariaDB Server
>                问题类型: 故障
>                  模块: Data Manipulation - Insert
>                影响版本: 10.4.18
>                  环境: linux
>                 报告人: lilei
>                 优先级: 严重
>                  标签: innodb, need_feedback
>                  附件: 10.6.5 crash
>
>
> 2021-11-30 17:52:47 0x7fedbc6ec640  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.4.18/storage/innobase/row/row0ins.cc line 218
> InnoDB: Failing assertion: !cursor->index->is_committed()
> 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/innodb-recovery-modes/
> InnoDB: about forcing recovery.
> 211130 17:52:47 [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.4.18-MariaDB-1:10.4.18+maria~focal-log
> key_buffer_size=134217728
> read_buffer_size=2097152
> max_used_connections=2
> max_threads=508
> thread_count=24
> It is possible that mysqld could use up to
> key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3499843 K  bytes of memory
> Hope that's ok; if not, decrease some variables in the equation.
> Thread pointer: 0x7fed40000c48
> 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 = 0x7fedbc6ebd68 thread_stack 0x80000
> mysqld(my_print_stacktrace+0x32)[0x55c5291aa192]
> mysqld(handle_fatal_signal+0x55d)[0x55c528c6154d]
> /lib/x86_64-linux-gnu/libpthread.so.0(+0x14bb0)[0x7ff14857bbb0]
> /lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcb)[0x7ff147c5f8cb]
> /lib/x86_64-linux-gnu/libc.so.6(abort+0x116)[0x7ff147c44864]
> 2021-11-30 17:52:47 3959 [Warning] Aborted connection 3959 to db: 'unconnected' user: 'unauthenticated' host: '192.192.192.21' (Got an error reading communication packets)
> mysqld(+0x5b0d47)[0x55c52892ed47]
> mysqld(+0x59dcf4)[0x55c52891bcf4]
> mysqld(+0xb5dadb)[0x55c528edbadb]
> mysqld(+0xb5ff71)[0x55c528eddf71]
> mysqld(+0xb712a0)[0x55c528eef2a0]
> mysqld(+0xab52ba)[0x55c528e332ba]
> mysqld(_ZN7handler12ha_write_rowEPKh+0x13a)[0x55c528c6f22a]
> mysqld(_ZN14Rows_log_event9write_rowEP14rpl_group_infob+0x184)[0x55c528d7bdf4]
> mysqld(_ZN20Write_rows_log_event11do_exec_rowEP14rpl_group_info+0x81)[0x55c528d7c3f1]
> mysqld(_ZN14Rows_log_event14do_apply_eventEP14rpl_group_info+0x23f)[0x55c528d7031f]
> mysqld(_Z18wsrep_apply_eventsP3THDP14Relay_log_infoPKvm+0x1b9)[0x55c528bdb779]
> mysqld(_ZN21Wsrep_applier_service15apply_write_setERKN5wsrep7ws_metaERKNS0_12const_bufferERNS0_14mutable_bufferE+0xa3)[0x55c528bc3a03]
> mysqld(+0xe99ca0)[0x55c529217ca0]
> mysqld(_ZN5wsrep12server_state8on_applyERNS_21high_priority_serviceERKNS_9ws_handleERKNS_7ws_metaERKNS_12const_bufferE+0xc1)[0x55c529218cf1]
> mysqld(+0xeac04c)[0x55c52922a04c]
> /usr/lib/galera/libgalera_smm.so(+0x6241b)[0x7ff146e7e41b]
> /usr/lib/galera/libgalera_smm.so(+0x7426e)[0x7ff146e9026e]
> /usr/lib/galera/libgalera_smm.so(+0x76dd8)[0x7ff146e92dd8]
> /usr/lib/galera/libgalera_smm.so(+0xaaa82)[0x7ff146ec6a82]
> /usr/lib/galera/libgalera_smm.so(+0xaac0b)[0x7ff146ec6c0b]
> /usr/lib/galera/libgalera_smm.so(+0xaae02)[0x7ff146ec6e02]
> /usr/lib/galera/libgalera_smm.so(+0x777d0)[0x7ff146e937d0]
> /usr/lib/galera/libgalera_smm.so(+0x4cdf1)[0x7ff146e68df1]
> mysqld(_ZN5wsrep18wsrep_provider_v2611run_applierEPNS_21high_priority_serviceE+0x12)[0x55c52922a592]
> mysqld(+0x85f5f3)[0x55c528bdd5f3]
> mysqld(_Z15start_wsrep_THDPv+0x2ec)[0x55c528bce89c]
> /lib/x86_64-linux-gnu/libpthread.so.0(+0x9590)[0x7ff148570590]
> /lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7ff147d37223]
> Trying to get some variables.
> Some pointers may be invalid and cause the dump to abort.
> Query (0x7ff1275a7edb): replace INTO `tb_6` (`id`, `parentid`, `name`, `size`, `manage_id`, `toindex`) VALUES ('BC2431B654A3403E939BC04EBCDBFD26', '0688233D1FAF4F8EB0C01EF658B68E29', '109521141068-0110', -1, '6AA84E63AC9349F5ACCFB35F9C6DB511', 'company_0_2')
> Connection ID (thread ID): 19
> 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=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
> The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
> information that should help you find out what is causing the crash.
> Writing a core file...
> Working directory at /var/lib/rds-mariadb/mariadb_data
> Resource Limits:
> Limit                     Soft Limit           Hard Limit           Units
> Max cpu time              unlimited            unlimited            seconds
> Max file size             unlimited            unlimited            bytes
> Max data size             unlimited            unlimited            bytes
> Max stack size            8388608              unlimited            bytes
> Max core file size        unlimited            unlimited            bytes
> Max resident set          unlimited            unlimited            bytes
> Max processes             unlimited            unlimited            processes
> Max open files            1048576              1048576              files
> Max locked memory         65536                65536                bytes
> Max address space         unlimited            unlimited            bytes
> Max file locks            unlimited            unlimited            locks
> Max pending signals       1028617              1028617              signals
> Max msgqueue size         819200               819200               bytes
> Max nice priority         0                    0
> Max realtime priority     0                    0
> Max realtime timeout      unlimited            unlimited            us
> Core pattern: core
> Fatal signal 11 while backtracing


这条信息是由Atlassian Jira发送的
(v8.13.13#813013)

Comment by Seppo Jaakola [ 2021-12-01 ]

The stack trace of muzisanshi shows that the this mariadb server is a node in galera cluster and crashes during applying of the write row event.
However, it looks like RoyBellingan is reporting similar issue, but happening now with asycn replication, is that correct understanding?

Comment by Roy Bellingan [ 2021-12-01 ]

@Seppo Jaakola Yes, in my case is a normal async replication (no parallel, single threaded, no gtid, row based replication)

Comment by Miguel P [ 2023-01-19 ]

This seems to be the same as MDEV-27145. I'm also affected by this on MariaDB 10.3.36-MariaDB-0+deb10u2-log. It started happening somewhat randomly on a system that had been replicating for a year, after a reboot.

Normal async replication. Master is the same and has binlog-format=ROW, InnoDB tables and a couple of MyISAM tables that I've added to ignore-table. Dumps obtained with single-transaction. I cannot set replication to work correctly - tried GTID and no GTID, innodb_change_buffering=all or none, mysqldump or mydumper, won't matter: on start it'll immediately encounter an inconsistency error as if I didn't get a consistent backup, and if you try to skip the error in any way (sql_slave_skip_counter=1, slave_skip_errors, etc.) it'll start crash looping with InnoDB: Assertion failure in file /build/mariadb-10.3-lMTCRk/mariadb-10.3-10.3.36/storage/innobase/row/row0ins.cc line 221
InnoDB: Failing assertion: !cursor->index->is_committed()

No idea what to do.

Comment by Miguel P [ 2023-01-20 ]

UPDATE: Finally found what was breaking our replication. Indices on GENERATED columns (which are pretty much the point of a GENERATED column — without indexing they're just pre-made aliases for convenience). These break replication and point-in-time recovery, but the funny thing is that they corrupt who knows what, then replication reports inconsistency errors in a different table (in our case, it tended to be on tables which had no GENERATED columns), then if these errors are attempted to be skipped or worked around, MySQL would start crash looping with said assertion. The workaround is to stay clear of GENERATED anything; just use a physical column with a trigger, at least on 10.3.

Comment by Marko Mäkelä [ 2023-06-02 ]

MDEV-22739 had already been filed for this assertion failure. The fix of MDEV-22739 is to replace the assertion failure with propagating the error up the call stack, in the spirit of MDEV-13542.

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