From e2c1869e273e7b34fdc8a80a8f457e2f8ee15c17 Mon Sep 17 00:00:00 2001 From: Philippe Marschall Date: Tue, 14 May 2024 17:55:48 +0200 Subject: [PATCH] HHH-18116 Support slow query logging for stored procedures --- .../procedure/internal/ProcedureCallImpl.java | 6 ++++-- .../procedure/internal/ProcedureOutputsImpl.java | 5 +++-- .../hibernate/result/internal/OutputsImpl.java | 16 ++++++++++++++-- 3 files changed, 21 insertions(+), 6 deletions(-) diff --git a/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureCallImpl.java b/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureCallImpl.java index f909c3e293..c39b58c05a 100644 --- a/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureCallImpl.java +++ b/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureCallImpl.java @@ -652,10 +652,11 @@ public class ProcedureCallImpl } LOG.debugf( "Preparing procedure call : %s", call); + final String sqlString = call.getSqlString(); final CallableStatement statement = (CallableStatement) getSession() .getJdbcCoordinator() .getStatementPreparer() - .prepareStatement( call.getSqlString(), true ); + .prepareStatement( sqlString, true ); try { // Register the parameter mode and type callableStatementSupport.registerParameters( @@ -721,7 +722,8 @@ public class ProcedureCallImpl this, parameterRegistrations, refCursorExtractors.toArray( new JdbcCallRefCursorExtractor[0] ), - statement + statement, + sqlString ); } diff --git a/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureOutputsImpl.java b/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureOutputsImpl.java index 1a9a2fc46c..a691724a59 100644 --- a/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureOutputsImpl.java +++ b/hibernate-core/src/main/java/org/hibernate/procedure/internal/ProcedureOutputsImpl.java @@ -40,8 +40,9 @@ public class ProcedureOutputsImpl extends OutputsImpl implements ProcedureOutput ProcedureCallImpl procedureCall, Map, JdbcCallParameterRegistration> parameterRegistrations, JdbcCallRefCursorExtractor[] refCursorParameters, - CallableStatement callableStatement) { - super( procedureCall, callableStatement ); + CallableStatement callableStatement, + String sql) { + super( procedureCall, callableStatement, sql ); this.procedureCall = procedureCall; this.callableStatement = callableStatement; this.parameterRegistrations = parameterRegistrations; diff --git a/hibernate-core/src/main/java/org/hibernate/result/internal/OutputsImpl.java b/hibernate-core/src/main/java/org/hibernate/result/internal/OutputsImpl.java index 41cb248d37..64a48811e1 100644 --- a/hibernate-core/src/main/java/org/hibernate/result/internal/OutputsImpl.java +++ b/hibernate-core/src/main/java/org/hibernate/result/internal/OutputsImpl.java @@ -16,6 +16,8 @@ import java.util.List; import java.util.function.Supplier; import org.hibernate.JDBCException; +import org.hibernate.engine.jdbc.spi.SqlExceptionHelper; +import org.hibernate.engine.jdbc.spi.SqlStatementLogger; import org.hibernate.engine.spi.SessionFactoryImplementor; import org.hibernate.internal.CoreLogging; import org.hibernate.procedure.internal.ProcedureCallImpl; @@ -51,13 +53,16 @@ public class OutputsImpl implements Outputs { private final ResultContext context; private final PreparedStatement jdbcStatement; + private final SqlStatementLogger sqlStatementLogger; + private final String sql; private CurrentReturnState currentReturnState; - public OutputsImpl(ResultContext context, PreparedStatement jdbcStatement) { + public OutputsImpl(ResultContext context, PreparedStatement jdbcStatement, String sql) { this.context = context; this.jdbcStatement = jdbcStatement; - + this.sqlStatementLogger = context.getSession().getJdbcServices().getSqlStatementLogger(); + this.sql = sql; } protected ResultContext getResultContext(){ @@ -65,6 +70,10 @@ public class OutputsImpl implements Outputs { } protected void executeStatement() { + long executeStartNanos = 0; + if ( sqlStatementLogger.getLogSlowQuery() > 0 ) { + executeStartNanos = System.nanoTime(); + } try { final boolean isResultSet = jdbcStatement.execute(); currentReturnState = buildCurrentReturnState( isResultSet ); @@ -72,6 +81,9 @@ public class OutputsImpl implements Outputs { catch (SQLException e) { throw convert( e, "Error calling CallableStatement.getMoreResults" ); } + finally { + sqlStatementLogger.logSlowQuery( sql, executeStartNanos, this.context.getSession().getJdbcSessionContext() ); + } } private CurrentReturnState buildCurrentReturnState(boolean isResultSet) {