| Bug #27971 | mysqld stop running after 'a long semaphore wait' appear | ||
|---|---|---|---|
| Submitted: | 20 Apr 2007 3:43 | Modified: | 4 Jan 2008 18:06 |
| Reporter: | Ken Chen | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
| Version: | 5.0.37,5.0.45 | OS: | FreeBSD (FreeBSD 6.2-RELEASE) |
| Assigned to: | Heikki Tuuri | CPU Architecture: | Any |
| Tags: | deadlock, innodb | ||
[20 Apr 2007 3:44]
Ken Chen
the full messages in the log file
Attachment: INNODB MONITOR OUTPUT.txt (text/plain), 18.34 KiB.
[20 Apr 2007 11:15]
Heikki Tuuri
Ken, did you post the entire transactions section in the .err file? If not, please post it. Heikki
[20 Apr 2007 11:37]
Heikki Tuuri
This seems to be inconsistent:
"
--Thread 514866688 has waited at buf0buf.c line 856 for 241.00 seconds the
semaphore:
Mutex at 0xc6af860 created file buf0buf.c line 545, lock var 0
waiters flag 0
"
It is waiting for the buffer pool mutex.
This is the only place where we set waiters = 0, but then we always set also the event:
sync0sync.c in 5.0:
/**********************************************************************
Releases the threads waiting in the primary wait array for this mutex. */
This is the only place
void
mutex_signal_object(
/*================*/
mutex_t* mutex) /* in: mutex */
{
mutex_set_waiters(mutex, 0);
/* The memory order of resetting the waiters field and
signaling the object is important. See LEMMA 1 above. */
os_event_set(mutex->event);
sync_array_object_signalled(sync_primary_wait_array);
}
This might be an OS bug, or memory corruption in InnoDB.
[20 Apr 2007 11:51]
Heikki Tuuri
Looks like the thread is still waiting for the event, though we should have the event now set!
sync0arr.c:
if (!cell->waiting) {
fputs("wait has ended\n", file);
}
}
[22 Apr 2007 22:39]
Ken Chen
It happened again last night. I upload the full log some minutes before, and hope it's helpful for this problem.
[23 Apr 2007 0:28]
Heikki Tuuri
How stable is FreeBSD 6.2-RELEASE? This could be an OS bug in waking up a thread after a cond variable wait.
[23 Apr 2007 3:20]
Ken Chen
Is it possible the reason? db1# limits Resource limits (current): cputime infinity secs filesize infinity kB datasize 1048576 kB stacksize 131072 kB coredumpsize infinity kB memoryuse infinity kB memorylocked infinity kB maxprocesses 5547 openfiles 4096 sbsize infinity bytes vmemoryuse infinity kB
[24 Apr 2007 5:13]
Heikki Tuuri
I am marking this as Can't repeat until we get more reports from FreeBSD-6.2. This might be an OS bug.
[26 Apr 2007 1:39]
Ken Chen
Thanks Heikki! Will mysql can not launch a new thread because of memory limitation cause this problem?
[26 Apr 2007 1:42]
Ken Chen
oh.. forgive my really poor English in last comment. You should know what I mean.. I adjust some numbers in /boot/loader.conf, and it works fine for days!
[30 Apr 2007 3:40]
Ken Chen
'a long semaphore wait' was gone, but new problem comes every 30 minutes! =============== 8< ================== 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=23 max_connections=130 threads_connected=20 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 1060342 K bytes of memory Hope that's ok; if not, decrease some variables in the equation =============== 8< ==================== I am sure I have enough memory. db1# limits Resource limits (current): cputime infinity secs filesize infinity kB datasize 1572864 kB stacksize 262144 kB coredumpsize infinity kB memoryuse infinity kB memorylocked infinity kB maxprocesses 5547 openfiles 11095 sbsize infinity bytes vmemoryuse infinity kB last pid: 7811; load averages: 2.58, 1.39, 1.31 up 0+16:33:50 11:37:58 73 processes: 7 running, 66 sleeping CPU states: % user, % nice, % system, % interrupt, % idle Mem: 422M Active, 2998M Inact, 178M Wired, 158M Cache, 112M Buf, 6472K Free Swap: 4096M Total, 20K Used, 4096M Free PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND 7771 mysql 53 96 0 670M 409M ucond 0 7:42 93.90% mysqld ============== 8< ============================= I guess too many thread make mysqld crash on this machine, and I will change other hardware in the afternoon.
[6 May 2007 19:58]
Ken Chen
After replacing new hardware, the problem has gone. Now it run on same model of mother board, and different SCSI harddisk. I think there is something wrong on my last harddisk. Thanks for great help, I suppose it's a hardware problem.
Description: After moving the mysql from Linux 2.4 to FreeBSD 6.2, it happens 2 times in last 8 hours. The FreeBSD hardware is an Intel SR2200 server with 2 x Xeon(TM) CPU 2.40GHz, HTT enabled, 4GB RAM. I am using the binary distribution, and set the libmap.conf. /usr/local/mysql/bin/mysqld: libcrypt.so.3 => /lib/libcrypt.so.3 (0x484fb000) libm.so.4 => /lib/libm.so.4 (0x48513000) libpthread.so.2 => /usr/lib/libthr.so.2 (0x48529000) libc.so.6 => /lib/libc.so.6 (0x4853b000) Here are the error messages.... Version: '5.0.37-log' socket: '/tmp/mysql.sock' port: 3307 MySQL Community Server (GPL) InnoDB: Warning: a long semaphore wait: --Thread 514866688 has waited at buf0buf.c line 856 for 241.00 seconds the semaphore: Mutex at 0xc6af860 created file buf0buf.c line 545, lock var 0 waiters flag 0 InnoDB: Warning: a long semaphore wait: --Thread 517134848 has waited at btr0sea.c line 995 for 241.00 seconds the semaphore: X-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: Warning: a long semaphore wait: --Thread 525105920 has waited at btr0sea.c line 916 for 241.00 seconds the semaphore: S-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: Warning: a long semaphore wait: --Thread 517106176 has waited at btr0sea.c line 916 for 241.00 seconds the semaphore: S-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: Warning: a long semaphore wait: --Thread 525103360 has waited at btr0sea.c line 1127 for 241.00 seconds the semaphore: S-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: Warning: a long semaphore wait: --Thread 517946880 has waited at btr0sea.c line 916 for 241.00 seconds the semaphore: S-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: Warning: a long semaphore wait: --Thread 530931712 has waited at btr0sea.c line 1127 for 241.00 seconds the semaphore: S-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: Warning: a long semaphore wait: --Thread 525105152 has waited at btr0sea.c line 916 for 241.00 seconds the semaphore: S-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: Warning: a long semaphore wait: --Thread 517104640 has waited at row0sel.c line 3326 for 241.00 seconds the semaphore: S-lock on RW-latch at 0xc6afa60 created in file btr0sea.c line 139 a writer (thread id 517134848) has reserved it in mode wait exclusive number of readers 1, waiters flag 1 Last time read locked in file btr0sea.c line 916 Last time write locked in file btr0sea.c line 995 InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info: InnoDB: Pending preads 0, pwrites 0 I will send following messages with file attaching. Thanks in advanced, and please forgive my poor English. How to repeat: no idea.