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

Rollback of insert fails when column reorder happens

Details

    Description

      MariaDB origin/10.4 ea912d1605b463a16a0c186bf10e61c4af519439 2020-05-18T12:14:50+02:00
      		 
       
      		 
      Version: '10.4.14-MariaDB-debug-log'  socket: ....
      		 
      mysqld: /storage/innobase/row/row0log.cc:1183: dberr_t row_log_table_get_pk_col(const dict_field_t*, const dict_index_t*, dfield_t*, mem_heap_t*, const rec_t*, const rec_offs*, ulint, ulint, ulint, const row_log_t*): Assertion `0' failed.
      		 
      ...
      		 
      Query (0x7f1b90011470): ROLLBACK
      		 
      Connection ID (thread ID): 45
      		 
      Status: NOT_KILLED
      		 
       
      		 
      (rr) bt
      		 
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
      		 
      #1  0x00007f1ca5426801 in __GI_abort () at abort.c:79
      		 
      #2  0x00007f1ca541639a in __assert_fail_base (fmt=0x7f1ca559d7d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x563d88969df1 "0", file=file@entry=0x563d8896b5a8 "/home/mleich/10.4/storage/innobase/row/row0log.cc", 
          line=line@entry=1183,
      		 
          function=function@entry=0x563d8896e6a0 <row_log_table_get_pk_col(dict_field_t const*, dict_index_t const*, dfield_t*, mem_block_info_t*, unsigned char const*, unsigned short const*, unsigned long, unsigned long, unsigned long, row_log_t const*)::__PRETTY_FUNCTION__> "dberr_t row_log_table_get_pk_col(const dict_field_t*, const dict_index_t*, dfield_t*, mem_heap_t*, const rec_t*, const rec_offs*, ulint, ulint, ulint, const row_log_t*)") at assert.c:92
      		 
      #3  0x00007f1ca5416412 in __GI___assert_fail (assertion=0x563d88969df1 "0", file=0x563d8896b5a8 "/home/mleich/10.4/storage/innobase/row/row0log.cc", line=1183, 
          function=0x563d8896e6a0 <row_log_table_get_pk_col(dict_field_t const*, dict_index_t const*, dfield_t*, mem_block_info_t*, unsigned char const*, unsigned short const*, unsigned long, unsigned long, unsigned long, row_log_t const*)::__PRETTY_FUNCTION__> "dberr_t row_log_table_get_pk_col(const dict_field_t*, const dict_index_t*, dfield_t*, mem_heap_t*, const rec_t*, const rec_offs*, ulint, ulint, ulint, const row_log_t*)") at assert.c:101
      		 
      #4  0x0000563d88077005 in row_log_table_get_pk_col (ifield=0x7f1bdc0327b8, index=0x7f1bdc032480, dfield=0x7f1b9001ff88, heap=0x7f1b9001fed0, rec=0x7f1c82b90112 "", offsets=0x7f1b900320f0, i=8, zip_size=0, max_len=3072, log=0x7f1bdc04a160)
      		 
          at /home/mleich/10.4/storage/innobase/row/row0log.cc:1183
      		 
      #5  0x0000563d88077ac2 in row_log_table_get_pk (rec=0x7f1c82b90112 "", index=0x7f1be0030320, offsets=0x7f1b900320f0, sys=0x0, heap=0x7f1bc9278c68) at /home/mleich/10.4/storage/innobase/row/row0log.cc:1350
      		 
      #6  0x0000563d88074838 in row_log_table_delete (rec=0x7f1c82b90112 "", index=0x7f1be0030320, offsets=0x7f1b900320f0, sys=0x0) at /home/mleich/10.4/storage/innobase/row/row0log.cc:729
      		 
      #7  0x0000563d882f1016 in row_undo_ins_remove_clust_rec (node=0x7f1b90025750) at /home/mleich/10.4/storage/innobase/row/row0uins.cc:123
      		 
      #8  0x0000563d882f2add in row_undo_ins (node=0x7f1b90025750, thr=0x7f1be8025930) at /home/mleich/10.4/storage/innobase/row/row0uins.cc:587
      		 
      #9  0x0000563d880b503e in row_undo (node=0x7f1b90025750, thr=0x7f1be8025930) at /home/mleich/10.4/storage/innobase/row/row0undo.cc:438
      		 
      #10 0x0000563d880b5314 in row_undo_step (thr=0x7f1be8025930) at /home/mleich/10.4/storage/innobase/row/row0undo.cc:499
      		 
      #11 0x0000563d87ff82ee in que_thr_step (thr=0x7f1be8025930) at /home/mleich/10.4/storage/innobase/que/que0que.cc:1037
      		 
      #12 0x0000563d87ff85a1 in que_run_threads_low (thr=0x7f1be8025930) at /home/mleich/10.4/storage/innobase/que/que0que.cc:1101
      		 
      #13 0x0000563d87ff87ef in que_run_threads (thr=0x7f1be8025930) at /home/mleich/10.4/storage/innobase/que/que0que.cc:1141
      		 
      #14 0x0000563d8811c4c5 in trx_rollback_to_savepoint_low (trx=0x7f1c8f6a11a0, savept=0x0) at /home/mleich/10.4/storage/innobase/trx/trx0roll.cc:136
      		 
      #15 0x0000563d8811c960 in trx_rollback_for_mysql_low (trx=0x7f1c8f6a11a0) at /home/mleich/10.4/storage/innobase/trx/trx0roll.cc:210
      		 
      #16 0x0000563d8811ce3d in trx_rollback_for_mysql (trx=0x7f1c8f6a11a0) at /home/mleich/10.4/storage/innobase/trx/trx0roll.cc:240
      		 
      #17 0x0000563d87eb7292 in innobase_rollback (hton=0x563d8aa89598, thd=0x7f1b90000ce8, rollback_trx=true) at /home/mleich/10.4/storage/innobase/handler/ha_innodb.cc:4690
      		 
      #18 0x0000563d87c727ed in ha_rollback_trans (thd=0x7f1b90000ce8, all=true) at /home/mleich/10.4/sql/handler.cc:1886
      		 
      #19 0x0000563d87ab26e8 in trans_rollback (thd=0x7f1b90000ce8) at /home/mleich/10.4/sql/transaction.cc:341
      		 
      #20 0x0000563d879209ab in mysql_execute_command (thd=0x7f1b90000ce8) at /home/mleich/10.4/sql/sql_parse.cc:5658
      		 
      #21 0x0000563d8792786d in mysql_parse (thd=0x7f1b90000ce8, rawbuf=0x7f1b90011470 "ROLLBACK  /* E_R Thread29 QNO 53 CON_ID 45 */", length=45, parser_state=0x7f1bc927a5a0, is_com_multi=false, is_next_command=false)
      		 
          at /home/mleich/10.4/sql/sql_parse.cc:7900
      		 
      #22 0x0000563d87913e28 in dispatch_command (command=COM_QUERY, thd=0x7f1b90000ce8, packet=0x7f1b90008119 " ROLLBACK  /* E_R Thread29 QNO 53 CON_ID 45 */ ", packet_length=47, is_com_multi=false, is_next_command=false)
      		 
          at /home/mleich/10.4/sql/sql_parse.cc:1841
      		 
      #23 0x0000563d879125c9 in do_command (thd=0x7f1b90000ce8) at /home/mleich/10.4/sql/sql_parse.cc:1359
      		 
      #24 0x0000563d87a99bf8 in do_handle_one_connection (connect=0x563d8b583228) at /home/mleich/10.4/sql/sql_connect.cc:1412
      		 
      #25 0x0000563d87a99947 in handle_one_connection (arg=0x563d8b583228) at /home/mleich/10.4/sql/sql_connect.cc:1316
      		 
      #26 0x00007f1ca63216db in start_thread (arg=0x7f1bc927b700) at pthread_create.c:463
      		 
      #27 0x00007f1ca550788f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      		 
      (rr)
      		 
       
      		 
       
      		 
       
      		 
      RQG:
      		 
      git clone https://github.com/mleich1/rqg --branch experimental RQG_mleich
      		 
      777f2c8c46aa3df3dab625b02972490b479c0aa8 2020-05-16T18:38:04+02:00
      		 
       
      		 
      perl rqg.pl \                   
      --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
      		 
      --grammar=conf/mariadb/table_stress_innodb.yy \
      		 
      --gendata=conf/mariadb/table_stress.zz \
      		 
      --gendata_sql=conf/mariadb/table_stress.sql \
      		 
      --engine=Innodb \
      		 
      --reporters=Deadlock1,ErrorLog,Backtrace \
      		 
      --mysqld=--connect_timeout=60 \
      		 
      --mysqld=--net_read_timeout=30 \
      		 
      --mysqld=--net_write_timeout=60 \
      		 
      --mysqld=--loose-idle_readonly_transaction_timeout=0 \
      		 
      --mysqld=--loose-idle_transaction_timeout=0 \
      		 
      --mysqld=--loose-idle_write_transaction_timeout=0 \
      		 
      --mysqld=--interactive_timeout=28800 \
      		 
      --mysqld=--lock_wait_timeout=86400 \
      		 
      --mysqld=--innodb-lock-wait-timeout=50 \
      		 
      --mysqld=--loose-table_lock_wait_timeout=50 \
      		 
      --mysqld=--wait_timeout=28800 \
      		 
      --mysqld=--slave_net_timeout=60 \
      		 
      --mysqld=--loose-max-statement-time=30 \
      		 
      --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
      		 
      --mysqld=--log-output=none \
      		 
      --duration=300 \
      		 
      --seed=random \
      		 
      --sqltrace=MarkErrors \
      		 
      --threads=33 \
      		 
      --mysqld=--innodb_adaptive_hash_index=OFF \
      		 
      --mysqld=--innodb_page_size=64K \
      		 
      --mysqld=--innodb-buffer-pool-size=256M \
      		 
      --no_mask \
      		 
      --workdir=...
      		 
      ...

      Attachments

        Issue Links

          duplicates

          Bug - A problem which impairs or prevents the functions of the product. MDEV-18334 Assertion `len <= col->len || ((col->mtype) == 5 || (col->mtype) == 14) || (col->len == 0 && col->mtype == 1)' failed in rec_get_converted_size_comp_prefix_low

          • Critical - Crashes, loss of data, severe memory leak.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            thiru Thirunarayanan Balathandayuthapani added a comment - - edited

            Test case:

            --source include/have_innodb.inc
            		 
            SET @@SQL_MODE = REPLACE(@@SQL_MODE, 'STRICT_TRANS_TABLES', '');
            		 
            SET @@SQL_MODE = REPLACE(@@SQL_MODE, 'STRICT_ALL_TABLES', '');
            		 
            CREATE TABLE t1(f1 int not null, f2 char(100),
            		 
                            f3 char(100),
            		 
                            f4 int not null, f5 int not null,
            		 
                            f6 char(100))engine=innodb;
            		 
            INSERT INTO t1 VALUES(1, "This is column2", "This is f3",
            		 
                                  4, 4, "This is f6");
            		 
            ALTER TABLE t1 DROP COLUMN f4, DROP COLUMN f5;
            		 
            set DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL scanned WAIT_FOR insert_done';
            		 
            --send ALTER TABLE t1 ADD PRIMARY KEY (f6(10), f3(10), f2(10)), ALGORITHM=INPLACE
            		 
            connect(con1,localhost,root,,);
            		 
            SET DEBUG_SYNC = 'now WAIT_FOR scanned';
            		 
            begin;
            		 
            insert into t1(f1, f2) values(2, "This is column2 value");
            		 
            rollback;
            		 
            set DEBUG_SYNC = 'now SIGNAL insert_done';
            		 
             
            		 
            connection default;
            		 
            reap;
            		 
            SELECT * FROM t1;
            		 
            disconnect con1;
            		 
            DROP TABLE t1;
            		 
            SET SQL_MODE=DEFAULT;

            thiru Thirunarayanan Balathandayuthapani added a comment - - edited Test case: --source include/have_innodb.inc SET @@SQL_MODE = REPLACE (@@SQL_MODE, 'STRICT_TRANS_TABLES' , '' ); SET @@SQL_MODE = REPLACE (@@SQL_MODE, 'STRICT_ALL_TABLES' , '' ); CREATE TABLE t1(f1 int not null , f2 char (100), f3 char (100), f4 int not null , f5 int not null , f6 char (100))engine=innodb; INSERT INTO t1 VALUES (1, "This is column2" , "This is f3" , 4, 4, "This is f6" ); ALTER TABLE t1 DROP COLUMN f4, DROP COLUMN f5; set DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL scanned WAIT_FOR insert_done' ; --send ALTER TABLE t1 ADD PRIMARY KEY (f6(10), f3(10), f2(10)), ALGORITHM=INPLACE connect (con1,localhost,root,,); SET DEBUG_SYNC = 'now WAIT_FOR scanned' ; begin ; insert into t1(f1, f2) values (2, "This is column2 value" ); rollback ; set DEBUG_SYNC = 'now SIGNAL insert_done' ;   connection default ; reap; SELECT * FROM t1; disconnect con1; DROP TABLE t1; SET SQL_MODE= DEFAULT ;
            marko Marko Mäkelä added a comment -

            Thank you. The proposed fix looks correct to me, but please read and address my comments. I suspect that also 10.3 is affected (and could deliver wrong results). Can you investigate more?

            marko Marko Mäkelä added a comment - Thank you. The proposed fix looks correct to me, but please read and address my comments. I suspect that also 10.3 is affected (and could deliver wrong results). Can you investigate more?
            thiru Thirunarayanan Balathandayuthapani added a comment -

            Patch is in bb-10.3-thiru

            thiru Thirunarayanan Balathandayuthapani added a comment - Patch is in bb-10.3-thiru
            marko Marko Mäkelä added a comment -

            Thanks! I sent one comment, questioning the access to log->old_table->field. I think that one more review is needed.

            marko Marko Mäkelä added a comment - Thanks! I sent one comment, questioning the access to log->old_table->field . I think that one more review is needed.
            thiru Thirunarayanan Balathandayuthapani added a comment -

            mleich The issues you pasted which're not relevant to this bug. I will check ASAN failure and create it as a seperate issue

            Closing this bug with following commit:

            commit 7476e8c7cdd73d60294126a2840baee97e7644b6 (HEAD -> 10.3, origin/10.3, 10.3-sample)
            		 
            Author: Thirunarayanan Balathandayuthapani <thiru@mariadb.com>
            		 
            Date:   Mon May 25 21:42:26 2020 +0530
            		 
             
            		 
                MDEV-22637 Rollback of insert fails when column reorder happens

            thiru Thirunarayanan Balathandayuthapani added a comment - mleich The issues you pasted which're not relevant to this bug. I will check ASAN failure and create it as a seperate issue Closing this bug with following commit: commit 7476e8c7cdd73d60294126a2840baee97e7644b6 (HEAD -> 10.3, origin/10.3, 10.3-sample) Author: Thirunarayanan Balathandayuthapani <thiru@mariadb.com> Date: Mon May 25 21:42:26 2020 +0530   MDEV-22637 Rollback of insert fails when column reorder happens

            People

              thiru Thirunarayanan Balathandayuthapani
              mleich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              4 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.