Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-25796

Failing assertion: !cursor->index->is_committed() in row0ins.cc

Details

    Description

      2021-05-27 11:26:07 0x7f18d2013700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.4.19/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.
      210527 11:26:07 [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.19-MariaDB-1:10.4.19+maria~buster-log
      key_buffer_size=131072
      read_buffer_size=131072
      max_used_connections=1624
      max_threads=5002
      thread_count=1640
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11008450 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x7f17f05735d8
      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 = 0x7f18d2012dd8 thread_stack 0x49000
      /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x5644a8906f0e]
      /usr/sbin/mysqld(handle_fatal_signal+0x54d)[0x5644a83f6fbd]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7f4c83c80730]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b)[0x7f4c837d67bb]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7f4c837c1535]
      /usr/sbin/mysqld(+0x5b4700)[0x5644a80e9700]
      /usr/sbin/mysqld(+0x5a2a9e)[0x5644a80d7a9e]
      /usr/sbin/mysqld(+0xb1158e)[0x5644a864658e]
      /usr/sbin/mysqld(+0xb11c76)[0x5644a8646c76]
      /usr/sbin/mysqld(+0xb23afb)[0x5644a8658afb]
      /usr/sbin/mysqld(+0xa6cfd5)[0x5644a85a1fd5]
      /usr/sbin/mysqld(_ZN7handler12ha_write_rowEPKh+0x1af)[0x5644a8402fff]
      /usr/sbin/mysqld(_Z12write_recordP3THDP5TABLEP12st_copy_info+0x1ad)[0x5644a81b464d]
      /usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0xabf)[0x5644a81baf3f]
      /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x3636)[0x5644a81ea636]
      /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x1e9)[0x5644a81eeb09]
      /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x17f5)[0x5644a81f11d5]
      /usr/sbin/mysqld(_Z10do_commandP3THD+0x13a)[0x5644a81f23ba]
      /usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x233)[0x5644a82d64a3]
      /usr/sbin/mysqld(handle_one_connection+0x3d)[0x5644a82d659d]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7f4c83c75fa3]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f4c838984cf]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7f17f0579930): insert ignore into listing (id,type,salesman,l) values (43284937,15389,354744,"2021-05-27 11:25:53"),(46976667,14257,321914,"2021-05-27 11:25:50"),(59124647,14683,336558,"2021-05-27 11:25:52"),(74179242,13467,569131,"2021-05-27 11:25:18"),(83293122,2186,336558,"2021-05-27 11:25:25"),(98548682,14685,336558,"2021-05-27 11:25:41"),(108276337,1795,339766,"2021-05-27 11:25:50"),(108535722,14683,336558,"2021-05-27 11:25:52"),(124098502,15202,336558,"2021-05-27 11:25:10"),(132142832,13053,519582,"2021-05-27 11:25:27"),(153330807,15323,519582,"2021-05-27 11:25:15"),(163292162,15389,354744,"2021-05-27 11:25:52"),(164598142,15397,354744,"2021-05-27 11:25:53"),(169325892,2230,519582,"2021-05-27 11:25:15"),(180647207,16144,519582,"2021-05-27 11:25:14"),(183833512,2661,519582,"2021-05-27 11:25:04"),(183871592,14816,519582,"2021-05-27 11:25:04"),(202487292,15389,354744,"20
      21-05-27 11:25:52"),(203071587,15389,354744,"2021-05-27 11:25:53"),(203072967,15389,354744,"2021-05-27 11:25:53"),(208207257,14385,519582,"2021-05-27 11:25:26"),(210784182,14385,519582,"2021-05-27 11:25:23"),(216390437,13285,519582,"2021-05-27 11:25:14"),(217873877,2657,519582,"2021-05-27 11:25:14"),(222547557,11534,519582,"2021-05-27 11:25:03"),(222549277
      ,2326,519582,"2021-05-27 11:25:03"),(224041982,12346,519582,"2021-05-27 11:25:14"),(224090257,12968,519582,"2021-05-27 11:25:25"),(225865867,13775,921672,"2021-05-27 11:25:14"),(2
      26408437,13455,534960,"2021-05-27 11:25:09"),(227050127,13455,534960,"2021-05-27 11:25:10"),(227870662,15389,354744,"2021-05-27 11:25:52"),(229697237,14034,569131,"2021-05-27 11:2
      5:15"),(229977642,15427,921672,"2021-05-27 11:25:31"),(231815522,14385,519582,"2021-05-27 11:25:26"),(231843492,2666,519582,"2021-05-27 11:25:14"),(234580232,13467,534960,"2021-05
      -27 11:25:34"),(234582992,14385,519582,"2021-05-27 11:25:34"),(234612197,13810,564261,"2021-05-27 11:25:48"),(234612287,13810,564261,"2021-05-27 11:25:48"),(234612322,13810,564261
      ,"2021-05-27 11:25:48"),(234612527,14899,564261,"2021-05-27 11:25:48"),(235183782,14025,569131,"2021-05-27 11:25:15"),(238932692,14196,436304,"2021-05-27 11:25:02"),(238932697,14225,359604,"2021-05-27 11:25:10"),(238932702,14646,358612,"2021-05-27 11:25:49"),(238932707,14212,60095,"2021-05-27 11:25:25"),(238932712,2230,882100,"2021-05-27 11:25:27"),(238932717,13051,304197,"2021-05-27 11:25:34"),(238932722,14683,453828,"2021-05-27 11:25:40"),(238932727,12686,336353,"2021-05-27 11:25:42"),(238932732,14371,357931,"2021-05-27 11:25:44"),(238932737,14924,342318,"2021-05-27 11:25:47"),(238932742,14339,344562,"2021-05-27 11:25:51"),(238932747,14924,342318,"2021-05-27 11:25:58")
       
      Connection ID (thread ID): 54201
      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 /db/main/tables
      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        0                    unlimited            bytes     
      Max resident set          unlimited            unlimited            bytes     
      Max processes             1031235              1031235              processes 
      Max open files            32768                32768                files     
      Max locked memory         65536                65536                bytes     
      Max address space         unlimited            unlimited            bytes     
      Max file locks            unlimited            unlimited            locks     
      Max pending signals       1031235              1031235              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
      

      Attachments

        Issue Links

          Activity

            alexcool Alex added a comment -

            And We have corrupted indexes in tables.

            alexcool Alex added a comment - And We have corrupted indexes in tables.
            alice Alice Sherepa added a comment -

            please add the output of SHOW CREATE TABLE listing;

            alice Alice Sherepa added a comment - please add the output of SHOW CREATE TABLE listing;
            alexcool Alex added a comment -

            CREATE TABLE `listing` (
              `id` int(10) unsigned NOT NULL DEFAULT 0,
              `salesman` mediumint(8) unsigned NOT NULL DEFAULT 0,
              `type` int(11) NOT NULL DEFAULT 0,
              `l` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(),
              PRIMARY KEY (`id`),
              KEY `e_t_i` (`type`)
            ) ENGINE=InnoDB DEFAULT CHARSET=utf8
            

            alexcool Alex added a comment - CREATE TABLE `listing` ( `id` int(10) unsigned NOT NULL DEFAULT 0, `salesman` mediumint(8) unsigned NOT NULL DEFAULT 0, `type` int(11) NOT NULL DEFAULT 0, `l` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(), PRIMARY KEY (`id`), KEY `e_t_i` (`type`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8

            I think that this could have been caused by MDEV-21069 and fixed in MDEV-25869. It is also possible that the database had been corrupted earlier, before MDEV-24449 was fixed.

            The fixes of MDEV-24449 and MDEV-25869 will only prevent further corruption of the kind; they will not magically fix existing tables. Dropping the corrupted secondary index and creating it again should fix this corruption. Until you can upgrade to a fixed server, you should run with innodb_change_buffering=none. Do you still observe this failure after those steps?

            marko Marko Mäkelä added a comment - I think that this could have been caused by MDEV-21069 and fixed in MDEV-25869 . It is also possible that the database had been corrupted earlier, before MDEV-24449 was fixed. The fixes of MDEV-24449 and MDEV-25869 will only prevent further corruption of the kind; they will not magically fix existing tables. Dropping the corrupted secondary index and creating it again should fix this corruption. Until you can upgrade to a fixed server, you should run with innodb_change_buffering=none . Do you still observe this failure after those steps?
            alexcool Alex added a comment -

            When we disabled change buffer this problem was fixed

            alexcool Alex added a comment - When we disabled change buffer this problem was fixed

            alexcool, thank you. I am going to disable the change buffer by default (MDEV-27734), but only starting with 10.5. Even with the latest fixes, as reported in MDEV-26977, it can cause some corruption.

            marko Marko Mäkelä added a comment - alexcool , thank you. I am going to disable the change buffer by default ( MDEV-27734 ), but only starting with 10.5. Even with the latest fixes, as reported in MDEV-26977 , it can cause some corruption.
            alexcool Alex added a comment -

            As I understand your plan is to remove change buffer. That is kind a fine with SSD but HDD installations will suffer.

            As you can see on this graph. HDD utilisation goes down significantly after turning on Change buffer. Server has 256G of ram.

            alexcool Alex added a comment - As I understand your plan is to remove change buffer. That is kind a fine with SSD but HDD installations will suffer. As you can see on this graph. HDD utilisation goes down significantly after turning on Change buffer. Server has 256G of ram.

            alexcool, yes, I expect the change buffer to be more helpful on HDD, because it aims to convert random seeks before reads into hopefully more sequential writes (with innodb_flush_neighbors).

            The benchmarks posted in MDEV-11634 suggest that the change buffer does not help much on SSD. Similar benchmarks on HDD should be run, to get a more complete picture.

            The buffer pool and page flushing changes in 10.5 could have improved the HDD utilization. I would think that configuring a very large redo log (maybe even larger than the buffer pool) can reduce the number of page writes and thus leave some more bandwidth available for page reads. Perhaps we could implement improved logic for triggering read-ahead, to reduce latency in cases that are currently helped by the change buffer.

            marko Marko Mäkelä added a comment - alexcool , yes, I expect the change buffer to be more helpful on HDD, because it aims to convert random seeks before reads into hopefully more sequential writes (with innodb_flush_neighbors ). The benchmarks posted in MDEV-11634 suggest that the change buffer does not help much on SSD. Similar benchmarks on HDD should be run, to get a more complete picture. The buffer pool and page flushing changes in 10.5 could have improved the HDD utilization. I would think that configuring a very large redo log (maybe even larger than the buffer pool) can reduce the number of page writes and thus leave some more bandwidth available for page reads. Perhaps we could implement improved logic for triggering read-ahead, to reduce latency in cases that are currently helped by the change buffer.

            People

              marko Marko Mäkelä
              alexcool Alex
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.