Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.2(EOL)
-
None
Description
|
10.2 1ca8637ae35061 |
mysqld: /data/src/10.2/storage/innobase/include/trx0trx.h:1423: static bool TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed.
|
170321 19:54:53 [ERROR] mysqld got signal 6 ;
|
# 2017-03-21T19:55:03 [23375] #7 0x00007f1af3371312 in __GI___assert_fail (assertion=0x7f1af67ef450 "srv_read_only_mode || trx->in_depth > 0", file=0x7f1af67ef418 "/data/src/10.2/storage/innobase/include/trx0trx.h", line=1423, function=0x7f1af67fde60 <TrxInInnoDB::is_aborted(trx_t const*)::__PRETTY_FUNCTION__> "static bool TrxInInnoDB::is_aborted(const trx_t*)") at assert.c:101
|
# 2017-03-21T19:55:03 [23375] #8 0x00007f1af61e7259 in TrxInInnoDB::is_aborted (trx=0x7f1adf401168) at /data/src/10.2/storage/innobase/include/trx0trx.h:1423
|
# 2017-03-21T19:55:03 [23375] #9 0x00007f1af61cee0c in ha_innobase::general_fetch (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001", direction=1, match_mode=0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10304
|
# 2017-03-21T19:55:03 [23375] #10 0x00007f1af61cf4a0 in ha_innobase::rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10532
|
# 2017-03-21T19:55:03 [23375] #11 0x00007f1af5ebe121 in handler::ha_rnd_next (this=0x7f1ac0ca6888, buf=0x7f1ac0c1e488 "\375\001") at /data/src/10.2/sql/handler.cc:2577
|
# 2017-03-21T19:55:03 [23375] #12 0x00007f1af60268bc in rr_sequential (info=0x7f1ac0c62188) at /data/src/10.2/sql/records.cc:484
|
# 2017-03-21T19:55:03 [23375] #13 0x00007f1af5cbd0be in sub_select (join=0x7f1ac0c60ff0, join_tab=0x7f1ac0c620c0, end_of_records=false) at /data/src/10.2/sql/sql_select.cc:18436
|
# 2017-03-21T19:55:03 [23375] #14 0x00007f1af5cbc5a3 in do_select (join=0x7f1ac0c60ff0, procedure=0x0) at /data/src/10.2/sql/sql_select.cc:17961
|
# 2017-03-21T19:55:03 [23375] #15 0x00007f1af5c975b7 in JOIN::exec_inner (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3463
|
# 2017-03-21T19:55:03 [23375] #16 0x00007f1af5c96abc in JOIN::exec (this=0x7f1ac0c60ff0) at /data/src/10.2/sql/sql_select.cc:3266
|
# 2017-03-21T19:55:03 [23375] #17 0x00007f1af5c97c2f in mysql_select (thd=0x7f1ac0c16070, tables=0x7f1ac0c608f8, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=553247836928, result=0x7f1ac0c60f48, unit=0x7f1ac0c19b50, select_lex=0x7f1ac0c1a280) at /data/src/10.2/sql/sql_select.cc:3658
|
# 2017-03-21T19:55:03 [23375] #18 0x00007f1af5c8c710 in handle_select (thd=0x7f1ac0c16070, lex=0x7f1ac0c19a88, result=0x7f1ac0c60f48, setup_tables_done_option=1073741824) at /data/src/10.2/sql/sql_select.cc:373
|
# 2017-03-21T19:55:03 [23375] #19 0x00007f1af5c51b98 in mysql_execute_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:4498
|
# 2017-03-21T19:55:03 [23375] #20 0x00007f1af5c5c52c in mysql_parse (thd=0x7f1ac0c16070, rawbuf=0x7f1ac0c60088 "INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */", length=56, parser_state=0x7f1af6d28e20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7858
|
# 2017-03-21T19:55:03 [23375] #21 0x00007f1af5c4a5f2 in dispatch_command (command=COM_QUERY, thd=0x7f1ac0c16070, packet=0x7f1ac0c54071 " INSERT INTO tmp SELECT * FROM t2 /* QNO 31 CON_ID 12 */ ", packet_length=58, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1812
|
# 2017-03-21T19:55:03 [23375] #22 0x00007f1af5c48f62 in do_command (thd=0x7f1ac0c16070) at /data/src/10.2/sql/sql_parse.cc:1362
|
# 2017-03-21T19:55:03 [23375] #23 0x00007f1af5d91f3f in do_handle_one_connection (connect=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1358
|
# 2017-03-21T19:55:03 [23375] #24 0x00007f1af5d91ccc in handle_one_connection (arg=0x7f1af2853870) at /data/src/10.2/sql/sql_connect.cc:1264
|
# 2017-03-21T19:55:03 [23375] #25 0x00007f1af5273064 in start_thread (arg=0x7f1af6d2a300) at pthread_create.c:309
|
# 2017-03-21T19:55:03 [23375] #26 0x00007f1af342b62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
|
Non-deterministic concurrent test
git clone https://github.com/elenst/rqg --branch mdev11197 rqg-mdev11197
|
cd rqg-mdev11197
|
perl ./runall-new.pl --skip-gendata --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --basedir=<your 10.2 basedir> --vardir=<your vardir>
|
# or, if you want to run it on an already started server (e.g. under debugger),
|
# assuming it's running on port 3306
|
perl ./gentest.pl --duration=300 --threads=2 --grammar=conf/mariadb/mdev11197.yy --dsn='dbi:mysql:host=127.0.0.1:port=3306:user=root:database=test'
|
Attachments
Activity
Happened again, 10.2 revision 8f05c848c5d856f53fa907ae202deac465a17656.
To me this looks like optimizer does not stop when InnoDB has already reported transaction abort instead it just continues the statement execution but InnoDB has already thrown transaction away.
Does not repeat with MySQL 5.7.18, repeats easily with current 10.2.
http://lists.askmonty.org/pipermail/commits/2017-May/011141.html
Could not yet construct repeatable test case from RQG test case log.
Please include my clean-up patch as well, and do not construct the TrxInInnoDB object before DBUG_ENTER.
For what it is worth, starting with MDEV-11236, InnoDB in MariaDB now tolerates (and ignores) a statement rollback from the SQL layer even after the transaction has been aborted.
commit f4df8c00c957146f04db031f1f9f80aab229d1d2
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Wed May 10 23:13:06 2017 +0300
MDEV-11197: TrxInInnoDB::is_aborted(const trx_t*): Assertion `srv_read_only_mode || trx->in_depth > 0' failed
TrxInInnoDB should be constructed to track if a transaction is executing
inside InnoDB code i.e. it is like a gate between Server and InnoDB
::rnd_next() is called from Server and thus construct TrxInInnoDB
also there.
Applied suggested clean-up to TrxInInnoDB class functions enter()
and exit(). Note that exactly original did not work for enter().
It seems to me that there could be a problem when merging from MySQL 5.7. The function innobase_kill_connection() which is bound to handlerton::kill_connection does not exist in MariaDB, but instead we have a similar function innobase_kill_query() that is bound to handlerton::kill_query().
At the very least, comments that refer to innobase_kill_connection() should be revised to refer to innobase_kill_query(). I suspect some difference near lock_trx_handle_wait().
While I was investigating this bug, I came up with the following clean-up patch that might marginally improve performance:
diff --git a/storage/innobase/include/trx0trx.h b/storage/innobase/include/trx0trx.hindex d0a67a7ed28..2d4132237af 100644--- a/storage/innobase/include/trx0trx.h+++ b/storage/innobase/include/trx0trx.h@@ -1473,12 +1473,8 @@ class TrxInInnoDB {ut_ad(!is_async_rollback(trx));- ++trx->in_depth;-- /* If trx->in_depth is greater than 1 then- transaction is already in InnoDB. */- if (trx->in_depth > 1) {-+ if (trx->in_depth++) {+ /* The transaction is already inside InnoDB. */return;}@@ -1528,9 +1524,7 @@ class TrxInInnoDB {ut_ad(trx->in_depth > 0);- --trx->in_depth;-- if (trx->in_depth > 0) {+ if (--trx->in_depth > 0) {return;Also, while I was looking at this, I noticed that my change to deprecate innodb_support_xa in MySQL 5.7.10 has not been merged.