[MDEV-15304] Server crash in print_keydup_error / key_unpack or unexpected ER_DUP_KEY - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.2(EOL)
Fix Version/s: 10.2.16
Component/s: Storage Engine - RocksDB
Labels:
- upstream

Description

Note: the test case fails for me all the time right now, but it's still non-deterministic. Try several times if it doesn't fail for you.

INSTALL SONAME 'ha_rocksdb';

CREATE TABLE t1 (a INT, KEY(a)) ENGINE=RocksDB;

INSERT INTO t1 VALUES (1),(2);

CREATE TABLE t2 (b INT) ENGINE=RocksDB;

CREATE OR REPLACE VIEW v2 AS SELECT * FROM t2;

CREATE OR REPLACE TABLE t3 (c INT) ENGINE=RocksDB;

BEGIN;

--connect (con1,localhost,root,,test)

SET lock_wait_timeout= 2;

--delimiter $

CREATE TRIGGER tr BEFORE UPDATE ON t3 FOR EACH ROW

BEGIN

  DELETE FROM t1;

  DELETE FROM non_existing_table;

END $

--delimiter ;

--send

	ALTER TABLE t1 FORCE;

--connection default

DELETE FROM v2 WHERE b < 1;

--error ER_BAD_FIELD_ERROR

UPDATE t3 SET unknown_column = NULL;

--connection con1

--reap

INSERT INTO t1 VALUES (3);

# Cleanup

--disconnect con1

--connection default

COMMIT;

DROP VIEW v2;

DROP TABLE t1, t2, t3;

UNINSTALL SONAME 'ha_rocksdb';

Till recently (I suppose till changes Monty made in scope of ~~MDEV-14970~~ / ~~MDEV-14141~~, although I didn't bisect), the test case above caused the crash:

10.2.12
#3 <signal handler called>
#4 0x000055d7081bc333 in key_unpack (to=0x7fa5e017e7a0, table=0x7fa5d0371c70, key=0x7fa5d03765d0) at /data/src/10.2-bug/sql/key.cc:432
#5 0x000055d7080caf56 in print_keydup_error (table=0x7fa5d0371c70, key=0x7fa5d03765d0, msg=0x55d70abcf1f4 "Duplicate entry '%-.64s' for key '%-.192s'", errflag=0) at /data/src/10.2-bug/sql/handler.cc:3334
#6 0x000055d7080cb094 in print_keydup_error (table=0x7fa5d0371c70, key=0x7fa5d03765d0, errflag=0) at /data/src/10.2-bug/sql/handler.cc:3356
#7 0x000055d7080cb2e8 in handler::print_error (this=0x7fa5d0372878, error=121, errflag=0) at /data/src/10.2-bug/sql/handler.cc:3433
#8 0x000055d707e2fc00 in write_record (thd=0x7fa5ac000b00, table=0x7fa5d0371c70, info=0x7fa5e01804a0) at /data/src/10.2-bug/sql/sql_insert.cc:1958
#9 0x000055d707e2d471 in mysql_insert (thd=0x7fa5ac000b00, table_list=0x7fa5ac011208, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /data/src/10.2-bug/sql/sql_insert.cc:1057
#10 0x000055d707e54af7 in mysql_execute_command (thd=0x7fa5ac000b00) at /data/src/10.2-bug/sql/sql_parse.cc:4415
#11 0x000055d707e5fa6e in mysql_parse (thd=0x7fa5ac000b00, rawbuf=0x7fa5ac011128 "INSERT INTO t1 VALUES (3)", length=25, parser_state=0x7fa5e0181200, is_com_multi=false, is_next_command=false) at /data/src/10.2-bug/sql/sql_parse.cc:7900
#12 0x000055d707e4d97c in dispatch_command (command=COM_QUERY, thd=0x7fa5ac000b00, packet=0x7fa5ac008941 "INSERT INTO t1 VALUES (3)", packet_length=25, is_com_multi=false, is_next_command=false) at /data/src/10.2-bug/sql/sql_parse.cc:1805
#13 0x000055d707e4c2da in do_command (thd=0x7fa5ac000b00) at /data/src/10.2-bug/sql/sql_parse.cc:1360
#14 0x000055d707f9a225 in do_handle_one_connection (connect=0x55d70adddcc0) at /data/src/10.2-bug/sql/sql_connect.cc:1335
#15 0x000055d707f99fb2 in handle_one_connection (arg=0x55d70adddcc0) at /data/src/10.2-bug/sql/sql_connect.cc:1241
#16 0x000055d7083b936e in pfs_spawn_thread (arg=0x55d70ac0d730) at /data/src/10.2-bug/storage/perfschema/pfs.cc:1863
#17 0x00007fa5e7bc6494 in start_thread (arg=0x7fa5e0182700) at pthread_create.c:333
#18 0x00007fa5e5fac93f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Now it causes ER_DUP_KEY on a table which has no unique keys:

mysqltest: At line 31: query 'INSERT INTO t1 VALUES (3)' failed: 1022: Can't write; duplicate key in table 't1'

Attachments

Issue Links

relates to

MDEV-14141 mysqld got exception 0xc0000005

Closed

MDEV-14970 MariaDB crashed with signal 11 and Aria table

Closed

MDEV-15485 Server crashes in read_sep_field / write_record / key_copy

Closed

MDEV-15237 "Can't write; duplicate key in table" when updating some rows in a transaction

Closed

Activity

Ascending order - Click to sort in descending order

Sergei Petrunia added a comment - 2018-04-08 09:54

Tried on the upstream. I got this error:

mysqltest: At line 30: query 'reap' failed: 1205: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1

If I add --error 0,ER_LOCK_WAIT_TIMEOUT before the reap command, then I dont get this ER_DUP_KEY error.

On the current MariaDB 10.2, I get the error fairly reliably

mysqltest: At line 31: query 'INSERT INTO t1 VALUES (3)' failed: 1022: Can't write; duplicate key in table 't1'

Sergei Petrunia added a comment - 2018-04-08 09:54 Tried on the upstream. I got this error: mysqltest: At line 30: query 'reap' failed: 1205: Lock wait timeout exceeded; try restarting transaction: Timeout on table metadata: test.t1 If I add --error 0,ER_LOCK_WAIT_TIMEOUT before the reap command, then I dont get this ER_DUP_KEY error. On the current MariaDB 10.2, I get the error fairly reliably mysqltest: At line 31: query 'INSERT INTO t1 VALUES (3)' failed: 1022: Can't write; duplicate key in table 't1'

Sergei Petrunia added a comment - 2018-05-17 11:20 - edited

Changed the last INSERT int the test to use 1+2:

INSERT INTO t1 VALUES (1+2);

and now I can see that the error originates here:

(gdb) p/x m_pk_descr->m_index_number

  $34 = 0x105

(gdb) wher

  #0  myrocks::ha_rocksdb::check_and_lock_unique_pk (this=0x7fffbc032298, key_id=@0x7fffe84b9078: 1, row_info=..., found=0x7fffe84b9077, pk_changed=0x7fffe84b90cb) at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9202

  #1  0x00007fffeb5ef5bc in myrocks::ha_rocksdb::check_uniqueness_and_lock (this=0x7fffbc032298, row_info=..., pk_changed=0x7fffe84b90cb) at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9355

  #2  0x00007fffeb5f07f9 in myrocks::ha_rocksdb::update_write_row (this=0x7fffbc032298, old_data=0x0, new_data=0x7fffbc030668 "\375\003", skip_unique_check=false) at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9689

  #3  0x00007fffeb5eeacf in myrocks::ha_rocksdb::write_row (this=0x7fffbc032298, buf=0x7fffbc030668 "\375\003") at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9084

  #4  0x0000555555d89b99 in handler::ha_write_row (this=0x7fffbc032298, buf=0x7fffbc030668 "\375\003") at /home/psergey/dev-git/10.2-r11/sql/handler.cc:5958

  #5  0x0000555555ae6b62 in write_record (thd=0x7fffc0000ba0, table=0x7fffbc031690, info=0x7fffe84b94a0) at /home/psergey/dev-git/10.2-r11/sql/sql_insert.cc:1929

  #6  0x0000555555ae4619 in mysql_insert (thd=0x7fffc0000ba0, table_list=0x7fffc0011210, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /home/psergey/dev-git/10.2-r11/sql/sql_insert.cc:1057

  #7  0x0000555555b0bef0 in mysql_execute_command (thd=0x7fffc0000ba0) at /home/psergey/dev-git/10.2-r11/sql/sql_parse.cc:4434

  #8  0x0000555555b17052 in mysql_parse (thd=0x7fffc0000ba0, rawbuf=0x7fffc0011128 "INSERT INTO t1 VALUES (1+2)", length=27, parser_state=0x7fffe84ba200, is_com_multi=false, is_next_command=false) at /home/psergey/dev-git/10.2-r11/sql/sql_parse.cc:7940

We try to lock an index tuple for the internal (hidden) PK. The value we are
trying to lock is:

(gdb) p row_info.new_pk_slice

  $32 = {data_ = 0x7fffbc01b5b0 "", size_ = 12}

(gdb) x/12c row_info.new_pk_slice.data_

  0x7fffbc01b5b0:	0 '\000'	0 '\000'	1 '\001'	5 '\005'	0 '\000'	0 '\000'	0 '\000'	0 '\000'

  0x7fffbc01b5b8:	0 '\000'	0 '\000'	0 '\000'	1 '\001'

(gdb) p/x m_pk_descr->m_index_number

  $34 = 0x105

The hidden PK val is stored here:

(gdb) p m_tbl_def->m_hidden_pk_val

  $35 = {<std::__atomic_base<long long>> = {_M_i = 2}, <No data fields>}

Sergei Petrunia added a comment - 2018-05-17 11:20 - edited Changed the last INSERT int the test to use 1+2: INSERT INTO t1 VALUES (1+2); and now I can see that the error originates here: (gdb) p/x m_pk_descr->m_index_number $34 = 0x105 (gdb) wher #0 myrocks::ha_rocksdb::check_and_lock_unique_pk (this=0x7fffbc032298, key_id=@0x7fffe84b9078: 1, row_info=..., found=0x7fffe84b9077, pk_changed=0x7fffe84b90cb) at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9202 #1 0x00007fffeb5ef5bc in myrocks::ha_rocksdb::check_uniqueness_and_lock (this=0x7fffbc032298, row_info=..., pk_changed=0x7fffe84b90cb) at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9355 #2 0x00007fffeb5f07f9 in myrocks::ha_rocksdb::update_write_row (this=0x7fffbc032298, old_data=0x0, new_data=0x7fffbc030668 "\375\003", skip_unique_check=false) at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9689 #3 0x00007fffeb5eeacf in myrocks::ha_rocksdb::write_row (this=0x7fffbc032298, buf=0x7fffbc030668 "\375\003") at /home/psergey/dev-git/10.2-r11/storage/rocksdb/ha_rocksdb.cc:9084 #4 0x0000555555d89b99 in handler::ha_write_row (this=0x7fffbc032298, buf=0x7fffbc030668 "\375\003") at /home/psergey/dev-git/10.2-r11/sql/handler.cc:5958 #5 0x0000555555ae6b62 in write_record (thd=0x7fffc0000ba0, table=0x7fffbc031690, info=0x7fffe84b94a0) at /home/psergey/dev-git/10.2-r11/sql/sql_insert.cc:1929 #6 0x0000555555ae4619 in mysql_insert (thd=0x7fffc0000ba0, table_list=0x7fffc0011210, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /home/psergey/dev-git/10.2-r11/sql/sql_insert.cc:1057 #7 0x0000555555b0bef0 in mysql_execute_command (thd=0x7fffc0000ba0) at /home/psergey/dev-git/10.2-r11/sql/sql_parse.cc:4434 #8 0x0000555555b17052 in mysql_parse (thd=0x7fffc0000ba0, rawbuf=0x7fffc0011128 "INSERT INTO t1 VALUES (1+2)", length=27, parser_state=0x7fffe84ba200, is_com_multi=false, is_next_command=false) at /home/psergey/dev-git/10.2-r11/sql/sql_parse.cc:7940 We try to lock an index tuple for the internal (hidden) PK. The value we are trying to lock is: (gdb) p row_info.new_pk_slice $32 = {data_ = 0x7fffbc01b5b0 "", size_ = 12} (gdb) x/12c row_info.new_pk_slice.data_ 0x7fffbc01b5b0: 0 '\000' 0 '\000' 1 '\001' 5 '\005' 0 '\000' 0 '\000' 0 '\000' 0 '\000' 0x7fffbc01b5b8: 0 '\000' 0 '\000' 0 '\000' 1 '\001' (gdb) p/x m_pk_descr->m_index_number $34 = 0x105 The hidden PK val is stored here: (gdb) p m_tbl_def->m_hidden_pk_val $35 = {<std::__atomic_base<long long>> = {_M_i = 2}, <No data fields>}

Sergei Petrunia added a comment - 2018-05-18 13:56

Filed as https://github.com/facebook/mysql-5.6/issues/834

Sergei Petrunia added a comment - 2018-05-18 13:56 Filed as https://github.com/facebook/mysql-5.6/issues/834

MariaDB Server

Server crash in print_keydup_error / key_unpack or unexpected ER_DUP_KEY

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration