Bug #44917 log-queries-not-using-indexes logs queries to informaion_scheme table unnecassar
Submitted: 16 May 2009 12:15 Modified: 12 Dec 2009 18:52
Reporter: Matt Jackson Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Logging Severity:S4 (Feature request)
Version:5.1.31, 5.1.43 OS:Any
Assigned to: CPU Architecture:Any
Tags: log-queries-not-using-indexes informaion_scheme

[16 May 2009 12:15] Matt Jackson
Description:
If a user enables the log-queries-not-using-indexes queries such as :
SELECT * FROM INFORMATION_SCHEMA.ROUTINES WHERE ROUTINE_SCHEMA LIKE 'sharedsms' AND ROUTINE_NAME LIKE 'spGetOutBoundMessagesByDate'
get recorded in the slow log as :
2009-05-17 00:06:17	[servername] [ipaddress]	00:00:00	00:00:00	1	205	[dbname]	0	0	200	SELECT * FROM INFORMATION_SCHEMA.ROUTINES WHERE ROUTINE_SCHEMA LIKE 'sharedsms' AND ROUTINE_NAME LIKE 'spGetOutBoundMessagesByDate'

although as you can see get logged unnecassarily

NOTE my config file has :
#Log all queries that have taken more than long_query_time seconds to execute to file.
long_query_time=2
#Log queries that are executed without benefit of any index.
log-queries-not-using-indexes
#Log some not critical warnings to the log file.
log-warnings

I don't imagine the tables in INFORMATION_SCHEMA have indexes but possibly these should only be logged if --log-slow-admin-statements or something similar is enabled as well otherwise we are unnecessarily logging details about admin / system tables.

Just a thought

How to repeat:
execute SELECT * FROM INFORMATION_SCHEMA.ROUTINES WHERE ROUTINE_SCHEMA LIKE 'sharedsms' AND ROUTINE_NAME LIKE 'spGetOutBoundMessagesByDate'

with the following in my.cnf

#Log all queries that have taken more than long_query_time seconds to execute to file.
long_query_time=2
#Log queries that are executed without benefit of any index.
log-queries-not-using-indexes
#Log some not critical warnings to the log file.
log-warnings

Suggested fix:
I don't imagine the tables in INFORMATION_SCHEMA have indexes but possibly these should only be logged if --log-slow-admin-statements or some other similar variable is enabled as well, otherwise we are unnecessarily logging details about admin / system tables.
[12 Dec 2009 18:52] Valeriy Kravchuk
Indeed, this query is logged:

77-52-7-73:5.1 openxs$ tail var/77-52-251-15-slow.log
/Users/openxs/dbs/5.1/libexec/mysqld, Version: 5.1.43-debug-log (Source distribution). started with:
Tcp port: 0  Unix socket: (null)
Time                 Id Command    Argument
# Time: 091212 20:49:48
# User@Host: root[root] @ localhost []
# Query_time: 0.390664  Lock_time: 0.378533 Rows_sent: 0  Rows_examined: 1
use test;
SET timestamp=1260643788;
SELECT * FROM INFORMATION_SCHEMA.ROUTINES WHERE ROUTINE_SCHEMA LIKE 'sharedsms' AND
ROUTINE_NAME LIKE 'spGetOutBoundMessagesByDate';

It would be nice to be able to control if queries to INFORMATION_SCHEMA tables (that do not have indexes at all) should be logged in this case.