MyRocks slave crashed because of the wrong errkey.

[mariadb-DanielLee]

Build tested:
myrocks@rocksdb:~/builds/mytest/mysql-5.6$ git show
commit f03213b
Author: Yoshinori Matsunobu yoshinori@fb.com
Date: Fri Dec 4 13:42:46 2015 -0800

Breaking this issue out issue #111 for ease of tracking:

Both Yoshinori and I encountered this issue.

From Daniel:

myrocks@rocksdb:/tmp$ gdb /home/myrocks/builds/mytest/mysql-5.6/sql/mysqld core
GNU gdb (Ubuntu 7.7.1-0ubuntu5~14.04.2) 7.7.1
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/.
Find the GDB manual and other documentation resources online at:
http://www.gnu.org/software/gdb/documentation/.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /home/myrocks/builds/mytest/mysql-5.6/sql/mysqld...done.
[New LWP 46461]
[New LWP 38939]
[New LWP 38935]
[New LWP 38941]
[New LWP 38940]
[New LWP 38942]
[New LWP 38980]
[New LWP 46451]
[New LWP 38982]
[New LWP 46161]
[New LWP 46457]
[New LWP 46459]
[New LWP 46384]
[New LWP 46411]
[New LWP 46453]
[New LWP 46413]
[New LWP 45561]
[New LWP 46116]
[New LWP 46381]
[New LWP 46337]
[New LWP 46341]
[New LWP 46463]
[New LWP 46465]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `./mysqld --defaults-file=/home/myrocks/builds/mytest/mytest.cnf --rocksdb_stric'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 key_unpack (to=to@entry=0x7f11a1c29860, table=table@entry=0x7f114c023490, key=key@entry=0x7f115b028bf8)

at /home/myrocks/builds/mytest/mysql-5.6/sql/key.cc:443
443 KEY_PART_INFO *key_part_end= key->key_part + key->user_defined_key_parts;
Traceback (most recent call last):
File "/usr/share/gdb/auto-load/usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.19-gdb.py", line 63, in
from libstdcxx.v6.printers import register_libstdcxx_printers
ImportError: No module named 'libstdcxx'
(gdb) bt
#0 key_unpack (to=to@entry=0x7f11a1c29860, table=table@entry=0x7f114c023490, key=key@entry=0x7f115b028bf8)

at /home/myrocks/builds/mytest/mysql-5.6/sql/key.cc:443
#1 0x000000000066d52f in print_keydup_error (table=table@entry=0x7f114c023490, key=key@entry=0x7f115b028bf8,

msg=0x237e72a "Duplicate entry '%-.64s' for key '%-.192s'", errflag=errflag@entry=0) at /home/myrocks/builds/mytest/mysql-5.6/sql/handler.cc:3738
#2 0x000000000066dcf9 in print_keydup_error (errflag=0, key=0x7f115b028bf8, table=0x7f114c023490) at /home/myrocks/builds/mytest/mysql-5.6/sql/handler.cc:3759
#3 handler::print_error (this=0x7f114c025330, error=, errflag=0) at /home/myrocks/builds/mytest/mysql-5.6/sql/handler.cc:3809
#4 0x0000000000de4e5d in ha_partition::print_error (this=0x7f114c024d40, error=121, errflag=0) at /home/myrocks/builds/mytest/mysql-5.6/sql/ha_partition.cc:8103
#5 0x00000000007a9bc2 in write_record (thd=thd@entry=0x24b41b0, table=table@entry=0x7f114c023490, info=info@entry=0x7f11a1c2c120,

update=update@entry=0x7f11a1c2c1a0) at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_insert.cc:1908
#6 0x00000000007ae608 in mysql_insert (thd=thd@entry=0x24b41b0, table_list=0x7f1144006b08, fields=..., values_list=..., update_fields=..., update_values=...,

duplic=DUP_ERROR, ignore=false) at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_insert.cc:1030
#7 0x00000000007c709b in mysql_execute_command (thd=thd@entry=0x24b41b0, statement_start_time=statement_start_time@entry=0x7f11a1c2d7b0,

post_parse=post_parse@entry=0x7f11a1c2d930) at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_parse.cc:4064
#8 0x00000000007ca4c7 in mysql_parse (thd=thd@entry=0x24b41b0, rawbuf=, length=, parser_state=parser_state@entry=0x7f11a1c2e0b0,

last_timer=last_timer@entry=0x7f11a1c2d930, async_commit=async_commit@entry=0x7f11a1c2d920 "") at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_parse.cc:7233
#9 0x00000000007cbd12 in dispatch_command (command=COM_QUERY, thd=0x24b41b0, packet=, packet_length=)

at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_parse.cc:1595
#10 0x00000000007cd80e in do_command (thd=) at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_parse.cc:1071
#11 0x00000000007935b5 in do_handle_one_connection (thd_arg=) at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_connect.cc:1071
#12 0x0000000000793679 in handle_one_connection (arg=) at /home/myrocks/builds/mytest/mysql-5.6/sql/sql_connect.cc:929
#13 0x00007f11a9f32182 in start_thread (arg=0x7f11a1c2f700) at pthread_create.c:312
#14 0x00007f11a943f47d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

(gdb)

From Herman:

I took a look at the core file. It looks like we might not be setting errkey properly when this duplicate key error occurs for the partitioned table.

(gdb) f 2
#2 0x000000000066dcf9 in print_keydup_error (errflag=0, key=0x7f115b028bf8, table=0x7f114c023490) at /home/myrocks/builds/mytest/mysql-5.6/sql/handler.cc:3759

3759 print_keydup_error(table, key, ER(ER_DUP_ENTRY_WITH_KEY_NAME), errflag);
(gdb) p key
$2 = (KEY *) 0x7f115b028bf8
(gdb) p table->key_info
$3 = (KEY *) 0x7f114c027f50
(gdb) p $2 - $3
$4 = 2097179
(gdb) p table->file->errkey
$5 = 2097179

From Yoshinori:

When I ran master/slave mismatch test (#107), MyRocks slave crashed because of the wrong errkey. This matches Herman's last issue.

(gdb) bt
#0 0x00007f837938a631 in pthread_kill (threadid=, signo=11) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1 0x0000000000723883 in handle_fatal_signal(int) (sig=11) at /home/yoshinori/local/mysql/5.6/sql/signal_handler.cc:239
#2 0x00007f837938d550 in () at /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
#3 0x000000000070d5da in key_unpack(String, TABLE, st_key*) (to=to@entry=0x7f836e756840, table=0x7f837088ee00, key=key@entry=0x7f9c771bf250) at /home/yoshinori/local/mysql/5.6/sql/key.cc:443
#4 0x0000000000658152 in print_keydup_error(TABLE_, st_key_, char const*, int) (table=, key=0x7f9c771bf250, msg=0x7f837677b33a "Duplicate entry '%-.64s' for key '%-.192s'", errflag=errflag@entry=0) at /home/yoshinori/local/mysql/5.6/sql/handler.cc:3738
#5 0x00000000006582f2 in print_keydup_error(TABLE_, st_key_, int) (table=, key=, errflag=errflag@entry=0) at /home/yoshinori/local/mysql/5.6/sql/handler.cc:3759
#6 0x0000000000658ccc in handler::print_error(int, int) (this=0x7f83708af410, error=121, errflag=0) at /home/yoshinori/local/mysql/5.6/sql/handler.cc:3809
#7 0x0000000000e2146d in ha_partition::print_error(int, int) (this=0x7f83708cd810, error=121, errflag=0) at /home/yoshinori/local/mysql/5.6/sql/ha_partition.cc:8103
#8 0x00000000008095a6 in mysql_update(THD_, TABLE_LIST_, List&, List&, Item_, unsigned int, st_order_, unsigned long long, enum_duplicates, bool, unsigned long long_, unsigned long long_) (thd=thd@entry=0x7f8372829640, table_list=, fields=..., values=..., conds=0x7f836d8314b8, order_num=, order=, limit=4, handle_duplicates=DUP_ERROR, ignore=false, found_return=found_return@entry=0x7f836e7594e0, updated_return=updated_return@entry=0x7f836e7595c0) at /home/yoshinori/local/mysql/5.6/sql/sql_update.cc:832
#9 0x00000000007a076a in mysql_execute_command(THD_, unsigned long long_, unsigned long long*) (thd=thd@entry=0x7f8372829640, statement_start_time=statement_start_time@entry=0x7f836e75a740, post_parse=post_parse@entry=0x7f836e75a8d0) at /home/yoshinori/local/mysql/5.6/sql/sql_parse.cc:3923
#10 0x00000000007a42e7 in mysql_parse(THD_, char_, unsigned int, Parser_state_, unsigned long long_, char*) (thd=thd@entry=0x7f8372829640, rawbuf=, length=, parser_state=parser_state@entry=0x7f836e75b050, last_timer=last_timer@entry=0x7f836e75a8d0, async_commit=async_commit@entry=0x7f836e75a8c0 "") at /home/yoshinori/local/mysql/5.6/sql/sql_parse.cc:7233
#11 0x00000000007a5adb in dispatch_command(enum_server_command, THD_, char_, unsigned int) (command=COM_QUERY, thd=0x7f8372829640, packet=, packet_length=) at /home/yoshinori/local/mysql/5.6/sql/sql_parse.cc:1595

(gdb) frame 3
#3 key_unpack (to=to@entry=0x7f836e756840, table=0x7f837088ee00, key=key@entry=0x7f9c771bf250) at /home/yoshinori/local/mysql/5.6/sql/key.cc:443

443 KEY_PART_INFO *key_part_end= key->key_part + key->user_defined_key_parts;
(gdb) p key->key_part
Cannot access memory at address 0x7f9c771bf288
(gdb) p key->user_defined_key_parts
Cannot access memory at address 0x7f9c771bf268
(gdb) p key
$1 = (KEY *) 0x7f9c771bf250
(gdb) p *key
Cannot access memory at address 0x7f9c771bf250

(gdb) p &table->key_info[0]
$39 = (KEY *) 0x7f8370857010
(gdb) p &table->key_info[1]
$40 = (KEY *) 0x7f8370857088
(gdb) p &table->key_info[2]
$41 = (KEY *) 0x7f8370857100
(gdb) p &table->key_info[3]
$42 = (KEY *) 0x7f8370857178
(gdb) p &table->key_info[4]
$43 = (KEY *) 0x7f83708571f0

(gdb) p error
$45 = 121
(gdb) p table
$46 = (TABLE *) 0x7f837088ee00

uint handler::get_dup_key(int error)
(gdb) p table->file->errkey
$47 = 895705912

[yoshinorim]

@dleeyh : Herman committed a fix yesterday https://reviews.facebook.net/D51675 . Could you rebuild MyRocks and try again if it reproduces?

[mariadb-DanielLee]

Build verified:
commit 9995793
Date: Mon Dec 7 16:09:46 2015 -0800
debug off
Status: Passed

Executed 100 RQG tests in a loop, with 20 threads
Executed 100 RQG tests in a loop, with 50 threads