Percona mysqld got signal 11

I've googled and searched stackexchange, but can't find anything relevant to this particular issue (there are other error 11 issues, just not for this as far as I can tell).

We have a server that is not really doing a ton of reads or writes. The server is a VM with 16 cores and 16GB ram.

MySQL crashes after some unknown amount of time and the error log shows:

```
09:17:14 UTC - mysqld got signal 11 ;
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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=33554432
read_buffer_size=131072
max_used_connections=21
max_threads=502
thread_count=12
connection_count=12
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1131343 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
hread pointer: 0x3329180
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 = 7f4a0043ee70 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0x7cbffc]
/usr/sbin/mysqld(handle_fatal_signal+0x4a1)[0x699251]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f4a3278b340]
/lib/x86_64-linux-gnu/libc.so.6(+0x9818e)[0x7f4a3114b18e]
/usr/sbin/mysqld(_ZN8Protocol14net_store_dataEPKhm+0x47)[0x52e3b7]
/usr/sbin/mysqld[0x52fea4]
/usr/sbin/mysqld(_ZN8Protocol24send_result_set_metadataEP4ListI4ItemEj+0x52c)[0x52fbbc]
/usr/sbin/mysqld(_Z18mysqld_list_fieldsP3THDP10TABLE_LISTPKc+0x22a)[0x5e8d2a]
/usr/sbin/mysqld(_Z16dispatch_command19enum_ser

What catches my eye is the Query recorded in the general log

150629  9:17:14 76946 Query     UPDATE `api_dictionaryitem` SET `name` = '', `group_id` = 4, `count` = 2248844, `last_occurence` = NULL WHERE `api_dictionaryitem`.`id` = 8

when you got signal 11

09:17:14 UTC - mysqld got signal 11 ;

I would suspect you hit some weird bug when running the table api_dictionaryitem in this instance. Why ?

Look at the response to the signal 11 you got which I will itemize

• 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.

Let's see what mysqld was doing before it had to resort to a stack trace

stack_bottom = 7f4a0043ee70 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0x7cbffc]
/usr/sbin/mysqld(handle_fatal_signal+0x4a1)[0x699251]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f4a3278b340]
/lib/x86_64-linux-gnu/libc.so.6(+0x9818e)[0x7f4a3114b18e]
/usr/sbin/mysqld(_ZN8Protocol14net_store_dataEPKhm+0x47)[0x52e3b7]
/usr/sbin/mysqld[0x52fea4]
/usr/sbin/mysqld(_ZN8Protocol24send_result_set_metadataEP4ListI4ItemEj+0x52c)[0x52fbbc]
/usr/sbin/mysqld(_Z18mysqld_list_fieldsP3THDP10TABLE_LISTPKc+0x22a)[0x5e8d2a]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x2498)[0x5a6988]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x13a)[0x643a4a]
/usr/sbin/mysqld(handle_one_connection+0x4a)[0x643b3a]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f4a32783182]

Look at the line that says

/usr/sbin/mysqld(_ZN8Protocol14net_store_dataEPKhm+0x47)[0x52e3b7]

The query at the moment of impact was

UPDATE `api_dictionaryitem` SET
`name` = '',
`group_id` = 4,
`count` = 2248844,
`last_occurence` = NULL
WHERE `api_dictionaryitem`.`id` = 8

What was net_store_data doing at that moment ?

The book Understanding MySQL Internals says something about net_store_data and NULL values on Pages 74,75 under the heading Server Responses subheading Data Fields

Data fields are critical components in many of the server response packets. A data field consists of a length specifier sequence followed by the actual data value. The length specifier sequence can be understood by studying of net_store_length() ...

What is interesting is that net_store_data() calls net_store_length() on line 482 in protocol.cc. That code looks like this

{
  to=net_store_length_fast(to,length);
  memcpy(to,from,length);
  return to+length;
}

On line 489, another version of net_store_data() looks like this:

{
  char buff[20];
  uint length=(uint) (int10_to_str(from,buff,10)-buff);
  to=net_store_length_fast(to,length);
  memcpy(to,buff,length);
  return to+length;
}

On line 498, another version of net_store_data() looks like this:

{
  char buff[22];
  uint length=(uint) (longlong10_to_str(from,buff,10)-buff);
  to=net_store_length_fast(to,length);
  memcpy(to,buff,length);
  return to+length;
}

These snippets of code can be found in SourceCodeBrowser

The code for net_store_length

00450 {
00451   uchar *packet=(uchar*) pkg;
00452   if (length < 251)
00453   {
00454     *packet=(uchar) length;
00455     return (char*) packet+1;
00456   }
00457   *packet++=252;
00458   int2store(packet,(uint) length);
00459   return (char*) packet+2;
00460 }

can be found here

Since net_store_data is the single point of failure in the stack trace, what is in the SQL that would have triggered such a a failure ?

Look back at the SQL

UPDATE `api_dictionaryitem` SET
`name` = '',
`group_id` = 4,
`count` = 2248844,
`last_occurence` = NULL
WHERE `api_dictionaryitem`.`id` = 8

The only thing that looks out of place to me is the

`last_occurence` = NULL

Look back at the code for net_store_length. Note the line

00452   if (length < 251)

What is so special about the number 251 ? According the book Understanding MySQL Internals, the last paragraph on page 74 says:

One may ask why the 1 byte length is limited to 251, when the first reserved value in the net_store_length() is 252. The code 251 has a special meaning. It indicates that there is no length value or data following the code, and the value of the field is the SQL NULL.

Aha !!! The NULL value is being mishandled in net_store_length() when dealing with the last_occurence field. If the last_occurence is a DATETIME or TIMESTAMP, using NULL is most likely not being permitted.

Perhaps changing

`last_occurence` = NULL

to a bogus but legitimate date value

`last_occurence` = '1970-01-01 00:00:00'

would probably nail this problem right on the head.

The stack trace's first response was right : `This could be because you

StackExchange Database Administrators Q#105459, answer score: 11