Description:
After the MySQL server upgradation from 5.5.28 to 5.5.30 MySQL Community Server (GPL),then it got hang and then crashed. So finally the automatic crash recovery happened followed by the crash. But here I am not sure what caused this to happened.
The information I got on the error log is as follows:
130819 4:48:37 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.5.28-log' socket: '/MysqlDatabase/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL)
130826 3:46:53 InnoDB: Starting shutdown...
130826 3:46:54 InnoDB: Shutdown completed; log sequence number 7811367303
130826 3:46:54 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete
130826 3:50:18 [Note] Plugin 'FEDERATED' is disabled.
130826 3:50:18 InnoDB: The InnoDB memory heap is disabled
130826 3:50:18 InnoDB: Mutexes and rw_locks use GCC atomic builtins
130826 3:50:18 InnoDB: Compressed tables use zlib 1.2.3
130826 3:50:18 InnoDB: Using Linux native AIO
130826 3:50:18 InnoDB: Initializing buffer pool, size = 256.0M
130826 3:50:18 InnoDB: Completed initialization of buffer pool
130826 3:50:18 InnoDB: highest supported file format is Barracuda.
130826 3:50:20 InnoDB: Waiting for the background threads to start
130826 3:50:21 InnoDB: 5.5.30 started; log sequence number 7811367313
130826 3:50:21 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
130826 3:50:21 [Note] - '0.0.0.0' resolves to '0.0.0.0';
130826 3:50:21 [Note] Server socket created on IP: '0.0.0.0'.
130826 3:50:21 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.5.30-log' socket: '/MysqlDatabase/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL)
InnoDB: Warning: a long semaphore wait:
=====================================
130826 4:32:56 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 55 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 530 1_second, 530 sleeps, 43 10_second, 101 background, 101 flush
srv_master_thread log flush and writes: 531
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 37, signal count 25
--Thread 47027457907008 has waited at trx0undo.ic line 156 for 245.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x2ac554e83540 created in file buf0buf.c line 936
a writer (thread id 47027457907008) has reserved it in mode wait exclusive
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff
Last time read locked in file buf0flu.c line 1319
Last time write locked in file /pb2/build/sb_0-8129293-1358322782.17/mysql-5.5.30/storage/innobase/include/trx0undo.ic line 156
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.
130826 4:44:47 InnoDB: Assertion failure in thread 47027445819712 in file srv0srv.c line 2489
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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
08:44:47 UTC - mysqld got signal 6 ;
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=1048576
max_used_connections=109
max_threads=151
thread_count=108
connection_count=108
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 573117 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 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 = 0 thread_stack 0x40000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x35)[0x79ffa5]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x403)[0x66f5a3]
/lib64/libpthread.so.0[0x339e80eca0]
/lib64/libc.so.6(gsignal+0x35)[0x339dc30265]
/lib64/libc.so.6(abort+0x110)[0x339dc31d10]
/usr/local/mysql/bin/mysqld[0x846b5e]
/lib64/libpthread.so.0[0x339e80683d]
/lib64/libc.so.6(clone+0x6d)[0x339dcd4f8d]
130826 4:56:57 [Note] Plugin 'FEDERATED' is disabled.
130826 4:56:57 InnoDB: The InnoDB memory heap is disabled
130826 4:56:57 InnoDB: Mutexes and rw_locks use GCC atomic builtins
130826 4:56:57 InnoDB: Compressed tables use zlib 1.2.3
130826 4:56:57 InnoDB: Using Linux native AIO
130826 4:56:57 InnoDB: Initializing buffer pool, size = 256.0M
130826 4:56:57 InnoDB: Completed initialization of buffer pool
130826 4:56:57 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 7811425741
130826 4:56:57 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: Doing recovery: scanned up to log sequence number 7811426924
InnoDB: Transaction 51F00FA0 was in the XA prepared state.
InnoDB: Transaction 51F00FB4 was in the XA prepared state.
InnoDB: 2 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 0 row operations to undo
InnoDB: Trx id counter is 51F01100
130826 5:00:51 InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 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: Last MySQL binlog file position 0 35467, file name ./mysql-bin.000167
InnoDB: Starting in background the rollback of uncommitted transactions
130826 5:00:52 InnoDB: Rollback of non-prepared transactions completed
130826 5:00:52 InnoDB: Waiting for the background threads to start
130826 5:00:53 InnoDB: 5.5.30 started; log sequence number 7811426924
130826 5:00:53 [Note] Recovering after a crash using mysql-bin
130826 5:00:53 [Note] Starting crash recovery...
130826 5:00:53 InnoDB: Starting recovery for XA transactions...
130826 5:00:53 InnoDB: Transaction 51F00FB4 in prepared state after recovery
130826 5:00:53 InnoDB: Transaction contains changes to 1 rows
130826 5:00:53 InnoDB: Transaction 51F00FA0 in prepared state after recovery
130826 5:00:53 InnoDB: Transaction contains changes to 1 rows
130826 5:00:53 InnoDB: 2 transactions in prepared state after recovery
130826 5:00:53 [Note] Found 2 prepared transaction(s) in InnoDB
130826 5:00:53 [Note] Crash recovery finished.
130826 5:00:53 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
130826 5:00:53 [Note] - '0.0.0.0' resolves to '0.0.0.0';
130826 5:00:53 [Note] Server socket created on IP: '0.0.0.0'.
130826 5:00:53 [Warning] 'proxies_priv' entry '@ root@apwedb01' ignored in --skip-name-resolve mode.
130826 5:00:53 [Note] Event Scheduler: Loaded 0 events
130826 5:00:53 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.5.30-log' socket: '/MysqlDatabase/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL).
How to repeat:
we suspect is that happening on each MySQL Upgrade or is there any dependencies on any Linux kernel level parameters. Please suggest what to do ?
