Corruption due to innodb_undo_log_truncate

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.