| Bug #25294 | Mysql crashes often (mixed InnoDB and MyISAM database) | ||
|---|---|---|---|
| Submitted: | 27 Dec 2006 16:37 | Modified: | 22 Mar 2008 23:28 |
| Reporter: | Dmitry Kochin | Email Updates: | |
| Status: | No Feedback | Impact on me: | |
| Category: | MySQL Server: General | Severity: | S2 (Serious) |
| Version: | 5.0.24a, 5.0.32 | OS: | Solaris (Solaris 10) |
| Assigned to: | Assigned Account | CPU Architecture: | Any |
| Tags: | crash, innodb, myisam | ||
[27 Dec 2006 16:37]
Dmitry Kochin
[29 Dec 2006 13:42]
Valeriy Kravchuk
Thank you for a problem report. Please, try to repeat with a newer version, 5.0.27. In case of similar crash, please, send your my.cnf file content (I suspect that out-of-memory issue is quite possible).
[7 Jan 2007 9:54]
Dmitry Kochin
We have installed mysql 5.0.32 from sources. I will notify you if the problem persists.
[7 Jan 2007 10:47]
Dmitry Kochin
Unfortunately, upgraded version crashes too. Version: '5.0.32-standard-log' socket: '/tmp/mysql.sock' port: 3306 Source distribution 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=268435456 read_buffer_size=2093056 max_used_connections=190 max_connections=1700 threads_connected=25 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 7218530 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. 070107 13:32:59 mysqld restarted 070107 13:32:59 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... 070107 13:32:59 InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 557 2756211941. InnoDB: Doing recovery: scanned up to log sequence number 557 2761454592 InnoDB: Doing recovery: scanned up to log sequence number 557 2766697472 InnoDB: Doing recovery: scanned up to log sequence number 557 2771940352 InnoDB: Doing recovery: scanned up to log sequence number 557 2777183232 InnoDB: Doing recovery: scanned up to log sequence number 557 2782426112 InnoDB: Doing recovery: scanned up to log sequence number 557 2787668992 InnoDB: Doing recovery: scanned up to log sequence number 557 2792911872 InnoDB: Doing recovery: scanned up to log sequence number 557 2798154752 InnoDB: Doing recovery: scanned up to log sequence number 557 2803397632 InnoDB: Doing recovery: scanned up to log sequence number 557 2808640512 InnoDB: Doing recovery: scanned up to log sequence number 557 2813883392 InnoDB: Doing recovery: scanned up to log sequence number 557 2819126272 InnoDB: Doing recovery: scanned up to log sequence number 557 2824369152 InnoDB: Doing recovery: scanned up to log sequence number 557 2829612032 InnoDB: Doing recovery: scanned up to log sequence number 557 2834854912 InnoDB: Doing recovery: scanned up to log sequence number 557 2840097792 InnoDB: Doing recovery: scanned up to log sequence number 557 2845340672 InnoDB: Doing recovery: scanned up to log sequence number 557 2850583552 InnoDB: Doing recovery: scanned up to log sequence number 557 2855826432 InnoDB: Doing recovery: scanned up to log sequence number 557 2861069312 InnoDB: Doing recovery: scanned up to log sequence number 557 2866312192 InnoDB: Doing recovery: scanned up to log sequence number 557 2871555072 InnoDB: Doing recovery: scanned up to log sequence number 557 2876797952 InnoDB: Doing recovery: scanned up to log sequence number 557 2882040832 InnoDB: Doing recovery: scanned up to log sequence number 557 2887283712 InnoDB: Doing recovery: scanned up to log sequence number 557 2892526592 InnoDB: Doing recovery: scanned up to log sequence number 557 2897769472 InnoDB: Doing recovery: scanned up to log sequence number 557 2902087024 InnoDB: 1 transaction(s) which must be rolled back or cleaned up InnoDB: in total 1 row operations to undo InnoDB: Trx id counter is 0 2000763392 070107 13:33: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 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 InnoDB: Apply batch completed InnoDB: Starting in background the rollback of uncommitted transactions 070107 13:33:23 InnoDB: Rolling back trx with id 0 2000762934, 1 rows to undo 070107 13:33:23 InnoDB: Started; log sequence number 557 2902087024 InnoDB: Rolling back of trx id 0 2000762934 completed 070107 13:33:23 InnoDB: Rollback of non-prepared transactions completed 070107 13:33:25 [Note] /usr/local/rnsw/64/db/mysql5/bin/mysqld: ready for connections. Version: '5.0.32-standard-log' socket: '/tmp/mysql.sock' port: 3306 Source distribution 070107 13:33:25 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddan/userenter.MYI'; try to repair it 070107 13:33:25 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key 070107 13:33:57 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:33:58 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:33:58 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:33:58 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:33:58 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:33:59 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddan/userenter.MYI'; try to repair it 070107 13:33:59 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:34:00 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:34:10 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:34:10 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:34:22 [ERROR] Got error 134 when reading table './haddan/userenter' 070107 13:34:25 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:34:25 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:34:26 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:34:26 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:34:27 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:34:27 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:34:28 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:40:35 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Table './haddan/userenter' is marked as crashed and should be repaired 070107 13:40:46 [Note] Found 877504 of 877510 rows when repairing './haddan/userenter' my.cnf is attached.
[7 Jan 2007 10:49]
Dmitry Kochin
Mysql configuration
Attachment: my.cnf (application/octet-stream, text), 5.66 KiB.
[11 Jan 2007 12:32]
Dmitry Kochin
Default config with group_concat_max_len = 16k
Attachment: my.cnf (application/octet-stream, text), 5.08 KiB.
[11 Jan 2007 12:37]
Dmitry Kochin
We have totally replaced the previous configuration with the default one (mysq_huge.cnf with innodb enabled). Server ran smoothly 4 days. Yesterday we noticed that our application needs group_concat_max_len=16k (larger buffer for gorup CONCAT). We executed SET GLOBAL group_concat_max_len=16384. Today server crashed two times: 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=402653184 read_buffer_size=2093056 max_used_connections=1260 max_connections=1700 threads_connected=701 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 7349602 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Pure virtual function called Pure virtual function called Fatal signal 6 while backtracing 070111 15:11:18 mysqld restarted 070111 15:11:19 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... 070111 15:11:19 InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 583 2462980166. InnoDB: Doing recovery: scanned up to log sequence number 583 2468222976 * skipped * InnoDB: Doing recovery: scanned up to log sequence number 583 2611533277 070111 15:11:25 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 ... 99 InnoDB: Apply batch completed 070111 15:11:49 InnoDB: Started; log sequence number 583 2611533277 070111 15:11:55 [Note] /usr/local/rnsw/64/db/mysql5/bin/mysqld: ready for connections. Version: '5.0.32-standard' socket: '/tmp/mysql.sock' port: 3306 Source distribution 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=402653184 read_buffer_size=2093056 max_used_connections=791 max_connections=1700 threads_connected=726 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 7349602 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Pure virtual function called Fatal signal 6 while backtracing 070111 15:12:11 mysqld restarted 070111 15:12:11 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... 070111 15:12:11 InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 583 2470652146. InnoDB: Doing recovery: scanned up to log sequence number 583 2475894784 *skipped* InnoDB: Doing recovery: scanned up to log sequence number 583 2620151404 070111 15:12:17 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 ... 99 InnoDB: Apply batch completed 070111 15:12:39 InnoDB: Started; log sequence number 583 2620151404 070111 15:12:42 [Note] /usr/local/rnsw/64/db/mysql5/bin/mysqld: ready for connections. Version: '5.0.32-standard' socket: '/tmp/mysql.sock' port: 3306 Source distribution 070111 15:13:10 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddanarc/battle.MYI'; try to repair it 070111 15:14:54 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddanarc/battle.MYI'; try to repair it 070111 15:15:02 [Note] Found 171978 of 171974 rows when repairing './haddanarc/battle' 070111 15:15:21 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddanarc/battlemember.MYI'; try to repair it 070111 15:15:31 [Note] Found 483739 of 483729 rows when repairing './haddanarc/battlemember' 070111 15:15:32 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddanarc/battlemove.MYI'; try to repair it 070111 15:15:50 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddanarc/battlemove.MYI'; try to repair it 070111 15:16:07 [Note] Found 1608534 of 1608504 rows when repairing './haddanarc/battlemove' 070111 15:16:27 [ERROR] /usr/local/rnsw/64/db/mysql5/bin/mysqld: Incorrect key file for table './haddanarc/battlelog.MYI'; try to repair it 070111 15:19:11 [Note] Found 2943984 of 2943919 rows when repairing './haddanarc/battlelog'
[12 Jan 2007 14:54]
Dmitry Kochin
Today it crashed once more. The only change in configuration was setting the default value for group_concat_max_len. We removed group_concat_max_len from the configuration, but it didn't help. I suspect that it crashes some time after heavy load. Well, is there anything we can do to clearify the situation? Turn on any debugging switches, run any debugging utilities? Frequent crashes just ruin all our work...
[13 Jan 2007 18:51]
Dmitry Kochin
One more crash today. But now we have core dump. It can be downloaded (172 Mb, archived) from http://haddan.ru/download/core/core_db2.haddan.2007-01-13.rar I hope it will help. error log contained: 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=402653184 read_buffer_size=2093056 max_used_connections=1201 max_connections=1200 threads_connected=83 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 5303606 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Pure virtual function called070113 18:42:51 mysqld restarted
[18 Jan 2007 18:18]
Jason Williams
Hi Dmitry, That sounds very similar to our problem. With the exception that in the first few crashes for you MySQL actually tried to backtrace. This is very frustrating. We've duplicated this problem on multiple Solaris 10 platforms (S10 Update 3 [AMD64 & SPARC], as well as Solaris Express Community Release Build 54 [AMD64]). I think we will finally get MySQL 5.1.14 to core dump properly, just waiting for it to do so. It has stayed up since we turned core-dump on and used coreadm to put the corefile in /tmp/ (verified with gcore). Have you had any luck with an analysis of the coredump by MySQL? (Cross-posting from http://bugs.mysql.com/bug.php?id=25460).
[18 Jan 2007 18:19]
Jason Williams
Dmitri, What version of Solaris are you running? Also, are you running UFS or ZFS as the filesystem?
[18 Jan 2007 22:07]
Jason Williams
Hi Dmitri, We noted a rapid connect/disconnect sequence during our 127 errors. This was noted in the general_log. Have you noted anything similar during your crashes? Best Regards, Jason
[19 Jan 2007 8:41]
Dmitry Kochin
Solaris 10 6/06 s10x_u2wos_09a X86 on Dual Core AMD Opteron 64. mysql bin's are on UFS, dtatabase is on ZFS. We didn't notice rapid connects-disconnects before the crash. We have 300-400 queries per second and cannot turn on general query log. We didn't analyze core dump because we just didn't know how to accomplish that.
[19 Jan 2007 14:17]
Jason Williams
Hi Dmitri, This may help: http://dev.mysql.com/doc/refman/5.0/en/using-gdb-on-mysqld.html We finally got a core last night. Be interested to compare your backtrace from GDB to ours.
[19 Jan 2007 14:21]
Jason Williams
BTW, you may want to upgrade to Update 3 or newer. ZFS's block cache by default will suck down all of your RAM minus 1GB. With Update 3 or newer there's a less than elegant way of getting ZFS to cap that. With Solaris Express Community Release Build 54 or newer there's a tunable you can set to cap the ZFS block cache to a maximum size. http://bugs.opensolaris.org/bugdatabase/view_bug.do?bug_id=6505658 Also, if you have a ton of small files on your ZFS filesystem you could suck down up to 3*block_cache (ARC) in RAM. But that's really rare...if you just have MySQL DB files it hasn't been a problem for us. Just needed to adjust the max ARC (block_cache) size. Hope this helps.
[21 Jan 2007 9:04]
Valeriy Kravchuk
Jason and Dmitri, Can you, please, send your backtraces to this bug report?
[22 Jan 2007 18:00]
Jason Williams
Hi Valeriy, I've posted the GDB backtrace to case 25460. It should be downloadable here I think: http://bugs.mysql.com/file.php?id=5431
[23 Jan 2007 8:34]
Valeriy Kravchuk
Jason, Do you think this bug report is related to bug #25460? Maybe, they are duplicates (about the same problem)? I will check backtrace, surely...
[23 Jan 2007 18:46]
Jason Williams
Hi Valeriy, I'm not entirely sure if its the same bug. Dmitry cross-posted on our bug (25460) that this might be the same. As far as I can tell, the main similarity is the crash without backtrace. I'm curious if Dmitry is using a MySQL built binary.
[23 Jan 2007 18:58]
Dmitry Kochin
We used mysql built binary 5.0.24a. It crashed often. We built mysql 5.0.32 from sources. Nothing changed, crashes happened the same way. We are going to apply recent patches to Solaris. If it continues to crash we will build community mysql 5.0.33 with debug info. Unfortunately we failed to generate GDB backtrace from the dump file. Can anyone here do it? The core dump is here: http://haddan.ru/download/core/core_db2.haddan.2007-01-13.rar
[23 Jan 2007 19:00]
Jason Williams
Hi Dimitry, Is the mysqld that crashed in the RAR as well? If not, where can we get at it?
[23 Jan 2007 19:12]
Dmitry Kochin
No they are separate. The core dump: http://haddan.ru/download/core/core_db2.haddan.2007-01-13.rar The mysqld binary: http://haddan.ru/download/core/mysqld-5.0.32.rar
[29 Jan 2007 16:19]
Sveta Smirnova
>Unfortunately we failed to generate GDB backtrace from the dump file. Can anyone here do it? Yes, it is readable by dbx. Dmitry, you said in the comment to bug #25460 you have other 4 dumps. Please, upload some: I want to check if crash always happens in one place. Thank you.
[29 Jan 2007 16:25]
Sveta Smirnova
part of dbx output
Attachment: bug25294.txt (text/plain), 34.32 KiB.
[30 Jan 2007 11:35]
Dmitry Kochin
The other dumps are here: http://haddan.ru/download/core/core_db2.haddan-a.rar (211 Mb) http://haddan.ru/download/core/core_db2.haddan-b.rar (107 Mb) http://haddan.ru/download/core/core_db2.haddan-c.rar (112 Mb) Sveta, have you managed to find the cause of the crash? By the way, after Solaris update mysql performed faster and didn't crash for 4 days, but crashed again today.
[1 Feb 2007 10:07]
Sveta Smirnova
dbx output part 2
Attachment: bug25294_2.txt (text/plain), 78.64 KiB.
[1 Feb 2007 12:33]
Sveta Smirnova
Dmitry, thank you for the uploaded core files. Your problem seems to be different from bug #25460. If you can build and run 5.0.33 with debug info, please build and send core file of it.
[2 Mar 2007 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".
[22 Feb 2008 23:28]
Sveta Smirnova
Please try current version 5.0.51a and if the problem still exists try to compile debug binaries (--with-debug=full) to we can see more information in cores.
[23 Mar 2008 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".
