MySQL Bugs: #71247: memcached set crash with policy caching

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

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

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

[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"."