Bug #12230 logSlowQueries should give better info
Submitted: 27 Jul 2005 21:10 Modified: 22 Nov 2005 4:31
Reporter: Boris Burtin Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / J Severity:S4 (Feature request)
Version:3.1.10 OS:Windows (XP)
Assigned to: Mark Matthews CPU Architecture:Any

[27 Jul 2005 21:10] Boris Burtin
Description:
There are a couple of problems with the messages that are logged when I set the "logSlowQueries" option:

1) The execution time of the query is not logged.
2) The logged SQL has "?" in place of bind variables.  This makes it impossible to run slow queries through EXPLAIN.

I made the changes below in my version of the JDBC driver to get around these problems.  See the lines that begin with ">>>".  I believe doing something similar in the core code would be useful to other developers.

--------------------

						&& (elapsedTime > this.connection
								.getSlowQueryThresholdMillis())) {
					StringBuffer mesgBuf = new StringBuffer(
							48 + this.originalSql.length());
					mesgBuf.append(Messages
							.getString("ServerPreparedStatement.15")); //$NON-NLS-1$
					mesgBuf.append(this.connection
							.getSlowQueryThresholdMillis());
>>>					mesgBuf.append(" ms, duration: " + elapsedTime);
					mesgBuf.append(Messages
							.getString("ServerPreparedStatement.16")); //$NON-NLS-1$
					mesgBuf.append(asSql(true));

					this.connection.getLog().logWarn(mesgBuf.toString());

					if (this.connection.getExplainSlowQueries()) {
>>>						String queryAsString = asSql(true);

						mysql.explainSlowQuery(queryAsString.getBytes(),
								queryAsString);
					}
				}

How to repeat:
Set the logSlowQueries and slowQueryThresholdMillis properties and run a query that takes longer than the threshold to execute.

Suggested fix:
Log the SQL with the bound values in place, as well as the execution time.
[22 Nov 2005 4:31] Mark Matthews
Fixed for 3.1.12 and 5.0.0, see nightly snapshots at http://download.mysql.com/snapshots.php#connector-j after 00:00 GMT Nov 23.