Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.2.35, 10.2.36, 10.2.37, 10.3.26, 10.3.27, 10.3.28, 10.4.16, 10.4.17, 10.4.18, 10.5.7, 10.5.8, 10.5.9
Description
|
10.6 43ca6059cae8 |
mysqld: /home/mariadb/have_x/10.6/storage/innobase/include/sux_lock.h:338: void sux_lock<srw>::s_lock() [with srw = ssux_lock_low]: Assertion `!have_x()' failed.
|
210204 15:18:37 [ERROR] mysqld got signal 6 ;
|
|
|
#2 0x00007fc90856142a in __assert_fail_base (fmt=0x7fc9086e8a38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5602b9648303 "!have_x()",
|
file=file@entry=0x5602b9648310 "/home/mariadb/have_x/10.6/storage/innobase/include/sux_lock.h", line=line@entry=338,
|
function=function@entry=0x5602b964b360 <sux_lock<ssux_lock_low>::s_lock()::__PRETTY_FUNCTION__> "void sux_lock<srw>::s_lock() [with srw = ssux_lock_low]") at assert.c:92
|
#3 0x00007fc9085614a2 in __GI___assert_fail (assertion=0x5602b9648303 "!have_x()", file=0x5602b9648310 "/home/mariadb/have_x/10.6/storage/innobase/include/sux_lock.h", line=338,
|
function=0x5602b964b360 <sux_lock<ssux_lock_low>::s_lock()::__PRETTY_FUNCTION__> "void sux_lock<srw>::s_lock() [with srw = ssux_lock_low]") at assert.c:101
|
#4 0x00005602b8d64b84 in sux_lock<ssux_lock_low>::s_lock (this=0x7fc8e408a640) at /home/mariadb/have_x/10.6/storage/innobase/include/sux_lock.h:338
|
#5 0x00005602b8d63e9b in mtr_t::page_lock (this=0x7fc9000268f0, block=0x7fc8e408a5c0, rw_latch=1) at /home/mariadb/have_x/10.6/storage/innobase/mtr/mtr0mtr.cc:1064
|
#6 0x00005602b8f55745 in buf_page_get_low (page_id=..., zip_size=0, rw_latch=1, guess=0x0, mode=10, mtr=0x7fc9000268f0, err=0x7fc90002679c, allow_ibuf_merge=false) at /home/mariadb/have_x/10.6/storage/innobase/buf/buf0buf.cc:3279
|
#7 0x00005602b8f559f0 in buf_page_get_gen (page_id=..., zip_size=0, rw_latch=1, guess=0x0, mode=10, mtr=0x7fc9000268f0, err=0x7fc90002679c, allow_ibuf_merge=false) at /home/mariadb/have_x/10.6/storage/innobase/buf/buf0buf.cc:3343
|
#8 0x00005602b8ccfce0 in btr_block_get (index=..., page=3, mode=1, merge=false, mtr=0x7fc9000268f0) at /home/mariadb/have_x/10.6/storage/innobase/include/btr0btr.h:237
|
#9 0x00005602b8eec9cc in btr_root_block_get (index=0x7fc8ac30af38, mode=RW_S_LATCH, mtr=0x7fc9000268f0) at /home/mariadb/have_x/10.6/storage/innobase/btr/btr0btr.cc:227
|
#10 0x00005602b8eecc7b in btr_height_get (index=0x7fc8ac30af38, mtr=0x7fc9000268f0) at /home/mariadb/have_x/10.6/storage/innobase/btr/btr0btr.cc:295
|
#11 0x00005602b8fc83b0 in dict_stats_analyze_index (index=0x7fc8ac30af38) at /home/mariadb/have_x/10.6/storage/innobase/dict/dict0stats.cc:1968
|
#12 0x00005602b8fc91bc in dict_stats_update_persistent (table=0x7fc8ac2f60f8) at /home/mariadb/have_x/10.6/storage/innobase/dict/dict0stats.cc:2250
|
#13 0x00005602b8fcbb74 in dict_stats_update (table=0x7fc8ac2f60f8, stats_upd_option=DICT_STATS_RECALC_PERSISTENT) at /home/mariadb/have_x/10.6/storage/innobase/dict/dict0stats.cc:3223
|
#14 0x00005602b8c87bd2 in ha_innobase::info_low (this=0x7fc8a02ad190, flag=28, is_analyze=true) at /home/mariadb/have_x/10.6/storage/innobase/handler/ha_innodb.cc:14026
|
#15 0x00005602b8c88640 in ha_innobase::analyze (this=0x7fc8a02ad190) at /home/mariadb/have_x/10.6/storage/innobase/handler/ha_innodb.cc:14319
|
#16 0x00005602b881c890 in handler::ha_analyze (this=0x7fc8a02ad190, thd=0x7fc8a0000d78, check_opt=0x7fc8a00061d8) at /home/mariadb/have_x/10.6/sql/handler.cc:4756
|
#17 0x00005602b8b744e1 in ha_partition::handle_opt_part (this=0x7fc8a04028d0, thd=0x7fc8a0000d78, check_opt=0x7fc8a00061d8, part_id=0, flag=2) at /home/mariadb/have_x/10.6/sql/ha_partition.cc:1355
|
#18 0x00005602b8b74d7f in ha_partition::handle_opt_partitions (this=0x7fc8a04028d0, thd=0x7fc8a0000d78, check_opt=0x7fc8a00061d8, flag=2) at /home/mariadb/have_x/10.6/sql/ha_partition.cc:1534
|
#19 0x00005602b8b74143 in ha_partition::analyze (this=0x7fc8a04028d0, thd=0x7fc8a0000d78, check_opt=0x7fc8a00061d8) at /home/mariadb/have_x/10.6/sql/ha_partition.cc:1235
|
#20 0x00005602b881c890 in handler::ha_analyze (this=0x7fc8a04028d0, thd=0x7fc8a0000d78, check_opt=0x7fc8a00061d8) at /home/mariadb/have_x/10.6/sql/handler.cc:4756
|
#21 0x00005602b8669ed5 in mysql_admin_table (thd=0x7fc8a0000d78, tables=0x7fc8a0012580, check_opt=0x7fc8a00061d8, operator_name=0x5602b935140f "analyze", lock_type=TL_READ_NO_INSERT, org_open_for_modify=true,
|
repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x5602b881c7ae <handler::ha_analyze(THD*, st_ha_check_opt*)>, view_operator_func=0x0)
|
at /home/mariadb/have_x/10.6/sql/sql_admin.cc:853
|
#22 0x00005602b866bf18 in Sql_cmd_analyze_table::execute (this=0x7fc8a0012c58, thd=0x7fc8a0000d78) at /home/mariadb/have_x/10.6/sql/sql_admin.cc:1389
|
#23 0x00005602b84b8703 in mysql_execute_command (thd=0x7fc8a0000d78) at /home/mariadb/have_x/10.6/sql/sql_parse.cc:5880
|
#24 0x00005602b84be997 in mysql_parse (thd=0x7fc8a0000d78, rawbuf=0x7fc8a0012450 "ANALYZE /* QNO 8597 CON_ID 13 */ TABLE `t8_innodb`", length=50, parser_state=0x7fc900029510) at /home/mariadb/have_x/10.6/sql/sql_parse.cc:7906
|
#25 0x00005602b84aaea7 in dispatch_command (command=COM_QUERY, thd=0x7fc8a0000d78, packet=0x7fc8a0008979 "", packet_length=50) at /home/mariadb/have_x/10.6/sql/sql_parse.cc:1833
|
#26 0x00005602b84a97ef in do_command (thd=0x7fc8a0000d78) at /home/mariadb/have_x/10.6/sql/sql_parse.cc:1365
|
#27 0x00005602b8652874 in do_handle_one_connection (connect=0x5602bcbc6d58, put_in_cache=true) at /home/mariadb/have_x/10.6/sql/sql_connect.cc:1410
|
#28 0x00005602b86525e2 in handle_one_connection (arg=0x5602bcbc6d58) at /home/mariadb/have_x/10.6/sql/sql_connect.cc:1312
|
#29 0x00005602b8b9741b in pfs_spawn_thread (arg=0x5602bcc0f4c8) at /home/mariadb/have_x/10.6/storage/perfschema/pfs.cc:2201
|
#30 0x00007fc90946c6db in start_thread (arg=0x7fc90002a700) at pthread_create.c:463
|
#31 0x00007fc908652a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
rr profile is available.
FMI, this is the test I used, at the moment it fails reasonably well at least on two different machines:
|
MariaDB/randgen elenst-dev 2cac3349f8 |
perl ./runall-new.pl --mysqld=--binlog-format=row --mysqld=--log-bin --mysqld=--log_bin_trust_function_creators=1 --mysqld=--thread-stack=131072 --duration=350 --seed=1612439028 --reporters=Backtrace,ErrorLog,Deadlock --mysqld=--log_output=FILE --mysqld=--max-statement-time=30 --mysqld=--lock-wait-timeout=10 --mysqld=--innodb-lock-wait-timeout=5 --mysqld=--lower-case-table-names=1 --vcols --mysqld=--plugin-load-add=query_cache_info --mysqld=--plugin-load-add=simple_password_check --threads=4 --queries=25000 --engine=InnoDB,MyISAM,Aria,HEAP --mysqld=--max-digest-length=0 --views=TEMPTABLE --redefine=conf/mariadb/modules/admin.yy --redefine=conf/mariadb/modules/metadata_lock_info.yy --redefine=conf/mariadb/modules/event.yy --redefine=conf/mariadb/modules/alter_table_indexes.yy --redefine=conf/mariadb/sp.yy --redefine=conf/mariadb/modules/dynamic_variables.yy --mysqld=--character-set-server=utf8mb4 --mysqld=--collation-server=utf8mb4_unicode_520_ci --mysqld=--log-tc-size=12K --grammar=conf/mariadb/multi_update.yy --gendata=conf/engines/falcon/falcon_recovery.zz --gendata-advanced --partitions --short-column-names --mtr-build-thread=300 --basedir1=`pwd`/../10.6 --seed=1612439028 --vardir=/dev/shm/var_have_x
|
Attachments
Issue Links
- is caused by
-
-
- Closed
-
- relates to
-
-
- Closed
-
Activity
nikitamalyavin, in row_upd_clust_step() I am seeing several goto exit_func that are not preceded by a call to mtr_t::commit(). One of them is the following, which was added by you in MDEV-20618:
if(!row_upd_store_row(node, trx->mysql_thd, |
thr->prebuilt ? thr->prebuilt->m_mysql_table : NULL)) {
|
err = DB_COMPUTE_VALUE_FAILED;
|
goto exit_func; |
}
|
I think that we need an assertion
ut_ad(!mtr.is_active());
|
at the end of the function. Please check that each code path in this function is actually committing the mini-transaction and thus releasing the page latches.
marko understood, thank you! I am not fluent in mtr stuff. Should I cover other goto's with mtr.commit() as well? Or maybe at exit_func add
if (mtr.is_active()) |
mtr.commit();
|
?
I do not think that mtr_t::is_active() should ever be used outside debug assertions. It is a little unfortunate that mtr_t is not implementing a proper RAII pattern. Maybe we could add a destructor with a debug assertion !is_active() to catch similar bugs.
I think that it is better to avoid code duplication, i.e., add a new label, like this.
diff --git a/storage/innobase/row/row0upd.cc b/storage/innobase/row/row0upd.cc
|
index 81cce1edc76..61142a859cf 100644
|
--- a/storage/innobase/row/row0upd.cc
|
+++ b/storage/innobase/row/row0upd.cc
|
@@ -2813,6 +2813,7 @@ row_upd_clust_step(
|
0, btr_pcur_get_block(pcur),
|
rec, index, offsets, thr);
|
if (err != DB_SUCCESS) {
|
+mtr_commit_and_exit_func:
|
mtr.commit();
|
goto exit_func;
|
} |
All goto exit_func code paths have to be carefully evaluated to ensure that they will be calling mtr_t::commit() after the mtr_t::start().
marko please review https://github.com/MariaDB/server/commit/c45a637a79f891a0f98295b4ff310b09445d8d55
At least one more code path in row_upd_clust_step() is missing a call to mtr_t::commit():
err = row_upd_del_mark_clust_rec(
|
node, index, offsets, thr, referenced,
|
#ifdef WITH_WSREP
|
foreign,
|
#endif
|
&mtr);
|
|
|
if (err == DB_SUCCESS) { |
node->state = UPD_NODE_UPDATE_ALL_SEC;
|
node->index = dict_table_get_next_index(index);
|
}
|
|
|
goto exit_func; |
Inside row_upd_del_mark_clust_rec() we are missing at least one call to mtr_t::commit():
if (!row_upd_store_row(node, trx->mysql_thd, |
thr->prebuilt && thr->prebuilt->table == node->table
|
? thr->prebuilt->m_mysql_table : NULL)) {
|
err = DB_COMPUTE_VALUE_FAILED;
|
return err; |
}
|
Please check all code paths, like I requested yesterday. And please try to not duplicate code. goto is a lesser evil.
marko
> Please check all code paths, like I requested yesterday
I did, but missed that row_upd_del_mark_clust_rec has conditional returns.
> And please try to not duplicate code. goto is a lesser evil
I can't see how can it be lesser here. You want to place a jump inside some `if` for a trade of several bytes.
At the same time the error handling branch can return without jump to a goto metioned, so this label wouldn't even hint for a usage.
So please don't make me overcomplicate readability for no worth
marko I have fixed the return from row_upd_del_mark_clust_rec here: https://github.com/MariaDB/server/commit/9f032c19eb500068f82d3c49a97abf0f7b378b37
I think that we must write a test case that repeats these failures. We must also run all tests and check the code coverage in InnoDB. I will try to do that.
I repeated the bug with RQG and rr, but creating a test case could require major effort. I tried using MDEV-24582 as a guideline, but it was not successful. The virtual column evaluation failure that caused the bug is on the column DB_ROW_HASH1 (MDEV-371) as follows:
|
10.6 b5cea823d7b9c8ecbb87cad8b2d9c35677885a16 |
#5 0x0000563d09890bf5 in push_warning_printf (thd=0x7fcda0002528,
|
level=Sql_state_errno_level::WARN_LEVEL_WARN, code=1406,
|
format=0x563d0a48febf "Data too long for column '%s' at row %lu")
|
at /mariadb/10.6/sql/sql_error.cc:749
|
#6 0x0000563d09b0e09e in Field_longstr::report_if_important_data (
|
this=this@entry=0x563d0d409dd0, pstr=<optimized out>,
|
end=end@entry=0x7fcda02da6cf "\003", count_spaces=false)
|
at /mariadb/10.6/sql/field.cc:11058
|
#7 0x0000563d09b0e362 in Field_longstr::check_conversion_status (
|
this=0x563d0d409dd0, copier=0x7fcda406a880, end=0x7fcda02da6cf "\003",
|
cs=<optimized out>, count_spaces=false) at /mariadb/10.6/sql/field.h:2162
|
#8 Field_longstr::well_formed_copy_with_check (this=0x563d0d409dd0,
|
to=<optimized out>, to_length=<optimized out>, from_cs=<optimized out>,
|
from=<optimized out>, from_length=108, nchars=<optimized out>,
|
count_spaces=false, copy_length=<optimized out>)
|
at /mariadb/10.6/sql/field.h:2177
|
#9 Field_string::store (this=0x563d0d409dd0, from=<optimized out>,
|
length=108, cs=<optimized out>) at /mariadb/10.6/sql/field.cc:7268
|
#10 0x0000563d099e69a4 in Field::save_in_field_str (this=<optimized out>,
|
to=0x563d0d409dd0) at /mariadb/10.6/sql/field.h:746
|
#11 0x0000563d09b56c83 in save_field_in_field (
|
from=0x563d0aa49528 <vtable for Counting_error_handler+16>,
|
null_value=0x563d0d631e6e, to=<optimized out>,
|
>) at /mariadb/10.6/sql/item.cc:6511
|
#12 Item_field::save_in_field (this=0x563d0d631df0, to=<optimized out>, no_conversions=<optimized out>) at /mariadb/10.6/sql/item.cc:6562
|
#13 0x0000563d09b4717f in Item_field::update_vcol_processor (this=0x563d0d5de1d8, arg=0x7fcdac1674e8) at /mariadb/10.6/sql/item.cc:967
|
#14 0x0000563d098c0c23 in Item_args::walk_args (this=0x563d0d5de180, processor=<optimized out>, walk_subquery=<optimized out>, arg=0x7fcdac1674e8) at /mariadb/10.6/sql/item.h:2591
|
#15 Item_func_or_sum::walk (this=0x563d0d5de0f0, processor=<optimized out>, walk_subquery=<optimized out>, arg=0x7fcdac1674e8) at /mariadb/10.6/sql/item.h:5234
|
#16 0x0000563d098c0c23 in Item_args::walk_args (this=0x563d0d5ded40, processor=<optimized out>, walk_subquery=<optimized out>, arg=0x7fcdac1674e8) at /mariadb/10.6/sql/item.h:2591
|
#17 Item_func_or_sum::walk (this=0x563d0d5decb0, processor=<optimized out>, walk_subquery=<optimized out>, arg=0x7fcdac1674e8) at /mariadb/10.6/sql/item.h:5234
|
#18 0x0000563d099c339d in TABLE::update_virtual_field (this=0x7fcdac167378, vf=0x563d0d409b48) at /mariadb/10.6/sql/table.cc:8738
|
#19 0x0000563d09e72374 in innobase_get_computed_value (row=<optimized out>, col=<optimized out>, col@entry=0x7fcd8085a1d8, index=<optimized out>, index@entry=0x7fcda023b0c8,
|
local_heap=local_heap@entry=0x7fcda406ba80, heap=0x7fcda01c52c8, ifield=ifield@entry=0x0, thd=0x7fcda0002528, mysql_table=0x7fcdac167378, mysql_rec=0x7fcda02d9e08 "\200b", old_table=0x0, parent_update=0x0,
|
foreign=0x0) at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:19906
|
#20 0x0000563d0a030fcd in row_upd_store_v_row (node=<optimized out>, update=0x0, thd=<optimized out>, mysql_table=<optimized out>) at /mariadb/10.6/storage/innobase/row/row0upd.cc:1850
|
#21 row_upd_store_row (node=<optimized out>, node@entry=0x563d0d5e5e10, thd=<optimized out>, mysql_table=<optimized out>) at /mariadb/10.6/storage/innobase/row/row0upd.cc:1919
|
#22 0x0000563d0a02bc2d in row_upd_del_mark_clust_rec (node=0x563d0d5e5e10, index=0x7fcda023b0c8, offsets=0x7fcda406bde0, thr=0x563d0d5e6318, referenced=0, foreign=<optimized out>, mtr=0x7fcda406c428)
|
at /mariadb/10.6/storage/innobase/row/row0upd.cc:2700
|
#23 row_upd_clust_step (node=0x563d0d5e5e10, thr=0x563d0d5e6318) at /mariadb/10.6/storage/innobase/row/row0upd.cc:2889
|
We have seem to have a unique index on a virtual BLOB column that depends on another virtual column. I tried to blindly create a test case, using MDEV-24582 for reference, but I failed to reproduce the bug. Here is one variation that I tried:
--source include/have_innodb.inc
|
CREATE TABLE t1 (a VARCHAR(3), |
v VARCHAR(3) AS (CONCAT('x-',a)) VIRTUAL, |
vb TEXT AS (v) VIRTUAL UNIQUE) |
ENGINE=InnoDB;
|
SET sql_mode=''; |
INSERT IGNORE INTO t1 SET a='foo'; |
DELETE FROM t1; |
DROP TABLE t1; |
In my test case, DELETE would proceed to innobase_get_computed_value(), but the evaluation would succeed. Because this failure probably depends on other bugs on virtual columns, it might not be meaningful to spend more effort on writing a regression test.
I decided to refactor the code so that we basically have all code paths going to a single mtr_t::commit() (and some subroutines are calling mtr_t::start() if they need to call mtr_t::commit()). While doing that, I only found the two code paths that were broken in MDEV-20618. So, my more comprehensive change should be functionally equivalent to what nikitamalyavin posted earlier.
Test case for the originally reported assertion failure (on 10.6):
--source include/have_innodb.inc
|
--source include/have_partition.inc
|
CREATE TABLE t1 ( |
id INT AUTO_INCREMENT, |
a BINARY(108), |
b VARCHAR(1621), |
va CHAR(223) AS (a) VIRTUAL, |
vb VARBINARY(2100) AS (b) PERSISTENT, |
PRIMARY KEY(id), |
UNIQUE(va(64),vb,b) |
) ENGINE=InnoDB
|
PARTITION BY LIST(id) ( |
PARTITION p1 VALUES IN (1,2), |
PARTITION p2 VALUES IN (100) |
);
|
INSERT INTO t1 (a,b) VALUES ('foo','bar'),('baz','qux'); |
--error ER_DATA_TOO_LONG
|
UPDATE t1 SET id = 100 LIMIT 1; |
ANALYZE TABLE t1; |
# Cleanup
|
DROP TABLE t1; |
nikitamalyavin, as far as I can tell, the exclusive root page latch was acquired in the thread, and we failed to invoke mtr_t::commit() as part of some error handling:
#3 0x00005602b8f4554e in sux_lock<ssux_lock_low>::x_lock_try (this=0x7fc8e408a640)at /home/mariadb/have_x/10.6/storage/innobase/include/sux_lock.h:442#4 0x00005602b8f55f88 in buf_page_optimistic_get (rw_latch=2,block=0x7fc8e408a5c0, modify_clock=1, mtr=0x7fc900027fb0)at /home/mariadb/have_x/10.6/storage/innobase/buf/buf0buf.cc:3405#5 0x00005602b8f17420 in btr_cur_optimistic_latch_leaves (block=0x7fc8e408a5c0, modify_clock=1, latch_mode=0x7fc900027638,cursor=0x7fc8a001efe8, mtr=0x7fc900027fb0)at /home/mariadb/have_x/10.6/storage/innobase/btr/btr0cur.cc:778#6 0x00005602b8f3afab in optimistic_latch_leaves::operator() (this=0x7fc9000278e0, hint=0x7fc8e408a5c0)at /home/mariadb/have_x/10.6/storage/innobase/btr/btr0pcur.cc:256#7 0x00005602b8f3affc in buf::Block_hint::run_with_hint<optimistic_latch_leaves> (this=0x7fc8a001f0a8, f=...)lude/buf0block_hint.h:57#8 0x00005602b8f39cc3 in btr_pcur_restore_position (latch_mode=2, cursor=0x7fc8a001efe8,mtr=0x7fc900027fb0) at /home/mariadb/have_x/10.6/storage/innobase/btr/btr0pcur.cc:334#9 0x00005602b8e7e911 in row_upd_clust_step (node=0x7fc8a036ae70, thr=0x7fc8a036b378)at /home/mariadb/have_x/10.6/storage/innobase/row/row0upd.cc:2800#10 0x00005602b8e7f37d in row_upd (node=0x7fc8a036ae70, thr=0x7fc8a036b378)at /home/mariadb/have_x/10.6/storage/innobase/row/row0upd.cc:2992…(rr) whenCurrent event: 1272574…(rr) finishRun till exit from #0 0x00005602b8e7e911 in row_upd_clust_step (node=0x7fc8a036ae70, thr=0x7fc8a036b378)at /home/mariadb/have_x/10.6/storage/innobase/row/row0upd.cc:28000x00005602b8e7f37d in row_upd (node=0x7fc8a036ae70, thr=0x7fc8a036b378)at /home/mariadb/have_x/10.6/storage/innobase/row/row0upd.cc:29922992 err = row_upd_clust_step(node, thr);Value returned is $15 = DB_COMPUTE_VALUE_FAILEDAll this time, I had a watchpoint set on the lock word, which remained as WRITER==1U<<31. Later, the same thread would fail because it notices that it is already holding a conflicting latch on the page.
Note: before
MDEV-24142, the outcome could have been different, because rw_lock_t was implemented in a different way. Possibly, it was allowed to acquire S-latch on top of an already acquired X-latch by the same thread. WithMDEV-24142, that is no longer supported. A non-debug build would hang due to this.