| Bug #86799 | Crash on UPDATE ON DUPLICATE KEY | ||
|---|---|---|---|
| Submitted: | 22 Jun 2017 18:07 | Modified: | 23 Jun 2017 2:07 |
| Reporter: | Sveta Smirnova (OCA) | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server | Severity: | S2 (Serious) |
| Version: | 5.7.18 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | regression | ||
[22 Jun 2017 18:07]
Sveta Smirnova
[22 Jun 2017 18:09]
Sveta Smirnova
test case for MTR
Attachment: bug1686340.test (application/octet-stream, text), 907 bytes.
[22 Jun 2017 23:24]
MySQL Verification Team
On MAC:
2017-06-22T23:16:28.129233Z 0 [Note] 5.7/bin/mysqld: ready for connections.
Version: '5.7.18-debug-asan' socket: '/tmp/mysql57.sock' port: 3309 Source distribution
2017-06-22T23:16:28.129283Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-06-22T23:16:28.129304Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-06-22T23:16:28.326702Z 0 [Note] End of list of non-natively partitioned tables
ASAN:DEADLYSIGNAL
=================================================================
==543==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000000 (pc 0x7fffe704ba59 bp 0x700010b7bd70 sp 0x700010b7bce0 T29)
==543==The signal is caused by a READ memory access.
==543==Hint: address points to the zero page.
#0 0x7fffe704ba58 in __dynamic_cast (libc++abi.dylib:x86_64+0x25a58)
#1 0x1074730f5 in Field_blob* down_cast<Field_blob*, Field*>(Field*) template_utils.h:78
#2 0x107e55198 in mysql_prepare_blob_values(THD*, List<Item>&, st_mem_root*) sql_insert.cc:398
#3 0x107e5aa96 in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) sql_insert.cc:1655
#4 0x107e5735a in Sql_cmd_insert::mysql_insert(THD*, TABLE_LIST*) sql_insert.cc:769
#5 0x107e649a1 in Sql_cmd_insert::execute(THD*) sql_insert.cc:3103
#6 0x107eea027 in mysql_execute_command(THD*, bool) sql_parse.cc:3607
#7 0x107d552ac in sp_instr_stmt::exec_core(THD*, unsigned int*) sp_instr.cc:983
#8 0x107d52160 in sp_lex_instr::reset_lex_and_exec_core(THD*, unsigned int*, bool) sp_instr.cc:411
#9 0x107d538b8 in sp_lex_instr::validate_lex_and_execute_core(THD*, unsigned int*, bool) sp_instr.cc:711
#10 0x107d54314 in sp_instr_stmt::execute(THD*, unsigned int*) sp_instr.cc:894
#11 0x107d47a99 in sp_head::execute(THD*, bool) sp_head.cc:789
#12 0x107d4b7f4 in sp_head::execute_procedure(THD*, List<Item>*) sp_head.cc:1522
#13 0x107ee77ba in mysql_execute_command(THD*, bool) sql_parse.cc:4593
#14 0x107ee15bc in mysql_parse(THD*, Parser_state*) sql_parse.cc:5612
#15 0x107eddfce in dispatch_command(THD*, COM_DATA const*, enum_server_command) sql_parse.cc:1461
#16 0x107edfce4 in do_command(THD*) sql_parse.cc:999
#17 0x108125183 in handle_connection connection_handler_per_thread.cc:300
#18 0x108a69a42 in pfs_spawn_thread pfs.cc:2188
#19 0x7fffe865293a in _pthread_body (libsystem_pthread.dylib:x86_64+0x393a)
#20 0x7fffe8652886 in _pthread_start (libsystem_pthread.dylib:x86_64+0x3886)
#21 0x7fffe865208c in thread_start (libsystem_pthread.dylib:x86_64+0x308c)
==543==Register values:
rax = 0x8f8f8f8f8f8f8f8f rbx = 0x000061200006de70 rcx = 0x0000000000000000 rdx = 0x000000010987b4e0
rdi = 0x000061200006de70 rsi = 0x0000000109875320 rbp = 0x0000700010b7bd70 rsp = 0x0000700010b7bce0
r8 = 0x0000000000000001 r9 = 0x0000000000000000 r10 = 0x02783f0102783f80 r11 = 0x0000000002783f00
r12 = 0x0000100000000000 r13 = 0x000061200006de70 r14 = 0x000060400003dc10 r15 = 0x000000010987b4e0
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV (libc++abi.dylib:x86_64+0x25a58) in __dynamic_cast
Thread T29 created by T0 here:
#0 0x10c924b96 in wrap_pthread_create (libclang_rt.asan_osx_dynamic.dylib:x86_64+0x49b96)
#1 0x108a69da8 in pfs_spawn_thread_v1 pfs.cc:2239
#2 0x108125e7d in Per_thread_connection_handler::add_connection(Channel_info*) connection_handler_per_thread.cc:403
#3 0x10739efe6 in Connection_handler_manager::process_new_connection(Channel_info*) connection_handler_manager.cc:268
#4 0x10815df1c in Connection_acceptor<Mysqld_socket_listener>::connection_event_loop() connection_acceptor.h:68
#5 0x108158ef6 in mysqld_main(int, char**) mysqld.cc:5045
#6 0x7fffe8439234 in start (libdyld.dylib:x86_64+0x5234)
==543==ABORTING
23:22:53 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68301 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x628000098100
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 700010b83dc0 thread_stack 0x40000
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (610000005370): INSERT INTO tablica_s_govnom(pri1, DT, dop1)
VALUES(pri1, NOW() ,dop1_1)
ON DUPLICATE KEY UPDATE DT=NOW(), dop1=VALUES(dop1)
Connection ID (thread ID): 3
Status: NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
==543==WARNING: ASan is ignoring requested __asan_handle_no_return: stack top: 0x700010b84000; bottom 0x000126ad2000; size: 0x6ffeea0b2000 (123140638973952)
False positive error reports may follow
For details see https://github.com/google/sanitizers/issues/189
miguel:test miguel$
[22 Jun 2017 23:30]
MySQL Verification Team
Verified on MAC OSX Sierra with 5.7.18 source need to test with most current source:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.7.18-debug-asan Source distribution
Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> create database buk;
Query OK, 1 row affected (0.00 sec)
mysql>
mysql> use buk;
Database changed
mysql>
mysql> CREATE TABLE tablica_s_govnom (
-> pri1 int(11) UNSIGNED NOT NULL,
-> DT datetime DEFAULT NULL,
-> dop1 text DEFAULT NULL ,
-> PRIMARY KEY (pri1),
-> INDEX UK_tablica_s_govnom (DT)
-> )
-> ENGINE = INNODB
-> AVG_ROW_LENGTH = 16384
-> CHARACTER SET utf8
-> COLLATE utf8_general_ci
-> ROW_FORMAT = DYNAMIC;
Query OK, 0 rows affected (0.13 sec)
mysql>
mysql> INSERT INTO tablica_s_govnom(pri1,DT,dop1) VALUES(1,NOW(),'2222');
Query OK, 1 row affected (0.00 sec)
mysql> DELIMITER //
mysql> CREATE PROCEDURE Sucks_test()
-> BEGIN
-> DECLARE pri1,pri3 int;
-> DECLARE pri2,comment VARCHAR(255);
-> DECLARE dop1_1,dop2,dop3 VARCHAR(255) DEFAULT '222';
->
-> set pri1=1,pri2='1',pri3=1,comment='123';
->
-> INSERT INTO tablica_s_govnom(pri1, DT, dop1)
-> VALUES(pri1, NOW() ,dop1_1)
-> ON DUPLICATE KEY UPDATE DT=NOW(), dop1=VALUES(dop1);
-> END//
Query OK, 0 rows affected (0.01 sec)
mysql> delimiter ;
mysql> use buk;
Database changed
mysql>
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.29 sec)
mysql> CALL Sucks_test()
-> ;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql>
[23 Jun 2017 2:07]
MySQL Verification Team
Thank you for the bug report. I was able to repeat with version reported 5.7.18 but not anymore with most recent source server so if was somewhat fixed:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.7.20-debug-asan Source distribution 2017-JUN-16
Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> set password='miguel';
Query OK, 0 rows affected (0.01 sec)
mysql> exit
Bye
miguel:test miguel$ mysql -uroot -p --socket=/tmp/mysql57.sock
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 5.7.20-debug-asan Source distribution 2017-JUN-16
Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> create database buk;
Query OK, 1 row affected (0.00 sec)
mysql>
mysql> use buk;
Database changed
mysql>
mysql> CREATE TABLE tablica_s_govnom (
-> pri1 int(11) UNSIGNED NOT NULL,
-> DT datetime DEFAULT NULL,
-> dop1 text DEFAULT NULL ,
-> PRIMARY KEY (pri1),
-> INDEX UK_tablica_s_govnom (DT)
-> )
-> ENGINE = INNODB
-> AVG_ROW_LENGTH = 16384
-> CHARACTER SET utf8
-> COLLATE utf8_general_ci
-> ROW_FORMAT = DYNAMIC;
Query OK, 0 rows affected (0.11 sec)
mysql>
mysql> INSERT INTO tablica_s_govnom(pri1,DT,dop1) VALUES(1,NOW(),'2222');
Query OK, 1 row affected (0.01 sec)
mysql> DELIMITER //
mysql> CREATE PROCEDURE Sucks_test()
-> BEGIN
-> DECLARE pri1,pri3 int;
-> DECLARE pri2,comment VARCHAR(255);
-> DECLARE dop1_1,dop2,dop3 VARCHAR(255) DEFAULT '222';
->
-> set pri1=1,pri2='1',pri3=1,comment='123';
->
-> INSERT INTO tablica_s_govnom(pri1, DT, dop1)
-> VALUES(pri1, NOW() ,dop1_1)
-> ON DUPLICATE KEY UPDATE DT=NOW(), dop1=VALUES(dop1);
-> END//
Query OK, 0 rows affected (0.00 sec)
mysql> delimiter ;
mysql> use buk;
Database changed
mysql>
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.28 sec)
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.02 sec)
mysql> use buk;
Database changed
mysql>
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.29 sec)
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.00 sec)
mysql> use buk;
Database changed
mysql>
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.00 sec)
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.00 sec)
mysql> use buk;
Database changed
mysql>
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.01 sec)
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.01 sec)
mysql> use buk;
Database changed
mysql>
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.00 sec)
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.01 sec)
mysql> use buk;
Database changed
mysql>
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.02 sec)
mysql> CALL Sucks_test();
Query OK, 2 rows affected (0.00 sec)
mysql>
2017-06-23T01:58:04.385864Z 0 [Note] Server socket created on IP: '::'.
2017-06-23T01:58:04.530098Z 0 [Note] Event Scheduler: Loaded 0 events
2017-06-23T01:58:04.531043Z 0 [Note] 5.7/bin/mysqld: ready for connections.
Version: '5.7.20-debug-asan' socket: '/tmp/mysql57.sock' port: 3309 Source distribution 2017-JUN-16
2017-06-23T01:58:04.531079Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-06-23T01:58:04.531096Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-06-23T01:58:04.597131Z 0 [Note] End of list of non-natively partitioned tables
[14 Aug 2017 22:28]
Yura Sorokin
Looks like the issue is fixed in 5.7.19 and 8.0.2 Incorrect behavior could occur for INSERT statements executed in stored-program or prepared-statement context, if the VALUES part of an ON DUPLICATE KEY UPDATE clause referred to a BLOB value in the INSERT column list. (Bug #24538207, Bug #25361251, Bug #25530880, Bug #25684790)
[26 Sep 2017 10:20]
Raghu Rajput
Hi This affects me,
Mysql version is : 5.7.19
And issue is for only on duplicate key, if duplicate key exists.
Following is the log.
(gdb) backtrace full
#0 __pthread_kill (threadid=<optimized out>, signo=11) at ../sysdeps/unix/sysv/linux/pthread_kill.c:62
pd = <optimized out>
tid = 8999
val = 0
#1 0x000056511346df15 in handle_fatal_signal ()
No symbol table info available.
#2 <signal handler called>
No locals.
#3 __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:242
No locals.
#4 0x000056511349d98d in Field_blob::copy_blob_value(st_mem_root*) ()
No symbol table info available.
#5 0x0000565113ab1f50 in mysql_prepare_blob_values(THD*, List<Item>&, st_mem_root*) ()
No symbol table info available.
#6 0x0000565113ab4592 in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) ()
No symbol table info available.
#7 0x0000565113ab4fe5 in Sql_cmd_insert::mysql_insert(THD*, TABLE_LIST*) ()
No symbol table info available.
#8 0x0000565113ab5852 in Sql_cmd_insert::execute(THD*) ()
No symbol table info available.
#9 0x00005651139364c2 in mysql_execute_command(THD*, bool) ()
No symbol table info available.
#10 0x000056511393b0cd in mysql_parse(THD*, Parser_state*) ()
No symbol table info available.
#11 0x000056511393c1b5 in dispatch_command(THD*, COM_DATA const*, enum_server_command) ()
No symbol table info available.
#12 0x000056511393d6ef in do_command(THD*) ()
No symbol table info available.
#13 0x00005651139fce38 in handle_connection ()
No symbol table info available.
#14 0x0000565113eec1e4 in pfs_spawn_thread ()
No symbol table info available.
#15 0x00007f97178956da in start_thread (arg=0x7f96f8103700) at pthread_create.c:456
__res = <optimized out>
pd = 0x7f96f8103700
now = <optimized out>
unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140286383634176, 2776709031422328569, 140728074655886, 140728074655887, 140286383634880, 140286383634176, -2763756585279029511, -2763251710482579719}, mask_was_saved = 0}}, priv = {
pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
not_first_call = <optimized out>
pagesize_m1 = <optimized out>
sp = <optimized out>
freesize = <optimized out>
__PRETTY_FUNCTION__ = "start_thread"
#16 0x00007f9716d27d7f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:105
No locals.
Please help me out as this is happening in production.
