Bug #71247 memcached set crash with policy caching
Submitted: 30 Dec 2013 14:14 Modified: 17 Jul 2014 8:37
Reporter: Michael Ivanov Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Memcached Severity:S1 (Critical)
Version:5.6.15 OS:Linux (CentOS 6)
Assigned to: CPU Architecture:Any

[30 Dec 2013 14:14] Michael Ivanov
Description:
When you invoke two memcached set commands over the same connection MySQL crashes with a default config and cache policy set to caching or cache_only. It works fine with cache policy innodb_only.

Here is the error log:
mysqld: /pb2/build/sb_0-10831761-1384711694.67/rpm/BUILD/mysql-5.6.15/mysql-5.6.15/plugin/innodb_memcached/innodb_memcache/cache-src/items.c:291: item_link_q: Assertion `it != *head' failed.
13:58:30 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.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68242 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
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 = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8d00d5]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x65f264]
/lib64/libpthread.so.0(+0xf710)[0x7fdf5c0df710]
/lib64/libc.so.6(gsignal+0x35)[0x7fdf5ad8a925]
/lib64/libc.so.6(abort+0x175)[0x7fdf5ad8c105]
/lib64/libc.so.6(+0x2ba4e)[0x7fdf5ad83a4e]
/lib64/libc.so.6(__assert_perror_fail+0x0)[0x7fdf5ad83b10]
/usr/lib64/mysql/plugin//innodb_engine.so(+0x10d22)[0x7fdf2d604d22]
/usr/lib64/mysql/plugin//innodb_engine.so(+0x11746)[0x7fdf2d605746]
/usr/lib64/mysql/plugin//innodb_engine.so(+0x11d8c)[0x7fdf2d605d8c]
/usr/lib64/mysql/plugin//innodb_engine.so(store_item+0x50)[0x7fdf2d606230]
/usr/lib64/mysql/plugin//innodb_engine.so(+0x9b72)[0x7fdf2d5fdb72]
/usr/lib64/mysql/plugin/libmemcached.so(conn_nread+0x760)[0x7fdf58e42f30]
/usr/lib64/mysql/plugin/libmemcached.so(+0x9a7c)[0x7fdf58e37a7c]
/usr/lib64/mysql/plugin/libmemcached.so(event_base_loop+0x286)[0x7fdf58e49b86]
/usr/lib64/mysql/plugin/libmemcached.so(+0x195d2)[0x7fdf58e475d2]
/lib64/libpthread.so.0(+0x79d1)[0x7fdf5c0d79d1]
/lib64/libc.so.6(clone+0x6d)[0x7fdf5ae40b6d]

How to repeat:
telnet to mysql memcached port and invoke 2 set command sequentially
[1 Jan 2014 7:30] Shane Bester
Thanks for the bug report.

(gdb) bt
#0  in pthread_kill () from /lib64/libpthread.so.0
#1  in handle_fatal_signal (sig=6) at ./mysqlcom-pro-5.6.15/sql/signal_handler.cc:248
#2  <signal handler called>
#3  in raise () from /lib64/libc.so.6
#4  in abort () from /lib64/libc.so.6
#5  in __assert_fail_base () from /lib64/libc.so.6
#6  in __assert_fail () from /lib64/libc.so.6
#7  in assoc_insert (engine=0x7f94702ad320, hash=1409645107, it=0x7f94680043a0) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/innodb_memcache/cache-src/assoc.c:113
#8  in do_item_link (engine=0x7f94702ad320, it=0x7f94680043a0) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/innodb_memcache/cache-src/items.c:331
#9  in do_item_replace (new_it=<optimized out>, it=<optimized out>, engine=<optimized out>) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/innodb_memcache/cache-src/items.c:399
#10 in do_store_item (engine=0x7f94702ad320, it=0x7f94680043a0, cas=0x7f9468000b10, operation=OPERATION_SET, cookie=0x7f94680008c0) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/innodb_memcache/cache-src/items.c:664
#11 in store_item (engine=0x7f94702ad320, item=0x7f94680043a0, cas=0x7f9468000b10, operation=OPERATION_SET, cookie=0x7f94680008c0) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/innodb_memcache/cache-src/items.c:881
#12 in innodb_store (handle=0x7f94702ad060, cookie=0x7f94680008c0, item=0x7f94680043a0, cas=0x7f9468000b10, op=OPERATION_SET, vbucket=<optimized out>) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/innodb_memcache/src/innodb_engine.c:1795
#13 in complete_nread (c=<optimized out>) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/daemon_memcached/daemon/memcached.c:1108
#14 in conn_nread (c=0x7f94680008c0) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/daemon_memcached/daemon/memcached.c:5378
#15 in event_handler (fd=<optimized out>, which=<optimized out>, arg=0x7f94680008c0) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/daemon_memcached/daemon/memcached.c:5684
#16 in event_process_active (base=<optimized out>) at ./mysqlcom-pro-5.6.15/libevent/event.c:392
#17 in event_base_loop (base=0x7f94702c54f0, flags=<optimized out>) at ./mysqlcom-pro-5.6.15/libevent/event.c:544
#18 in worker_libevent (arg=0x7f94702cb1d0) at ./mysqlcom-pro-5.6.15/plugin/innodb_memcached/daemon_memcached/daemon/thread.c:304
#19 in start_thread () from /lib64/libpthread.so.0
#20 in clone () from /lib64/libc.so.6
[17 Jul 2014 8:37] Erlend Dahl
[9 Jan 2014 5:26] Daniel T Price

Fixed as of 5.6.16, and here's the changelog entry:

"Due to a regression introduced by the fix for Bug#17371537, memory was
not allocated for the default Memcached engine when using the default
Memcached engine as the backstore for data instead of "InnoDB"."