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

Corruption due to innodb_undo_log_truncate

    XMLWordPrintable

    Details

      Description

      origin/10.6 b0d38448a176dc990554c7dd5b184c3ebe64be8b 2021-08-19T16:35:44+05:30
       
      Workflow:
      1. Bootstrap + start DB server with
           --mysqld=--innodb_undo_tablespaces=3 --mysqld=--innodb_undo_log_truncate=ON
           in command line.
      2. One sessions creates some initial data and disconnects.
      3. Several sessions run for a few minutes concurrent DML on the tables created in 2.
           and disconnect.
      4. Dump data, shutdown of DB server
      5. Restart of DB server
      6. Run SHOW VARIABLES
       
      Most frequent seen failure:
      mysqld: /data/Server/10.6Z/storage/innobase/trx/trx0purge.cc:99: bool TrxUndoRsegsIterator::set_next(): Assertion `purge_sys.purge_queue.empty() || purge_sys.purge_queue.top() != m_rsegs' failed.
       
      Less frequent seen
      # 2021-08-20T12:44:32 [2934208] | 2021-08-20 12:44:26 5 [ERROR] InnoDB: PAGE_MAX_TRX_ID out of bounds: 8205, 4
      # 2021-08-20T12:44:32 [2934208] | 2021-08-20 12:44:26 5 [ERROR] InnoDB: Apparent corruption in space 8 page 280 of index col_longtext_utf8_key of table test.table100_innodb_int_autoinc
      ...
       mysqld: /data/Server/10.6Z/storage/innobase/trx/trx0sys.cc:62: static void ReadViewBase::check_trx_id_sanity(trx_id_t, const table_name_t&): Assertion `0' failed.
      ---------------
      # 2021-08-20T12:34:35 [2762582] | 2021-08-20 12:33:47 16 [Note] InnoDB: trying to read page [page id: space=3, page number=102] in nonexisting or being-dropped tablespace
      ...  many repetitions of the line above
      # 2021-08-20T12:34:35 [2762582] | 2021-08-20 12:33:47 16 [ERROR] [FATAL] InnoDB: Unable to read page [page id: space=3, page number=102] into the buffer pool after 100. The most probable cause of this error may be that the table has been corrupted. See https://mariadb.com/kb/en/library/innodb-recovery-modes/
      # 2021-08-20T12:34:35 [2762582] | 210820 12:33:47 [ERROR] mysqld got signal 6 ;
      ---------------
      Workflow like above including
      7. CHECK TABLE ...
      # 2021-08-20T16:24:28 [936058] | [rr 990542 12500]2021-08-20 16:23:51 5 [Warning] InnoDB: A transaction id in a record of table `test`.`table100_innodb_int_autoinc` is newer than the system-wide maximum.
      mysqld: /data/Server/10.6Z/storage/innobase/trx/trx0sys.cc:62: static void ReadViewBase::check_trx_id_sanity(trx_id_t, const table_name_t&): Assertion `0' failed.
      -----------------
      [ERROR] [FATAL] InnoDB: Trying to read 4096 bytes at 2097152 outside the bounds of the file: .//undo001
       
       
      RQG
      ====
      git clone https://github.com/mleich1/rqg --branch experimental RQG
       
      perl rqg.pl \
      --grammar=conf/engines/many_indexes.yy \
      --gendata=conf/engines/many_indexes.zz \
      --reporters=RestartConsistencyRR \
      --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
      --mysqld=--loose-idle_write_transaction_timeout=0 \
      --mysqld=--loose-idle_transaction_timeout=0 \
      --mysqld=--loose-idle_readonly_transaction_timeout=0 \
      --mysqld=--connect_timeout=60 \
      --mysqld=--interactive_timeout=28800 \
      --mysqld=--slave_net_timeout=60 \
      --mysqld=--net_read_timeout=30 \
      --mysqld=--net_write_timeout=60 \
      --mysqld=--loose-table_lock_wait_timeout=50 \
      --mysqld=--wait_timeout=28800 \
      --mysqld=--lock-wait-timeout=86400 \
      --mysqld=--innodb-lock-wait-timeout=50 \
      --no-mask \
      --queries=10000000 \
      --seed=random \
      --reporters=Backtrace \
      --reporters=ErrorLog \
      --reporters=Deadlock1 \
      --validators=None \
      --mysqld=--log_output=none \
      --mysqld=--log_bin_trust_function_creators=1 \
      --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
      --engine=InnoDB \
      --restart_timeout=240 \
      --mysqld=--plugin-load-add=file_key_management.so \
      --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
      --duration=150 \
      --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
      --mysqld=--innodb_stats_persistent=on \
      --mysqld=--innodb_adaptive_hash_index=on \
      --mysqld=--log-bin \
      --mysqld=--sync-binlog=1 \
      --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \
      --mysqld=--loose-max-statement-time=30 \
      --threads=9 \
      --mysqld=--innodb_use_native_aio=1 \
      --mysqld=--innodb_undo_tablespaces=3 \
      --mysqld=--innodb_undo_log_truncate=ON \
      --mysqld=--innodb_page_size=16K \
      --mysqld=--innodb-buffer-pool-size=8M \
      --no_mask \
      --workdir=<local settings>
      --vardir=<local settings>
      --mtr-build-thread=<local settings>
      --basedir1=<local settings>
      --script_debug=_nix_
       
      Observations:
      1. innodb-buffer-pool-size=8M seems to be extreme small for innodb_page_size=16K.
          Raising innodb-buffer-pool-size to 32M does not let the failures disappear.
      2. In case the server finally shut down was running under 'rr' than the problems
           did never show up.
      3. After setting  innodb_undo_log_truncate=off the failures disappeared.
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              marko Marko Mäkelä
              Reporter:
              mleich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration