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

Crash in rollback of a recovered INSERT transaction after upgrade

Details

    Description

      2017-08-10 17:48:57 140405466861632 [Note] InnoDB: Completed initialization of buffer pool
      		 
      2017-08-10 17:48:57 140404724037376 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      		 
      2017-08-10 17:48:57 140405466861632 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 1 row operations to undo
      		 
      2017-08-10 17:48:57 140405466861632 [Note] InnoDB: Trx id counter is 7424
      		 
      2017-08-10 17:48:57 140405466861632 [Note] InnoDB: Upgrading redo log: 2*50331648 bytes; LSN=9779797
      		 
      2017-08-10 17:48:57 140405466861632 [Note] InnoDB: Starting to delete and rewrite log files.
      		 
      2017-08-10 17:48:57 140405466861632 [Note] InnoDB: Setting log file ./ib_logfile101 size to 50331648 bytes
      		 
      2017-08-10 17:48:57 140405466861632 [Note] InnoDB: Setting log file ./ib_logfile1 size to 50331648 bytes
      		 
      2017-08-10 17:48:58 140405466861632 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
      		 
      2017-08-10 17:48:58 140405466861632 [Note] InnoDB: New log files created, LSN=9779797
      		 
      2017-08-10 17:48:58 140404715644672 [Note] InnoDB: Starting in background the rollback of recovered transactions
      		 
      2017-08-10 17:48:58 140405466861632 [Note] InnoDB: 128 out of 128 rollback segments are active.
      		 
      2017-08-10 17:48:58 140404715644672 [Note] InnoDB: Rolling back trx with id 6568, 1 rows to undo
      		 
      2017-08-10 17:48:58 140405466861632 [Note] InnoDB: Creating shared tablespace for temporary tables
      		 
      2017-08-10 17:48:58 140405466861632 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      		 
      mysqld: /data/src/10.3/storage/innobase/trx/trx0trx.cc:1918: void trx_commit_low(trx_t*, mtr_t*): Assertion `!mtr == !trx->has_logged()' failed.
      		 
      170810 17:48:58 [ERROR] mysqld got signal 6 ;

      10.3 73297f532fba89e33785460448e93f87478c2505

      		 
      #3  0x00007f3ff87f7ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
      		 
      #4  0x0000565165cfad75 in trx_commit_low (trx=0x7f3ff5406878, mtr=0x7f3fce337470) at /data/src/10.3/storage/innobase/trx/trx0trx.cc:1918
      		 
      #5  0x0000565165cfafcc in trx_commit (trx=0x7f3ff5406878) at /data/src/10.3/storage/innobase/trx/trx0trx.cc:2018
      		 
      #6  0x0000565165cee5c2 in trx_rollback_finish (trx=0x7f3ff5406878) at /data/src/10.3/storage/innobase/trx/trx0roll.cc:1147
      		 
      #7  0x0000565165cecf5b in trx_rollback_active (trx=0x7f3ff5406878) at /data/src/10.3/storage/innobase/trx/trx0roll.cc:689
      		 
      #8  0x0000565165ced427 in trx_rollback_resurrected (trx=0x7f3ff5406878, all=1) at /data/src/10.3/storage/innobase/trx/trx0roll.cc:773
      		 
      #9  0x0000565165ced6d6 in trx_rollback_or_clean_recovered (all=1) at /data/src/10.3/storage/innobase/trx/trx0roll.cc:841
      		 
      #10 0x0000565165ced889 in trx_rollback_or_clean_all_recovered (arg=0x0) at /data/src/10.3/storage/innobase/trx/trx0roll.cc:881
      		 
      #11 0x00007f3ffa73c494 in start_thread (arg=0x7f3fce338700) at pthread_create.c:333
      		 
      #12 0x00007f3ff88b493f in clone () from /lib/x86_64-linux-gnu/libc.so.6

      The attached datadir was created as a part of MDEV-13269 workflow.

      • 10.2 server (86f9b7714791) was started with --innodb-change-buffering=none --innodb-page-size=8K --innodb-compression-algorithm=zlib, otherwise defaults;
      • a number of tables was created and concurrent DML was executed in 4 threads for about a minute;
      • the server was SIGKILL-ed;
      • the server was started again with the same options plus --innodb-force-recovery=3;
      • the server was shut down normally.

      Now, to reproduce the reported assertion failure, start 10.3 server on the provided datadir with --innodb-change-buffering=none --innodb-page-size=8K --innodb-compression-algorithm=zlib, the failure happens upon startup.

      10.2 starts all right on this datadir.

      Note: in the initial scenario, there was an intermediate step when the 10.3 server is started on the datadir with --innodb-read-only and then gets shut down normally. It starts all right, but the step does not change the outcome when the server is finally restarted in a normal mode, so it's omitted above.

      Attachments

        1. data.tar.gz
          5.91 MB
          Elena Stepanova
        2. threads1
          24 kB
          Elena Stepanova

        Issue Links

          is caused by

          Task - A task that needs to be done. MDEV-12288 Reset DB_TRX_ID when the history is removed, to speed up MVCC

          • Major - Major loss of function.
          • Closed
          relates to

          Task - A task that needs to be done. MDEV-13269 Upgrade tests for InnoDB undo log

          • Major - Major loss of function.
          • Closed

          Activity

            Transition Time In Source Status Execution Times
            Marko Mäkelä made transition -
            Open Confirmed
            		18h 34m 1
            Marko Mäkelä made transition -
            Confirmed In Progress
            		1s 1
            Marko Mäkelä made transition -
            In Progress Closed
            		24m 47s 1

            People

              marko Marko Mäkelä
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              2 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.