Marko Mäkelä added a comment - 2021-10-27 12:35 The test case innodb.alter_copy would cover this, but it currently exposes a problem: 2021-10-27 15:19:24 0 [ERROR] DDL_LOG: Got error 4182 when trying to execute action for entry 2 of type 'alter table' In addition to this error, we would ‘leak’ a #sql-alter table from an ALTER TABLE operation that was interrupted by killing the server. Because in the general case it is not possible to apply only part of the DDL recovery log, it may be simplest to make the entire server to refuse start up if some storage engine is unable to perform DDL recovery.

Marko Mäkelä added a comment - 2021-10-29 06:29 With the original dataset and with a recent 10.6 that includes a fix of MDEV-25919 , I am seeing the following for both data directories: sql/mariadbd --innodb-force-recovery=3 --datadir /dev/shm/atomic_ddl/MDEV-25683/data_orig sql/mariadbd --innodb-force-recovery=3 --datadir /dev/shm/atomic_ddl/MDEV-25683/data 10.6 d8c6c53a0658ea8315252997f65d796b13182387 … 2021-10-29 8:19:21 0 [Note] InnoDB: At LSN: 4048912: unable to open file ./test/#sql-backup-27122f-10.ibd for tablespace 88 2021-10-29 8:19:21 0 [Note] InnoDB: At LSN: 4190176: unable to open file ./test/#sql-backup-27122f-10.ibd for tablespace 104 … 2021-10-29 8:19:22 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2021-10-29 8:19:22 0 [Note] InnoDB: 10.6.5 started; log sequence number 4332081; transaction id 2959 2021-10-29 8:19:22 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/atomic_ddl/MDEV-25683/data_orig/ib_buffer_pool 2021-10-29 8:19:22 0 [Note] Plugin 'FEEDBACK' is disabled. 2021-10-29 8:19:22 0 [Note] InnoDB: Buffer pool(s) load completed at 211029 8:19:22 2021-10-29 8:19:22 0 [ERROR] mariadbd: Can't open shared library '/usr/local/mysql/lib/plugin/disks.so' (errno: 0, cannot open shared object file: No such file or directory) 2021-10-29 8:19:22 0 [Warning] 10.6m/sql/mariadbd: unknown option '--loose-enable-named-pipe' 2021-10-29 8:19:22 0 [ERROR] InnoDB: Trying to load index `PRIMARY` for table `test`.`#sql-alter-27122f-10`, but the index tree has been freed! 2021-10-29 8:19:22 0 [Note] InnoDB: Index is corrupt but forcing load into data dictionary The server is hanging in ddl_log_execute_recovery() and not responding to SIGQUIT . The culprit is a lock wait on the InnoDB table SYS_TABLES when trying to drop the table #sql-alter-27122f-10 . That lock wait will occur because a DDL transaction was recovered, but its rollback was prohibited by innodb_force_recovery=3 . The last messages about #sql-alter-27122f-10 are issued by dict_load_indexes() and should be removed by MDEV-26933 . Now, how would the situation change if I set innodb_force_recovery=5 or innodb_read_only=ON ? In those modes, InnoDB should refuse any DDL or DML operation, except maybe to temporary tables. sql/mariadbd --innodb-read-only --datadir /dev/shm/atomic_ddl/MDEV-25683/data_orig 10.6 d8c6c53a0658ea8315252997f65d796b13182387 … 2021-10-29 8:55:47 0 [Warning] InnoDB: innodb_read_only prevents crash recovery 2021-10-29 8:55:47 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1423] with error Read only transaction … 2021-10-29 8:55:47 0 [ERROR] Unknown/unsupported storage engine: InnoDB 2021-10-29 8:55:47 0 [ERROR] Aborting MDEV-12700 has been filed for lifting this limitation. sql/mariadbd --innodb-force-recovery=5 --datadir /dev/shm/atomic_ddl/MDEV-25683/data_orig 10.6 d8c6c53a0658ea8315252997f65d796b13182387 … 2021-10-29 8:52:32 0 [Note] DDL_LOG: Crash recovery executed 1 entries 2021-10-29 8:52:32 0 [Note] Server socket created on IP: '0.0.0.0'. 2021-10-29 8:52:32 0 [Note] Server socket created on IP: '::'. 2021-10-29 8:52:32 1 [ERROR] InnoDB: Failed to find tablespace for table `mysql`.`gtid_slave_pos` in the cache. Attempting to load the tablespace with space id 6 2021-10-29 8:52:32 0 [Note] 10.6/sql/mariadbd: ready for connections. Version: '10.6.5-MariaDB-debug' socket: '/dev/shm/mariadb.sock' port: 3306 Source distribution The server will start up, but not nicely. There is no log message saying that we failed to drop the table #sql-alter-27122f-10 from InnoDB. The .frm file will be removed, but the #sql-alter-27122f-10.ibd will remain, as will the InnoDB data dictionary entries for the table. This would not be corrected on the next restart without that InnoDB setting. Note: I would not recommend to trust any dumped data if the server was started up with innodb_force_recovery=5 . That would make all transactions use the READ UNCOMMITTED isolation level. Currently, a start-up with innodb_force_recovery=5 would avoid the DDL recovery hang and leave the InnoDB dictionary inconsistent with the DDL log. But, it would also allow a subsequent restart with innodb_force_recovery=3 , which should be safer for dumping the data, because the proper REPEATABLE READ isolation level will be available. (If some pointers to undo log are corrupted, then the server might crash while reading some data.) Now, one last attempt. What if we implement my earlier suggestion that we will start to distinguish innodb_force_recovery=4 from innodb_force_recovery=3 in 10.6? (That setting was effectively removed by MDEV-19514 in 10.5.) That is, innodb_force_recovery=4 would prevent the rollback of a recovered DDL transaction, while innodb_force_recovery=3 would only prevent the rollback of DML transactions: diff --git a/storage/innobase/srv/srv0start.cc b/storage/innobase/srv/srv0start.cc index 3f0ccf44b1e..2975bc10f51 100644 --- a/storage/innobase/srv/srv0start.cc +++ b/storage/innobase/srv/srv0start.cc @@ -1745,7 +1745,7 @@ dberr_t srv_start(bool create_new_db) should guarantee that there is at most one data dictionary transaction active at a time. */ if (!high_level_read_only - && srv_force_recovery < SRV_FORCE_NO_TRX_UNDO) { + && srv_force_recovery <= SRV_FORCE_NO_TRX_UNDO) { /* If the following call is ever removed, the first-time ha_innobase::open() must hold (or acquire and release) a table lock that diff --git a/storage/innobase/trx/trx0roll.cc b/storage/innobase/trx/trx0roll.cc index a0582413d07..fd28dae4715 100644 --- a/storage/innobase/trx/trx0roll.cc +++ b/storage/innobase/trx/trx0roll.cc @@ -709,7 +709,7 @@ void trx_rollback_recovered(bool all) { std::vector<trx_t*> trx_list; - ut_a(srv_force_recovery < SRV_FORCE_NO_TRX_UNDO); + ut_a(srv_force_recovery < (all ? SRV_FORCE_NO_TRX_UNDO : SRV_FORCE_NO_IBUF_MERGE)); /* Collect list of recovered ACTIVE transaction ids first. Once collected, no The final fix would rename SRV_FORCE_NO_IBUF_MERGE to a more descriptive name SRV_FORCE_NO_DDL_UNDO and change the documentation of innodb_force_recovery . With the above patch, the server will start up and perform the DDL log recovery normally on both data directories: sql/mariadbd --innodb-force-recovery=3 --datadir /dev/shm/atomic_ddl/MDEV-25683/data_orig sql/mariadbd --innodb-force-recovery=3 --datadir /dev/shm/atomic_ddl/MDEV-25683/data 10.6 d8c6c53a0658ea8315252997f65d796b13182387 with patch … 2021-10-29 9:21:19 0 [Note] DDL_LOG: Crash recovery executed 1 entries 2021-10-29 9:21:19 0 [Note] Server socket created on IP: '0.0.0.0'. 2021-10-29 9:21:19 0 [Note] Server socket created on IP: '::'. 2021-10-29 9:21:19 0 [Note] 10.6m/sql/mariadbd: ready for connections. Version: '10.6.5-MariaDB-debug' socket: '/dev/shm/mariadb.sock' port: 3306 Source distribution There will be no #sql files in the data directories afterwards. With or without the above patch, the hang can be reproduced with innodb_force_recovery=4 just fine. And the message about #sql-alter- will be back too: sql/mariadbd --innodb-force-recovery=4 --datadir /dev/shm/atomic_ddl/MDEV-25683/data_orig/ 10.6 d8c6c53a0658ea8315252997f65d796b13182387 with or without patch … 2021-10-29 9:26:35 0 [ERROR] InnoDB: Trying to load index `PRIMARY` for table `test`.`#sql-alter-27122f-10`, but the index tree has been freed! 2021-10-29 9:26:35 0 [Note] InnoDB: Index is corrupt but forcing load into data dictionary [startup hangs here]

Marko Mäkelä added a comment - 2021-10-29 07:48 Fix: innodb_force_recovery=3 will no longer prevent the rollback of recovered DDL transactions. This allows the data set to recover correctly when using innodb_force_recovery=3 . Other settings than innodb_force_recovery=3 were unaffected by this change. The setting innodb_force_recovery=4 will continue to prevent the rollback of recovered DDL transactions and likely make the DDL log recovery hang. The setting innodb_force_recovery=5 allows the server to start up, but the DDL log recovery will be skipped inside InnoDB (causing inconsistency between InnoDB and the .frm files).

Sergei Golubchik added a comment - 2021-10-29 08:21 greenman , see above and in particular see the commit comment. This impacts the documentation of innodb_force_recovery

Marko Mäkelä added a comment - 2021-11-04 08:46 MDEV-26966 in 10.6.6 (not 10.6.5) removes these two messages that were previously output at innodb_force_recovery=4 : 10.6 d8c6c53a0658ea8315252997f65d796b13182387 2021-10-29 9:26:35 0 [ERROR] InnoDB: Trying to load index `PRIMARY` for table `test`.`#sql-alter-27122f-10`, but the index tree has been freed! 2021-10-29 9:26:35 0 [Note] InnoDB: Index is corrupt but forcing load into data dictionary After MDEV-26966 , the startup will look like this: 10.6 667e71399ea5deba0b2530afe26a0699a59c56ec 2021-11-04 10:41:34 0 [Note] InnoDB: 10.6.5 started; log sequence number 4332197; transaction id 2959 2021-11-04 10:41:34 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/atomic_ddl/MDEV-25683/data/ib_buffer_pool 2021-11-04 10:41:34 0 [Note] InnoDB: Buffer pool(s) load completed at 211104 10:41:34 2021-11-04 10:41:34 0 [Note] Plugin 'FEEDBACK' is disabled. 2021-11-04 10:41:34 0 [ERROR] mariadbd: Can't open shared library '/usr/local/mysql/lib/plugin/disks.so' (errno: 0, cannot open shared object file: No such file or directory) 2021-11-04 10:41:34 0 [Warning] /dev/shm/10.6m/sql/mariadbd: unknown option '--loose-enable-named-pipe' Yes, it will still hang there due to the lock conflict on a dictionary table, because the recovered DDL transaction will not be rolled back at innodb_force_recovery=4 . This MDEV-25683 changed it only for innodb_force_recovery=3 .