Bug #48279 Mysql.5.1.39 Automatic restart or Hangs (suspended animation)
Submitted: 24 Oct 2009 11:48 Modified: 25 Nov 2009 16:08
Reporter: jabincn jabincn Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:Mysql.5.1.39 OS:Linux
Assigned to: CPU Architecture:Any
Tags: Running a half-day Automatic restart or Hangs (suspended animation)

[24 Oct 2009 11:48] jabincn jabincn
Description:
Running a half-day Automatic restart or Hangs (suspended animation)

err.log:

091024 12:36:01 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
091024 12:36:02 [Note] Starting MySQL Cluster Binlog Thread
InnoDB: The InnoDB memory heap is disabled
InnoDB: Neither mutexes nor rw_locks use GCC atomic builtins.
091024 12:36:03  InnoDB: highest supported file format is Barracuda.
091024 12:36:03 InnoDB Plugin 1.0.4 started; log sequence number 76669222479
091024 12:36:03 [Note] Event Scheduler: Loaded 0 events
091024 12:36:03 [Note] /usr/local/mysql/libexec/mysqld: ready for connections.
Version: '5.1.39-log'  socket: '/usr/local/mysql/tmp/mysql.sock'  port: 3306  Source distribution

Status information:

Current dir: /usr/local/mysql/data/
Running threads: 41  Stack size: 131072
Current locks:
lock: 0x279141b0:

lock: 0x27d0a1a8:

lock: 0xe69e790:

lock: 0xe699620:

lock: 0xe6969d8:

lock: 0xe691f08:

lock: 0xe68f6d0:

lock: 0xe68dfe0:

lock: 0xe673478:

lock: 0x28ea29d8:

lock: 0x28ec6e78:

lock: 0xe6826f0:

lock: 0xe688d00:

lock: 0xe67a3f0:

lock: 0xe6783b0:

lock: 0xe674ab0:

lock: 0xe671aa0:

lock: 0xe66f4a0:

lock: 0xe66e870:

lock: 0xe669268:

lock: 0xe658480:

lock: 0xe658b38:

lock: 0xe647b20:

lock: 0xe63f0b0:

lock: 0xe62c958:

lock: 0xe61dd88:

lock: 0xe618970:

lock: 0xe60c950:

lock: 0xe60b750:

lock: 0xe6072c0:

lock: 0xe600788:

lock: 0xe5fd0b8:

lock: 0xe5c95a8:

lock: 0xe5f4f38:

lock: 0xe5f7e08:

lock: 0xe5e1770:

lock: 0xe5d97a8:

lock: 0xe5d82e8:

lock: 0xe5cff88:

lock: 0xe5cad10:

lock: 0xe5d0730:

lock: 0xe5c39b8:

lock: 0xe5c02d8:

lock: 0xe5bb7e0:

lock: 0xe5b7b78:

lock: 0xe5bbf90:

lock: 0xe5b0dd0:

lock: 0xe5a7760:

lock: 0xe5a39e0:

lock: 0xe5a0d78:

lock: 0xe59c188:

lock: 0xe5973b0:

lock: 0xe591ac8:

lock: 0xe58ffe0:

lock: 0xe58cb50:

lock: 0xe5807c8:

lock: 0xe57bb38:

lock: 0xe57a0e8:

lock: 0xe574838:

lock: 0xe571cf0:

lock: 0xe576ba0:

lock: 0xe562268:

lock: 0xe55d6e8:

lock: 0xe55c5f0:

lock: 0xe556040:

lock: 0xe553418:

lock: 0xe548878:

lock: 0xe544430:

lock: 0xe540408:

lock: 0xe539838:

lock: 0xe52b028:

lock: 0xe522998:

lock: 0xe4fb4f8:

lock: 0xe515060:

lock: 0xe50fcb0:

lock: 0xe50afe8:

lock: 0xe509560:

lock: 0xe505b40:

lock: 0x28498ac8:

lock: 0x284967b0:

lock: 0xe4f9dd0:

lock: 0xe4f53f0:

lock: 0xe4f0b80:

lock: 0xe4ef458:

lock: 0xe4eaa78:

lock: 0xe4e5dc8:

lock: 0xe4e3000:

lock: 0xe4e0f28:

lock: 0xe4b1138:

lock: 0x27f08a68:

lock: 0x289b5020:

lock: 0xe4af340:

lock: 0xe489090:

lock: 0xe4b3200:

lock: 0xe489bd8:

lock: 0xe4a6ae0:

lock: 0xe4660e0:

lock: 0xe49d400:

lock: 0xe49a0b8:

lock: 0xe498818:

Key caches:
default
Buffer_size:       4194304
Block_size:           1024
Division_limit:        100
Age_limit:             300
blocks used:          3624
not flushed:             0
w_requests:        1154578

lock: 0xe489090:

lock: 0xe4b3200:

lock: 0xe489bd8:

lock: 0xe4a6ae0:

lock: 0xe4660e0:

lock: 0xe49d400:

lock: 0xe49a0b8:

lock: 0xe498818:

Key caches:
default
Buffer_size:       4194304
Block_size:           1024
Division_limit:        100
Age_limit:             300
blocks used:          3624
not flushed:             0
w_requests:        1154578
writes:             119003
r_requests:        4218018
reads:              108028

handler status:
read_key:     55835877
read_next:   199185133
read_rnd       3532044
read_first:     207800
write:         4707398
delete            9635
update:       34293852

Table status:
Opened tables:        388
Open tables:          368
Open files:            20
Open streams:           0

Alarm status:
Active alarms:   39
Max used alarms: 44
Next alarm time: 16339

How to repeat:

Thread database.table_name          Locked/Waiting        Lock_type

27      jap.avp_settimetailreport  Locked - read         Low priority read lock

End safemalloc memory dump.
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=4194304
read_buffer_size=524288
max_used_connections=46
max_threads=120
threads_connected=41
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 557815 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 0x20000
/usr/local/mysql/libexec/mysqld(my_print_stacktrace+0x22) [0x85c1092]
/usr/local/mysql/libexec/mysqld(handle_segfault+0x37f) [0x823ad0f]
[0x7f1420]
/usr/local/mysql/libexec/mysqld(ha_binlog_index_purge_file(THD*, char const*)+0x72) [0x8334ae2]
/usr/local/mysql/libexec/mysqld(MYSQL_BIN_LOG::purge_logs(char const*, bool, bool, bool, unsigned lo
ng long*)+0x40c) [0x82e0a0c]
/usr/local/mysql/libexec/mysqld(MYSQL_BIN_LOG::purge_logs_before_date(long)+0x1b0) [0x82e0e80]
/usr/local/mysql/libexec/mysqld(MYSQL_BIN_LOG::rotate_and_purge(unsigned int)+0xce) [0x82e437e]
/usr/local/mysql/libexec/mysqld(reload_acl_and_cache(THD*, unsigned long, TABLE_LIST*, bool*)+0x39f)
 [0x8244bef]
/usr/local/mysql/libexec/mysqld(signal_hand+0x382) [0x823a252]
/lib/libpthread.so.0 [0x72046b]
/lib/libc.so.6(clone+0x5e) [0x677dbe]
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.

Memory status:
Non-mmapped space allocated from system: 82616320
Number of free chunks:                   345
Number of fastbin blocks:                0
Number of mmapped regions:               41
Space in mmapped regions:                100163584
Maximum total allocated space:           0
Space available in freed fastbin blocks: 0
Total allocated space:                   80237528
Total free space:                        2378792
Top-most, releasable space:              135008
Estimated memory (with thread stack):    188153856

Events status:
LLA = Last Locked At  LUA = Last Unlocked At
WOC = Waiting On Condition  DL = Data Locked

Event scheduler status:
State      : INITIALIZED
Thread id  : 0
LLA        : n/a:0
LUA        : n/a:0
WOC        : NO
Workers    : 0
Executed   : 0
Data locked: NO

Event queue status:
Element count   : 0
Data locked     : NO
Attempting lock : NO
LLA             : init_queue:132
LUA             : init_queue:142
WOC             : NO
Next activation : never
091024 16:34:19 mysqld_safe Number of processes running now: 0
091024 16:34:19 mysqld_safe mysqld restarted
091024 16:34:20 [Note] Starting MySQL Cluster Binlog Thread
InnoDB: The InnoDB memory heap is disabled
InnoDB: Neither mutexes nor rw_locks use GCC atomic builtins.
091024 16:34:20  InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 77479628850
091024 16:34:20  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.

InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 77484871680
InnoDB: Doing recovery: scanned up to log sequence number 77490114560
InnoDB: Doing recovery: scanned up to log sequence number 77495357440
InnoDB: Doing recovery: scanned up to log sequence number 77500600320
InnoDB: Doing recovery: scanned up to log sequence number 77504191006
091024 16:34:25  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 695320202, file name ./mysql-bin.000115
091024 16:34:33 InnoDB Plugin 1.0.4 started; log sequence number 77504191006
091024 16:34:33 [Note] Recovering after a crash using mysql-bin
091024 16:34:33 [Note] Starting crash recovery...
091024 16:34:33 [Note] Crash recovery finished.
091024 16:34:33 [Note] Event Scheduler: Loaded 0 events
091024 16:34:33 [Note] /usr/local/mysql/libexec/mysqld: ready for connections.
Version: '5.1.39-log'  socket: '/usr/local/mysql/tmp/mysql.sock'  port: 3306  Source distribution

Suggested fix:

[root@localhost data]# free -m
             total       used       free     shared    buffers     cached
Mem:          4052       2495       1556          0         46       1841
-/+ buffers/cache:        608       3444
Swap:         1983          0       1983
[root@localhost data]# 

./configure --prefix=/usr/local/mysql --localstatedir=/usr/local/mysql/data --with-unix-socket-path=/usr/local/mysql/tmp/mysql.sock --with-charset=utf8 --with-extra-charsets=armscii8,ascii,big5,cp1250,cp1251,cp1256,cp1257,cp850,cp852,cp866,cp932,dec8,eucjpms,euckr,gb2312,gbk,geostd8,greek,hebrew,hp8,keybcs2,koi8r,koi8u,latin1,latin2,latin5,latin7,macce,macroman,sjis,swe7,tis620,ucs2,ujis,utf8 --with-pthread --enable-thread-safe-client  --with-ssl --with-plugins=partition,federated,ndbcluster,innobase,csv,blackhole,myisam,innodb_plugin,heap,archive --enable-shared --enable-assembler
[25 Oct 2009 16:08] Valeriy Kravchuk
Sorry, but I still do not understand what shell I do to repeat this problem. Can you be more specific? What SQL statements/script/program I have to run?
[26 Nov 2009 0:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".