[MDEV-11779] Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed in Diagnostics_area::set_ok_status upon UPDATE on partitioned table Created: 2017-01-12  Updated: 2021-01-14  Resolved: 2018-06-10

Status: Closed
Project: MariaDB Server
Component/s: Data Manipulation - Update, Partitioning
Affects Version/s: 10.0, 10.1, 10.2
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: None

Issue Links:
Duplicate
is duplicated by MDEV-5628 Assertion `! is_set()' or `!is_set() ... Closed
Problem/Incident
causes MDEV-16455 Re-verify alternative test cases and ... Open

 Description   

Note: MDEV-11597 and MDEV-11317 have been fixed by now, but the problem below (much more difficult to reproduce) is still there.

10.2 fd0479ce592e0

 
mysqld: /data/src/10.2/sql/sql_error.cc:380: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed.
 
170112  2:52:15 [ERROR] mysqld got signal 6 ;


# 2017-01-12T02:52:40 [13124] #6  0x00007f79e2fcd266 in __assert_fail_base (fmt=0x7f79e3106238 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f79e652e430 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=file@entry=0x7f79e652e368 "/data/src/10.2/sql/sql_error.cc", line=line@entry=380, function=function@entry=0x7f79e652e880 <Diagnostics_area::set_ok_status(unsigned long long, unsigned long long, char const*)::__PRETTY_FUNCTION__> "void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*)") at assert.c:92
 
# 2017-01-12T02:52:40 [13124] #7  0x00007f79e2fcd312 in __GI___assert_fail (assertion=0x7f79e652e430 "!is_set() || (m_status == DA_OK_BULK && is_bulk_op())", file=0x7f79e652e368 "/data/src/10.2/sql/sql_error.cc", line=380, function=0x7f79e652e880 <Diagnostics_area::set_ok_status(unsigned long long, unsigned long long, char const*)::__PRETTY_FUNCTION__> "void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*)") at assert.c:101
 
# 2017-01-12T02:52:40 [13124] #8  0x00007f79e5a80a5d in Diagnostics_area::set_ok_status (this=0x7f799d41b050, affected_rows=0, last_insert_id=0, message=0x0) at /data/src/10.2/sql/sql_error.cc:380
 
# 2017-01-12T02:52:40 [13124] #9  0x00007f79e5a3604d in my_ok (thd=0x7f799d416070, affected_rows=0, id=0, message=0x0) at /data/src/10.2/sql/sql_class.h:4329
 
# 2017-01-12T02:52:40 [13124] #10 0x00007f79e5aae3e5 in mysql_execute_command (thd=0x7f799d416070) at /data/src/10.2/sql/sql_parse.cc:3937
 
# 2017-01-12T02:52:40 [13124] #11 0x00007f79e5aba8a0 in mysql_parse (thd=0x7f799d416070, rawbuf=0x7f799d4631d0 "CREATE OR REPLACE TABLE `create_or_replace_tmp` LIKE `t6` /* QNO 430 CON_ID 13 */", length=81, parser_state=0x7f79e6b6be20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7842
 
# 2017-01-12T02:52:40 [13124] #12 0x00007f79e5aa89ab in dispatch_command (command=COM_QUERY, thd=0x7f799d416070, packet=0x7f799d454071 "CREATE OR REPLACE TABLE `create_or_replace_tmp` LIKE `t6` /* QNO 430 CON_ID 13 */ ", packet_length=82, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1800
 
# 2017-01-12T02:52:40 [13124] #13 0x00007f79e5aa73a3 in do_command (thd=0x7f799d416070) at /data/src/10.2/sql/sql_parse.cc:1360
 
# 2017-01-12T02:52:40 [13124] #14 0x00007f79e5befc48 in do_handle_one_connection (connect=0x7f79e2460050) at /data/src/10.2/sql/sql_connect.cc:1354
 
# 2017-01-12T02:52:40 [13124] #15 0x00007f79e5bef9d5 in handle_one_connection (arg=0x7f79e2460050) at /data/src/10.2/sql/sql_connect.cc:1260
 
# 2017-01-12T02:52:40 [13124] #16 0x00007f79e50da0a4 in start_thread (arg=0x7f79e6b6d300) at pthread_create.c:309
 
# 2017-01-12T02:52:40 [13124] #17 0x00007f79e308787d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

On 10.0 and 10.1 the assertion is different:

10.1 4b05d60e62e

 
mysqld: /data/src/10.1/sql/sql_error.cc:378: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `! is_set()' failed.
 
170112  3:05:13 [ERROR] mysqld got signal 6 ;
 
 
 
# 2017-01-12T03:05:36 [13531] #7  0x00007f95227a6312 in __GI___assert_fail (assertion=0x7f95258c72c0 "! is_set()", file=0x7f95258c71f8 "/data/src/10.1/sql/sql_error.cc", line=378, function=0x7f95258c76c0 <Diagnostics_area::set_ok_status(unsigned long long, unsigned long long, char const*)::__PRETTY_FUNCTION__> "void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*)") at assert.c:101
 
# 2017-01-12T03:05:36 [13531] #8  0x00007f9524f86b00 in Diagnostics_area::set_ok_status (this=0x7f94fe671e78, affected_rows=0, last_insert_id=0, message=0x0) at /data/src/10.1/sql/sql_error.cc:378
 
# 2017-01-12T03:05:36 [13531] #9  0x00007f9524f40471 in my_ok (thd=0x7f94fe66d070, affected_rows=0, id=0, message=0x0) at /data/src/10.1/sql/sql_class.h:4080
 
# 2017-01-12T03:05:36 [13531] #10 0x00007f9524fb0dfb in mysql_execute_command (thd=0x7f94fe66d070) at /data/src/10.1/sql/sql_parse.cc:3467
 
# 2017-01-12T03:05:36 [13531] #11 0x00007f9524fbcbcd in mysql_parse (thd=0x7f94fe66d070, rawbuf=0x7f94f4822088 "CREATE OR REPLACE TABLE `create_or_replace_tmp` LIKE `t2` /* QNO 454 CON_ID 8 */", length=80, parser_state=0x7f9525e58630) at /data/src/10.1/sql/sql_parse.cc:7322
 
# 2017-01-12T03:05:36 [13531] #12 0x00007f9524fabbda in dispatch_command (command=COM_QUERY, thd=0x7f94fe66d070, packet=0x7f94fe673071 "CREATE OR REPLACE TABLE `create_or_replace_tmp` LIKE `t2` /* QNO 454 CON_ID 8 */ ", packet_length=81) at /data/src/10.1/sql/sql_parse.cc:1488
 
# 2017-01-12T03:05:36 [13531] #13 0x00007f9524faa953 in do_command (thd=0x7f94fe66d070) at /data/src/10.1/sql/sql_parse.cc:1109
 
# 2017-01-12T03:05:36 [13531] #14 0x00007f95250e07cc in do_handle_one_connection (thd_arg=0x7f94fe66d070) at /data/src/10.1/sql/sql_connect.cc:1350
 
# 2017-01-12T03:05:36 [13531] #15 0x00007f95250e0530 in handle_one_connection (arg=0x7f94fe66d070) at /data/src/10.1/sql/sql_connect.cc:1262
 
# 2017-01-12T03:05:36 [13531] #16 0x00007f95246a80a4 in start_thread (arg=0x7f9525e59b00) at pthread_create.c:309
 
# 2017-01-12T03:05:36 [13531] #17 0x00007f952286087d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

To reproduce:

git clone https://github.com/elenst/rqg --branch mdev11779 rqg-mdev11779
 
cd rqg-mdev11779
 
. ./run <basedir> <vardir>

The test starts the server on port 19300 and runs the test flow for 5 minutes. The flow includes killing and restarting the server, it produces a lot of noise. It can also return bogus STATUS_SERVER_CRASHED at the end, it is not an indication of the problem itself. The real indication is that the test terminates prematurely and prints a stack trace at the end (and of course the server error log contains the error report).

Due to crash/restart being a part of the flow, unfortunately it's impossible to convert it to gentest.pl running on a previously started server.



 Comments   
Comment by Elena Stepanova [ 2017-12-31 ]

I am getting numerous occasions of the same assertion failure in 10.3 tests, maybe we can do better than an RQG test for reproducing.

https://api.travis-ci.org/v3/job/323242512/log.txt

Comment by Elena Stepanova [ 2018-06-10 ]

It turns out we can, apparently it's the same problem as MDEV-5628. Here is a non-finalized test case derived directly from a travis failure:

--source include/have_partition.inc
 
--disable_abort_on_error
 
--let $con4_id= `SELECT CONNECTION_ID() AS con4`
 
	CREATE TABLE `table2_key_pk_parts_2_int_autoinc` (
 
 `col_int` int,
 
 pk integer auto_increment,
 
 `col_char_12` char(12),
 
 `col_char_12_key` char(12),
 
 `col_int_key` int,
 
 primary key (pk),
 
 key (`col_int_key` )) /*!50100 PARTITION BY key (pk) partitions 2 */ /* QNO 38 CON_ID 4 */;
 
	CREATE OR REPLACE VIEW `view_table2_key_pk_parts_2_int_autoinc` AS SELECT * FROM `table2_key_pk_parts_2_int_autoinc` /* QNO 39 CON_ID 4 */;
 
--let $con8_id= `SELECT CONNECTION_ID() AS con8`
 
--let $con12_id= `SELECT CONNECTION_ID() AS con12`
 
--let $con13_id= `SELECT CONNECTION_ID() AS con13`
 
	CREATE OR REPLACE TABLE `table10_key_pk_parts_2_int_autoinc` (scol8 VARCHAR(47233), `pk` INT UNSIGNED NOT NULL, `col_char_12_key` BINARY NOT NULL, `col_char_12` CHAR )  /* QNO 78 CON_ID 13 */;
 
	INSERT INTO `table10_key_pk_parts_2_int_autoinc` () VALUES () /* QNO 1853 CON_ID 12 */;
 
	INSERT LOW_PRIORITY IGNORE INTO `table10_key_pk_parts_2_int_autoinc` (`pk`) VALUES (NULL) /* QNO 1861 CON_ID 12 */;
 
	UPDATE LOW_PRIORITY `view_table2_key_pk_parts_2_int_autoinc` AS X SET `pk` = 1919352832 WHERE X.`pk` = ( SELECT `col_char_12_key` FROM `table10_key_pk_parts_2_int_autoinc` WHERE `pk` = 'o' ) ORDER BY `col_char_12`,`col_char_12_key`,`col_int`,`col_int_key`,`pk` LIMIT 8 /* QNO 2332 CON_ID 12 */;

It fails as described here, on 10.x as of 10.0 c4499a03917ae, 10.1 3627dd7f6a1c, 10.2 a31e99a89cc75, 10.3 62d21ddac1; but it doesn't fail on 5.5 as MDEV-5628, so there is still a chance it's a somewhat different variation. I'll close it as a duplicate for now, but will add it to the task MDEV-16455 (re-verifying probable duplicates)

Comment by Elena Stepanova [ 2021-01-14 ]

It was indeed fixed by the patch for MDEV-5628.

Generated at Thu Feb 08 07:52:35 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.