One may think one may use MySQL Slow query log to log all slow queries to catch problematic queries or for audit purposes. In fact however not all the queries are logged. I already mentioned mysql slave queries are not logged to slow query log and it looks like I was wrong connecting it just with replication.
In reality it is not the fact the thread is replication thread causes queries to be omitted from slow query log but the fact thread uses SET TIMESTAMP functionality. If you do this within normal connection result would be the same.
Why is this happening ? I guess it happens because of the way the code is structured. During query start current timestamp is stored to special value which will be used for the query execution by all NOW() calls internal timestamp assignments etc. At certain point someone thought it is nice idea to be able to go back to future or to the past and SET TIMESTAMP was implemented, which instead of patching bunch of function simply writes different timestamp to this variable. When query execution is completed, normally another time() is used to get current time and time difference between start and end time is used to check if query should be logged as slow query. This obviously does not work if start time can be in the future or in the past so slow query logging had to be disabled for such queries.
What does it mean ? Simply what you can’t really trust standard slow query log – some queries may be omitted from it. Also if someone would like to hide complex queries from you it can be easily done by using SET TIMESTAMP statement before running the query.
Perhaps we can get something to handle this into the mysql-proxy.
http://jan.kneschke.de/2007/6/25/mysql-proxy-0-5-0-released
Thanks Jan for releasing the Proxy.
On other hand I do not think this is proxy thing, which is rather gotcha in MySQL server which should be fixed.
Timing things on proxy is great but a lot of information is not available at this level, such as number of examined rows or lock time vs exec time.
Is this still true with 5.5 as well? We use MySQL 5.5 Percona build and seem to have some slow queries missing. Wasn’t sure if these details from 2007 are still applicable.
this is still the case in 5.6.36-82.0-log