By using this site, you agree to our updated Privacy Policy and our Terms of Use. Manage your Cookies Settings.
445,870 Members | 1,189 Online
Bytes IT Community
+ Ask a Question
Need help? Post your question and get tips & solutions from a community of 445,870 IT Pros & Developers. It's quick & easy.

Innodb: lockup problem caused machine slave to crash

P: n/a
Hi all,

Hoping someone can help us with this strange Innodb problem. At about
5:15 AM 2/2/04 (this morning), our slave server stopped accepting
connections. The machine was pingable, but you could not SSH into the
machine.

We had to manually reboot the machine, and restart the slave. Looking
in the error file we found this:

InnoDB: Warning: a long semaphore wait:
--Thread 1158482288 has waited at log0log.c line 1865 for 242.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic
info:

=====================================
040202 5:14:22 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 57 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 243.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864883, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867442
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867435, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118728568 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867284, not started, process no 4441, OS thread id
1196427632
MySQL thread id 3874, query id 118727156 pub98.ezboard.com
209.247.51.98 ezreader

(it goes on to list a LOT of these....)

--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: doing file i/o (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 1, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
114 OS file reads, 28812405 OS file writes, 17994844 OS fsyncs
0 pending preads, 1 pending pwrites
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf for space 0: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 4980539, used cells 2383080, node heap has 4783
buffer(s)
590.76 hash searches/s, 142.28 non-hash searches/s
---
LOG
---
Log sequence number 1 476373164
Log flushed up to 1 476372189
Last checkpoint at 1 476346048
1 pending log writes, 1 pending chkp writes
17078524 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4013346285; in additional pool allocated
4887040
Buffer pool size 153600
Free buffers 74580
Database pages 74237
Modified db pages 4
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 128, created 74109, written 13134904
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
Main thread process no. 4441, id 1158482288, state: making checkpoint
Number of rows inserted 4538821, updated 13940546, deleted 1215428,
read 214961069
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 444.61 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

=====================================
040202 5:14:38 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 16 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 259.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864884, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867671
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867522, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118729545 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867443, not started, process no 4441, OS thread id
1196427632

(again .. list as whole bunch more)...

it repeats these outputs a few more times.. then no more log entries
until the server is restarted an hour or so later.

The server was running for over a month with no problems until this
happened.
We are using 4.0.15 on both master and slave.

Thanks for any help!
Jul 19 '05 #1
Share this Question
Share on Google+
3 Replies


P: n/a
Hi!

It is waiting for an asynchronous checkpoint write to complete:

"
if (sync) {
/* Wait for the checkpoint write to complete */
rw_lock_s_lock(&(log_sys->checkpoint_lock));
rw_lock_s_unlock(&(log_sys->checkpoint_lock));
}
"

The log i/o thread is stuck inside os_file_pwrite:

"
I/O thread 1 state: doing file i/o (log thread) .... Pending flushes (fsync) log: 1; buffer pool: 0
114 OS file reads, 28812405 OS file writes, 17994844 OS fsyncs
0 pending preads, 1 pending pwrites
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s "

The following code shows that the thread probably is indeed stuck inside an
operating system call pwrite:

"
os_mutex_enter(os_file_count_mutex);
os_file_n_pending_pwrites++;
os_mutex_exit(os_file_count_mutex);

ret = pwrite(file, buf, n, offs);

os_mutex_enter(os_file_count_mutex);
os_file_n_pending_pwrites--;
os_mutex_exit(os_file_count_mutex);
"

Are you running Linux? What distro? This is probably a bug in the OS or a
hardware fault.

Best regards,

Heikki Tuuri
Innobase Oy
http://www.innodb.com
Foreign keys, transactions, and row level locking for MySQL
InnoDB Hot Backup - a hot backup tool for InnoDB which also backs up MyISAM
tables

Order MySQL technical support from https://order.mysql.com/

"Vanchau Nguyen" <va*****@ezboard.com> kirjoitti viestissä
news:fa**************************@posting.google.c om... Hi all,

Hoping someone can help us with this strange Innodb problem. At about
5:15 AM 2/2/04 (this morning), our slave server stopped accepting
connections. The machine was pingable, but you could not SSH into the
machine.

We had to manually reboot the machine, and restart the slave. Looking
in the error file we found this:

InnoDB: Warning: a long semaphore wait:
--Thread 1158482288 has waited at log0log.c line 1865 for 242.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic
info:

=====================================
040202 5:14:22 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 57 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 243.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864883, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867442
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867435, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118728568 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867284, not started, process no 4441, OS thread id
1196427632
MySQL thread id 3874, query id 118727156 pub98.ezboard.com
209.247.51.98 ezreader

(it goes on to list a LOT of these....)

--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: doing file i/o (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 1, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
114 OS file reads, 28812405 OS file writes, 17994844 OS fsyncs
0 pending preads, 1 pending pwrites
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf for space 0: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 4980539, used cells 2383080, node heap has 4783
buffer(s)
590.76 hash searches/s, 142.28 non-hash searches/s
---
LOG
---
Log sequence number 1 476373164
Log flushed up to 1 476372189
Last checkpoint at 1 476346048
1 pending log writes, 1 pending chkp writes
17078524 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4013346285; in additional pool allocated
4887040
Buffer pool size 153600
Free buffers 74580
Database pages 74237
Modified db pages 4
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 128, created 74109, written 13134904
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
Main thread process no. 4441, id 1158482288, state: making checkpoint
Number of rows inserted 4538821, updated 13940546, deleted 1215428,
read 214961069
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 444.61 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

=====================================
040202 5:14:38 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 16 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 259.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864884, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867671
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867522, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118729545 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867443, not started, process no 4441, OS thread id
1196427632

(again .. list as whole bunch more)...

it repeats these outputs a few more times.. then no more log entries
until the server is restarted an hour or so later.

The server was running for over a month with no problems until this
happened.
We are using 4.0.15 on both master and slave.

Thanks for any help!

Jul 19 '05 #2

P: n/a
Hi!

It is waiting for an asynchronous checkpoint write to complete:

"
if (sync) {
/* Wait for the checkpoint write to complete */
rw_lock_s_lock(&(log_sys->checkpoint_lock));
rw_lock_s_unlock(&(log_sys->checkpoint_lock));
}
"

The log i/o thread is stuck inside os_file_pwrite:

"
I/O thread 1 state: doing file i/o (log thread) .... Pending flushes (fsync) log: 1; buffer pool: 0
114 OS file reads, 28812405 OS file writes, 17994844 OS fsyncs
0 pending preads, 1 pending pwrites
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s "

The following code shows that the thread probably is indeed stuck inside an
operating system call pwrite:

"
os_mutex_enter(os_file_count_mutex);
os_file_n_pending_pwrites++;
os_mutex_exit(os_file_count_mutex);

ret = pwrite(file, buf, n, offs);

os_mutex_enter(os_file_count_mutex);
os_file_n_pending_pwrites--;
os_mutex_exit(os_file_count_mutex);
"

Are you running Linux? What distro? This is probably a bug in the OS or a
hardware fault.

Best regards,

Heikki Tuuri
Innobase Oy
http://www.innodb.com
Foreign keys, transactions, and row level locking for MySQL
InnoDB Hot Backup - a hot backup tool for InnoDB which also backs up MyISAM
tables

Order MySQL technical support from https://order.mysql.com/

"Vanchau Nguyen" <va*****@ezboard.com> kirjoitti viestissä
news:fa**************************@posting.google.c om... Hi all,

Hoping someone can help us with this strange Innodb problem. At about
5:15 AM 2/2/04 (this morning), our slave server stopped accepting
connections. The machine was pingable, but you could not SSH into the
machine.

We had to manually reboot the machine, and restart the slave. Looking
in the error file we found this:

InnoDB: Warning: a long semaphore wait:
--Thread 1158482288 has waited at log0log.c line 1865 for 242.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic
info:

=====================================
040202 5:14:22 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 57 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 243.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864883, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867442
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867435, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118728568 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867284, not started, process no 4441, OS thread id
1196427632
MySQL thread id 3874, query id 118727156 pub98.ezboard.com
209.247.51.98 ezreader

(it goes on to list a LOT of these....)

--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: doing file i/o (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 1, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
114 OS file reads, 28812405 OS file writes, 17994844 OS fsyncs
0 pending preads, 1 pending pwrites
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf for space 0: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 4980539, used cells 2383080, node heap has 4783
buffer(s)
590.76 hash searches/s, 142.28 non-hash searches/s
---
LOG
---
Log sequence number 1 476373164
Log flushed up to 1 476372189
Last checkpoint at 1 476346048
1 pending log writes, 1 pending chkp writes
17078524 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4013346285; in additional pool allocated
4887040
Buffer pool size 153600
Free buffers 74580
Database pages 74237
Modified db pages 4
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 128, created 74109, written 13134904
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
Main thread process no. 4441, id 1158482288, state: making checkpoint
Number of rows inserted 4538821, updated 13940546, deleted 1215428,
read 214961069
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 444.61 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

=====================================
040202 5:14:38 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 16 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 259.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864884, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867671
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867522, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118729545 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867443, not started, process no 4441, OS thread id
1196427632

(again .. list as whole bunch more)...

it repeats these outputs a few more times.. then no more log entries
until the server is restarted an hour or so later.

The server was running for over a month with no problems until this
happened.
We are using 4.0.15 on both master and slave.

Thanks for any help!

Jul 19 '05 #3

P: n/a
Hi!

It is waiting for an asynchronous checkpoint write to complete:

"
if (sync) {
/* Wait for the checkpoint write to complete */
rw_lock_s_lock(&(log_sys->checkpoint_lock));
rw_lock_s_unlock(&(log_sys->checkpoint_lock));
}
"

The log i/o thread is stuck inside os_file_pwrite:

"
I/O thread 1 state: doing file i/o (log thread) .... Pending flushes (fsync) log: 1; buffer pool: 0
114 OS file reads, 28812405 OS file writes, 17994844 OS fsyncs
0 pending preads, 1 pending pwrites
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s "

The following code shows that the thread probably is indeed stuck inside an
operating system call pwrite:

"
os_mutex_enter(os_file_count_mutex);
os_file_n_pending_pwrites++;
os_mutex_exit(os_file_count_mutex);

ret = pwrite(file, buf, n, offs);

os_mutex_enter(os_file_count_mutex);
os_file_n_pending_pwrites--;
os_mutex_exit(os_file_count_mutex);
"

Are you running Linux? What distro? This is probably a bug in the OS or a
hardware fault.

Best regards,

Heikki Tuuri
Innobase Oy
http://www.innodb.com
Foreign keys, transactions, and row level locking for MySQL
InnoDB Hot Backup - a hot backup tool for InnoDB which also backs up MyISAM
tables

Order MySQL technical support from https://order.mysql.com/

"Vanchau Nguyen" <va*****@ezboard.com> kirjoitti viestissä
news:fa**************************@posting.google.c om... Hi all,

Hoping someone can help us with this strange Innodb problem. At about
5:15 AM 2/2/04 (this morning), our slave server stopped accepting
connections. The machine was pingable, but you could not SSH into the
machine.

We had to manually reboot the machine, and restart the slave. Looking
in the error file we found this:

InnoDB: Warning: a long semaphore wait:
--Thread 1158482288 has waited at log0log.c line 1865 for 242.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic
info:

=====================================
040202 5:14:22 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 57 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 243.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864883, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867442
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867435, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118728568 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867284, not started, process no 4441, OS thread id
1196427632
MySQL thread id 3874, query id 118727156 pub98.ezboard.com
209.247.51.98 ezreader

(it goes on to list a LOT of these....)

--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: doing file i/o (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 1, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
114 OS file reads, 28812405 OS file writes, 17994844 OS fsyncs
0 pending preads, 1 pending pwrites
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf for space 0: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 4980539, used cells 2383080, node heap has 4783
buffer(s)
590.76 hash searches/s, 142.28 non-hash searches/s
---
LOG
---
Log sequence number 1 476373164
Log flushed up to 1 476372189
Last checkpoint at 1 476346048
1 pending log writes, 1 pending chkp writes
17078524 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4013346285; in additional pool allocated
4887040
Buffer pool size 153600
Free buffers 74580
Database pages 74237
Modified db pages 4
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 128, created 74109, written 13134904
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
Main thread process no. 4441, id 1158482288, state: making checkpoint
Number of rows inserted 4538821, updated 13940546, deleted 1215428,
read 214961069
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 444.61 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

=====================================
040202 5:14:38 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 16 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 319509, signal count 319415
--Thread 1158482288 has waited at log0log.c line 1865 for 259.00
seconds the semaphore:
S-lock on RW-latch at 2a961f32e0 created in file log0log.c line 738
a writer (thread id 1158482288) has reserved it in mode exclusive
number of readers 0, waiters flag 1
Last time read locked in file log0log.c line 1865
Last time write locked in file log0log.c line 1667
Mutex spin waits 864884, rounds 1378688, OS waits 14390
RW-shared spins 503597, OS waits 250920; RW-excl spins 57181, OS waits
50899
------------
TRANSACTIONS
------------
Trx id counter 0 37867671
Purge done for trx's n:o < 0 25411749 undo n:o < 0 0
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 37867522, not started, process no 4441, OS thread id
1174407536
MySQL thread id 3875, query id 118729545 pub14.ezboard.com
209.247.51.14 ezreader
---TRANSACTION 0 37867443, not started, process no 4441, OS thread id
1196427632

(again .. list as whole bunch more)...

it repeats these outputs a few more times.. then no more log entries
until the server is restarted an hour or so later.

The server was running for over a month with no problems until this
happened.
We are using 4.0.15 on both master and slave.

Thanks for any help!

Jul 19 '05 #4

This discussion thread is closed

Replies have been disabled for this discussion.