Seeing the SQL Hibernate actually runs
show-sql is not enough - bind parameters, statement counts and the N+1 you cannot see.
Open this lesson in the learning hubKey points
show-sqlprints statements without bind parameters, so you see the shape but not the values - which is exactly what you need when diagnosing a wrong result.- Turning on the binder logger fills that in, but the real problem is counting: a page that issues 300 queries prints 300 lines and looks like normal activity.
- A statement counter is what turns that into a signal. Asserting a query count in a test catches an N+1 the moment it is introduced, rather than in production.
- Datasource proxies such as datasource-proxy or p6spy log the real statement with parameters inline, and can log slow queries only - far more usable than raw Hibernate logging.
- The persistence context hides work too. A
getReferencethat is never touched issues nothing; the same code touching one field issues a select. Reading the log without knowing that is confusing. - In production, log a summary rather than statements: query count and total time per request, tagged with the endpoint. That surfaces regressions without the cost of logging every statement.
Example
# Development only - the second line is what adds bind parameters.
logging:
level:
org.hibernate.SQL: DEBUG
org.hibernate.orm.jdbc.bind: TRACE # Hibernate 6
# org.hibernate.type.descriptor.sql: TRACE # Hibernate 5
# Statistics - the numbers, rather than a wall of statements.
spring:
jpa:
properties:
hibernate:
generate_statistics: true
session:
events:
log:
LOG_QUERIES_SLOWER_THAN_MS: 50
---
// The test that stops N+1 ever reaching production.
@Test
void loadingOrdersDoesNotNPlusOne() {
Statistics stats = entityManagerFactory
.unwrap(SessionFactory.class).getStatistics();
stats.clear();
List<Order> orders = orderRepository.findAllWithLines();
orders.forEach(o -> o.getLines().size()); // touch the association
// One query, not 1 + N. This assertion is the whole point:
// it fails the build the day someone removes the JOIN FETCH.
assertThat(stats.getPrepareStatementCount()).isEqualTo(1);
}
/*
* What generate_statistics prints per session:
*
* Session Metrics {
* 1234567 nanoseconds spent acquiring 1 JDBC connection;
* 89012345 nanoseconds spent preparing 247 JDBC statements; <- 247
* 12345678 nanoseconds spent executing 247 JDBC statements;
* 0 nanoseconds spent performing 0 L2C puts;
* }
*
* 247 statements for one request is an N+1, whatever the page looks like.
*/
Count statements rather than reading them - an asserted query count in a test is what stops N+1 from ever shipping.
Why GenerationType.IDENTITY disables batch inserts
JOIN FETCH, entity graphs and the pagination trap
This is a reading copy. The full lesson — with the visual explainer, the interactive lab and a Run button for the code — lives in the Hibernate course, and every lesson in it is listed on the Hibernate contents page.