| Bug #48385 | Crash and restart : Invalid pointer | ||
|---|---|---|---|
| Submitted: | 28 Oct 2009 17:43 | Modified: | 31 Dec 2010 19:15 |
| Reporter: | Francis Besset | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
| Version: | 5.0.51a-24+lenny2-log, 5.0.90 | OS: | Linux (Debian Lenny) |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | invalid pointer crash restart | ||
[28 Oct 2009 17:43]
Francis Besset
[28 Oct 2009 17:51]
Valeriy Kravchuk
Thank you for the problem report. Please, send your my.cnf file content and the results of: uname -a free Linux commands. Had you noted what SQL statement(s) or applications were executed at the moment of crash?
[28 Oct 2009 18:19]
Francis Besset
Hello, Thank you for you response. my.cnf : ~# cat /etc/mysql/my.cnf # # The MySQL database server configuration file. # # You can copy this to one of: # - "/etc/mysql/my.cnf" to set global options, # - "~/.my.cnf" to set user-specific options. # # One can use all long options that the program supports. # Run program with --help to get a list of available options and with # --print-defaults to see which it would actually understand and use. # # For explanations see # http://dev.mysql.com/doc/mysql/en/server-system-variables.html # This will be passed to all mysql clients # It has been reported that passwords should be enclosed with ticks/quotes # escpecially if they contain "#" chars... # Remember to edit /etc/mysql/debian.cnf when changing the socket location. [client] port = 3306 socket = /var/run/mysqld/mysqld.sock # Here is entries for some specific programs # The following values assume you have at least 32M ram # This was formally known as [safe_mysqld]. Both versions are currently parsed. [mysqld_safe] socket = /var/run/mysqld/mysqld.sock nice = 0 [mysqld] # # * Basic Settings # user = mysql pid-file = /var/run/mysqld/mysqld.pid socket = /var/run/mysqld/mysqld.sock port = 3306 basedir = /usr datadir = /var/lib/mysql tmpdir = /tmp language = /usr/share/mysql/english skip-external-locking # # Instead of skip-networking the default is now to listen only on # localhost which is more compatible and is not less secure. bind-address = 127.0.0.1 # # * Fine Tuning # key_buffer = 16M max_allowed_packet = 16M thread_stack = 128K thread_cache_size = 8 max_heap_table_size = 32M tmp_table_size = 64M # This replaces the startup script and checks MyISAM tables if needed # the first time they are touched myisam-recover = BACKUP max_connections = 125 table_cache = 350 #thread_concurrency = 10 # # * Query Cache Configuration # query_cache_limit = 1M query_cache_size = 16M # # * Logging and Replication # # Both location gets rotated by the cronjob. # Be aware that this log type is a performance killer. #log = /var/log/mysql/mysql.log # # Error logging goes to syslog. This is a Debian improvement :) # # Here you can see queries with especially long duration log_slow_queries = /var/log/mysql/mysql-slow.log long_query_time = 5 #log-queries-not-using-indexes #low_priority_updates = 1 #concurrent_insert = 2 # # The following can be used as easy to replay backup logs or for replication. # note: if you are setting up a replication slave, see README.Debian about # other settings you may need to change. #server-id = 1 log_bin = /var/log/mysql/mysql-bin.log sync-binlog = 1 expire_logs_days = 10 max_binlog_size = 100M #binlog_do_db = include_database_name #binlog_ignore_db = include_database_name # # * BerkeleyDB # # Using BerkeleyDB is now discouraged as its support will cease in 5.1.12. skip-bdb # # * InnoDB # # InnoDB is enabled by default with a 10MB datafile in /var/lib/mysql/. # Read the manual for more InnoDB related options. There are many! # You might want to disable InnoDB to shrink the mysqld process by circa 100MB. #skip-innodb # # * Security Features # # Read the manual, too, if you want chroot! # chroot = /var/lib/mysql/ # # For generating SSL certificates I recommend the OpenSSL GUI "tinyca". # # ssl-ca=/etc/mysql/cacert.pem # ssl-cert=/etc/mysql/server-cert.pem # ssl-key=/etc/mysql/server-key.pem [mysqldump] quick quote-names max_allowed_packet = 16M [mysql] #no-auto-rehash # faster start of mysql but no tab completition [isamchk] key_buffer = 16M # # * NDB Cluster # # See /usr/share/doc/mysql-server-*/README.Debian for more information. # # The following configuration is read by the NDB Data Nodes (ndbd processes) # not from the NDB Management Nodes (ndb_mgmd processes). # # [MYSQL_CLUSTER] # ndb-connectstring=127.0.0.1 # # * IMPORTANT: Additional settings that can override those from this file! # The files must end with '.cnf', otherwise they'll be ignored. # !includedir /etc/mysql/conf.d/ The folder /etc/mysql/conf.d is empty. ~# uname -a Linux ns38999.ovh.net 2.6.27.10-grsec-xxxx-grs-ipv4-64 #6 SMP Fri Aug 14 10:29:05 UTC 2009 x86_64 GNU/Linux ~# free total used free shared buffers cached Mem: 2036744 1364980 671764 0 144072 723760 -/+ buffers/cache: 497148 1539596 Swap: 8385912 2724 8383188 Applications run at this moment : Apache, lighttpd, postfix. I have the binary log. I have mainly SELECT request with inner join between the tables. The requests INSERT have often of ON DUPLICATE KEY UPDATE. Regards.
[30 Oct 2009 12:54]
Francis Besset
I still had this problem today except that que MySQL has not restarted again automatically. Oct 30 12:04:39 ns38999 kernel: grsec: From 81.65.xxx.xxx: signal 11 sent to /usr/sbin/mysqld[mysqld:26469] uid/euid:103/103 gid/egid:106/106, parent /usr/bin/mysqld_safe[mysqld_safe:24960] uid/euid:0/0 gid/eg$ Oct 30 12:04:39 ns38999 mysqld[10806]: 091030 12:04:39 - mysqld got signal 11; Oct 30 12:04:39 ns38999 mysqld[10806]: This could be because you hit a bug. It is also possible that this binary Oct 30 12:04:39 ns38999 mysqld[10806]: or one of the libraries it was linked against is corrupt, improperly built, Oct 30 12:04:39 ns38999 mysqld[10806]: or misconfigured. This error can also be caused by malfunctioning hardware. Oct 30 12:04:39 ns38999 mysqld[10806]: We will try our best to scrape up some info that will hopefully help diagnose Oct 30 12:04:39 ns38999 mysqld[10806]: the problem, but since we have already crashed, something is definitely wrong Oct 30 12:04:39 ns38999 mysqld[10806]: and this may fail. Oct 30 12:04:39 ns38999 mysqld[10806]: Oct 30 12:04:39 ns38999 mysqld[10806]: key_buffer_size=16777216 Oct 30 12:04:39 ns38999 mysqld[10806]: read_buffer_size=131072 Oct 30 12:04:39 ns38999 mysqld[10806]: max_used_connections=42 Oct 30 12:04:39 ns38999 mysqld[10806]: max_connections=125 Oct 30 12:04:39 ns38999 mysqld[10806]: threads_connected=4 Oct 30 12:04:39 ns38999 mysqld[10806]: It is possible that mysqld could use up to Oct 30 12:04:39 ns38999 mysqld[10806]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 288383 K Oct 30 12:04:39 ns38999 mysqld[10806]: bytes of memory Oct 30 12:04:39 ns38999 mysqld[10806]: Hope that's ok; if not, decrease some variables in the equation. Oct 30 12:04:39 ns38999 mysqld[10806]: Oct 30 12:04:39 ns38999 mysqld[10806]: thd=0x7f74dc05b2b0 Oct 30 12:04:39 ns38999 mysqld[10806]: Attempting backtrace. You can use the following information to find out Oct 30 12:04:39 ns38999 mysqld[10806]: where mysqld died. If you see no messages after this, something went Oct 30 12:04:39 ns38999 mysqld[10806]: terribly wrong... Oct 30 12:04:39 ns38999 mysqld[10806]: Cannot determine thread, fp=0x7f74dc05b2b0, backtrace may not be correct. Oct 30 12:04:39 ns38999 mysqld[10806]: Bogus stack limit or frame pointer, fp=0x7f74dc05b2b0, stack_bottom=0x41030000, thread_stack=131072, aborting backtrace. Oct 30 12:04:39 ns38999 mysqld[10806]: Trying to get some variables. Oct 30 12:04:39 ns38999 mysqld[10806]: Some pointers may be invalid and cause the dump to abort... Oct 30 12:04:39 ns38999 mysqld[10806]: thd->query at 0x7f74e403c580 is invalid pointer Oct 30 12:04:39 ns38999 mysqld[10806]: thd->thread_id=471621 Oct 30 12:04:39 ns38999 mysqld[10806]: The manual page at http://www.mysql.com/doc/en/Crashing.html contains Oct 30 12:04:39 ns38999 mysqld[10806]: information that should help you find out what is causing the crash. Oct 30 12:04:39 ns38999 kernel: mysqld[10805]: segfault at 8 ip 00000000005d1712 sp 00007ffff22055a0 error 6 in mysqld[400000+742000] Oct 30 12:04:39 ns38999 kernel: grsec: From 81.65.xxx.xxx: signal 11 sent to /usr/sbin/mysqld[mysqld:10805] uid/euid:103/103 gid/egid:106/106, parent /usr/bin/mysqld_safe[mysqld_safe:24960] uid/euid:0/0 gid/eg$ Oct 30 12:04:39 ns38999 mysqld_safe[11649]: ended When I have a SQL problem, I send an automatic email report. The first two messages have different mistakes of others: [SQL-ConnectError] SQLSTATE[HY000] [2013] Lost connection to MySQL server at 'reading initial communication packet', system error: 104 And : [SQL-ConnectError] SQLSTATE[HY000] [2013] Lost connection to MySQL server at 'reading initial communication packet', system error: 0 Francis.
[18 Nov 2009 8:10]
Sveta Smirnova
Thank you for the feedback. At first glance setup looks fine. But version 5.0.51 is too old and any bugs were fixed since. Please upgrade to current version 5.0.87, try with it and if problem still exists try to find query which caused failure. You can use general query log or proxy (for example, MySQL Proxy) for it.
[19 Dec 2009 0: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".
[20 Jul 2010 21:29]
Charlton Kao
I got a similar crash to this today. Any information on how this was fixed for the previous user? We're using 5.0.91. <b>uname -a: </b> Linux la-dbb1 2.6.31-hardened-r10 #7 SMP Sat May 15 01:04:25 UTC 2010 x86_64 Intel(R) Xeon(R) CPU E5520 @ 2.27GHz GenuineIntel GNU/Linux <b>ulimit -a: </b> core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 270336 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 1024 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 8192 cpu time (seconds, -t) unlimited max user processes (-u) 270336 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited <b>free: </b> total used free shared buffers cached Mem: 32957564 32664004 293560 0 4684 13351376 -/+ buffers/cache: 19307944 13649620 Swap: 2008116 494912 1513204 <b> error from mysqld.err: </b> 100720 17:33:55 - 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. key_buffer_size=2147483648 read_buffer_size=2097152 max_used_connections=476 max_connections=4096 threads_connected=30 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 278921216 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x6345a27b9b90 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... Cannot determine thread, fp=0x6345c45300a0, backtrace may not be correct. Bogus stack limit or frame pointer, fp=0x6345c45300a0, stack_bottom=0x6345c4530000, thread_stack=262144, aborting backtrace. Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x6345449572f0 is invalid pointer thd->thread_id=13881784 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash. pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called pure virtual method called terminate called recursively Fatal signal 6 while backtracing terminate called recursively terminate called recursively terminate called recursively terminate called recursively terminate called recursively terminate called recursively terminate called recursively terminate called recursively terminate called recursively terminate called recursively pure virtual method called terminate called recursively pure virtual method called terminate called recursively InnoDB: The InnoDB memory heap is disabled InnoDB: use atomic builtins. InnoDB: Log scan progressed past the checkpoint lsn 332 2836422206 100720 17:35:04 InnoDB: Database was not shut down normally! InnoDB: Starting crash recovery. InnoDB: Reading tablespace information from the .ibd files... InnoDB: Restoring possible half-written data pages from the doublewrite InnoDB: buffer... InnoDB: Doing recovery: scanned up to log sequence number 332 2841665024 InnoDB: Doing recovery: scanned up to log sequence number 332 2844038242 100720 17:35:05 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 $ InnoDB: Apply batch completed InnoDB: Last MySQL binlog file position 0 724862635, file name /var/lib/db/mysql-bin/la-dbb1-bin.000881 100720 17:35:17 InnoDB: Started; log sequence number 332 2844038242 100720 17:35:17 [Note] Recovering after a crash using /var/lib/db/mysql-bin/la-dbb1-bin 100720 17:35:29 [Note] Starting crash recovery... 100720 17:35:29 [Note] Crash recovery finished. 100720 17:35:30 [Note] /usr/sbin/mysqld: ready for connections. Version: '5.0.90-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Gentoo Linux mysql-5.0.90-r2 100720 17:35:30 [Note] Slave SQL thread initialized, starting replication in log 'la-dbb2-bin.000874' at position 81001428, rela$ 100720 17:35:30 [Note] Slave I/O thread: connected to master 'repl@la-dbb2:3306', replication started in log 'la-dbb2-bin.00087$
[23 Jul 2010 15:17]
Sveta Smirnova
Thank you for the feedback. Error 11 means "segmentation fault". Could you please send us your configuration file so we can be sure your settings are sane?
[31 Dec 2010 19:15]
Sveta Smirnova
As we continued discussion with Charlton in bug #54610 and there is no more feedack here closing this one as "Can't repeat".
