hibernate-orm HHH-13741 : Logging SQL query when using LOG_SLOW

Jun 04 '22 10:06 jai-yadav

Hi, thanks for this PR. I'd like to ask: Will there be a way how to override getStatement() method? So returned string could be formatter or extended?

As Oracle DBA I'm looking for a way how to relate SQL statement logged by application with SQL statement seen in the database. And it is still very hard because SQLs logged by Hibernate are formatted, truncated and moreover JDBC driver internally replaces bind parameters '?' with enumerated bind parameters ':1'.

So for me id would be great if I could call OracleStatement.getOriginalSQL() somewhere and I could log exact SQL statement which was sent into the database (rather that some similar, truncated fragment of SQL)

Moreover all SQLs in Oracle are identified by SQL_ID which is MD5 of original SQL sent into the database. I wrote piece of code which can compute this SQL_ID in Java, so slow SQLs could be logged as SQL_IDs, and the rest of diagnostic information could be found in the database.

https://tanelpoder.com/2009/02/22/sql_id-is-just-a-fancy-representation-of-hash-value/

Jun 06 '22 11:06 ibre5041

@ibre5041 You are probably more interested in using Hibernate's support for SQL comments.

For basic CRUD operations, Hibernate operations can automatically inject comments - there is a setting to wnae that.

For queries (HQL, Criteria, etc) you can inject custom comments.

Googlw is your friend

Jun 07 '22 07:06 sebersole

Hey @jai-yadav and thanks for your contribution. A few comments:

Sometimes you are trying to access the SQL through the registry even when the SQL is given as argument, that should be fixed
I don't think having a registry for the SQL strings is necessary, as you can unwrap statements like statement.unwrap(Statement.class) and call toString on that
For Oracle, I think I'd personally prefer accessing oracle.jdbc.driver.OracleStatement#getOriginalSql reflectively through a static final method instead. Alternatively, we could add org.hibernate.engine.jdbc.spi.ResultSetReturn#extract(java.sql.PreparedStatement, java.lang.String) variants which will use the SQL string argument just for logging purposes

Any thoughts on that @sebersole ?

Jun 08 '22 10:06 beikov

@sebersole comments could be good if I wanted to relate for example REST API call with SQL statement executed. But in case of criteria api the same comment can present in dozens of very similar SQLs. When SQL in logfile is indented&truncated then it is very hard to relate it to any SQL present in database's performance metrics. The key information like part where clause is usually omitted.

I understand that computing MD5 is Oracle's proprietary method, that is why I am looking for some way how to implement custom SQL logger. So apps could easily relate performance data from app's log files with performance data from database.
PS: MS SQL also uses MD5 checksum of SQL statement as a part of sql_handle. They have different but similar way how to uniquely identify SQL statement in performance metrics.

@beikov unfortunately calling Statement.toString() does not guarantee that you get SQL statement. It does not work at least for Oracle, DB2, SQLLite. It works for PostgreSQL and MySQL.

Jun 08 '22 14:06 ibre5041

Sorry, but I have no idea what you are talking about...

package org.hibernate.query;

public interface Query<R> ... {

	/**
	 * Set the comment for this query.
	 * <p>
	 * If SQL commenting is enabled, the comment will be added to the SQL
	 * query sent to the database, which may be useful for identifying the
	 * source of troublesome queries.
	 * <p>
	 * SQL commenting may be enabled using the configuration property
	 * {@value org.hibernate.cfg.AvailableSettings#USE_SQL_COMMENTS}.
	 *
	 * @param comment The human-readable comment
	 *
	 * @return {@code this}, for method chaining
	 *
	 * @see #getComment()
	 */
	Query<R> setComment(String comment);
}

Criteria queries must be "compiled" into a Query (aka ^^) to execute.

Every DBA I have ever worked with would MUCH rather be able to correlate this stuff on the database itself

Jun 08 '22 16:06 sebersole

Hi @beikov Thanks for your feedback. Agreed on 1st, Added changes to use SQL directly when available instead of using registry in those cases.

But I'm not clear on 2nd and 3rd points how they can help in logging plain SQL text. Using statement.unwrap(Statement.class) doesn't seems to provide SQL on toString(). Unwrap