Bug #50818 Process sleep time out of value interactive_timeout
Submitted: 2 Feb 2010 9:37 Modified: 3 Feb 2010 9:31
Reporter: He yunfei Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:5.1.40 OS:Linux (5.3 X86_64)
Assigned to: CPU Architecture:Any
Tags: Process sleep time out of value interactive_timeout

[2 Feb 2010 9:37] He yunfei
Description:
root@127.0.0.1 : (none) 17:31:45> show variables like '%timeout%'; 
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| connect_timeout            | 10    |
| delayed_insert_timeout     | 300   |
| innodb_lock_wait_timeout   | 60    |
| innodb_rollback_on_timeout | OFF   |
| interactive_timeout        | 28800 |
| net_read_timeout           | 30    |
| net_write_timeout          | 60    |
| slave_net_timeout          | 3600  |
| table_lock_wait_timeout    | 50    |
| wait_timeout               | 28800 |
+----------------------------+-------+

I monitor the Process every minute with bash : 
-------------------------------
# /bin/sh 

. /root/.bash_profile
LOGFILE=/tmp/TIMOUT_`date +%F`.log 
echo `date` >> $LOGFILE
echo "---------------------------------------------------------" >> $LOGFILE
mysql -uroot -h127.0.0.1 -e " show processlist ; " | grep -v "system" |grep -v "replicator"  | sort -k 6 -n | tail -10  >> $LOGFILE
echo "---------------------------------------------------------" >> $LOGFILE
echo "" >> $LOGFILE
echo "" >> $LOGFILE
-------------------------------

The result is : 
Id              User     Host                  Db       Command  Time  State
-----------------------------------------------------------------------------
21401983	apsara	10.249.51.6:59046	auc	Sleep	33876	NULL
21401983	apsara	10.249.51.6:59046	auc	Sleep	33936	NULL
21401983	apsara	10.249.51.6:59046	auc	Sleep	33996	NULL
21401983	apsara	10.249.51.6:59046	auc	Sleep	34056	NULL

The value is more then 28800。

How to repeat:
Look above
[2 Feb 2010 9:39] He yunfei
Monitor result

Attachment: TIMOUT_2010-02-02.rar (application/octet-stream, text), 22.59 KiB.

[3 Feb 2010 7:42] Sveta Smirnova
Thank you for the report.

But "Time" column shows times started when client connects. So following scenario can occur:

- user connects
- user runs a lot of queries
- connection idle for 3 seconds
- when monitor connects it sees large value in Time column
[3 Feb 2010 8:59] He yunfei
Thx a lot for ur reply ,
Please Close the Case .
[3 Feb 2010 9:31] He yunfei
Hi,Sveta Smirnova 
I made some test later, 
and found the "time" value in "show processlist" is 
 ---- seconds between "now" and "last query executed".

Please check again.