从库mysqldump 时,mysql 有时会导致重启……
数据文件大约200GB,平时备份(mysqldump)压缩后的大小大约20GB最近,从库用mysqldump 备份时,error log 中出现很多:
InnoDB: Warning: a long semaphore wait:
--Thread 1183631680 has waited at ../../storage/innobase/include/btr0btr.ic line 28 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x2aacda28d898 created in file buf/buf0buf.c line 550
a writer (thread id 1183631680) has reserved it in mode  exclusive
number of readers 0, waiters flag 1
Last time read locked in file btr/btr0pcur.c line 246
Last time write locked in file buf/buf0buf.c line 1823
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 1, pwrites 0=====================================
120217 10:40:47 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 27 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 62196, signal count 62194
--Thread 1183631680 has waited at ../../storage/innobase/include/btr0btr.ic line 28 for 256.00 seconds the semaphore:
S-lock on RW-latch at 0x2aacda28d898 created in file buf/buf0buf.c line 550
a writer (thread id 1183631680) has reserved it in mode  exclusive
number of readers 0, waiters flag 1
Last time read locked in file btr/btr0pcur.c line 246
Last time write locked in file buf/buf0buf.c line 1823
Mutex spin waits 0, rounds 98353, OS waits 1500
RW-shared spins 118450, OS waits 59162; RW-excl spins 1996, OS waits 1404
------------
TRANSACTIONS
------------
Trx id counter 0 91046918
Purge done for trx's n < 0 91046756 undo n < 0 0
History list length 21
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 91046818, not started, process no 4553, OS thread id 1183832384
MySQL thread id 154, query id 294386 localhost root
---TRANSACTION 0 91046875, ACTIVE 1300 sec, process no 4553, OS thread id 1183631680 fetching rows, thread declared inside InnoDB 500
mysql tables in use 1, locked 0
MySQL thread id 134, query id 294200 localhost backup Sending data
SELECT /*!40001 SQL_NO_CACHE */ * FROM `table1`
Trx read view will not see trx with id >= 0 91046876, sees < 0 91046876
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: doing file i/o (read thread) ev set
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 64, aio writes: 0,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
192399 OS file reads, 256617 OS file writes, 7538 OS fsyncs
1 pending preads, 0 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: size 1, free list len 20875, seg size 20877,
53381 inserts, 53381 merged recs, 31096 merges
Hash table size 18563003, node heap has 1 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 43 3634229620
Log flushed up to   43 3634229620
Last checkpoint at  43 3634229620
0 pending log writes, 0 pending chkp writes
125902 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 9945977032; in additional pool allocated 13424640
Dictionary memory allocated 648760
Buffer pool size   549824
Free buffers       0
Database pages     549823
Modified db pages  0
Pending reads 64
Pending writes: LRU 0, flush list 0, single page 0
Pages read 3798473, created 3084, written 142124
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
--------------
ROW OPERATIONS
--------------
1 queries inside InnoDB, 0 queries in queue
2 read views open inside InnoDB
Main thread process no. 4553, id 1182828864, state: waiting for server activity
Number of rows inserted 90188, updated 33099, deleted 0, read 249911055
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
InnoDB: ###### Diagnostic info printed to the standard error stream
其中还出现过宕机:
InnoDB: Error: semaphore wait has lasted > 600 seconds
InnoDB: We intentionally crash the server, because it appears to be hung.
120217  8:45:16  InnoDB: Assertion failure in thread 1162561856 in file srv/srv0srv.c line 2236
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
120217  8:45:16 - 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=267108864
read_buffer_size=3145728
max_used_connections=3
max_threads=300
threads_connected=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2110308 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...
stack_bottom = (nil) thread_stack 0x30000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x20) [0xa16470]
/usr/local/mysql/bin/mysqld(handle_segfault+0x368) [0x609c34]
/lib64/libpthread.so.0 [0x3d5d60e7c0]
/usr/local/mysql/bin/mysqld(srv_error_monitor_thread+0x2f3) [0x94ca0d]
/lib64/libpthread.so.0 [0x3d5d6064a7]
/lib64/libc.so.6(clone+0x6d) [0x3d5cad3c2d]
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.
120217 08:45:17 mysqld_safe Number of processes running now: 0
120217 08:45:17 mysqld_safe mysqld restarted
120217  8:45:17 [Note] Plugin 'FEDERATED' is disabled.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
120217  8:45:22  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 547, file name /usr/local/mysql/log/mysql-bin.000035
120217  8:45:27  InnoDB: Started; log sequence number 43 3565657939
120217  8:45:27 [Note] Recovering after a crash using /usr/local/mysql/log/mysql-bin
120217  8:45:27 [Note] Starting crash recovery...
120217  8:45:27 [Note] Crash recovery finished.
120217  8:45:42 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000037' at position 89665957, relay log '/usr/local/mysql/log/relay-bin.000238' position: 89666102
120217  8:45:42 [Note] Slave I/O thread: connected to master 'user@host:3306',replication started in log 'mysql-bin.000037' at position 131046151
120217  8:45:42 [Note] Event Scheduler: Loaded 0 events
120217  8:45:42 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.1.50-log'  socket: '/usr/local/mysql/tmp/mysql.sock'  port: 3306  MySQL Community Server (GPL)
烦请各位大侠帮忙分析一下,谢谢!!!

解决方案 »

  1.   

    用mysqldump备200G的库有点大了 如果还频繁重启 建议用Percona XtraBackup,在线备份的是物理文件 而不是导数据
      

  2.   


    这个是从库,不提供服务,单单是mysqldump操作,就出现这些告警信息……
    只重启过一次,想问一下,什么情况下会触发重启?
      

  3.   

    还有个疑问是 mysqldump 操作 为什么会导致 InnoDB: Warning: a long semaphore wait ?
      

  4.   

    这个是由于numa导致的,调整numa内存策略即可