What causes "startTimeNanos [${startTimeNanos}] should be greater than 0" in hibernate/hibernate-orm?

Capture long t0 = System.nanoTime() immediately before statement execution and pass t0

hibernate/hibernate-orm · error · IllegalArgumentException

startTimeNanos [${startTimeNanos}] should be greater than 0

Error message

startTimeNanos [${startTimeNanos}] should be greater than 0

What it means

SqlStatementLogger.logSlowQuery(String, long, JdbcSessionContext) is invoked after each statement when a slow-query threshold is configured (milliseconds; 0 disables - set via hibernate's LOG_QUERIES_SLOWER_THAN_MS / hibernate.log_slow_query). With a threshold >= 1 it demands a startTimeNanos greater than 0 - a System.nanoTime() timestamp captured immediately before execution - and throws IllegalArgumentException for 0 or negative values to reject an unset or bogus start time.

Source

Thrown at hibernate-core/src/main/java/org/hibernate/engine/jdbc/spi/SqlStatementLogger.java:143

			LOG.debug( statement );
			if ( logToStdout ) {
				String prefix = highlight ? "\u001b[35m[Hibernate]\u001b[0m " : "Hibernate: ";
				System.out.println( prefix + statement );
			}
		}
	}

	/**
	 * Log a slow SQL query
	 *
	 * @param sql The SQL query.
	 * @param startTimeNanos Start time in nanoseconds.
	 */
	public void logSlowQuery(final String sql, final long startTimeNanos, final JdbcSessionContext context) {
		if ( logSlowQuery >= 1 ) {
			if ( startTimeNanos <= 0 ) {
				throw new IllegalArgumentException(
						"startTimeNanos [" + startTimeNanos + "] should be greater than 0" );
			}

			final long queryExecutionMillis = elapsedFrom( startTimeNanos );

			if ( queryExecutionMillis > logSlowQuery ) {
				logSlowQueryInternal( context, queryExecutionMillis, sql );
			}
		}
	}

	private static long elapsedFrom(final long startTimeNanos) {
		return TimeUnit.NANOSECONDS.toMillis( System.nanoTime() - startTimeNanos );
	}

	@AllowSysOut
	private void logSlowQueryInternal(final JdbcSessionContext context, final long queryExecutionMillis, final String sql) {
		final String logData = "Slow query took " + queryExecutionMillis + " milliseconds [" + sql + "]";

View on GitHub (pinned to fad1729dce)

Solutions

Capture long t0 = System.nanoTime() immediately before statement execution and pass t0
Only call logSlowQuery when you actually recorded a start time; skip the call otherwise
Use System.nanoTime() (monotonic), never System.currentTimeMillis() or guessed constants
Keep the capture and the logSlowQuery call on the same code path so the timestamp cannot be lost

Example fix

// before
long startTimeNanos = 0; // never set
stmt.execute(sql);
logger.logSlowQuery(sql, startTimeNanos, context); // IllegalArgumentException

// after
long t0 = System.nanoTime();
stmt.execute(sql);
logger.logSlowQuery(sql, t0, context);

Defensive patterns

Strategy: validation

Validate before calling

// Capture and pass a real nanoTime; never call the logger without one
final long startTimeNanos = System.nanoTime();
stmt.execute(sql);
if (startTimeNanos > 0) {
    sqlStatementLogger.logSlowQuery(sql, startTimeNanos, context);
}

Try / catch

if (startTimeNanos > 0) {
    sqlStatementLogger.logSlowQuery(sql, startTimeNanos, context);
} // else: no valid start time was captured - skipping the slow-query log is correct

Prevention

Capture System.nanoTime() in the same try block that executes the statement
Use System.nanoTime() (monotonic), never System.currentTimeMillis() or constants
Keep the capture point and the logSlowQuery call in one component so the value cannot be lost

When it happens

Trigger: Custom integrations (statement observers, wrapped JDBC resources, perf tools) calling logSlowQuery(sql, 0, context) because no start time was recorded; code passing an arbitrary epoch like -1 or a default long field; passing a placeholder because the statement was prepared in one component and executed in another that lost the timestamp.

Common situations: Enabling slow-query logging in a custom SessionFactory customization or connection wrapper that instruments execution but never captured System.nanoTime(); test harnesses invoking the logger directly; integrations migrated from older signatures that took milliseconds instead of nanoseconds.

Related errors

AI-assisted analysis of hibernate/hibernate-orm@fad1729dce (2026-08-22). Data as JSON: /api/errors/e0efe66f8c852459. Report an issue: GitHub.