Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.4.0
-
None
Description
Several recent crashes
- http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/11364 (bb-10.4-
MDEV-15563, seems to be first occurence?) - http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/11394/steps/test/logs/stdio (main 10.4 tree)
- http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/11370/steps/test/logs/stdio (main 10.4 tree)
- http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/11640/steps/test/logs/stdio (main 10.4 tree)
2018-12-11 23:01:41 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=124279366
2018-12-11 23:01:42 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 3 row operations to undo
2018-12-11 23:01:42 0 [Note] InnoDB: Trx id counter is 17207
2018-12-11 23:01:42 0 [Note] InnoDB: Starting final batch to recover 21 pages from redo log.
Assertion failed: n < tuple->n_fields, file d:\winx64-debug\build\src\storage\innobase\include\data0data.ic, line 433
callstack:
mysqld.exe!dtuple_get_nth_field()[data0data.ic:433]
|
mysqld.exe!btr_push_update_extern_fields()[btr0cur.cc:7155]
|
mysqld.exe!btr_cur_pessimistic_update()[btr0cur.cc:4818]
|
mysqld.exe!row_undo_mod_clust_low()[row0umod.cc:141]
|
mysqld.exe!row_undo_mod_clust()[row0umod.cc:322]
|
mysqld.exe!row_undo_mod()[row0umod.cc:1383]
|
mysqld.exe!row_undo()[row0undo.cc:441]
|
mysqld.exe!row_undo_step()[row0undo.cc:497]
|
mysqld.exe!que_thr_step()[que0que.cc:1040]
|
mysqld.exe!que_run_threads_low()[que0que.cc:1104]
|
mysqld.exe!que_run_threads()[que0que.cc:1146]
|
mysqld.exe!trx_rollback_active()[trx0roll.cc:664]
|
mysqld.exe!trx_rollback_recovered()[trx0roll.cc:819]
|
mysqld.exe!srv_start()[srv0start.cc:2104]
|
mysqld.exe!innodb_init()[ha_innodb.cc:4256]
|
mysqld.exe!ha_initialize_handlerton()[handler.cc:523]
|
mysqld.exe!plugin_initialize()[sql_plugin.cc:1437]
|
mysqld.exe!plugin_init()[sql_plugin.cc:1719]
|
mysqld.exe!init_server_components()[mysqld.cc:5228]
|
mysqld.exe!win_main()[mysqld.cc:5757]
|
mysqld.exe!mysql_service()[mysqld.cc:6017]
|
mysqld.exe!mysqld_main()[mysqld.cc:6208]
|
mysqld.exe!main()[main.cc:26]
|
Attachments
Issue Links
- is caused by
-
MDEV-15562 Instant DROP COLUMN or changing the order of columns
-
- Closed
-
- relates to
-
MDEV-18009 Missing redo log flush in innodb.instant_alter_crash
-
- Closed
-
I am pretty convinced that the problem is caused by
MDEV-15562, not the initial part ofMDEV-15563.I can repeat this with the following change to the test:
diff --git a/mysql-test/suite/innodb/t/instant_alter_crash.test b/mysql-test/suite/innodb/t/instant_alter_crash.test
index b1615041393..d6ec012a618 100644
--- a/mysql-test/suite/innodb/t/instant_alter_crash.test
+++ b/mysql-test/suite/innodb/t/instant_alter_crash.test
@@ -83,6 +83,7 @@ connection default;
SET DEBUG_SYNC='now WAIT_FOR ddl';
SET GLOBAL innodb_flush_log_at_trx_commit=1;
DELETE FROM t1;
+sleep 2;
--source include/kill_mysqld.inc
Independent of the failure, we must find out why the redo log was not being flushed for the implicit commit of the DELETE statement.
The problem appears to be in btr_cur_trim(), which is not correctly handling the case when we are rolling back from is_alter_metadata to is_alter_metadata. In this case, the old metadata BLOB needs to be restored. The rollback only appears to work to return the table back to the 10.3
MDEV-11369instant ADD COLUMN format. In this test case, the previously committed ALTER TABLE operation was DROP COLUMN.