MySQL Bugs: #61567: purge reached the head of the history list

Bug #61567	purge reached the head of the history list
Submitted:	20 Jun 2011 6:14	Modified:	20 Jun 2011 11:53
Reporter:	Suresh Kotian	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server	Severity:	S2 (Serious)
Version:	5.0.77	OS:	Linux
Assigned to:		CPU Architecture:	Any

Description:
Hello,

My mysql server behaving extremely slow. Whenever user browse web page getting timeout. I could see warning in log file.
Following is server warning logged:

110620  0:26:27  InnoDB: Warning: purge reached the head of the history list,
InnoDB: but its length is still reported as 3044592! Make a detailed bug
InnoDB: report, and post it to bugs.mysql.com

Server details as follows:

mysql  Ver 14.12 Distrib 5.0.77, for redhat-linux-gnu (x86_64) using readline 5.1

Linux conve1-db01.inetu.net 2.6.18-164.6.1.el5 #1 SMP Tue Oct 27 11:28:30 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux

[mysqldump]
socket=/home/mysqldata/mysql.sock

[mysql]
socket=/home/mysqldata/mysql.sock

---Following is my.cnf setting in my server.
[mysqld]
#datadir=/var/lib/mysql
#socket=/var/lib/mysql/mysql.sock
datadir=/home/mysqldata
socket=/home/mysqldata/mysql.sock
user=mysql
# Default to using old password format for compatibility with mysql 3.x
# clients (those using the mysqlclient10 compatibility package).
old_passwords=1
default-storage-engine=InnoDB
lower_case_table_names=1
set-variable=max_connections=250
innodb_log_file_size=256M
innodb_log_buffer_size=4M
#sort_buffer_size=2G

innodb_buffer_pool_size=6G
log-slow-queries=/var/log/mysqld-slow.log
long_query_time=2

[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

Thanks,
Adil

How to repeat:
Don't know. Messages appears every 5 minutes.

Suggested fix:

My Innodb status as follows,

110620  2:19:18 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 50 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 134035, signal count 134015
Mutex spin waits 0, rounds 2146932, OS waits 5213
RW-shared spins 79570, OS waits 39766; RW-excl spins 78568, OS waits 76075
------------
TRANSACTIONS
------------
Trx id counter 0 860246813
Purge done for trx's n:o < 0 854693608 undo n:o < 0 282551
History list length 3044644
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 2968, OS thread id 1170094400
MySQL thread id 19, query id 14611 conve1-db01.inetu.net 192.168.148.4 root
SHOW INNODB STATUS
---TRANSACTION 0 860246797, not started, process no 2968, OS thread id 1106381120
MySQL thread id 17, query id 14577 192.168.1.1 lytiks_prod
---TRANSACTION 0 860246674, not started, process no 2968, OS thread id 1106114880
MySQL thread id 5, query id 14333 192.168.148.5 CAAdmin
---TRANSACTION 0 860246812, not started, process no 2968, OS thread id 1105848640
MySQL thread id 2, query id 14610 192.168.148.5 CAAdmin
--------
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: 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: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
1946480 OS file reads, 1470 OS file writes, 801 OS fsyncs
47.63 reads/s, 70979 avg bytes/read, 0.02 writes/s, 0.02 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 473, seg size 475,
294 inserts, 253 merged recs, 191 merges
Hash table size 12750011, used cells 21083, node heap has 32 buffer(s)
110.14 hash searches/s, 183608.19 non-hash searches/s
---
LOG
---
Log sequence number 58 3198064036
Log flushed up to   58 3198064036
Last checkpoint at  58 3197995169
0 pending log writes, 0 pending chkp writes
733 log i/o's done, 0.02 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 7158357096; in additional pool allocated 1045760
Buffer pool size   393216
Free buffers       1
Database pages     393183
Modified db pages  70
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 4528121, created 19, written 774
199.44 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
1 read views open inside InnoDB
Main thread process no. 2968, id 1169828160, state: purging
Number of rows inserted 411, updated 100, deleted 130, read 24561623
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 2.30 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Thank you for the bug report.. Duplicate of http://bugs.mysql.com/bug.php?id=44923.

Related Bug #82213