A fast (>0.01s) query sometimes slow (>2s)

[Julien Palard]

Hi there, i have a strange question that i can't solve using Google )o:
So if someone can understand it, is should help a lot :)

I have a very simple query :
SELECT id FROM table WHERE login = 'a login'

I wrote a simple shell script to execute it with profiling, in localhost, with a random login (peek from a file, shuffled... so the time report count the 'cat logins | shuf | head -n 1')

Here the results (after so many tries to get a slow one !)
A normal one : (> 99% of tries)
$ time ./query
id_membre
87406
Status Duration
(initialization) 0.000002
Opening tables 0.000019
System lock 0.000004
Table lock 0.000005
init 0.000013
optimizing 0.000005
statistics 0.000063
preparing 0.000009
executing 0.000003
Sending data 0.009296
end 0.000009
query end 0.000003
freeing items 0.000005
closing tables 0.000004
logging slow query 0.000002

real 0m0.054s
user 0m0.008s
sys 0m0.036s

A slow one (<1% of tries):
$ time ./query
id_membre
39444
Status Duration
(initialization) 0.000002
Opening tables 0.000021
System lock 0.000005
Table lock 0.000006
init 0.000019
optimizing 0.000007
statistics 0.000073
preparing 0.000011
executing 0.000003
Sending data 2.630971
end 0.000026
query end 0.000003
freeing items 0.000005
closing tables 0.000004
logging slow query 0.000011

real 0m2.707s
user 0m0.024s
sys 0m0.056s

I have some monitoring on the server, some weeks ago i was fighing real slow queries (complex one that was not optimized by our developpers, eating time...) now there are no more evident slow queries on the slow query report, only 'very simple ones' that slow 'rarely'.

The DB is under > 1000 query / second, last week i got 0.06 slow queries by second, but those simple one taking time are growing and i got 0.68 slow queries/second today. Tables are InnoDB, and during the good week semaphores got 10k spin round /second, but today it growed to 26k/second if those values help.

How can I diagnose this more deeply ?