[MDEV-14988] innodb_read_only tries to modify files if transactions were recovered in COMMITTED state Created: 2018-01-18  Updated: 2018-02-13  Resolved: 2018-02-13

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: 10.0, 10.1, 10.2, 10.3
Fix Version/s: 10.0.35, 10.1.32, 10.2.14, 10.3.5

Type: Bug Priority: Major
Reporter: Marko Mäkelä Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: crash, recovery, transactions, upstream

Issue Links:
Relates
relates to MDEV-14985 innodb_undo_log_truncate may be block... Closed

 Description   

Because I had some doubts if my fix for MDEV-14985 needs something more, I wanted to test a scenario where InnoDB will recover a transaction in the COMMITTED state.
It is a bit tricky to arrange this. Versions before 10.2 will require a DEBUG_SYNC point; below is the 5.5 version:

diff --git a/storage/innobase/trx/trx0trx.c b/storage/innobase/trx/trx0trx.c
index 151e70013f9..8f6f90bf36d 100644
--- a/storage/innobase/trx/trx0trx.c
+++ b/storage/innobase/trx/trx0trx.c
@@ -43,6 +43,7 @@ Created 3/26/1996 Heikki Tuuri
 #include "trx0xa.h"
 #include "trx0purge.h"
 #include "ha_prototypes.h"
+#include "my_sys.h" /* DEBUG_SYNC_C */
 
 /** Dummy session used currently in MySQL interface */
 UNIV_INTERN sess_t*		trx_dummy_sess = NULL;
@@ -985,6 +986,7 @@ trx_commit_off_kernel(
 	if (lsn) {
 
 		mutex_exit(&kernel_mutex);
+		DEBUG_SYNC_C("after_trx_committed_in_memory");
 
 		if (trx->insert_undo != NULL) {
 

The test is a variation of innodb.read_only_recovery:

--source include/have_innodb.inc
--source include/have_debug.inc
--source include/have_debug_sync.inc
# need to restart server
--source include/not_embedded.inc
 
--connect(con1, localhost, root)
CREATE TABLE t(a INT PRIMARY KEY) ENGINE=InnoDB;
INSERT INTO t VALUES(1);
BEGIN;
# Generate insert_undo log.
INSERT INTO t VALUES(2);
# Generate update_undo log.
DELETE FROM t WHERE a=2;
--connect(con2, localhost, root)
--echo # Normal MariaDB shutdown would roll back the above transaction.
--echo # We want the transaction to remain open, so we will kill the server
--echo # after ensuring that any non-transactional files are clean.
FLUSH TABLES;
--echo # Create another transaction that will be recovered as COMMITTED.
BEGIN;
# Generate multiple pages of both insert_undo and update_undo, so that
# the state TRX_UNDO_CACHE will not be chosen.
--disable_query_log
let $n= 10000;
while ($n) {
dec $n;
eval INSERT INTO t VALUES(-$n);
eval DELETE FROM t WHERE a=-$n;
}
--enable_query_log
SET DEBUG_SYNC='after_trx_committed_in_memory SIGNAL committed WAIT_FOR ever';
send COMMIT;
 
connection default;
SET DEBUG_SYNC='now WAIT_FOR committed';
--echo # Ensure that the above incomplete transactions become durable.
SET GLOBAL innodb_flush_log_at_trx_commit=1;
BEGIN;
INSERT INTO t VALUES(-10000);
ROLLBACK;
--let $restart_parameters= --innodb-force-recovery=3
--let $shutdown_timeout= 0
--source include/restart_mysqld.inc
--let $shutdown_timeout= 30
--disconnect con1
--disconnect con2
SELECT * FROM t;
SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED;
SELECT * FROM t;
UPDATE t SET a=3 WHERE a=1;
--let $restart_parameters= --loose-innodb-read-only
--source include/restart_mysqld.inc
--echo # Starting with MariaDB 10.2, innodb_read_only implies READ UNCOMMITTED.
--echo # In earlier versions, this would return the last committed version
--echo # (empty table)!
SELECT * FROM t;
SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED;
SELECT * FROM t;
--let $restart_parameters=
--source include/restart_mysqld.inc
SELECT * FROM t;
DROP TABLE t;

In MariaDB 5.5, there is no --innodb-read-only option, and therefore the last-but-one restart can be omitted. MariaDB 5.5 could be unaffected by this bug.

This will trigger at least the following assertion failures:

180118 16:04:45 [Note] InnoDB: Starting shutdown...
2018-01-18 16:04:46 7fe21c330700  InnoDB: Assertion failure in thread 140609112442624 in file lock0lock.cc line 7006
InnoDB: Failing assertion: trx_state_eq(trx, TRX_STATE_ACTIVE)

This one occurs on 10.0:

2018-01-18 16:04:47 7f20f39c5080  InnoDB: Assertion failure in thread 139779502788736 in file mtr0mtr.cc line 322
InnoDB: Failing assertion: !srv_read_only_mode
#6  0x00007f20ec9ae658 in mtr_commit (mtr=0x7ffea6e73e38) at /mariadb/10.0/storage/innobase/mtr/mtr0mtr.cc:322
#7  0x00007f20ecaed2e9 in trx_undo_seg_free (undo=0x33f7478) at /mariadb/10.0/storage/innobase/trx/trx0undo.cc:1251
#8  0x00007f20ecaed0c4 in trx_undo_insert_cleanup (trx=0x3422ca8) at /mariadb/10.0/storage/innobase/trx/trx0undo.cc:1990
#9  0x00007f20ecae464d in trx_cleanup_at_db_startup (trx=0x3422ca8) at /mariadb/10.0/storage/innobase/trx/trx0trx.cc:1426
#10 0x00007f20ecad63d1 in trx_rollback_resurrected (trx=0x3422ca8, all=0x7ffea6e74408) at /mariadb/10.0/storage/innobase/trx/trx0roll.cc:679

In 10.2, the assertion expression is different, but the idea is the same:

2018-01-18 15:41:49 139918570912896 [Note] InnoDB: Cleaning up trx with id 0x507
mysqld: /mariadb/10.2/storage/innobase/mtr/mtr0mtr.cc:570: void mtr_t::commit(): Assertion `!srv_read_only_mode || m_impl.m_log_mode == MTR_LOG_NO_REDO' failed.
mtr/mtr0mtr.cc:572(mtr_t::commit())[0x1b4a8d6]
trx/trx0undo.cc:1111(trx_undo_seg_free(trx_undo_t const*, bool))[0x1f3b877]
trx/trx0undo.cc:1796(trx_undo_commit_cleanup(trx_undo_t*, bool))[0x1f3b018]
trx/trx0trx.cc:2009(trx_cleanup_at_db_startup(trx_t*))[0x1f0cd1e]
trx/trx0roll.cc:749(trx_rollback_resurrected(trx_t*, unsigned long*))[0x1ee5a85]



 Comments   
Comment by Marko Mäkelä [ 2018-02-13 ]

The 10.2 patch is simple:

diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc
index ca20a5033dc..d74ac76745d 100644
--- a/storage/innobase/lock/lock0lock.cc
+++ b/storage/innobase/lock/lock0lock.cc
@@ -7484,7 +7484,10 @@ lock_trx_release_locks(
 
 		mutex_exit(&trx_sys->mutex);
 	} else {
-		ut_ad(trx_state_eq(trx, TRX_STATE_ACTIVE));
+		ut_ad(trx_state_eq(trx, TRX_STATE_ACTIVE)
+		      || (trx_state_eq(trx, TRX_STATE_COMMITTED_IN_MEMORY)
+			  && trx->is_recovered
+			  && !UT_LIST_GET_LEN(trx->lock.trx_locks)));
 	}
 
 	bool	release_lock;
diff --git a/storage/innobase/trx/trx0undo.cc b/storage/innobase/trx/trx0undo.cc
index e3eb2595365..c93003f9e03 100644
--- a/storage/innobase/trx/trx0undo.cc
+++ b/storage/innobase/trx/trx0undo.cc
@@ -1793,7 +1793,9 @@ trx_undo_commit_cleanup(trx_undo_t* undo, bool is_temp)
 
 		/* Delete first the undo log segment in the file */
 		mutex_exit(&rseg->mutex);
-		trx_undo_seg_free(undo, is_temp);
+		if (!srv_read_only_mode) {
+			trx_undo_seg_free(undo, is_temp);
+		}
 		mutex_enter(&rseg->mutex);
 
 		ut_ad(rseg->curr_size > undo->size);

Comment by Marko Mäkelä [ 2018-02-13 ]

The test passes in 5.5, probably because there is no innodb_read_only mode. In 10.0, the UPDATE right before the restart with --loose-innodb-read-only is refused based on innodb_force_recovery=3:

mysqltest: At line 51: query 'UPDATE t SET a=3 WHERE a=1' failed: 1036: Table 't' is read only

But the read-only shutdown will crash, and the above 10.2 patch is needed in 10.0 already.
The symptom of this bug is that on shutdown, --innodb-read-only would break its promise of not modifying any data files when some transactions were recovered in committed state.
MariaDB 10.3 is not affected, because MDEV-15104 refactored the code.

Comment by Marko Mäkelä [ 2018-02-13 ]

Merged up to 10.2 so far. In 10.3 some of the code changes will have to be omitted.

Generated at Thu Feb 08 08:17:51 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.