| Bug #8126 | Mysql daemon crashes in Slave during replication | ||
|---|---|---|---|
| Submitted: | 25 Jan 2005 7:12 | Modified: | 22 Mar 2005 15:45 |
| Reporter: | Sumit Kumar Roy | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
| Version: | 4.0.17 | OS: | Linux (Linux 7.1 Kernal 2.4.26) |
| Assigned to: | Heikki Tuuri | CPU Architecture: | Any |
[25 Jan 2005 7:12]
Sumit Kumar Roy
[25 Jan 2005 8:08]
Heikki Tuuri
Hi! Please read http://www.mysql.com/doc/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved stack trace is much more helpful in diagnosing the problem, so please do resolve it Your log sequence number is only a few hundred MB, but you already encounter corruption. My first guess is a hardware problem. But please resolve the stack trace. Regards, Heikki
[25 Jan 2005 8:12]
Heikki Tuuri
Hi! Ok, I read the bug report more carefully. If BOTH the master AND the slave crashed at the same time, then this very probably is an InnoDB bug. Please show the COMPLETE contents of the .err log in both the master and the slave, and resolve the stack traces. Does the crash happen again, if you run the same queries? Regards, Heikki
[25 Jan 2005 9:27]
Sumit Kumar Roy
Hi The Master Mysql Daemon is up but the Slave Daemon is down and it cannot be brought up. I am starting the daemon by giving the following command mysqld --defaults-file=/opt/archive/utils/active/etc/slave.cnf --flush --log-warnings & Meanwhile I am doing a stack_trace The complete .err log file is as follows: InnoDB: Warning: database page corruption or a failed InnoDB: file read of page 198. InnoDB: Trying to recover it from the doublewrite buffer. InnoDB: Recovered the page from the doublewrite buffer. 050125 11:17:47 InnoDB: Database was not shut down normally. InnoDB: Starting recovery from log files... InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 0 413459122 InnoDB: Doing recovery: scanned up to log sequence number 0 413459122 InnoDB: In a MySQL replication slave the last master binlog file InnoDB: position 0 12405394, file name db1_log_bin.023 InnoDB: Last MySQL binlog file position 0 12405260, file name /usr/local/archivedb/log_s/db2_log_bin.022 050125 11:17:47 InnoDB: Flushing modified pages from the buffer pool... 050125 11:17:47 InnoDB: Started 050125 11:17:47 Slave SQL thread initialized, starting replication in log 'db1_log_bin.023' at position 12405394, relay log '/usr/local/archivedb/data_s/standby_rlog.057' position: 4016666 050125 11:17:47 Slave I/O thread: connected to master 'arcslv@cp_dbsrv:3356', replication started in log 'db1_log_bin.023' at position 12405394 /usr/sbin/mysqld: ready for connections. Version: '4.0.17-standard-log' socket: '/usr/local/archivedb/socks/slave.sock2' port: 3357 InnoDB: error in sec index entry update in InnoDB: index Classes table archivedb/FileEntry InnoDB: tuple 0: SQL NULL; 1: len 8; hex 000000000001302a; asc ......0*;; InnoDB: record RECORD: info bits 32 0: SQL NULL; 1: len 8; hex 0000000000012fda; asc ....../.;; TRANSACTION 0 3004426, ACTIVE 0 sec, process no 5080, OS thread id 40971 updating or deleting, thread declared inside InnoDB 499 mysql tables in use 2, locked 1 13 lock struct(s), heap size 1024, undo log entries 2 MySQL thread id 2, query id 78 Sending data DELETE from NameSpaceEntry using NameSpaceEntry, FileEntry WHERE NameSpaceEntry.idNameSpaceEntry=FileEntry.idFile AND FileEntry.idStorageContainer=0 InnoDB: Make a detailed bug report and send it InnoDB: to mysql@lists.mysql.com InnoDB: error in sec index entry update in InnoDB: index Classes table archivedb/FileEntry InnoDB: tuple 0: SQL NULL; 1: len 8; hex 000000000001302b; asc ......0+;; InnoDB: record RECORD: info bits 32 0: SQL NULL; 1: len 8; hex 0000000000012fda; asc ....../.;; TRANSACTION 0 3004426, ACTIVE 0 sec, process no 5080, OS thread id 40971 updating or deleting, thread declared inside InnoDB 496 mysql tables in use 2, locked 1 15 lock struct(s), heap size 1024, undo log entries 4 MySQL thread id 2, query id 78 Sending data DELETE from NameSpaceEntry using NameSpaceEntry, FileEntry WHERE NameSpaceEntry.idNameSpaceEntry=FileEntry.idFile AND FileEntry.idStorageContainer=0 InnoDB: Make a detailed bug report and send it InnoDB: to mysql@lists.mysql.com InnoDB: error in sec index entry update in InnoDB: index Classes table archivedb/FileEntry InnoDB: tuple 0: SQL NULL; 1: len 8; hex 000000000001302c; asc ......0,;; InnoDB: record RECORD: info bits 32 0: SQL NULL; 1: len 8; hex 0000000000012fda; asc ....../.;; TRANSACTION 0 3004426, ACTIVE 0 sec, process no 5080, OS thread id 40971 updating or deleting, thread declared inside InnoDB 493 mysql tables in use 2, locked 1 15 lock struct(s), heap size 1024, undo log entries 6 MySQL thread id 2, query id 78 Sending data DELETE from NameSpaceEntry using NameSpaceEntry, FileEntry WHERE NameSpaceEntry.idNameSpaceEntry=FileEntry.idFile AND FileEntry.idStorageContainer=0 InnoDB: Make a detailed bug report and send it InnoDB: to mysql@lists.mysql.com InnoDB: error in sec index entry update in InnoDB: index Classes table archivedb/FileEntry InnoDB: tuple 0: SQL NULL; 1: len 8; hex 000000000001302e; asc ......0.;; InnoDB: record RECORD: info bits 32 0: SQL NULL; 1: len 8; hex 0000000000012fda; asc ....../.;; TRANSACTION 0 3004426, ACTIVE 0 sec, process no 5080, OS thread id 40971 updating or deleting, thread declared inside InnoDB 490 mysql tables in use 2, locked 1 15 lock struct(s), heap size 1024, undo log entries 8 MySQL thread id 2, query id 78 Sending data DELETE from NameSpaceEntry using NameSpaceEntry, FileEntry WHERE NameSpaceEntry.idNameSpaceEntry=FileEntry.idFile AND FileEntry.idStorageContainer=0 InnoDB: Make a detailed bug report and send it InnoDB: to mysql@lists.mysql.com 050125 11:19:57 Slave I/O thread killed while reading event 050125 11:19:57 Slave I/O thread exiting, read up to log 'db1_log_bin.025', position 4 050125 11:19:57 Error reading relay log event: slave SQL thread was killed 050125 11:20:23 Slave SQL thread initialized, starting replication in log 'db1_log_bin.025' at position 4, relay log '/usr/local/archivedb/data_s/standby_rlog.058' position: 98182 050125 11:20:23 Slave I/O thread: connected to master 'arcslv@cp_dbsrv:3356', replication started in log 'db1_log_bin.025' at position 4 050125 11:20:38 InnoDB: Assertion failure in thread 53259 in file ../../innobase/btr/../include/page0page.ic line 482 InnoDB: Failing assertion: offs < UNIV_PAGE_SIZE InnoDB: We intentionally generate a memory trap. InnoDB: Send a detailed bug report to mysql@lists.mysql.com 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=67108864 read_buffer_size=1044480 max_used_connections=0 max_connections=100 threads_connected=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 269935 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x87f6cd0 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=0x7fe5edf8, backtrace may not be correct. Stack range sanity check OK, backtrace follows: 0x8071fb4 0x8292c58 0x817c9eb 0x810e499 0x810e504 0x8133900 0x80ce27d 0x80a8f6d 0x807e159 0x8080905 0x80b2b22 0x80ec40d 0x80ecf8a 0x829040c 0x82c3b3a New value of fp=(nil) failed sanity check, terminating stack trace! Please read http://www.mysql.com/doc/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved stack trace is much more helpful in diagnosing the problem, so please do resolve it Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x87bd6aa = UPDATE FileEntry SET WriteLock = 0 WHERE idFile = 76762 thd->thread_id=14 The manual page at http://www.mysql.com/doc/en/Crashing.html contains information that should help you find out what is causing the crash. 050125 11:58:58 InnoDB: Database was not shut down normally. InnoDB: Starting recovery from log files... InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 0 413584207 InnoDB: Doing recovery: scanned up to log sequence number 0 414520340 050125 11:58:58 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 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: In a MySQL replication slave the last master binlog file InnoDB: position 0 571101, file name db1_log_bin.025 InnoDB: Last MySQL binlog file position 0 571101, file name /usr/local/archivedb/log_s/db2_log_bin.024 050125 11:58:59 InnoDB: Flushing modified pages from the buffer pool... 050125 11:58:59 InnoDB: Started 050125 11:58:59 Slave SQL thread initialized, starting replication in log 'db1_log_bin.025' at position 571101, relay log '/usr/local/archivedb/data_s/standby_rlog.059' position: 571143 050125 11:58:59 Slave I/O thread: connected to master 'arcslv@cp_dbsrv:3356', replication started in log 'db1_log_bin.025' at position 653056 050125 11:58:59 InnoDB: Assertion failure in thread 40971 in file ../../innobase/btr/../include/page0page.ic line 482 InnoDB: Failing assertion: offs < UNIV_PAGE_SIZE InnoDB: We intentionally generate a memory trap. InnoDB: Send a detailed bug report to mysql@lists.mysql.com 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=67108864 read_buffer_size=1044480 max_used_connections=0 max_connections=100 threads_connected=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 269935 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x87b5520 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=0x7fe5e0b8, backtrace may not be correct. Stack range sanity check OK, backtrace follows: 0x8071fb4 0x8292c58 0x817c9eb 0x810e499 0x810e504 0x8105018 0x80cc9ab 0x80c68c4 0x8094525 0x8090dd7 0x809023a 0x80911e9 0x80a8666 0x807e159 0x8080905 0x80b2b22 0x80ec40d 0x80ecf8a 0x829040c 0x82c3b3a New value of fp=(nil) failed sanity check, terminating stack trace! Please read http://www.mysql.com/doc/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved stack trace is much more helpful in diagnosing the problem, so please do resolve it Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x87b051a = UPDATE FileEntry SET WriteLock = 0 WHERE idFile = 76thd->thread_id=2 The manual page at http://www.mysql.com/doc/en/Crashing.html contains information that should help you find out what is causing the crash. 050125 12:01:30 InnoDB: Database was not shut down normally. InnoDB: Starting recovery from log files... InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 0 414520340 InnoDB: Doing recovery: scanned up to log sequence number 0 414520340 InnoDB: In a MySQL replication slave the last master binlog file InnoDB: position 0 571101, file name db1_log_bin.025 InnoDB: Last MySQL binlog file position 0 571101, file name /usr/local/archivedb/log_s/db2_log_bin.024 050125 12:01:30 InnoDB: Flushing modified pages from the buffer pool... 050125 12:01:30 InnoDB: Started 050125 12:01:30 Slave I/O thread: connected to master 'arcslv@cp_dbsrv:3356', replication started in log 'db1_log_bin.025' at position 691436 mysqld: ready for connections. Version: '4.0.17-standard-log' socket: '/usr/local/archivedb/socks/slave.sock2' port: 3357 050125 12:01:31 Slave SQL thread initialized, starting replication in log 'db1_log_bin.025' at position 571101, relay log '/usr/local/archivedb/data_s/standby_rlog.059' position: 571143 050125 12:01:31 InnoDB: Assertion failure in thread 40971 in file ../../innobase/btr/../include/page0page.ic line 482 InnoDB: Failing assertion: offs < UNIV_PAGE_SIZE InnoDB: We intentionally generate a memory trap. InnoDB: Send a detailed bug report to mysql@lists.mysql.com 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=67108864 read_buffer_size=1044480 max_used_connections=0 max_connections=100 threads_connected=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 269935 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x87b5520 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=0x7fe5e0b8, backtrace may not be correct. Stack range sanity check OK, backtrace follows: 0x8071fb4 0x8292c58 0x817c9eb 0x810e499 0x810e504 0x8105018 0x80cc9ab 0x80c68c4 0x8094525 0x8090dd7 0x809023a 0x80911e9 0x80a8666 0x807e159 0x8080905 0x80b2b22 0x80ec40d 0x80ecf8a 0x829040c 0x82c3b3a New value of fp=(nil) failed sanity check, terminating stack trace! Please read http://www.mysql.com/doc/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved stack trace is much more helpful in diagnosing the problem, so please do resolve it Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x87b086a = UPDATE FileEntry SET WriteLock = 0 WHERE idFile = 76762 thd->thread_id=2 The manual page at http://www.mysql.com/doc/en/Crashing.html contains information that should help you find out what is causing the crash. 050125 12:04:08 InnoDB: Database was not shut down normally. InnoDB: Starting recovery from log files... InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 0 414520340 InnoDB: Doing recovery: scanned up to log sequence number 0 414520340 InnoDB: In a MySQL replication slave the last master binlog file InnoDB: position 0 571101, file name db1_log_bin.025 InnoDB: Last MySQL binlog file position 0 571101, file name /usr/local/archivedb/log_s/db2_log_bin.024 050125 12:04:08 InnoDB: Flushing modified pages from the buffer pool... 050125 12:04:08 InnoDB: Started 050125 12:04:08 Slave SQL thread initialized, starting replication in log 'db1_log_bin.025' at position 571101, relay log '/usr/local/archivedb/data_s/standby_rlog.059' position: 571143 mysqld: ready for connections. Version: '4.0.17-standard-log' socket: '/usr/local/archivedb/socks/slave.sock2' port: 3357 050125 12:04:08 Slave I/O thread: connected to master 'arcslv@cp_dbsrv:3356', replication started in log 'db1_log_bin.025' at position 785100 050125 12:04:08 InnoDB: Assertion failure in thread 40971 in file ../../innobase/btr/../include/page0page.ic line 482 InnoDB: Failing assertion: offs < UNIV_PAGE_SIZE InnoDB: We intentionally generate a memory trap. InnoDB: Send a detailed bug report to mysql@lists.mysql.com 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=67108864 read_buffer_size=1044480 max_used_connections=0 max_connections=100 threads_connected=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 269935 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x87b5520 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=0x7fe5e0b8, backtrace may not be correct. Stack range sanity check OK, backtrace follows: 0x8071fb4 0x8292c58 0x817c9eb 0x810e499 0x810e504 0x8105018 0x80cc9ab 0x80c68c4 0x8094525 0x8090dd7 0x809023a 0x80911e9 0x80a8666 0x807e159 0x8080905 0x80b2b22 0x80ec40d 0x80ecf8a 0x829040c 0x82c3b3a New value of fp=(nil) failed sanity check, terminating stack trace! Please read http://www.mysql.com/doc/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved stack trace is much more helpful in diagnosing the problem, so please do resolve it Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x87b0752 = UPDATE FileEntry SET WriteLock = 0 WHERE idFile = 76762 thd->thread_id=2 The manual page at http://www.mysql.com/doc/en/Crashing.html contains information that should help you find out what is causing the crash. 050125 12:08:21 InnoDB: Database was not shut down normally. InnoDB: Starting recovery from log files... InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 0 414520340 InnoDB: Doing recovery: scanned up to log sequence number 0 414520340 InnoDB: In a MySQL replication slave the last master binlog file InnoDB: position 0 571101, file name db1_log_bin.025 InnoDB: Last MySQL binlog file position 0 571101, file name /usr/local/archivedb/log_s/db2_log_bin.024 050125 12:08:21 InnoDB: Flushing modified pages from the buffer pool... 050125 12:08:21 InnoDB: Started 050125 12:08:21 Slave SQL thread initialized, starting replication in log 'db1_log_bin.025' at position 571101, relay log '/usr/local/archivedb/data_s/standby_rlog.059' position: 571143 mysqld: ready for connections. Version: '4.0.17-standard-log' socket: '/usr/local/archivedb/socks/slave.sock2' port: 3357 050125 12:08:21 Slave I/O thread: connected to master 'arcslv@cp_dbsrv:3356', replication started in log 'db1_log_bin.025' at position 791488 050125 12:08:21 InnoDB: Assertion failure in thread 40971 in file ../../innobase/btr/../include/page0page.ic line 482 InnoDB: Failing assertion: offs < UNIV_PAGE_SIZE InnoDB: We intentionally generate a memory trap. InnoDB: Send a detailed bug report to mysql@lists.mysql.com 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=67108864 read_buffer_size=1044480 max_used_connections=0 max_connections=100 threads_connected=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 269935 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x31a00510 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=0x7fe5e0b8, backtrace may not be correct. Stack range sanity check OK, backtrace follows: 0x8071fb4 0x8292c58 0x817c9eb 0x810e499 0x810e504 0x8105018 0x80cc9ab 0x80c68c4 0x8094525 0x8090dd7 0x809023a 0x80911e9 0x80a8666 0x807e159 0x8080905 0x80b2b22 0x80ec40d 0x80ecf8a 0x829040c New value of fp=(nil) failed sanity check, terminating stack trace! Please read http://www.mysql.com/doc/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved stack trace is much more helpful in diagnosing the problem, so please do resolve it Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x31a0d002 is invalid pointer thd->thread_id=2 The manual page at http://www.mysql.com/doc/en/Crashing.html contains information that should help you find out what is causing the crash.
[25 Jan 2005 9:56]
Sumit Kumar Roy
Hi I have just completed the stack_trace. the result is as follows: [test]# resolve_stack_dump -s ./mysqld.sym -n mysqld.stack 0x8071fb4 handle_segfault + 420 0x8292c58 pthread_sighandler + 184 0x817c9eb btr_estimate_number_of_different_key_vals + 2203 0x810e499 dict_update_statistics_low + 89 0x810e504 dict_update_statistics + 20 0x8105018 dict_table_get_and_increment_handle_count + 552 0x80cc9ab open__11ha_innobasePCciUi + 203 0x80c68c4 ha_open__7handlerPCcii + 36 0x8094525 openfrm__FPCcT0UiUiUiP8st_table + 5301 0x8090dd7 open_unireg_entry__FP3THDP8st_tablePCcN22 + 87 0x809023a open_table__FP3THDPCcN21Pb + 858 0x80911e9 open_ltable__FP3THDP13st_table_list13thr_lock_type + 57 0x80a8666 mysql_update__FP3THDP13st_table_listRt4List1Z4ItemT2P4ItemP8st_orderUl15enum_duplicates + 102 0x807e159 mysql_execute_command__Fv + 6233 0x8080905 mysql_parse__FP3THDPcUi + 149 0x80b2b22 exec_event__15Query_log_eventP17st_relay_log_info + 434 0x80ec40d exec_relay_log_event__FP3THDP17st_relay_log_info + 541 0x80ecf8a handle_slave_sql + 682 0x829040c pthread_start_thread + 220 0x82c3b3a thread_start + 4
[25 Jan 2005 10:00]
Sumit Kumar Roy
Hi Heikki If you suggest to change some parameters in the cnf files, I can do so.
[25 Jan 2005 12:36]
Heikki Tuuri
Hi! Ok, if the master and the slave do not crash at the same time, then this might be random memory corruption. The table archivedb/FileEntry is probably corrupt in the slave. Your log sequence number is only 400 MB. People can easily run InnoDB to a 1000 times bigger lsn without a single crash. My guess is still a hardware problem. Please test your application on another computer with another Linux kernel. Regards, Heikki
[27 Jan 2005 8:53]
Sumit Kumar Roy
Hi Heikki The platform we are working is our target platform. Can you suggest any remady? Regards Sumit Kumar Roy
[28 Feb 2005 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".
