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

InnoDB: Assertion failure in thread 139946191502080 in file row0ins.cc line 285

Details

    Description

      After upgrading from 5.5 to 10.1.32 our imports of mysqldumps into warehouse database are failing...with the following in the error log.

      2018-07-12 10:39:38 7f47c3083b00  InnoDB: Assertion failure in thread 139946191502080 in file row0ins.cc line 285
      InnoDB: Failing assertion: *cursor->index->name == TEMP_INDEX_PREFIX
      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: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.
      180712 10:39:38 [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.1.32-MariaDB
      key_buffer_size=17179869184
      read_buffer_size=131072
      max_used_connections=15
      max_threads=502
      thread_count=3
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 17879995 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x7f473ed10008
      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 = 0x7f47c3083140 thread_stack 0x48400
      /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7f5937629e2b]
      /usr/sbin/mysqld(handle_fatal_signal+0x4d5)[0x7f5937186a45]
      /lib64/libpthread.so.0(+0x3ccd20f7e0)[0x7f59367807e0]
      /lib64/libc.so.6(gsignal+0x35)[0x7f5934ba6495]
      /lib64/libc.so.6(abort+0x175)[0x7f5934ba7c75]
      /usr/sbin/mysqld(+0x89c3ad)[0x7f593744d3ad]
      /usr/sbin/mysqld(+0x89e5c4)[0x7f593744f5c4]
      /usr/sbin/mysqld(+0x89e9af)[0x7f593744f9af]
      /usr/sbin/mysqld(+0x8ab4da)[0x7f593745c4da]
      /usr/sbin/mysqld(+0x80182b)[0x7f59373b282b]
      /usr/sbin/mysqld(_ZN7handler12ha_write_rowEPh+0x177)[0x7f59371905e7]
      /usr/sbin/mysqld(_Z12write_recordP3THDP5TABLEP12st_copy_info+0x71)[0x7f5936ff3ff1]
      /usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0x1291)[0x7f5936ffa8b1]
      /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x40b6)[0x7f5937010ec6]
      row/row0ins.cc:285(row_ins_sec_index_entry_by_modify)[0x7f5937015d15]
      row/row0ins.cc:3067(row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*))[0x7f59370187fe]
      row/row0mysql.cc:1445(row_insert_for_mysql(unsigned char*, row_prebuilt_t*))[0x7f5937018d9b]
      handler/ha_innodb.cc:8885(ha_innobase::write_row(unsigned char*))[0x7f59370d988f]
      sql/handler.cc:5950(handler::ha_write_row(unsigned char*))[0x7f59370d99c7]
      /lib64/libpthread.so.0(+0x3ccd207aa1)[0x7f5936778aa1]
      /lib64/libc.so.6(clone+0x6d)[0x7f5934c5cbcd]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7f47df11f020): is an invalid pointer
      Connection ID (thread ID): 2821
      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=off
       
      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.
       
      We think the query pointer is invalid, but we will try to print it anyway.
      Query: INSERT INTO `notes` VALUES
      

      Attachments

        Issue Links

          Activity

            elenst Elena Stepanova added a comment - - edited

            I brought the test case to the point when I could run bisecting. It appears that at least the non-debug assertion failure in question is gone in the current 10.1 tree, particularly after this bugfix:

            commit c4eb4bcef648eb2ebdc6edc06905f39f95ef7f6b
            Author: Marko Mäkelä <marko.makela@mariadb.com>
            Date:   Tue Jun 26 11:34:51 2018 +0300
             
                MDEV-16515 InnoDB: Failing assertion: ++retries < 10000 in file
                dict0dict.cc
                
                buf_LRU_drop_page_hash_for_tablespace(): Return whether any adaptive
                hash index entries existed. If yes, the caller should keep retrying to
                drop the adaptive hash index.
                
                row_import_for_mysql(), row_truncate_table_for_mysql(),
                row_drop_table_for_mysql(): Ensure that the adaptive hash index was
                entirely dropped for the table.
            

            I'm not yet sure that all related problems are gone, as my test case doesn't reproduce all variations easily.

            marko, what do you think – is it possible that the patch above really fixes the problem, or does it just mask it?

            Later update

            I've realized we don't have a proper stack trace anywhere in this issue, so I'm adding it to make it searchable and also for the reference, as I keep comparing this issue to other similar ones.

            10.1.29 non-debug

            Version: '10.1.29-MariaDB'  socket: '/data/logs/vardir/mysql.sock'  port: 19300  MariaDB Server
            InnoDB: error in sec index entry update in
            InnoDB: index `idx_c` of table `test`.`t1`
            InnoDB: tuple DATA TUPLE: 2 fields;
             0: len 8; hex 656d657267696e67; asc emerging;;
             1: len 4; hex 80000076; asc    v;;
             
            InnoDB: record PHYSICAL RECORD: n_fields 2; compact format; info bits 0
             0: len 9; hex 656d657267656e6379; asc emergency;;
             1: len 4; hex 80000f9b; asc     ;;
             
            TRANSACTION 1349, ACTIVE 0 sec updating or deleting
            mysql tables in use 2, locked 2
            71 lock struct(s), heap size 13864, 5193 row lock(s), undo log entries 118
            MySQL thread id 6, OS thread handle 0x7efd1ff40b00, query id 63 localhost 127.0.0.1 root Sending data
            REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 42 CON_ID 6 */
             
            InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
            2018-08-02 13:45:14 7efd1ff40b00  InnoDB: Assertion failure in thread 139625627912960 in file row0ins.cc line 285
            InnoDB: Failing assertion: *cursor->index->name == TEMP_INDEX_PREFIX
            

            #4  0x00007efd1e9ee3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6
            #5  0x000055ef4c6388ad in row_ins_sec_index_entry_by_modify (mtr=0x7efd1ff3c840, thr=0x7efcf1c2b130, entry=0x7efcf1c96068, heap=0x7efcf1c96a00, offsets_heap=0x7efcf1c96500, offsets=0x7efd1ff3c6a0, cursor=0x7efd1ff3c6e0, mode=2, flags=0) at /home/buildbot/buildbot/build/storage/xtradb/row/row0ins.cc:285
            #6  row_ins_sec_index_entry_low (flags=flags@entry=0, mode=mode@entry=2, index=index@entry=0x7efcf1c2f068, offsets_heap=offsets_heap@entry=0x7efcf1c96500, heap=heap@entry=0x7efcf1c96a00, entry=entry@entry=0x7efcf1c96068, trx_id=trx_id@entry=0, thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0ins.cc:2869
            #7  0x000055ef4c63aac4 in row_ins_sec_index_entry (index=index@entry=0x7efcf1c2f068, entry=0x7efcf1c96068, thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0ins.cc:3063
            #8  0x000055ef4c66641e in row_upd_sec_index_entry (node=node@entry=0x7efcf1ccfc48, thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2043
            #9  0x000055ef4c66a322 in row_upd_sec_step (thr=<optimized out>, node=0x7efcf1ccfc48) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2070
            #10 row_upd (thr=0x7efcf1c2b130, node=0x7efcf1ccfc48) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2877
            #11 row_upd_step (thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2994
            #12 0x000055ef4c648cd3 in row_update_for_mysql (mysql_rec=mysql_rec@entry=0x7efcf1c2e948 "\bv", prebuilt=0x7efcf1ccf068) at /home/buildbot/buildbot/build/storage/xtradb/row/row0mysql.cc:1875
            #13 0x000055ef4c597ad3 in ha_innobase::update_row (this=<optimized out>, old_row=0x7efcf1c2e948 "\bv", new_row=0x7efcf1c2e820 "\374v") at /home/buildbot/buildbot/build/storage/xtradb/handler/ha_innodb.cc:9446
            #14 0x000055ef4c37d98a in handler::ha_update_row (this=0x7efcf1c6f020, old_data=0x7efcf1c2e948 "\bv", new_data=0x7efcf1c2e820 "\374v") at /home/buildbot/buildbot/build/sql/handler.cc:6014
            #15 0x000055ef4c1e28c4 in write_record (thd=0x7efcfaeaa008, table=0x7efcf1cf1c08, info=info@entry=0x7efcf1c24f58) at /home/buildbot/buildbot/build/sql/sql_insert.cc:1856
            #16 0x000055ef4c1e2f80 in send_data (this=0x7efcf1c24f18, values=...) at /home/buildbot/buildbot/build/sql/sql_insert.cc:3710
            #17 select_insert::send_data (this=0x7efcf1c24f18, values=...) at /home/buildbot/buildbot/build/sql/sql_insert.cc:3674
            #18 0x000055ef4c2410b3 in end_send (join=0x7efcf1c24fb8, join_tab=<optimized out>, end_of_records=<optimized out>) at /home/buildbot/buildbot/build/sql/sql_select.cc:19547
            #19 end_send (join=0x7efcf1c24fb8, join_tab=<optimized out>, end_of_records=<optimized out>) at /home/buildbot/buildbot/build/sql/sql_select.cc:19517
            #20 0x000055ef4c22744f in evaluate_join_record (join=join@entry=0x7efcf1c24fb8, join_tab=join_tab@entry=0x7efcf1c277d0, error=error@entry=0) at /home/buildbot/buildbot/build/sql/sql_select.cc:18636
            #21 0x000055ef4c23102b in sub_select (join=0x7efcf1c24fb8, join_tab=0x7efcf1c277d0, end_of_records=<optimized out>) at /home/buildbot/buildbot/build/sql/sql_select.cc:18452
            #22 0x000055ef4c23ef4d in do_select (join=join@entry=0x7efcf1c24fb8, fields=fields@entry=0x7efcf1c25388, table=table@entry=0x0, procedure=0x0) at /home/buildbot/buildbot/build/sql/sql_select.cc:18068
            #23 0x000055ef4c25285e in JOIN::exec_inner (this=this@entry=0x7efcf1c24fb8) at /home/buildbot/buildbot/build/sql/sql_select.cc:3225
            #24 0x000055ef4c2547ed in JOIN::exec (this=this@entry=0x7efcf1c24fb8) at /home/buildbot/buildbot/build/sql/sql_select.cc:2512
            #25 0x000055ef4c2511ba in mysql_select (thd=thd@entry=0x7efcfaeaa008, rref_pointer_array=rref_pointer_array@entry=0x7efcfaeae2f0, tables=<optimized out>, wild_num=<optimized out>, fields=..., conds=<optimized out>, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3489958656, result=result@entry=0x7efcf1c24f18, unit=unit@entry=0x7efcfaead948, select_lex=select_lex@entry=0x7efcfaeae048) at /home/buildbot/buildbot/build/sql/sql_select.cc:3449
            #26 0x000055ef4c254ad5 in handle_select (thd=thd@entry=0x7efcfaeaa008, lex=lex@entry=0x7efcfaead880, result=result@entry=0x7efcf1c24f18, setup_tables_done_option=setup_tables_done_option@entry=1073741824) at /home/buildbot/buildbot/build/sql/sql_select.cc:384
            #27 0x000055ef4c202df3 in mysql_execute_command (thd=thd@entry=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_parse.cc:4021
            #28 0x000055ef4c2038a5 in mysql_parse (thd=0x7efcfaeaa008, rawbuf=<optimized out>, length=<optimized out>, parser_state=0x7efd1ff3f640) at /home/buildbot/buildbot/build/sql/sql_parse.cc:7344
            #29 0x000055ef4c20639e in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7efcfaeaa008, packet=0x7efcf1c24020 "REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 42 CON_ID 6 */", packet_length=58, packet_length@entry=60) at /home/buildbot/buildbot/build/sql/sql_parse.cc:1477
            #30 0x000055ef4c20690e in do_command (thd=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_parse.cc:1106
            #31 0x000055ef4c2c721f in do_handle_one_connection (thd_arg=thd_arg@entry=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_connect.cc:1349
            #32 0x000055ef4c2c7357 in handle_one_connection (arg=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_connect.cc:1261
            #33 0x00007efd1f3e5494 in start_thread (arg=0x7efd1ff40b00) at pthread_create.c:333
            #34 0x00007efd1eaa293f in clone () from /lib/x86_64-linux-gnu/libc.so.6
            

            10.1.29 debug

            Version: '10.1.29-MariaDB-debug'  socket: '/data/logs/vardir/mysql.sock'  port: 19300  Source distribution
            InnoDB: error in sec index entry update in
            InnoDB: index `idx_c` of table `test`.`t1`
            InnoDB: tuple DATA TUPLE: 2 fields;
             0: len 10; hex 696e7370656374696f6e; asc inspection;;
             1: len 4; hex 80000072; asc    r;;
             
            InnoDB: record PHYSICAL RECORD: n_fields 2; compact format; info bits 0
             0: len 6; hex 696e73697374; asc insist;;
             1: len 4; hex 80001035; asc    5;;
             
            TRANSACTION 1364, ACTIVE 0 sec updating or deleting
            mysql tables in use 2, locked 2
            71 lock struct(s), heap size 14776, 5189 row lock(s), undo log entries 114
            MySQL thread id 6, OS thread handle 0x7fe4544b9b00, query id 73 localhost 127.0.0.1 root Sending data
            REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 52 CON_ID 6 */
             
            InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
            2018-08-02 13:49:06 7fe4544b9b00  InnoDB: Assertion failure in thread 140618643512064 in file row0upd.cc line 1962
            InnoDB: Failing assertion: 0
            

            #5  0x00007fe4524ab3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6
            #6  0x0000556347346425 in row_upd_sec_index_entry (node=0x7fe425127c70, thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:1962
            #7  0x000055634734691f in row_upd_sec_step (node=0x7fe425127c70, thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:2070
            #8  0x00005563473485ae in row_upd (node=0x7fe425127c70, thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:2877
            #9  0x0000556347348893 in row_upd_step (thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:2994
            #10 0x0000556347309b29 in row_update_for_mysql (mysql_rec=0x7fe42505acb0 "\244r", prebuilt=0x7fe425127078) at /data/src/10.1.29/storage/xtradb/row/row0mysql.cc:1875
            #11 0x00005563471f9661 in ha_innobase::update_row (this=0x7fe4250bc888, old_row=0x7fe42505acb0 "\244r", new_row=0x7fe42505ab88 "\371r") at /data/src/10.1.29/storage/xtradb/handler/ha_innodb.cc:9446
            #12 0x0000556346ec95ff in handler::ha_update_row (this=0x7fe4250bc888, old_data=0x7fe42505acb0 "\244r", new_data=0x7fe42505ab88 "\371r") at /data/src/10.1.29/sql/handler.cc:6014
            #13 0x0000556346c60571 in write_record (thd=0x7fe42eb56070, table=0x7fe425138e70, info=0x7fe42504ffc0) at /data/src/10.1.29/sql/sql_insert.cc:1857
            #14 0x0000556346c6548b in select_insert::send_data (this=0x7fe42504ff80, values=...) at /data/src/10.1.29/sql/sql_insert.cc:3710
            #15 0x0000556346cec3d8 in end_send (join=0x7fe425050020, join_tab=0x7fe425052c80, end_of_records=false) at /data/src/10.1.29/sql/sql_select.cc:19547
            #16 0x0000556346cea151 in evaluate_join_record (join=0x7fe425050020, join_tab=0x7fe425052938, error=0) at /data/src/10.1.29/sql/sql_select.cc:18636
            #17 0x0000556346ce9bf7 in sub_select (join=0x7fe425050020, join_tab=0x7fe425052938, end_of_records=false) at /data/src/10.1.29/sql/sql_select.cc:18452
            #18 0x0000556346ce92c6 in do_select (join=0x7fe425050020, fields=0x7fe4250503f0, table=0x0, procedure=0x0) at /data/src/10.1.29/sql/sql_select.cc:18068
            #19 0x0000556346cc3c7e in JOIN::exec_inner (this=0x7fe425050020) at /data/src/10.1.29/sql/sql_select.cc:3225
            #20 0x0000556346cc0f0f in JOIN::exec (this=0x7fe425050020) at /data/src/10.1.29/sql/sql_select.cc:2512
            #21 0x0000556346cc44a5 in mysql_select (thd=0x7fe42eb56070, rref_pointer_array=0x7fe42eb5a518, tables=0x7fe42504f8f0, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3489958656, result=0x7fe42504ff80, unit=0x7fe42eb59b70, select_lex=0x7fe42eb5a270) at /data/src/10.1.29/sql/sql_select.cc:3449
            #22 0x0000556346cb9eae in handle_select (thd=0x7fe42eb56070, lex=0x7fe42eb59aa8, result=0x7fe42504ff80, setup_tables_done_option=1073741824) at /data/src/10.1.29/sql/sql_select.cc:384
            #23 0x0000556346c82ff8 in mysql_execute_command (thd=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_parse.cc:4021
            #24 0x0000556346c8d4bb in mysql_parse (thd=0x7fe42eb56070, rawbuf=0x7fe42504f088 "REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 52 CON_ID 6 */", length=58, parser_state=0x7fe4544b8630) at /data/src/10.1.29/sql/sql_parse.cc:7344
            #25 0x0000556346c7c064 in dispatch_command (command=COM_QUERY, thd=0x7fe42eb56070, packet=0x7fe4251a2071 " REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 52 CON_ID 6 */ ", packet_length=60) at /data/src/10.1.29/sql/sql_parse.cc:1477
            #26 0x0000556346c7ade9 in do_command (thd=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_parse.cc:1106
            #27 0x0000556346db3af1 in do_handle_one_connection (thd_arg=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_connect.cc:1349
            #28 0x0000556346db3855 in handle_one_connection (arg=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_connect.cc:1261
            #29 0x00007fe4541a6494 in start_thread (arg=0x7fe4544b9b00) at pthread_create.c:333
            #30 0x00007fe45255f93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
            

            elenst Elena Stepanova added a comment - - edited I brought the test case to the point when I could run bisecting. It appears that at least the non-debug assertion failure in question is gone in the current 10.1 tree, particularly after this bugfix: commit c4eb4bcef648eb2ebdc6edc06905f39f95ef7f6b Author: Marko Mäkelä <marko.makela@mariadb.com> Date: Tue Jun 26 11:34:51 2018 +0300   MDEV-16515 InnoDB: Failing assertion: ++retries < 10000 in file dict0dict.cc buf_LRU_drop_page_hash_for_tablespace(): Return whether any adaptive hash index entries existed. If yes, the caller should keep retrying to drop the adaptive hash index. row_import_for_mysql(), row_truncate_table_for_mysql(), row_drop_table_for_mysql(): Ensure that the adaptive hash index was entirely dropped for the table. I'm not yet sure that all related problems are gone, as my test case doesn't reproduce all variations easily. marko , what do you think – is it possible that the patch above really fixes the problem, or does it just mask it? Later update I've realized we don't have a proper stack trace anywhere in this issue, so I'm adding it to make it searchable and also for the reference, as I keep comparing this issue to other similar ones. 10.1.29 non-debug Version: '10.1.29-MariaDB' socket: '/data/logs/vardir/mysql.sock' port: 19300 MariaDB Server InnoDB: error in sec index entry update in InnoDB: index `idx_c` of table `test`.`t1` InnoDB: tuple DATA TUPLE: 2 fields; 0: len 8; hex 656d657267696e67; asc emerging;; 1: len 4; hex 80000076; asc v;;   InnoDB: record PHYSICAL RECORD: n_fields 2; compact format; info bits 0 0: len 9; hex 656d657267656e6379; asc emergency;; 1: len 4; hex 80000f9b; asc ;;   TRANSACTION 1349, ACTIVE 0 sec updating or deleting mysql tables in use 2, locked 2 71 lock struct(s), heap size 13864, 5193 row lock(s), undo log entries 118 MySQL thread id 6, OS thread handle 0x7efd1ff40b00, query id 63 localhost 127.0.0.1 root Sending data REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 42 CON_ID 6 */   InnoDB: Submit a detailed bug report to https://jira.mariadb.org/ 2018-08-02 13:45:14 7efd1ff40b00 InnoDB: Assertion failure in thread 139625627912960 in file row0ins.cc line 285 InnoDB: Failing assertion: *cursor->index->name == TEMP_INDEX_PREFIX #4 0x00007efd1e9ee3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6 #5 0x000055ef4c6388ad in row_ins_sec_index_entry_by_modify (mtr=0x7efd1ff3c840, thr=0x7efcf1c2b130, entry=0x7efcf1c96068, heap=0x7efcf1c96a00, offsets_heap=0x7efcf1c96500, offsets=0x7efd1ff3c6a0, cursor=0x7efd1ff3c6e0, mode=2, flags=0) at /home/buildbot/buildbot/build/storage/xtradb/row/row0ins.cc:285 #6 row_ins_sec_index_entry_low (flags=flags@entry=0, mode=mode@entry=2, index=index@entry=0x7efcf1c2f068, offsets_heap=offsets_heap@entry=0x7efcf1c96500, heap=heap@entry=0x7efcf1c96a00, entry=entry@entry=0x7efcf1c96068, trx_id=trx_id@entry=0, thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0ins.cc:2869 #7 0x000055ef4c63aac4 in row_ins_sec_index_entry (index=index@entry=0x7efcf1c2f068, entry=0x7efcf1c96068, thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0ins.cc:3063 #8 0x000055ef4c66641e in row_upd_sec_index_entry (node=node@entry=0x7efcf1ccfc48, thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2043 #9 0x000055ef4c66a322 in row_upd_sec_step (thr=<optimized out>, node=0x7efcf1ccfc48) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2070 #10 row_upd (thr=0x7efcf1c2b130, node=0x7efcf1ccfc48) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2877 #11 row_upd_step (thr=thr@entry=0x7efcf1c2b130) at /home/buildbot/buildbot/build/storage/xtradb/row/row0upd.cc:2994 #12 0x000055ef4c648cd3 in row_update_for_mysql (mysql_rec=mysql_rec@entry=0x7efcf1c2e948 "\bv", prebuilt=0x7efcf1ccf068) at /home/buildbot/buildbot/build/storage/xtradb/row/row0mysql.cc:1875 #13 0x000055ef4c597ad3 in ha_innobase::update_row (this=<optimized out>, old_row=0x7efcf1c2e948 "\bv", new_row=0x7efcf1c2e820 "\374v") at /home/buildbot/buildbot/build/storage/xtradb/handler/ha_innodb.cc:9446 #14 0x000055ef4c37d98a in handler::ha_update_row (this=0x7efcf1c6f020, old_data=0x7efcf1c2e948 "\bv", new_data=0x7efcf1c2e820 "\374v") at /home/buildbot/buildbot/build/sql/handler.cc:6014 #15 0x000055ef4c1e28c4 in write_record (thd=0x7efcfaeaa008, table=0x7efcf1cf1c08, info=info@entry=0x7efcf1c24f58) at /home/buildbot/buildbot/build/sql/sql_insert.cc:1856 #16 0x000055ef4c1e2f80 in send_data (this=0x7efcf1c24f18, values=...) at /home/buildbot/buildbot/build/sql/sql_insert.cc:3710 #17 select_insert::send_data (this=0x7efcf1c24f18, values=...) at /home/buildbot/buildbot/build/sql/sql_insert.cc:3674 #18 0x000055ef4c2410b3 in end_send (join=0x7efcf1c24fb8, join_tab=<optimized out>, end_of_records=<optimized out>) at /home/buildbot/buildbot/build/sql/sql_select.cc:19547 #19 end_send (join=0x7efcf1c24fb8, join_tab=<optimized out>, end_of_records=<optimized out>) at /home/buildbot/buildbot/build/sql/sql_select.cc:19517 #20 0x000055ef4c22744f in evaluate_join_record (join=join@entry=0x7efcf1c24fb8, join_tab=join_tab@entry=0x7efcf1c277d0, error=error@entry=0) at /home/buildbot/buildbot/build/sql/sql_select.cc:18636 #21 0x000055ef4c23102b in sub_select (join=0x7efcf1c24fb8, join_tab=0x7efcf1c277d0, end_of_records=<optimized out>) at /home/buildbot/buildbot/build/sql/sql_select.cc:18452 #22 0x000055ef4c23ef4d in do_select (join=join@entry=0x7efcf1c24fb8, fields=fields@entry=0x7efcf1c25388, table=table@entry=0x0, procedure=0x0) at /home/buildbot/buildbot/build/sql/sql_select.cc:18068 #23 0x000055ef4c25285e in JOIN::exec_inner (this=this@entry=0x7efcf1c24fb8) at /home/buildbot/buildbot/build/sql/sql_select.cc:3225 #24 0x000055ef4c2547ed in JOIN::exec (this=this@entry=0x7efcf1c24fb8) at /home/buildbot/buildbot/build/sql/sql_select.cc:2512 #25 0x000055ef4c2511ba in mysql_select (thd=thd@entry=0x7efcfaeaa008, rref_pointer_array=rref_pointer_array@entry=0x7efcfaeae2f0, tables=<optimized out>, wild_num=<optimized out>, fields=..., conds=<optimized out>, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3489958656, result=result@entry=0x7efcf1c24f18, unit=unit@entry=0x7efcfaead948, select_lex=select_lex@entry=0x7efcfaeae048) at /home/buildbot/buildbot/build/sql/sql_select.cc:3449 #26 0x000055ef4c254ad5 in handle_select (thd=thd@entry=0x7efcfaeaa008, lex=lex@entry=0x7efcfaead880, result=result@entry=0x7efcf1c24f18, setup_tables_done_option=setup_tables_done_option@entry=1073741824) at /home/buildbot/buildbot/build/sql/sql_select.cc:384 #27 0x000055ef4c202df3 in mysql_execute_command (thd=thd@entry=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_parse.cc:4021 #28 0x000055ef4c2038a5 in mysql_parse (thd=0x7efcfaeaa008, rawbuf=<optimized out>, length=<optimized out>, parser_state=0x7efd1ff3f640) at /home/buildbot/buildbot/build/sql/sql_parse.cc:7344 #29 0x000055ef4c20639e in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7efcfaeaa008, packet=0x7efcf1c24020 "REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 42 CON_ID 6 */", packet_length=58, packet_length@entry=60) at /home/buildbot/buildbot/build/sql/sql_parse.cc:1477 #30 0x000055ef4c20690e in do_command (thd=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_parse.cc:1106 #31 0x000055ef4c2c721f in do_handle_one_connection (thd_arg=thd_arg@entry=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_connect.cc:1349 #32 0x000055ef4c2c7357 in handle_one_connection (arg=0x7efcfaeaa008) at /home/buildbot/buildbot/build/sql/sql_connect.cc:1261 #33 0x00007efd1f3e5494 in start_thread (arg=0x7efd1ff40b00) at pthread_create.c:333 #34 0x00007efd1eaa293f in clone () from /lib/x86_64-linux-gnu/libc.so.6 10.1.29 debug Version: '10.1.29-MariaDB-debug' socket: '/data/logs/vardir/mysql.sock' port: 19300 Source distribution InnoDB: error in sec index entry update in InnoDB: index `idx_c` of table `test`.`t1` InnoDB: tuple DATA TUPLE: 2 fields; 0: len 10; hex 696e7370656374696f6e; asc inspection;; 1: len 4; hex 80000072; asc r;;   InnoDB: record PHYSICAL RECORD: n_fields 2; compact format; info bits 0 0: len 6; hex 696e73697374; asc insist;; 1: len 4; hex 80001035; asc 5;;   TRANSACTION 1364, ACTIVE 0 sec updating or deleting mysql tables in use 2, locked 2 71 lock struct(s), heap size 14776, 5189 row lock(s), undo log entries 114 MySQL thread id 6, OS thread handle 0x7fe4544b9b00, query id 73 localhost 127.0.0.1 root Sending data REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 52 CON_ID 6 */   InnoDB: Submit a detailed bug report to https://jira.mariadb.org/ 2018-08-02 13:49:06 7fe4544b9b00 InnoDB: Assertion failure in thread 140618643512064 in file row0upd.cc line 1962 InnoDB: Failing assertion: 0 #5 0x00007fe4524ab3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6 #6 0x0000556347346425 in row_upd_sec_index_entry (node=0x7fe425127c70, thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:1962 #7 0x000055634734691f in row_upd_sec_step (node=0x7fe425127c70, thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:2070 #8 0x00005563473485ae in row_upd (node=0x7fe425127c70, thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:2877 #9 0x0000556347348893 in row_upd_step (thr=0x7fe42512f140) at /data/src/10.1.29/storage/xtradb/row/row0upd.cc:2994 #10 0x0000556347309b29 in row_update_for_mysql (mysql_rec=0x7fe42505acb0 "\244r", prebuilt=0x7fe425127078) at /data/src/10.1.29/storage/xtradb/row/row0mysql.cc:1875 #11 0x00005563471f9661 in ha_innobase::update_row (this=0x7fe4250bc888, old_row=0x7fe42505acb0 "\244r", new_row=0x7fe42505ab88 "\371r") at /data/src/10.1.29/storage/xtradb/handler/ha_innodb.cc:9446 #12 0x0000556346ec95ff in handler::ha_update_row (this=0x7fe4250bc888, old_data=0x7fe42505acb0 "\244r", new_data=0x7fe42505ab88 "\371r") at /data/src/10.1.29/sql/handler.cc:6014 #13 0x0000556346c60571 in write_record (thd=0x7fe42eb56070, table=0x7fe425138e70, info=0x7fe42504ffc0) at /data/src/10.1.29/sql/sql_insert.cc:1857 #14 0x0000556346c6548b in select_insert::send_data (this=0x7fe42504ff80, values=...) at /data/src/10.1.29/sql/sql_insert.cc:3710 #15 0x0000556346cec3d8 in end_send (join=0x7fe425050020, join_tab=0x7fe425052c80, end_of_records=false) at /data/src/10.1.29/sql/sql_select.cc:19547 #16 0x0000556346cea151 in evaluate_join_record (join=0x7fe425050020, join_tab=0x7fe425052938, error=0) at /data/src/10.1.29/sql/sql_select.cc:18636 #17 0x0000556346ce9bf7 in sub_select (join=0x7fe425050020, join_tab=0x7fe425052938, end_of_records=false) at /data/src/10.1.29/sql/sql_select.cc:18452 #18 0x0000556346ce92c6 in do_select (join=0x7fe425050020, fields=0x7fe4250503f0, table=0x0, procedure=0x0) at /data/src/10.1.29/sql/sql_select.cc:18068 #19 0x0000556346cc3c7e in JOIN::exec_inner (this=0x7fe425050020) at /data/src/10.1.29/sql/sql_select.cc:3225 #20 0x0000556346cc0f0f in JOIN::exec (this=0x7fe425050020) at /data/src/10.1.29/sql/sql_select.cc:2512 #21 0x0000556346cc44a5 in mysql_select (thd=0x7fe42eb56070, rref_pointer_array=0x7fe42eb5a518, tables=0x7fe42504f8f0, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3489958656, result=0x7fe42504ff80, unit=0x7fe42eb59b70, select_lex=0x7fe42eb5a270) at /data/src/10.1.29/sql/sql_select.cc:3449 #22 0x0000556346cb9eae in handle_select (thd=0x7fe42eb56070, lex=0x7fe42eb59aa8, result=0x7fe42504ff80, setup_tables_done_option=1073741824) at /data/src/10.1.29/sql/sql_select.cc:384 #23 0x0000556346c82ff8 in mysql_execute_command (thd=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_parse.cc:4021 #24 0x0000556346c8d4bb in mysql_parse (thd=0x7fe42eb56070, rawbuf=0x7fe42504f088 "REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 52 CON_ID 6 */", length=58, parser_state=0x7fe4544b8630) at /data/src/10.1.29/sql/sql_parse.cc:7344 #25 0x0000556346c7c064 in dispatch_command (command=COM_QUERY, thd=0x7fe42eb56070, packet=0x7fe4251a2071 " REPLACE INTO `t1` SELECT * FROM `t1` /* QNO 52 CON_ID 6 */ ", packet_length=60) at /data/src/10.1.29/sql/sql_parse.cc:1477 #26 0x0000556346c7ade9 in do_command (thd=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_parse.cc:1106 #27 0x0000556346db3af1 in do_handle_one_connection (thd_arg=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_connect.cc:1349 #28 0x0000556346db3855 in handle_one_connection (arg=0x7fe42eb56070) at /data/src/10.1.29/sql/sql_connect.cc:1261 #29 0x00007fe4541a6494 in start_thread (arg=0x7fe4544b9b00) at pthread_create.c:333 #30 0x00007fe45255f93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
            marko Marko Mäkelä added a comment - - edited

            elenst, your test case uses TRUNCATE TABLE and innodb_adaptive_hash_index=ON. I think that before the MDEV-16515 fix, this can lead to corruption of the adaptive hash index (AHI). Given that the TRUNCATE would reuse the same dict_index_t objects, which buf_block_t::index is pointing to for the AHI, the corruption will not lead to an immediate crash. In DROP INDEX or DROP TABLE or similar, we would free the dict_index_t objects, and the server could crash in more spectacular ways if the freed memory was reused for something else before AHI tries to dereference a stale block->index.

            The failure mechanism would be that TRUNCATE is leaving some stale adaptive hash index entries for pages that are freed. Later, as more data is inserted, the page numbers will be reused for something else. Given that the inserted data is similar to the existing contents of the table, the byte addresses to the records in the adaptive hash index could remain valid (or they are simply pointing to pre-truncate freed pages that were not yet reused in the buffer pool). Timing is critical here.

            marko Marko Mäkelä added a comment - - edited elenst , your test case uses TRUNCATE TABLE  and innodb_adaptive_hash_index=ON . I think that before the MDEV-16515 fix, this can lead to corruption of the adaptive hash index (AHI). Given that the TRUNCATE would reuse the same dict_index_t objects, which buf_block_t::index is pointing to for the AHI, the corruption will not lead to an immediate crash. In DROP INDEX or DROP TABLE or similar, we would free the dict_index_t objects, and the server could crash in more spectacular ways if the freed memory was reused for something else before AHI tries to dereference a stale block->index . The failure mechanism would be that TRUNCATE is leaving some stale adaptive hash index entries for pages that are freed. Later, as more data is inserted, the page numbers will be reused for something else. Given that the inserted data is similar to the existing contents of the table, the byte addresses to the records in the adaptive hash index could remain valid (or they are simply pointing to pre-truncate freed pages that were not yet reused in the buffer pool). Timing is critical here.

            As joe.oreste@xpressbet.com mentioned earlier, he only gets the failure with innodb_adaptive_hash_index=ON and with TRUNCATE, so it fits.

            I think we can consider this particular variation of the problem fixed in scope of MDEV-16515, although remaining ones are still in question.

            joe.oreste@xpressbet.com, 10.1.35 should be out soon enough, then you can upgrade and see if it helps. You might also want to watch MDEV-9663, which is where the most of activity regarding related issues is happening.

            elenst Elena Stepanova added a comment - As joe.oreste@xpressbet.com mentioned earlier, he only gets the failure with innodb_adaptive_hash_index=ON and with TRUNCATE , so it fits. I think we can consider this particular variation of the problem fixed in scope of MDEV-16515 , although remaining ones are still in question. joe.oreste@xpressbet.com , 10.1.35 should be out soon enough, then you can upgrade and see if it helps. You might also want to watch MDEV-9663 , which is where the most of activity regarding related issues is happening.

            We have also tested for 24 hours replacing the TRUNCATE with DELETE FROM statement with innodb_adaptive_hash_index=ON for testing purposes and there were no crashes.

            joe.oreste@xpressbet.com Joseph Oreste (Inactive) added a comment - We have also tested for 24 hours replacing the TRUNCATE with DELETE FROM statement with innodb_adaptive_hash_index=ON for testing purposes and there were no crashes.

            Also for the record, this variation of the failure (at least what's triggered by my test case) appeared in 10.1 with this commit (released in 10.1.29):

            commit 51b4366bfb8a77c6341d7811f71c851e52f36f68
            Author: Marko Mäkelä
            Date:   Thu Nov 2 22:38:37 2017 +0200
             
                MDEV-13328 ALTER TABLE…DISCARD TABLESPACE takes a lot of time
            

            elenst Elena Stepanova added a comment - Also for the record, this variation of the failure (at least what's triggered by my test case) appeared in 10.1 with this commit (released in 10.1.29): commit 51b4366bfb8a77c6341d7811f71c851e52f36f68 Author: Marko Mäkelä Date: Thu Nov 2 22:38:37 2017 +0200   MDEV-13328 ALTER TABLE…DISCARD TABLESPACE takes a lot of time

            People

              Unassigned Unassigned
              joe.oreste@xpressbet.com Joseph Oreste (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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