| Bug #47525 | MySQL crashed (Federated) | ||
|---|---|---|---|
| Submitted: | 22 Sep 2009 16:09 | Modified: | 18 Dec 2009 15:00 |
| Reporter: | Zigmund Bulinsh | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Federated storage engine | Severity: | S2 (Serious) |
| Version: | 5.1.39 | OS: | Windows |
| Assigned to: | Davi Arnaut | CPU Architecture: | Any |
| Tags: | regression | ||
[22 Sep 2009 16:09]
Zigmund Bulinsh
[22 Sep 2009 16:12]
Zigmund Bulinsh
Just thought that this can help you, if you changed code regarding some component or object (before I had never had such exception in versions from 5.1.31 to 5.1.38). I haven;t redumbed database from 5.1.31, because I haven't seen that there were some changes in file formats and also redumping gigabytes' database is not so fun...
[22 Sep 2009 16:37]
Zigmund Bulinsh
Happened again. And I see that it happens after 30 minutes of work... InnoDB: The log sequence number in ibdata files does not match InnoDB: the log sequence number in the ib_logfiles! 090922 19:04:47 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: Last MySQL binlog file position 0 5910, file name .\agora_log.000341 090922 19:04:47 InnoDB: Started; log sequence number 6 2099162683 090922 19:04:47 [Note] Recovering after a crash using agora_log 090922 19:04:47 [Note] Starting crash recovery... 090922 19:04:47 [Note] Crash recovery finished. 090922 19:04:48 [Note] Slave SQL thread initialized, starting replication in log 'datacenter_log.000033' at position 1685, relay log '.\agora_relay_log.001668' position: 1835 090922 19:04:48 [Note] Event Scheduler: Loaded 0 events 090922 19:04:48 [Note] D:\MySQL\bin\mysqld.exe: ready for connections. Version: '5.1.39-community-log' socket: '' port: 3306 MySQL Community Server (GPL) 090922 19:04:48 [Note] Event Scheduler: scheduler thread started with id 3 090922 19:04:48 [Note] Slave I/O thread: connected to master 'replication@127.0.0.1:3333',replication started in log 'datacenter_log.000033' at position 1685 090922 19:34:47 - mysqld got exception 0xc0000005 ; 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=396361728 read_buffer_size=16777216 max_used_connections=5 max_threads=100 threads_connected=2 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2435703 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd: 0x0 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... 00422E26 mysqld.exe!slave_io_thread_detach_vio()[slave.cc:3757] 004DE9C7 mysqld.exe!end_server()[client.c:949] 004DEA49 mysqld.exe!mysql_close()[client.c:2756] 0059DCE9 mysqld.exe!ha_federated::close()[ha_federated.cc:1660] 004D694D mysqld.exe!closefrm()[table.cc:1971] 00460A18 mysqld.exe!intern_close_table()[sql_base.cc:780] 00460A2B mysqld.exe!free_cache_entry()[sql_base.cc:802] 00682720 mysqld.exe!my_hash_delete()[hash.c:551] 0045FC8F mysqld.exe!flush_tables()[sql_base.cc:8387] 0043D107 mysqld.exe!handle_manager()[sql_manager.cc:110] 00679D2B mysqld.exe!pthread_start()[my_winthread.c:85] 006592D3 mysqld.exe!_callthreadstart()[thread.c:293] 0065936C mysqld.exe!_threadstart()[thread.c:275] 75EFD0E9 kernel32.dll!BaseThreadInitThunk() 770819BB ntdll.dll!RtlInitializeExceptionChain() 7708198E ntdll.dll!RtlInitializeExceptionChain() 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.
[22 Sep 2009 16:39]
Zigmund Bulinsh
I have no any events created for 30 minutes.. But the time when server crashes is strictly 30 minutes with 1 second delay.
[22 Sep 2009 17:01]
MySQL Verification Team
It is a slave server setup?. Thanks in advance.
[22 Sep 2009 17:49]
Zigmund Bulinsh
Yes. It is. The master is located on the localhost as you see with the same version (5.1.39). OS = Windows Vista SP1.
[22 Sep 2009 17:52]
MySQL Verification Team
looks like it's happening each 30 minutes because this is the default value for "flush_time" on windows. probably running "flush tables" will crash too..
[23 Sep 2009 6:59]
Zigmund Bulinsh
Hm.. No. Flush tables work. It just crashes after 30 minutes. And it happens now on all production systems, so I rolled back to the 5.1.38. And happens only if federated tables are connected to the local database on the other server port.
[23 Sep 2009 7:01]
Zigmund Bulinsh
As it happens on all my DB instances which has a federated table connections to the replication master's tables.
[23 Sep 2009 7:04]
Zigmund Bulinsh
Just checked now... It happens absolutely on all instances with federated tables (and also without any operations made on them). Just crashes...
[23 Sep 2009 7:10]
Zigmund Bulinsh
The same stack trace for every instance.
[23 Sep 2009 8:25]
Zigmund Bulinsh
I found when it happens. it happens only when you update data through the federated tables. After the update goes 30 minutes and then crashes. If I make flush files, then it works, but still crashes after minutes.
[23 Sep 2009 8:38]
Valeriy Kravchuk
I've repeated this on 64-bit XP without any problem. Look:
C:\Program Files\MySQL\MySQL Server 5.0\bin>mysql -uroot -proot -P3306 test
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 10
Server version: 5.0.81-community-nt MySQL Community Edition (GPL)
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> show create table t1;
ERROR 1146 (42S02): Table 'test.t1' doesn't exist
mysql> create table t1(c1 int) engine=MyISAM;
Query OK, 0 rows affected (0.27 sec)
mysql> insert into t1 values(1), (2);
Query OK, 2 rows affected (0.19 sec)
Records: 2 Duplicates: 0 Warnings: 0
mysql> exit
Bye
So, I've created some table on other MySQL server running on the same machine. Then:
C:\Program Files\MySQL\MySQL Server 5.0\bin>mysql -uroot -proot -P3307 test
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.1.39-community MySQL Community Server (GPL)
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> create table tfed(c1 int) engine=federated
-> connection='mysql://root:root@localhost:3306/test/t1';
Query OK, 0 rows affected (0.00 sec)
mysql> select * from tfed;
+------+
| c1 |
+------+
| 1 |
| 2 |
+------+
2 rows in set (1.06 sec)
Then I just waited for 30 minutes doing nothing and had got exactly the same crash:
090923 10:57:45 InnoDB: Started; log sequence number 0 183597
090923 10:57:45 [Note] Event Scheduler: Loaded 0 events
090923 10:57:45 [Note] C:\Program Files\MySQL\MySQL Server 5.1\bin\mysqld: ready
for connections.
Version: '5.1.39-community' socket: '' port: 3307 MySQL Community Server (GPL
)
090923 11:27:46 - mysqld got exception 0xc0000005 ;
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=8388608
read_buffer_size=65536
max_used_connections=2
max_threads=100
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 41085 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
thd: 0x0
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...
000000014002A3A2 mysqld.exe!slave_io_thread_detach_vio()[slave.cc:3757]
00000001401175AF mysqld.exe!end_server()[client.c:949]
0000000140117650 mysqld.exe!mysql_close()[client.c:2758]
0000000140200CA1 mysqld.exe!ha_federated::close()[ha_federated.cc:1660]
000000014010DEB9 mysqld.exe!closefrm()[table.cc:1971]
00000001400752F0 mysqld.exe!intern_close_table()[sql_base.cc:782]
000000014007530E mysqld.exe!free_cache_entry()[sql_base.cc:803]
000000014031F9E1 mysqld.exe!my_hash_delete()[hash.c:551]
000000014007432F mysqld.exe!flush_tables()[sql_base.cc:8387]
000000014004B8BF mysqld.exe!handle_manager()[sql_manager.cc:110]
0000000140315B25 mysqld.exe!pthread_start()[my_winthread.c:85]
00000001402DFDA7 mysqld.exe!_callthreadstart()[thread.c:295]
00000001402DFE75 mysqld.exe!_threadstart()[thread.c:275]
0000000077D6B71A kernel32.dll!BaseThreadStart()
[23 Sep 2009 9:30]
MySQL Verification Team
is this a regression caused by fix to bug #45242 I wonder ?
[29 Sep 2009 15:34]
Zigmund Bulinsh
This happens also without updating federated tables. It is enough to make a database dump (with mysqldump). And after 30 minutes it crashes again.
[30 Sep 2009 14:10]
Davi Arnaut
Yes, regression caused by Bug#45242. The patch missed a condition that happens due to FLUSH TABLES.
[30 Sep 2009 19:01]
Davi Arnaut
BTW, the crash after 30 minutes is probably due to the FLUSH_TIME variable which flushes tables at a given interval.
[30 Sep 2009 20:49]
Davi Arnaut
Workaround: set flush_time to 0.
[30 Sep 2009 21:38]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/85275 2813 Davi Arnaut 2009-09-30 Bug#47525: MySQL crashed (Federated) On Mac OS X or Windows, sending a SIGHUP to the server or a asynchronous flush (triggered by flush_time), would cause the server to crash. The problem was that a hook used to detach client API handles wasn't prepared to handle cases where the thread does not have a associated session. The solution is to verify whether the thread has a associated session before trying to detach a handle. @ mysql-test/r/federated_debug.result Add test case result for Bug#47525 @ mysql-test/t/federated_debug-master.opt Debug point. @ mysql-test/t/federated_debug.test Add test case for Bug#47525 @ sql/slave.cc Check whether a the thread has a associated session. @ sql/sql_parse.cc Add debug code to simulate a reload without thread session.
[30 Sep 2009 21:43]
Davi Arnaut
Queued to 5.0-bugteam
[5 Oct 2009 17:09]
Zigmund Bulinsh
Just wanted to inform that "set global flush_time = 0" does not solves the problem. Server still crashes.
[5 Oct 2009 19:41]
Davi Arnaut
flush_time only takes effect on start up (cnf file) or after the current flush_time is expires (that is, if flush_time was previously set, it will run once).
[6 Oct 2009 8:57]
Bugs System
Pushed into 5.0.87 (revid:joro@sun.com-20091006073202-rj21ggvo2gw032ks) (version source revid:davi.arnaut@sun.com-20090930213802-w029fmi6q1hd1ggp) (merge vers: 5.0.87) (pib:11)
[6 Oct 2009 9:01]
Bugs System
Pushed into 5.1.40 (revid:joro@sun.com-20091006073316-lea2cpijh9r6on7c) (version source revid:ingo.struewing@sun.com-20091002112748-2xmjv846dk323nc3) (merge vers: 5.1.40) (pib:11)
[14 Oct 2009 15:34]
Paul DuBois
Noted in 5.0.87, 5.1.40 changelogs. On Mac OS X or Windows, sending a SIGHUP signal to the server or an asynchronous flush (triggered by flush_time) caused the server to crash. Setting report to NDI pending push into 5.5.x+.
[22 Oct 2009 6:33]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091022063126-l0qzirh9xyhp0bpc) (version source revid:alik@sun.com-20091019135554-s1pvptt6i750lfhv) (merge vers: 6.0.14-alpha) (pib:13)
[22 Oct 2009 7:06]
Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091022060553-znkmxm0g0gm6ckvw) (version source revid:alik@sun.com-20091013094238-g67x6tgdm9a7uik0) (merge vers: 5.5.0-beta) (pib:13)
[22 Oct 2009 19:51]
Paul DuBois
Noted in 5.5.0, 6.0.14 changelogs.
[18 Dec 2009 10:29]
Bugs System
Pushed into 5.1.41-ndb-7.1.0 (revid:jonas@mysql.com-20091218102229-64tk47xonu3dv6r6) (version source revid:jonas@mysql.com-20091218095730-26gwjidfsdw45dto) (merge vers: 5.1.41-ndb-7.1.0) (pib:15)
[18 Dec 2009 10:44]
Bugs System
Pushed into 5.1.41-ndb-6.2.19 (revid:jonas@mysql.com-20091218100224-vtzr0fahhsuhjsmt) (version source revid:jonas@mysql.com-20091217101452-qwzyaig50w74xmye) (merge vers: 5.1.41-ndb-6.2.19) (pib:15)
[18 Dec 2009 11:00]
Bugs System
Pushed into 5.1.41-ndb-6.3.31 (revid:jonas@mysql.com-20091218100616-75d9tek96o6ob6k0) (version source revid:jonas@mysql.com-20091217154335-290no45qdins5bwo) (merge vers: 5.1.41-ndb-6.3.31) (pib:15)
[18 Dec 2009 11:14]
Bugs System
Pushed into 5.1.41-ndb-7.0.11 (revid:jonas@mysql.com-20091218101303-ga32mrnr15jsa606) (version source revid:jonas@mysql.com-20091218064304-ezreonykd9f4kelk) (merge vers: 5.1.41-ndb-7.0.11) (pib:15)
[18 Dec 2009 15:00]
Tony Bedford
Also noted in the following changelogs: 5.1.41-ndb-7.1.0 5.1.41-ndb-6.2.19 5.1.41-ndb-6.3.31 5.1.41-ndb-7.0.11
[12 Sep 2018 20:20]
Vincent Wansink
I can confirm that this is also happening on 5.5.61. My server is extremely busy (thousands of transactions per second) and mysql crashes exactly 30 minutes after it was restarted all day every day. This only started happening after I started using federated tables.
[13 Sep 2018 15:27]
Vincent Wansink
I can also confirm that setting "flush_time = 0" in my.ini makes this problem go away.
[23 Feb 2021 9:36]
Aldo Rizzardi
Happened to me also on 5.5.62 with federated tables, 30minutes exactly and seems solved with "flush_time = 0". I had before version 5.5.60 without the issue. Thanks Vincent Wansink for your update comment, I registered to add mine too.
