Bug #40474 mysqld got signal 11
Submitted: 2 Nov 2008 13:51 Modified: 23 Apr 2009 16:39
Reporter: Jui-Nan Lin Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: General Severity:S3 (Non-critical)
Version:5.1.29, 5.1.30 OS:Linux (Debian 2.6.18-6-amd64)
Assigned to: CPU Architecture:Any
Tags: regression

[2 Nov 2008 13:51] Jui-Nan Lin
Description:
mysqld as a replication slave got signal 11 while running some queries. We use InnoDB only. Master server is 5.1.23.

Here is mysql.err:
574674 081102 21:29:28 - mysqld got signal 11 ;
574675 This could be because you hit a bug. It is also possible that this binary
574676 or one of the libraries it was linked against is corrupt, improperly built,
574677 or misconfigured. This error can also be caused by malfunctioning hardware.
574678 We will try our best to scrape up some info that will hopefully help diagnose
574679 the problem, but since we have already crashed, something is definitely wrong
574680 and this may fail.
574681
574682 key_buffer_size=67108864
574683 read_buffer_size=33554432
574684 max_used_connections=288
574685 max_threads=4096
574686 threads_connected=5
574687 It is possible that mysqld could use up to
574688 key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 402760320 K
574689 bytes of memory
574690 Hope that's ok; if not, decrease some variables in the equation.
574691
574692 thd: 0x1b0df00
574693 Attempting backtrace. You can use the following information to find out
574694 where mysqld died. If you see no messages after this, something went
574695 terribly wrong...
574696 stack_bottom = 0x4409a0f8 thread_stack 0x30000
574697 /srv/mysql/libexec/mysqld(my_print_stacktrace+0x24) [0x87a1c4]
574698 /srv/mysql/libexec/mysqld(handle_segfault+0x322) [0x5c2122]
574699 /lib/libpthread.so.0 [0x2b669850da80]
574700 /lib/libc.so.6(memmove+0x98) [0x2b6699593348]
574701 /srv/mysql/libexec/mysqld(my_vsnprintf+0x39f) [0x8908ff]
574702 /srv/mysql/libexec/mysqld(vprint_msg_to_log(loglevel, char const*, __va_list_tag*)+0x23) [0x6       55673]
574703 /srv/mysql/libexec/mysqld(Log_to_file_event_handler::log_error(loglevel, char const*, __va_li       st_tag*)+0x11) [0x655771]
574704 /srv/mysql/libexec/mysqld(sql_print_warning(char const*, ...)+0xad) [0x65990d]
574705 /srv/mysql/libexec/mysqld(THD::binlog_query(THD::enum_binlog_query_type, char const*, unsigne       d long, bool, bool, THD::killed_state)+0x1b3) [0x5b1e83]
574706 /srv/mysql/libexec/mysqld(mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, un       signed int, st_order*, unsigned long, enum_duplicates, bool)+0xbcf) [0x64d81f]
574707 /srv/mysql/libexec/mysqld(mysql_execute_command(THD*)+0xfce) [0x5d2e1e]
574708 /srv/mysql/libexec/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x357) [       0x5d7607]
574709 /srv/mysql/libexec/mysqld(Query_log_event::do_apply_event(Relay_log_info const*, char const*,        unsigned int)+0x3da) [0x67ad8a]
574710 /srv/mysql/libexec/mysqld(apply_event_and_update_pos(Log_event*, THD*, Relay_log_info*, bool)       +0xfd) [0x6ed3ed]
574711 /srv/mysql/libexec/mysqld(handle_slave_sql+0xba5) [0x6ee575]
574712 /lib/libpthread.so.0 [0x2b6698505fc7]
574713 /lib/libc.so.6(clone+0x6d) [0x2b66995e65ad]
574714 Trying to get some variables.
574715 Some pointers may be invalid and cause the dump to abort...
574716 thd->query at 0x2aaac8261f4e is an invalid pointer
574717 thd->thread_id=2
574718 thd->killed=NOT_KILLED
574719 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
574720 information that should help you find out what is causing the crash.
574721
574722 The "--memlock" argument, which was enabled, uses system calls that are
574723 unreliable and unstable on some operating systems and operating-system
574724 versions (notably, some versions of Linux).  This crash could be due to use
574725 of those buggy OS calls.  You should consider whether you really need the
574726 "--memlock" parameter and/or consult the OS distributer about "mlockall"
574727 bugs.
574728 081102 21:29:28 mysqld_safe Number of processes running now: 0
574729 081102 21:29:28 mysqld_safe mysqld restarted

Here is my configuration parameters:
  $ ./configure --prefix=/big/mysql --enable-assembler --enable-local-infile --with-pthread --without-debug --with-vio --enable-thread-safe-client --with-unix-socket-path=/tmp/mysql.sock --with-tcp-port=3306 --with-charset=latin1 --with-extra-charsets=utf8,big5 --with-fast-mutexes --with-comment --with-plugins=innobase,partition

Here is my uname -a:
Linux db 2.6.18-6-amd64 #1 SMP Mon Jun 16 22:30:01 UTC 2008 x86_64 GNU/Linux

How to repeat:
running mysql for a while.

Suggested fix:
Do not crash.
[2 Nov 2008 17:06] Valeriy Kravchuk
Thank you for a problem report. Please, send your my.cnf file content and the results of:

free

Linux command.
[3 Nov 2008 4:35] Valeriy Kravchuk
Can you try to comment out memlock in your my.cnf and check if the bug is repeatable after that.
[3 Nov 2008 5:40] Jui-Nan Lin
Okay I'll remove the memlock option. But mysql 5.1.23 and previous version with memlock never crashes with the same OS, glibc and hardware. After 5.1.24, mysql with memlock starts getting signal 11.
[3 Nov 2008 16:40] Jui-Nan Lin
After turning off memlock, mysqld still got signal 11:
118928 081104  0:06:40 - mysqld got signal 11 ;
118929 This could be because you hit a bug. It is also possible that this binary
118930 or one of the libraries it was linked against is corrupt, improperly built,
118931 or misconfigured. This error can also be caused by malfunctioning hardware.
118932 We will try our best to scrape up some info that will hopefully help diagnose
118933 the problem, but since we have already crashed, something is definitely wrong
118934 and this may fail.
118935
118936 key_buffer_size=67108864
118937 read_buffer_size=33554432
118938 max_used_connections=704
118939 max_threads=4096
118940 threads_connected=3
118941 It is possible that mysqld could use up to
118942 key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 402760320 K
118943 bytes of memory
118944 Hope that's ok; if not, decrease some variables in the equation.
118945
118946 thd: 0x12eadc20
118947 Attempting backtrace. You can use the following information to find out
118948 where mysqld died. If you see no messages after this, something went
118949 terribly wrong...
118950 stack_bottom = 0x4409a0f8 thread_stack 0x30000
118951 /srv/mysql/libexec/mysqld(my_print_stacktrace+0x24) [0x87a1c4]
118952 /srv/mysql/libexec/mysqld(handle_segfault+0x322) [0x5c2122]
118953 /lib/libpthread.so.0 [0x2b3003c62a80]
118954 /lib/libc.so.6(memmove+0x98) [0x2b3004ce8348]
118955 /srv/mysql/libexec/mysqld(my_vsnprintf+0x39f) [0x8908ff]
118956 /srv/mysql/libexec/mysqld(vprint_msg_to_log(loglevel, char const*, __va_list_tag*)+0x23) [0x6       55673]
118957 /srv/mysql/libexec/mysqld(Log_to_file_event_handler::log_error(loglevel, char const*, __va_li       st_tag*)+0x11) [0x655771]
118958 /srv/mysql/libexec/mysqld(sql_print_warning(char const*, ...)+0xad) [0x65990d]
118959 /srv/mysql/libexec/mysqld(THD::binlog_query(THD::enum_binlog_query_type, char const*, unsigne       d long, bool, bool, THD::killed_state)+0x1b3) [0x5b1e83]
118960 /srv/mysql/libexec/mysqld(mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, un       signed int, st_order*, unsigned long, enum_duplicates, bool)+0xbcf) [0x64d81f]
118961 /srv/mysql/libexec/mysqld(mysql_execute_command(THD*)+0xfce) [0x5d2e1e]
118962 /srv/mysql/libexec/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x357) [       0x5d7607]
118963 /srv/mysql/libexec/mysqld(Query_log_event::do_apply_event(Relay_log_info const*, char const*,        unsigned int)+0x3da) [0x67ad8a]
118964 /srv/mysql/libexec/mysqld(apply_event_and_update_pos(Log_event*, THD*, Relay_log_info*, bool)       +0xfd) [0x6ed3ed]
118965 /srv/mysql/libexec/mysqld(handle_slave_sql+0xba5) [0x6ee575]
118966 /lib/libpthread.so.0 [0x2b3003c5afc7]
118967 /lib/libc.so.6(clone+0x6d) [0x2b3004d3b5ad]
118968 Trying to get some variables.
118969 Some pointers may be invalid and cause the dump to abort...
118970 thd->query at 0x2aae080a7d4e is an invalid pointer
118971 thd->thread_id=1
118972 thd->killed=NOT_KILLED
118973 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
118974 information that should help you find out what is causing the crash.
118975 pure virtual method called
118976 terminate called without an active exception
118977 Fatal signal 6 while backtracing
[3 Nov 2008 16:47] Valeriy Kravchuk
Can you try to figure out (from application side, maybe) what exact statement had led to this crash?
[30 Nov 2008 15:42] Jui-Nan Lin
5.1.30 still got signal 11:

   27 081130 19:56:30 - mysqld got signal 11 ;
   28 This could be because you hit a bug. It is also possible that this binary
   29 or one of the libraries it was linked against is corrupt, improperly built,
   30 or misconfigured. This error can also be caused by malfunctioning hardware.
   31 We will try our best to scrape up some info that will hopefully help diagnose
   32 the problem, but since we have already crashed, something is definitely wrong
   33 and this may fail.
   34
   35 key_buffer_size=67108864
   36 read_buffer_size=33554432
   37 max_used_connections=0
   38 max_threads=4096
   39 threads_connected=0
   40 It is possible that mysqld could use up to
   41 key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 402759776 K
   42 bytes of memory
   43 Hope that's ok; if not, decrease some variables in the equation.
   44
   45 081130 19:56:30 mysqld_safe mysqld restarted
   46 081130 19:56:30 [Warning] The syntax '--log_slow_queries' is deprecated and will be removed in       MySQL 7.0. Please use '--slow_query_log'/'--slow_query_log_file' instead.
   47 081130 19:56:30 [Warning] The syntax 'for replication startup options' is deprecated and will       be removed in MySQL 5.2. Please use 'CHANGE MASTER' instead.
   48 081130 19:56:30 [Warning] Changed limits: max_open_files: 11095  max_connections: 4096  table_      cache: 3494
   49 InnoDB: Log scan progressed past the checkpoint lsn 34 3588499552
   50 081130 19:56:34  InnoDB: Database was not shut down normally!
   51 InnoDB: Starting crash recovery.
   52 InnoDB: Reading tablespace information from the .ibd files...
   53 InnoDB: Restoring possible half-written data pages from the doublewrite
   54 InnoDB: buffer...
   55 InnoDB: Doing recovery: scanned up to log sequence number 34 3588861853
   56 081130 19:56:34  InnoDB: Starting an apply batch of log records to the database...
   57 InnoDB: Progress in percents: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 2      7 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58       59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89       90 91 92 93 94 95 96 97 98 99
   58 InnoDB: Apply batch completed
   59 InnoDB: Last MySQL binlog file position 0 106, file name ./db-bin.000013
   60 081130 19:56:40  InnoDB: Started; log sequence number 34 3588861853
   61 081130 19:56:40 [Note] Recovering after a crash using db-bin
   62 081130 19:56:40 [Note] Starting crash recovery...
   63 081130 19:56:40 [Note] Crash recovery finished.
   64 081130 19:56:40 [Warning] 'user' entry 'root@test1' ignored in --skip-name-resolve mode.
   65 081130 19:56:40 [Warning] 'user' entry '@test1' ignored in --skip-name-resolve mode.
   66 081130 19:56:40 [Note] Slave SQL thread initialized, starting replication in log 'db-bin.00005      6' at position 850980625, relay log '/srv/mysql/var/db-blog-3-bak-relay-bin.000895' position:       767568548
   67 081130 19:56:40 [Note] Event Scheduler: Loaded 0 events
   68 081130 19:56:40 [Note] /srv/mysql/libexec/mysqld: ready for connections.
   69 Version: '5.1.30-log'  socket: '/tmp/mysql.sock'  port: 3306  yes
   70 081130 19:56:40 [Note] Slave I/O thread: connected to master 'repl@drbd-blog-3:3306',replicati      on started in log 'db-bin.000056' at position 851045709
   71 081130 19:56:40 - mysqld got signal 11 ;
   72 This could be because you hit a bug. It is also possible that this binary
   73 or one of the libraries it was linked against is corrupt, improperly built,
   74 or misconfigured. This error can also be caused by malfunctioning hardware.
   75 We will try our best to scrape up some info that will hopefully help diagnose
   76 the problem, but since we have already crashed, something is definitely wrong
   77 and this may fail.

The corresponding query is in the next private comment.
[9 Dec 2008 8:41] Valeriy Kravchuk
Please, send the results of 

SHOW CREATE TABLE `blogreferer`\G

Check also bug #40688 that looks very similar.
[9 Dec 2008 11:49] Jui-Nan Lin
mysql> SHOW CREATE TABLE `blogreferer`\G
*************************** 1. row ***************************
       Table: blogreferer
Create Table: CREATE TABLE `blogreferer` (
  `blogreferer_id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `blogreferer_blogid` int(10) unsigned NOT NULL,
  `blogreferer_url` varchar(255) NOT NULL,
  `blogreferer_times` int(10) unsigned NOT NULL,
  `blogreferer_lastaccesstime` int(10) unsigned NOT NULL,
  PRIMARY KEY (`blogreferer_id`),
  UNIQUE KEY `blogreferer_blogid_url` (`blogreferer_blogid`,`blogreferer_url`),
  KEY `blogreferer_blogid_times` (`blogreferer_blogid`,`blogreferer_times`),
  KEY `blogreferer_blogid_lastaccesstime` (`blogreferer_blogid`,`blogreferer_lastaccesstime`)
) ENGINE=InnoDB AUTO_INCREMENT=412365 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)
[23 Mar 2009 16:39] Susanne Ebrecht
Please provide output of ulimit -a of your mysqld owner.

Interesting here is value of open files. It should be bigger as 4096. If it is lower then please set it to a higher value.
[23 Apr 2009 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".