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

Various crashes & asserts and UBSAN null pointer passed as argument 2 in trx_undo_report_row_operation

    XMLWordPrintable

Details

    Description

      Strong suspicion that this issue is in InnoDB. Also see first comment in MDEV-26217 which has a similar stack but looks otherwise unrelated. Issue seems to be a combination of unforeseen circumstances converging. Whilst not proven, corruption seems a possibility. Note that enforce-storage-engine=InnoDB cannot be on startup (MDEV-26372). Testcase may be lightly sporadic.

      # mysqld options required for replay: --enforce-storage-engine=InnoDB 
      SET sql_mode='';
      ALTER TABLE mysql.slow_log ENGINE=MyISAM;
      SET tx_read_only=1;
      SET SESSION long_query_time=0;
      SET SESSION slow_query_log=1;
      SET GLOBAL slow_query_log=1;
      SET GLOBAL log_output='TABLE,FILE';
      ALTER TABLE mysql.slow_log ENGINE=MyISAM;
      

      Leads to:

      10.6.5 9ac1ac006197c8979db1dc73f4e983f623e831e8 (Optimized)

      Core was generated by `/test/MD160821-mariadb-10.6.5-linux-x86_64-opt/bin/mysqld --no-defaults --core-'.
      Program terminated with signal SIGSEGV, Segmentation fault.
      #0  0x00005604205cc1b9 in std::__atomic_base<unsigned int>::compare_exchange_strong (__m2=std::memory_order_relaxed, __m1=std::memory_order_acquire, 
          __i2=2147483648, __i1=<synthetic pointer>: 0, this=0x8)
          at /usr/include/c++/9/bits/atomic_base.h:493
      493	      compare_exchange_strong(__int_type& __i1, __int_type __i2,
      [Current thread is 1 (Thread 0x14c5c5560700 (LWP 2521451))]
      (gdb) bt
      #0  0x00005604205cc1b9 in std::__atomic_base<unsigned int>::compare_exchange_strong (__m2=std::memory_order_relaxed, __m1=std::memory_order_acquire, __i2=2147483648, __i1=<synthetic pointer>: 0, this=0x8) at /usr/include/c++/9/bits/atomic_base.h:493
      #1  srw_mutex::wr_lock_try (this=0x8) at /test/10.6_opt/storage/innobase/include/srw_lock.h:65
      #2  srw_mutex::wr_lock (this=0x8) at /test/10.6_opt/storage/innobase/include/srw_lock.h:70
      #3  ssux_lock_low::wr_lock (this=0x8) at /test/10.6_opt/storage/innobase/include/srw_lock.h:212
      #4  trx_undo_assign_low (trx=trx@entry=0x14c5c781a130, rseg=rseg@entry=0x0, undo=undo@entry=0x14c5c781b0e0, err=err@entry=0x14c5c555bc84, mtr=mtr@entry=0x14c5c555bcd0) at /test/10.6_opt/storage/innobase/trx/trx0undo.cc:1208
      #5  0x00005604205ad76c in trx_undo_report_row_operation (thr=thr@entry=0x14c590033960, index=index@entry=0x14c59002e310, clust_entry=clust_entry@entry=0x14c59002ee50, update=update@entry=0x0, cmpl_info=cmpl_info@entry=0, rec=rec@entry=0x0, offsets=0x0, roll_ptr=0x14c5c555ce80) at /test/10.6_opt/storage/innobase/trx/trx0rec.cc:2065
      #6  0x00005604205f66db in btr_cur_ins_lock_and_undo (inherit=0x14c5c555ce67, mtr=0x14c5c555d870, thr=0x14c590033960, entry=0x14c59002ee50, cursor=0x14c5c555d120, flags=0) at /test/10.6_opt/storage/innobase/btr/btr0cur.cc:3300
      #7  btr_cur_optimistic_insert (flags=0, cursor=0x14c5c555d120, offsets=offsets@entry=0x14c5c555d108, heap=heap@entry=0x14c5c555d100, entry=entry@entry=0x14c59002ee50, rec=rec@entry=0x14c5c555d118, big_rec=0x14c5c555d0f8, n_ext=<optimized out>, thr=0x14c590033960, mtr=0x14c5c555d870) at /test/10.6_opt/storage/innobase/btr/btr0cur.cc:3527
      #8  0x000056042055e72d in row_ins_clust_index_entry_low (flags=<optimized out>, mode=<optimized out>, index=0x14c59002e310, n_uniq=<optimized out>, entry=0x14c59002ee50, n_ext=<optimized out>, thr=<optimized out>) at /test/10.6_opt/storage/innobase/row/row0ins.cc:2752
      #9  0x0000560420560039 in row_ins_clust_index_entry (index=0x14c59002e310, entry=0x14c59002ee50, thr=0x14c590033960, n_ext=0) at /test/10.6_opt/storage/innobase/row/row0ins.cc:3225
      #10 0x0000560420560729 in row_ins_index_entry (thr=0x14c590033960, entry=<optimized out>, index=<optimized out>) at /test/10.6_opt/storage/innobase/row/row0ins.cc:3351
      #11 row_ins_index_entry_step (thr=0x14c590033960, node=<optimized out>) at /test/10.6_opt/storage/innobase/row/row0ins.cc:3519
      #12 row_ins (thr=0x14c590033960, node=<optimized out>) at /test/10.6_opt/storage/innobase/row/row0ins.cc:3665
      #13 row_ins_step (thr=thr@entry=0x14c590033960) at /test/10.6_opt/storage/innobase/row/row0ins.cc:3811
      #14 0x0000560420570865 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x14c590028190 "a\031\355\231\f\336\321\031", prebuilt=0x14c5900328d0, ins_mode=ROW_INS_NORMAL) at /test/10.6_opt/storage/innobase/row/row0mysql.cc:1342
      #15 0x00005604204c0e6a in ha_innobase::write_row (this=0x14c590027420, record=0x14c590028190 "a\031\355\231\f\336\321\031") at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:7781
      #16 0x00005604201b3360 in handler::ha_write_row (this=0x14c590027420, buf=0x14c590028190 "a\031\355\231\f\336\321\031") at /test/10.6_opt/sql/handler.cc:7514
      #17 0x00005604202a0629 in Log_to_csv_event_handler::log_slow (this=<optimized out>, thd=0x14c590000c58, current_time=<optimized out>, user_host=0x14c5c555f0e0 "root[root] @ localhost []", user_host_len=25, query_utime=<optimized out>, lock_utime=0, is_command=false, sql_text=0x14c590010840 "SET GLOBAL log_output='TABLE,FILE'", sql_text_len=34) at /test/10.6_opt/sql/log.cc:1004
      #18 0x000056042029a8ea in LOGGER::slow_log_print (this=0x5604210e1b80 <logger>, thd=0x14c590000c58, query=0x14c590010840 "SET GLOBAL log_output='TABLE,FILE'", query_length=34, current_utime=<optimized out>) at /test/10.6_opt/sql/log.cc:1371
      #19 0x000056041ff6e0d7 in log_slow_statement (thd=thd@entry=0x14c590000c58) at /test/10.6_opt/sql/sql_class.h:1357
      #20 0x000056041ff738f6 in dispatch_command (command=COM_QUERY, thd=0x14c590000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:2428
      #21 0x000056041ff763e7 in do_command (thd=0x14c590000c58, blocking=blocking@entry=true) at /test/10.6_opt/sql/sql_parse.cc:1404
      #22 0x0000560420084ef7 in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/10.6_opt/sql/sql_connect.cc:1418
      #23 0x000056042008523d in handle_one_connection (arg=arg@entry=0x560422bf6558) at /test/10.6_opt/sql/sql_connect.cc:1312
      #24 0x000056042040f778 in pfs_spawn_thread (arg=0x560422b78888) at /test/10.6_opt/storage/perfschema/pfs.cc:2201
      #25 0x000014c5dc8ea609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #26 0x000014c5dc4d8293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      10.7.0 52505bf20de0ce77a5c0b0a74af021051987bb0d (Debug)

      mysqld: /test/10.7_dbg/storage/innobase/trx/trx0rec.cc:2058: dberr_t trx_undo_report_row_operation(que_thr_t*, dict_index_t*, const dtuple_t*, const upd_t*, ulint, const rec_t*, const rec_offs*, roll_ptr_t*): Assertion `!trx->read_only' failed.
      

      10.7.0 52505bf20de0ce77a5c0b0a74af021051987bb0d (Debug)

      Core was generated by `/test/MD160821-mariadb-10.7.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      [Current thread is 1 (Thread 0x14ce60130700 (LWP 3553419))]
      (gdb) bt
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #1  0x000014ce6a796859 in __GI_abort () at abort.c:79
      #2  0x000014ce6a796729 in __assert_fail_base (fmt=0x14ce6a92c588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x56173ed669b1 "!trx->read_only", file=0x56173ed66c30 "/test/10.7_dbg/storage/innobase/trx/trx0rec.cc", line=2058, function=<optimized out>) at assert.c:92
      #3  0x000014ce6a7a7f36 in __GI___assert_fail (assertion=assertion@entry=0x56173ed669b1 "!trx->read_only", file=file@entry=0x56173ed66c30 "/test/10.7_dbg/storage/innobase/trx/trx0rec.cc", line=line@entry=2058, function=function@entry=0x56173ed677d8 "dberr_t trx_undo_report_row_operation(que_thr_t*, dict_index_t*, const dtuple_t*, const upd_t*, ulint, const rec_t*, const rec_offs*, roll_ptr_t*)") at assert.c:101
      #4  0x000056173e6fa607 in trx_undo_report_row_operation (thr=thr@entry=0x14ce08026688, index=index@entry=0x14ce08038858, clust_entry=clust_entry@entry=0x14ce08039658, update=update@entry=0x0, cmpl_info=cmpl_info@entry=0, rec=rec@entry=0x0, offsets=0x0, roll_ptr=0x14ce6012cbf0) at /test/10.7_dbg/storage/innobase/trx/trx0rec.cc:2058
      #5  0x000056173e754fad in btr_cur_ins_lock_and_undo (flags=flags@entry=0, cursor=cursor@entry=0x14ce6012d100, entry=entry@entry=0x14ce08039658, thr=thr@entry=0x14ce08026688, mtr=mtr@entry=0x14ce6012d6b0, inherit=inherit@entry=0x14ce6012ccd7) at /test/10.7_dbg/storage/innobase/btr/btr0cur.cc:3300
      #6  0x000056173e75ba06 in btr_cur_optimistic_insert (flags=flags@entry=0, cursor=cursor@entry=0x14ce6012d100, offsets=offsets@entry=0x14ce6012d0c8, heap=heap@entry=0x14ce6012d0c0, entry=entry@entry=0x14ce08039658, rec=rec@entry=0x14ce6012d0d8, big_rec=0x14ce6012d0b8, n_ext=<optimized out>, thr=0x14ce08026688, mtr=0x14ce6012d6b0) at /test/10.7_dbg/storage/innobase/btr/btr0cur.cc:3527
      #7  0x000056173e63d3ee in row_ins_clust_index_entry_low (flags=flags@entry=0, mode=<optimized out>, mode@entry=2, index=index@entry=0x14ce08038858, n_uniq=n_uniq@entry=0, entry=entry@entry=0x14ce08039658, n_ext=n_ext@entry=0, thr=<optimized out>) at /test/10.7_dbg/storage/innobase/row/row0ins.cc:2752
      #8  0x000056173e63efe1 in row_ins_clust_index_entry (index=index@entry=0x14ce08038858, entry=entry@entry=0x14ce08039658, thr=thr@entry=0x14ce08026688, n_ext=n_ext@entry=0) at /test/10.7_dbg/storage/innobase/row/row0ins.cc:3225
      #9  0x000056173e643ef7 in row_ins_index_entry (thr=0x14ce08026688, entry=0x14ce08039658, index=0x14ce08038858) at /test/10.7_dbg/storage/innobase/row/row0ins.cc:3351
      #10 row_ins_index_entry_step (thr=0x14ce08026688, node=0x14ce08025d08) at /test/10.7_dbg/storage/innobase/row/row0ins.cc:3519
      #11 row_ins (thr=0x14ce08026688, node=0x14ce08025d08) at /test/10.7_dbg/storage/innobase/row/row0ins.cc:3665
      #12 row_ins_step (thr=thr@entry=0x14ce08026688) at /test/10.7_dbg/storage/innobase/row/row0ins.cc:3811
      #13 0x000056173e667c26 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x14ce080205c0 "a\031\362\257\n\255\317\031", prebuilt=0x14ce080255d8, ins_mode=ROW_INS_NORMAL) at /test/10.7_dbg/storage/innobase/row/row0mysql.cc:1342
      #14 0x000056173e4f0b87 in ha_innobase::write_row (this=0x14ce0802d170, record=0x14ce080205c0 "a\031\362\257\n\255\317\031") at /test/10.7_dbg/storage/innobase/handler/ha_innodb.cc:7776
      #15 0x000056173e1549c5 in handler::ha_write_row (this=0x14ce0802d170, buf=0x14ce080205c0 "a\031\362\257\n\255\317\031") at /test/10.7_dbg/sql/handler.cc:7514
      #16 0x000056173e291b15 in Log_to_csv_event_handler::log_slow (this=<optimized out>, thd=0x14ce08000db8, current_time=<optimized out>, user_host=0x14ce6012f060 "root[root] @ localhost []", user_host_len=25, query_utime=<optimized out>, lock_utime=0, is_command=false, sql_text=0x14ce08013d20 "SET GLOBAL log_output='TABLE,FILE'", sql_text_len=34) at /test/10.7_dbg/sql/log.cc:1004
      #17 0x000056173e28a1f7 in LOGGER::slow_log_print (this=this@entry=0x56173f4436c0 <logger>, thd=thd@entry=0x14ce08000db8, query=0x14ce08013d20 "SET GLOBAL log_output='TABLE,FILE'", query_length=34, current_utime=<optimized out>) at /test/10.7_dbg/sql/log.cc:1371
      #18 0x000056173e293614 in slow_log_print (thd=thd@entry=0x14ce08000db8, query=<optimized out>, query_length=<optimized out>, current_utime=<optimized out>) at /test/10.7_dbg/sql/log.cc:6831
      #19 0x000056173de3d2eb in log_slow_statement (thd=thd@entry=0x14ce08000db8) at /test/10.7_dbg/sql/sql_class.h:1357
      #20 0x000056173de46982 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14ce08000db8, packet=<optimized out>, packet@entry=0x14ce0800b7d9 "", packet_length=packet_length@entry=34, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_parse.cc:2428
      #21 0x000056173de47ae9 in do_command (thd=0x14ce08000db8, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_parse.cc:1404
      #22 0x000056173dfbddd6 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x561740fb6358, put_in_cache=put_in_cache@entry=true) at /test/10.7_dbg/sql/sql_connect.cc:1418
      #23 0x000056173dfbe3db in handle_one_connection (arg=arg@entry=0x561740fb6358) at /test/10.7_dbg/sql/sql_connect.cc:1312
      #24 0x000056173e426ce4 in pfs_spawn_thread (arg=0x561740edf038) at /test/10.7_dbg/storage/perfschema/pfs.cc:2201
      #25 0x000014ce6aca5609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #26 0x000014ce6a893293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Bug confirmed present in:
      MariaDB: 10.2.41 (dbg), 10.2.41 (opt), 10.3.32 (dbg), 10.3.32 (opt), 10.4.22 (dbg), 10.4.22 (opt), 10.5.13 (dbg), 10.5.13 (opt), 10.6.5 (dbg), 10.6.5 (opt), 10.7.0 (dbg), 10.7.0 (opt)

      Bug (or feature/syntax) confirmed not present in:
      MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.35 (dbg), 5.7.35 (opt), 8.0.26 (dbg), 8.0.26 (opt)

      Attachments

        Issue Links

          Activity

            People

              sanja Oleksandr Byelkin
              Roel Roel Van de Paar
              Votes:
              0 Vote for this issue
              Watchers:
              3 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.