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

0x7fe2d0125700 InnoDB: Assertion failure in file /build/mariadb-10.3-V9JMsi/mariadb-10.3-10.3.23/storage/innobase/row/row0ins.cc line 234

    XMLWordPrintable

    Details

      Description

      This is the second time this happened. The master slave configuration was ok but at some point I created a new generated column ("dirty") on a table ("f2pfeed") and also I created an index on it. It went ok for the master but after a few hours I saw that the slave crashed with an error similar with what is below. I dumped the master to an SQL file and imported from scratch again into the slave and then it crashed again (see the low below)

      2020-10-03 11:52:16 46 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='10.8.5.12', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='10.8.5.12', master_port='3306', master_log_file='mysql-bin.000082', master_log_pos='373267861'.
      2020-10-03 11:52:19 51 [Note] Slave I/O thread: Start asynchronous replication to master 'root@10.8.5.12:3306' in log 'mysql-bin.000082' at position 373267861
      2020-10-03 11:52:19 52 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000082' at position 373267861, relay log '/var/log/mysql/mysql-relay-bin.000001' position: 4
      2020-10-03 11:52:19 51 [Note] Slave I/O thread: connected to master 'root@10.8.5.12:3306',replication started in log 'mysql-bin.000082' at position 373267861
      2020-10-03 11:57:36 0x7f0cd80c7700 InnoDB: Assertion failure in file /build/mariadb-10.3-V9JMsi/mariadb-10.3-10.3.23/storage/innobase/row/row0ins.cc line 234
      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.
      201003 11:57:36 [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.3.23-MariaDB-0+deb10u1-log
      key_buffer_size=20971520
      read_buffer_size=131072
      max_used_connections=3
      max_threads=5002
      thread_count=11
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11017471 K bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.

      Thread pointer: 0x7f081400f4a8
      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 = 0x7f0cd80c6728 thread_stack 0x30000
      /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55c4103e6b7e]
      /usr/sbin/mysqld(handle_fatal_signal+0x54d)[0x55c40ff197ad]
      2020-10-03 11:57:37 0 [ERROR] InnoDB: Unable to find a record to delete-mark
      InnoDB: tuple DATA TUPLE: 2 fields;
      0: SQL NULL;
      1: len 4; hex 8a864968; asc Ih;;

      InnoDB: record PHYSICAL RECORD: n_fields 1; compact format; info bits 0
      0: len 8; hex 696e66696d756d00; asc infimum ;;
      2020-10-03 11:57:37 0 [ERROR] InnoDB: page [page id: space=54, page number=79] (1546 records, index id 303).
      2020-10-03 11:57:37 0 [ERROR] InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7f0cdb1d6730]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b)[0x7f0cda7937bb]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7f0cda77e535]
      /usr/sbin/mysqld(+0x4daa75)[0x55c40fc5fa75]
      /usr/sbin/mysqld(+0x4c8683)[0x55c40fc4d683]
      /usr/sbin/mysqld(+0x9a5d7c)[0x55c41012ad7c]
      /usr/sbin/mysqld(+0x9d8bd8)[0x55c41015dbd8]
      /usr/sbin/mysqld(+0x9dda77)[0x55c410162a77]
      /usr/sbin/mysqld(+0x9b6344)[0x55c41013b344]
      /usr/sbin/mysqld(+0x910fcc)[0x55c410095fcc]
      /usr/sbin/mysqld(ZN7handler13ha_update_rowEPKhS1+0x102)[0x55c40ff240b2]
      /usr/sbin/mysqld(_ZN21Update_rows_log_event11do_exec_rowEP14rpl_group_info+0x243)[0x55c410002543]
      /usr/sbin/mysqld(_ZN14Rows_log_event14do_apply_eventEP14rpl_group_info+0x22f)[0x55c40fff5e0f]
      /usr/sbin/mysqld(+0x52c6d2)[0x55c40fcb16d2]
      /usr/sbin/mysqld(handle_slave_sql+0x12bf)[0x55c40fcba2af]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7f0cdb1cbfa3]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f0cda8554cf]

      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x0):
      Connection ID (thread ID): 52
      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,split_materialized=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.
      Writing a core file...
      Working directory at /storage-data/mysql
      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 193076 193076 processes
      Max open files 16364 16364 files
      Max locked memory 65536 65536 bytes
      Max address space unlimited unlimited bytes
      Max file locks unlimited unlimited locks
      Max pending signals 193076 193076 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: co...
      2020-10-03 11:57:47 0 [Note] Using unique option prefix 'myisam-reco...' is error-prone and can break in the future. Please use the full name 'myisam-recover-options' instead.
      2020-10-03 11:57:47 0 [Note] InnoDB: Using Linux native AIO
      2020-10-03 11:57:47 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2020-10-03 11:57:47 0 [Note] InnoDB: Uses event mutexes
      2020-10-03 11:57:47 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2020-10-03 11:57:47 0 [Note] InnoDB: Number of pools: 1
      2020-10-03 11:57:47 0 [Note] InnoDB: Using SSE2 crc32 instructions
      2020-10-03 11:57:47 0 [Note] InnoDB: Initializing buffer pool, total size = 16G, instances = 8, chunk size = 128M
      2020-10-03 11:57:48 0 [Note] InnoDB: Completed initialization of buffer pool
      2020-10-03 11:57:48 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2020-10-03 11:57:48 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=122405715514
      2020-10-03 11:57:48 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 1 row operations to undo
      2020-10-03 11:57:48 0 [Note] InnoDB: Trx id counter is 100624
      2020-10-03 11:57:48 0 [Note] InnoDB: Starting final batch to recover 105 pages from redo log.
      2020-10-03 11:57:49 0 [Note] InnoDB: Last binlog file '/var/log/mysql/mysql-bin.004101', position 431097105
      2020-10-03 11:57:49 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
      2020-10-03 11:57:49 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
      2020-10-03 11:57:49 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
      2020-10-03 11:57:49 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      2020-10-03 11:57:49 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2020-10-03 11:57:49 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2020-10-03 11:57:49 0 [Note] InnoDB: Waiting for purge to start
      2020-10-03 11:57:49 0 [Note] InnoDB: 10.3.23 started; log sequence number 122405758777; transaction id 100626
      2020-10-03 11:57:49 0 [Note] InnoDB: Loading buffer pool(s) from /storage-data/mysql/ib_buffer_pool
      2020-10-03 11:57:49 0 [Note] Plugin 'FEEDBACK' is disabled.
      2020-10-03 11:57:49 0 [Note] Recovering after a crash using /var/log/mysql/mysql-bin
      2020-10-03 11:57:49 0 [Warning] InnoDB: Record in index `dirty` of table `jinglero`.`f2pfeed` was not found on rollback, trying to insert: TUPLE (info_bits=0, 2 fields):

      {NULL,[4] Ih(0x8A864968)} at: COMPACT RECORD(info_bits=0, 1 fields): {[8]infimum (0x696E66696D756D00)}
      2020-10-03 11:57:49 0 [Warning] InnoDB: Record in index `dirty` of table `jinglero`.`f2pfeed` was not found on rollback, trying to insert: TUPLE (info_bits=0, 2 fields): {NULL,[4] Ih(0x8A864968)}

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

      {[8]infimum (0x696E66696D756D00)}
      2020-10-03 11:57:49 0 [Note] InnoDB: Rolled back recovered transaction 100623
      2020-10-03 11:57:49 0 [Note] InnoDB: Rollback of non-prepared transactions completed
      2020-10-03 11:57:50 0 [Note] Starting crash recovery...
      2020-10-03 11:57:50 0 [Note] Crash recovery finished.
      2020-10-03 11:57:50 0 [Note] InnoDB: Buffer pool(s) load completed at 201003 11:57:50
      2020-10-03 11:57:50 0 [Note] Server socket created on IP: '10.8.5.13'.
      2020-10-03 11:57:50 0 [Warning] 'user' entry 'root@her' ignored in --skip-name-resolve mode.
      2020-10-03 11:57:50 0 [Warning] 'user' entry 'root@#' ignored in --skip-name-resolve mode.
      2020-10-03 11:57:50 0 [Warning] 'proxies_priv' entry '@% root@her' ignored in --skip-name-resolve mode.
      2020-10-03 11:57:50 0 [Note] Reading of all Master_info entries succeeded
      2020-10-03 11:57:50 0 [Note] Added new Master_info '' to hash table
      2020-10-03 11:57:53 10 [Note] Slave I/O thread: Start asynchronous replication to master 'root@10.8.5.12:3306' in log 'mysql-bin.000082' at position 377673453
      2020-10-03 11:57:53 11 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000082' at position 377651604, relay log '/var/log/mysql/mysql-relay-bin.000002' position: 4371685
      2020-10-03 11:57:53 10 [Note] Slave I/O thread: connected to master 'root@10.8.5.12:3306',replication started in log 'mysql-bin.000082' at position 377673453
      2020-10-03 11:57:54 0 [Note] /usr/sbin/mysqld: ready for connections.
      Version: '10.3.23-MariaDB-0+deb10u1-log' socket: '/run/mysqld/mysqld.sock' port: 3306 Debian 10
      2020-10-03 11:57:54 11 [ERROR] InnoDB: Record in index `dirty` of table `jinglero`.`f2pfeed` was not found on update: TUPLE (info_bits=0, 2 fields): {NULL,[4] Ib(0x8A864962)} at: COMPACT RECORD(info_bits=0, 1 fields): {[8]infimum (0x696E66696D756D00)}

      2020-10-03 11:57:54 0x7fb09c0d2700 InnoDB: Assertion failure in file /build/mariadb-10.3-V9JMsi/mariadb-10.3-10.3.23/storage/innobase/row/row0ins.cc line 234
      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.
      201003 11:57:54 [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.3.23-MariaDB-0+deb10u1-log
      key_buffer_size=20971520
      read_buffer_size=131072
      max_used_connections=1
      max_threads=5002
      thread_count=10
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11017471 K bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.

      Thread pointer: 0x7fb018001508
      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 = 0x7fb09c0d1728 thread_stack 0x30000
      /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55de3b192b7e]
      /usr/sbin/mysqld(handle_fatal_signal+0x54d)[0x55de3acc57ad]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7fb4de494730]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b)[0x7fb4dda517bb]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7fb4dda3c535]
      /usr/sbin/mysqld(+0x4daa75)[0x55de3aa0ba75]
      /usr/sbin/mysqld(+0x4c8683)[0x55de3a9f9683]
      /usr/sbin/mysqld(+0x9a5d7c)[0x55de3aed6d7c]
      /usr/sbin/mysqld(+0x9d8bd8)[0x55de3af09bd8]
      /usr/sbin/mysqld(+0x9dda77)[0x55de3af0ea77]
      /usr/sbin/mysqld(+0x9b6344)[0x55de3aee7344]
      /usr/sbin/mysqld(+0x910fcc)[0x55de3ae41fcc]
      /usr/sbin/mysqld(ZN7handler13ha_update_rowEPKhS1+0x102)[0x55de3acd00b2]
      /usr/sbin/mysqld(_ZN21Update_rows_log_event11do_exec_rowEP14rpl_group_info+0x243)[0x55de3adae543]
      /usr/sbin/mysqld(_ZN14Rows_log_event14do_apply_eventEP14rpl_group_info+0x22f)[0x55de3ada1e0f]
      /usr/sbin/mysqld(+0x52c6d2)[0x55de3aa5d6d2]
      /usr/sbin/mysqld(handle_slave_sql+0x12bf)[0x55de3aa662af]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7fb4de489fa3]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fb4ddb134cf]

      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x0):
      Connection ID (thread ID): 11
      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,split_materialized=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.
      Writing a core file...
      Working directory at /storage-data/my...
      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 193076 193076 processes
      Max open files 16364 16364 files
      Max locked memory 65536 65536 bytes
      Max address space unlimited unlimited bytes
      Max file locks unlimited unlimited locks
      Max pending signals 193076 193076 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: co...
      2020-10-03 11:58:00 0 [Note] Using unique option prefix 'myisam-reco...' is error-prone and can break in the future. Please use the full name 'myisam-recover-options' instead.
      2020-10-03 11:58:00 0 [Note] InnoDB: Using Linux native AIO
      2020-10-03 11:58:00 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2020-10-03 11:58:00 0 [Note] InnoDB: Uses event mutexes
      2020-10-03 11:58:00 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2020-10-03 11:58:00 0 [Note] InnoDB: Number of pools: 1
      2020-10-03 11:58:00 0 [Note] InnoDB: Using SSE2 crc32 instructions
      2020-10-03 11:58:00 0 [Note] InnoDB: Initializing buffer pool, total size = 16G, instances = 8, chunk size = 128M
      2020-10-03 11:58:01 0 [Note] InnoDB: Completed initialization of buffer pool
      2020-10-03 11:58:01 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2020-10-03 11:58:01 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=122405771843
      2020-10-03 11:58:01 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 1 row operations to undo
      2020-10-03 11:58:01 0 [Note] InnoDB: Trx id counter is 100639
      2020-10-03 11:58:01 0 [Note] InnoDB: Starting final batch to recover 118 pages from redo log.
      2020-10-03 11:58:01 0 [Note] InnoDB: Last binlog file '/var/log/mysql/mysql-bin.004101', position 431097105
      2020-10-03 11:58:01 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
      2020-10-03 11:58:01 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
      2020-10-03 11:58:01 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
      2020-10-03 11:58:01 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      2020-10-03 11:58:01 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2020-10-03 11:58:01 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2020-10-03 11:58:01 0 [Warning] InnoDB: Record in index `dirty` of table `jinglero`.`f2pfeed` was not found on rollback, trying to insert: TUPLE (info_bits=0, 2 fields):

      {NULL,[4] Ib(0x8A864962)}

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

      {[8]infimum (0x696E66696D756D00)}

      2020-10-03 11:58:01 0 [Note] InnoDB: Rolled back recovered transaction 100636
      2020-10-03 11:58:01 0 [Note] InnoDB: Rollback of non-prepared transactions completed
      2020-10-03 11:58:01 0 [Note] InnoDB: Waiting for purge to start
      2020-10-03 11:58:01 0 [Note] InnoDB: 10.3.23 started; log sequence number 122405775730; transaction id 100642
      2020-10-03 11:58:01 0 [Note] InnoDB: Loading buffer pool(s) from /storage-data/mysql/ib_buffer_pool
      2020-10-03 11:58:01 0 [Note] Plugin 'FEEDBACK' is disabled.
      2020-10-03 11:58:01 0 [Note] Recovering after a crash using /var/log/mysql/mysql-bin
      2020-10-03 11:58:01 0 [Note] Starting crash recovery...
      2020-10-03 11:58:01 0 [Note] Crash recovery finished.
      2020-10-03 11:58:02 0 [Note] InnoDB: Buffer pool(s) load completed at 201003 11:58:02
      2020-10-03 11:58:02 0 [Note] Server socket created on IP: '10.8.5.13'.
      2020-10-03 11:58:02 0 [Warning] 'user' entry 'root@her' ignored in --skip-name-resolve mode.
      2020-10-03 11:58:02 0 [Warning] 'user' entry 'root@#' ignored in --skip-name-resolve mode.
      2020-10-03 11:58:02 0 [Warning] 'proxies_priv' entry '@% root@her' ignored in --skip-name-resolve mode.
      2020-10-03 11:58:02 0 [Note] Reading of all Master_info entries succeeded
      2020-10-03 11:58:02 0 [Note] Added new Master_info '' to hash table

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            puthre Valentin Zagura
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Git Integration