Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.2(EOL)
Description
|
10.2 25d6f634b |
mysqld: /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0sys.cc:1002: ulint trx_sys_any_active_transactions(): Assertion `trx->in_rw_trx_list || trx->state == TRX_STATE_NOT_STARTED || trx->state == TRX_STATE_ACTIVE' failed.
|
201218 1:37:39 [ERROR] mysqld got signal 6 ;
|
|
|
#1 0x00007fb9116388b1 in __GI_abort () at abort.c:79
|
#2 0x00007fb91162842a in __assert_fail_base (fmt=0x7fb9117afa38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
|
assertion=assertion@entry=0x5653337e63c0 "trx->in_rw_trx_list || trx->state == TRX_STATE_NOT_STARTED || trx->state == TRX_STATE_ACTIVE",
|
file=file@entry=0x5653337e5d58 "/home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0sys.cc", line=line@entry=1002,
|
function=function@entry=0x5653337e7080 <trx_sys_any_active_transactions()::__PRETTY_FUNCTION__> "ulint trx_sys_any_active_transactions()") at assert.c:92
|
#3 0x00007fb9116284a2 in __GI___assert_fail (assertion=0x5653337e63c0 "trx->in_rw_trx_list || trx->state == TRX_STATE_NOT_STARTED || trx->state == TRX_STATE_ACTIVE",
|
file=0x5653337e5d58 "/home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0sys.cc", line=1002, function=0x5653337e7080 <trx_sys_any_active_transactions()::__PRETTY_FUNCTION__> "ulint trx_sys_any_active_transactions()")
|
at assert.c:101
|
#4 0x00005653331b8d0b in trx_sys_any_active_transactions () at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0sys.cc:1002
|
#5 0x0000565333107eda in row_drop_tables_for_mysql_in_background () at /home/mariadb/MDEV-24434/10.2/storage/innobase/row/row0mysql.cc:2589
|
#6 0x000056533316d8c7 in srv_master_do_active_tasks () at /home/mariadb/MDEV-24434/10.2/storage/innobase/srv/srv0srv.cc:2216
|
#7 0x000056533316e460 in srv_master_thread (arg=0x0) at /home/mariadb/MDEV-24434/10.2/storage/innobase/srv/srv0srv.cc:2468
|
#8 0x00007fb91232f6db in start_thread (arg=0x7fb8bfcff700) at pthread_create.c:463
|
#9 0x00007fb911719a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
rr profile is available.
I couldn't reproduce it on 10.3+ right away, but it's not a guarantee that the problem doesn't exist there.
For the record, I used this test run to reproduce the failure (works with and without rr, but with rr it takes much longer):
|
MariaDB/randgen branch mdev24434 |
perl ./runall-trials.pl --grammar=conf/partitioning/partitions.yy --gendata-advanced --skip-gendata --duration=350 --seed=1608184357 --reporters=Backtrace,ErrorLog,Deadlock --partitions --engine=InnoDB,MyISAM,Aria --filter=conf/mariadb/10.4-combo-filter.ff --redefine=conf/mariadb/bulk_insert.yy --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/modules/admin.yy --redefine=conf/mariadb/modules/alter_table_columns.yy --redefine=conf/mariadb/modules/alter_table_indexes.yy --redefine=conf/mariadb/modules/foreign_keys.yy --mysqld=--server-id=111 --mysqld=--log_output=FILE --mysqld=--max-statement-time=20 --mysqld=--lock-wait-timeout=10 --mysqld=--innodb-lock-wait-timeout=5 --threads=3 --redefine=conf/mariadb/modules/dynamic_variables.yy --validators=TransformerNoComparator --transformers=ExecuteAsCTE,ExecuteAsExecuteImmediate,ExecuteAsDeleteReturning,ExecuteAsInsertSelect,ExecuteAsUnion,ExecuteAsUpdateDelete,ExecuteAsPreparedTwice --mysqld=--log-bin --mysqld=--log_bin_trust_function_creators=1 --basedir1=`pwd`/../10.2 --vardir1=/dev/shm/var_mdev24434 --rr --trials=50
|
Attachments
Activity
| Field | Original Value | New Value |
|---|---|---|
| Description | _stub, need a number_ |
{noformat:title=10.2 25d6f634b}
mysqld: /home/mariadb/ 201218 1:37:39 [ERROR] mysqld got signal 6 ; #1 0x00007fb9116388b1 in __GI_abort () at abort.c:79 #2 0x00007fb91162842a in __assert_fail_base (fmt=0x7fb9117afa38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5653337e63c0 "trx->in_rw_trx_list || trx->state == TRX_STATE_NOT_STARTED || trx->state == TRX_STATE_ACTIVE", file=file@entry=0x5653337e5d58 "/home/mariadb/ function=function@entry=0x5653337e7080 <trx_sys_any_active_transactions()::__PRETTY_FUNCTION__> "ulint trx_sys_any_active_transactions()") at assert.c:92 #3 0x00007fb9116284a2 in __GI___assert_fail (assertion=0x5653337e63c0 "trx->in_rw_trx_list || trx->state == TRX_STATE_NOT_STARTED || trx->state == TRX_STATE_ACTIVE", file=0x5653337e5d58 "/home/mariadb/ at assert.c:101 #4 0x00005653331b8d0b in trx_sys_any_active_transactions () at /home/mariadb/ #5 0x0000565333107eda in row_drop_tables_for_mysql_in_background () at /home/mariadb/ #6 0x000056533316d8c7 in srv_master_do_active_tasks () at /home/mariadb/ #7 0x000056533316e460 in srv_master_thread (arg=0x0) at /home/mariadb/ #8 0x00007fb91232f6db in start_thread (arg=0x7fb8bfcff700) at pthread_create.c:463 #9 0x00007fb911719a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 {noformat} rr profile is available. I couldn't reproduce it on 10.3+ right away, but it's not a guarantee that the problem doesn't exist there. For the record, I used this test run to reproduce the failure (works with and without rr, but with rr it takes much longer): {noformat:title=MariaDB/randgen branch mdev24434} perl ./runall-trials.pl --grammar=conf/partitioning/partitions.yy --gendata-advanced --skip-gendata --duration=350 --seed=1608184357 --reporters=Backtrace,ErrorLog,Deadlock --partitions --engine=InnoDB,MyISAM,Aria --filter=conf/mariadb/10.4-combo-filter.ff --redefine=conf/mariadb/bulk_insert.yy --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/modules/admin.yy --redefine=conf/mariadb/modules/alter_table_columns.yy --redefine=conf/mariadb/modules/alter_table_indexes.yy --redefine=conf/mariadb/modules/foreign_keys.yy --mysqld=--server-id=111 --mysqld=--log_output=FILE --mysqld=--max-statement-time=20 --mysqld=--lock-wait-timeout=10 --mysqld=--innodb-lock-wait-timeout=5 --threads=3 --redefine=conf/mariadb/modules/dynamic_variables.yy --validators=TransformerNoComparator --transformers=ExecuteAsCTE,ExecuteAsExecuteImmediate,ExecuteAsDeleteReturning,ExecuteAsInsertSelect,ExecuteAsUnion,ExecuteAsUpdateDelete,ExecuteAsPreparedTwice --mysqld=--log-bin --mysqld=--log_bin_trust_function_creators=1 --basedir1=`pwd`/../10.2 --vardir1=/dev/shm/var_mdev24434 --rr --trials=50 {noformat} |
| Labels | rr-profile |
| Assignee | Elena Stepanova [ elenst ] | Marko Mäkelä [ marko ] |
| Summary | Assertion `trx->in_rw_trx_list || trx->state == TRX_STATE_NOT_STARTE D || trx->state == TRX_STATE_ACTIVE' failed in trx_sys_any_active_transactions | Assertion `trx->in_rw_trx_list || trx->state == TRX_STATE_NOT_STARTED || trx->state == TRX_STATE_ACTIVE' failed in trx_sys_any_active_transactions |
| Status | Open [ 1 ] | In Progress [ 3 ] |
| issue.field.resolutiondate | 2021-04-12 08:39:04.0 | 2021-04-12 08:39:04.345 |
| Fix Version/s | 10.2.38 [ 25207 ] | |
| Fix Version/s | 10.2 [ 14601 ] | |
| Resolution | Fixed [ 1 ] | |
| Status | In Progress [ 3 ] | Closed [ 6 ] |
| Workflow | MariaDB v3 [ 117138 ] | MariaDB v4 [ 158701 ] |
The transaction in question was in PREPARE state and is in the process of being committed:
10.2 25d6f634b89c4b1ad8ae721921b5ccf595073270
#6 0x00005653331ccc02 in trx_undo_seg_free (undo=0x7fb86c17d6a0, noredo=false)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0undo.cc:1088#7 0x00005653331cec07 in trx_undo_commit_cleanup (undo=0x7fb86c17d6a0,is_temp=false)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0undo.cc:1789#8 0x00005653331beeba in trx_commit_in_memory (trx=0x7fb9105fc228,mtr=0x7fb8d40f1c20, serialised=true)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:1773#9 0x00005653331bf90e in trx_commit_low (trx=0x7fb9105fc228,mtr=0x7fb8d40f1c20)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:1957#10 0x00005653331bf9c6 in trx_commit (trx=0x7fb9105fc228)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:1981#11 0x00005653331c0273 in trx_commit_for_mysql (trx=0x7fb9105fc228)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:2190#12 0x0000565332fbf1f4 in innobase_commit_low (trx=0x7fb9105fc228)at /home/mariadb/MDEV-24434/10.2/storage/innobase/handler/ha_innodb.cc:4432#13 0x0000565332fbf537 in innobase_commit_ordered_2 (trx=0x7fb9105fc228,thd=0x7fb86c000d50)at /home/mariadb/MDEV-24434/10.2/storage/innobase/handler/ha_innodb.cc:4556#14 0x0000565332fbf708 in innobase_commit_ordered (hton=0x565335bfa2c0,thd=0x7fb86c000d50, all=true)at /home/mariadb/MDEV-24434/10.2/storage/innobase/handler/ha_innodb.cc:4616#15 0x0000565332ed3f7e in TC_LOG::run_commit_ordered (this=0x565334139260 <mysql_bin_log>, thd=0x7fb86c000d50, all=true)at /home/mariadb/MDEV-24434/10.2/sql/log.cc:8842#16 0x0000565332ed1ee2 in MYSQL_BIN_LOG::trx_group_commit_leader (this=0x565334139260 <mysql_bin_log>, leader=0x7fb8d40f23d0)at /home/mariadb/MDEV-24434/10.2/sql/log.cc:8069#17 0x0000565332ed0ea5 in MYSQL_BIN_LOG::write_transaction_to_binlog_events (this=0x565334139260 <mysql_bin_log>, entry=0x7fb8d40f23d0)at /home/mariadb/MDEV-24434/10.2/sql/log.cc:7645#18 0x0000565332ed0511 in MYSQL_BIN_LOG::write_transaction_to_binlog (this=0x565334139260 <mysql_bin_log>, thd=0x7fb86c000d50,cache_mngr=0x7fb86c9e5080, end_ev=0x7fb8d40f2570, all=true,using_stmt_cache=true, using_trx_cache=true)at /home/mariadb/MDEV-24434/10.2/sql/log.cc:7319#19 0x0000565332ec1afe in binlog_flush_cache (thd=0x7fb86c000d50,cache_mngr=0x7fb86c9e5080, end_ev=0x7fb8d40f2570, all=true,using_stmt=true, using_trx=true)at /home/mariadb/MDEV-24434/10.2/sql/log.cc:1745#20 0x0000565332ec203f in binlog_commit_flush_xid_caches (thd=0x7fb86c000d50,cache_mngr=0x7fb86c9e5080, all=true, xid=8153)at /home/mariadb/MDEV-24434/10.2/sql/log.cc:1853#21 0x0000565332ed6011 in MYSQL_BIN_LOG::log_and_order (this=0x565334139260 <mysql_bin_log>, thd=0x7fb86c000d50, xid=8153,all=true, need_prepare_ordered=false, need_commit_ordered=true)at /home/mariadb/MDEV-24434/10.2/sql/log.cc:9625#22 0x0000565332dc6969 in ha_commit_trans (thd=0x7fb86c000d50, all=true)at /home/mariadb/MDEV-24434/10.2/sql/handler.cc:1496#23 0x0000565332caef3b in trans_commit_implicit (thd=0x7fb86c000d50)at /home/mariadb/MDEV-24434/10.2/sql/transaction.cc:368#24 0x0000565332b484a0 in mysql_execute_command (thd=0x7fb86c000d50)at /home/mariadb/MDEV-24434/10.2/sql/sql_parse.cc:3407#25 0x0000565332b55f13 in mysql_parse (thd=0x7fb86c000d50,rawbuf=0x7fb86c013548 "DROP /* QNO 3172 CON_ID 15 */ TABLE transforms.insert_select_45800", length=66, parser_state=0x7fb8d40f3640, is_com_multi=false,is_next_command=false)at /home/mariadb/MDEV-24434/10.2/sql/sql_parse.cc:7762The assertion is failing, because the transaction had been removed from the rw_trx_list and its state is TRX_STATE_COMMITTED_IN_MEMORY:
#0 0x00005653331be5bb in trx_erase_lists (trx=0x7fb9105fc228, serialised=true)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:1657#1 0x00005653331beb00 in trx_commit_in_memory (trx=0x7fb9105fc228,mtr=0x7fb8d40f1c20, serialised=true)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:1733#2 0x00005653331bf90e in trx_commit_low (trx=0x7fb9105fc228,mtr=0x7fb8d40f1c20)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:1957#3 0x00005653331bf9c6 in trx_commit (trx=0x7fb9105fc228)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:1981#4 0x00005653331c0273 in trx_commit_for_mysql (trx=0x7fb9105fc228)at /home/mariadb/MDEV-24434/10.2/storage/innobase/trx/trx0trx.cc:2190I think that the following should be an acceptable fix:
diff --git a/storage/innobase/trx/trx0sys.cc b/storage/innobase/trx/trx0sys.ccindex 8d00bd824a2..0f18850fb2e 100644--- a/storage/innobase/trx/trx0sys.cc+++ b/storage/innobase/trx/trx0sys.cc@@ -997,11 +997,6 @@ trx_sys_any_active_transactions(void)/* This may count some ACTIVE transactions twice,both in rw_trx_list and mysql_trx_list. */total_trx += trx->state == TRX_STATE_ACTIVE;- /* Any PREPARED or COMMITTED transactions must be- in rw_trx_list, so it suffices to count them there. */- ut_ad(trx->in_rw_trx_list- || trx->state == TRX_STATE_NOT_STARTED- || trx->state == TRX_STATE_ACTIVE);trx_mutex_exit(trx);}In 10.3, the list was replaced by trx_sys.rw_trx_hash and this code is rather different. Like the surviving comment says, the count returned by trx_sys_any_active_transactions() is not accurate. It is only being tested for 0, so the duplicate counts should be harmless.