Hi,
We have a problem with updating from hibernate 6.5.3 to to 6.6.0 as part of a spring boot 2.4.x upgrade. A reproducer for the problem can be found here: https://github.com/a1dutch/streaming-responses
We are using async streaming from a Controller to write a csv report line by line but get a ResultSet closed exception below:
2025-01-29T19:09:21.820000 DEBUG 44527 --- [demo] [nio-8080-exec-2] org.apache.coyote.AsyncStateMachine : Changing async state from [DISPATCHING] to [DISPATCHED]
2025-01-29T19:09:21.822000 DEBUG 44527 --- [demo] [nio-8080-exec-2] o.apache.catalina.core.StandardWrapper : Returning instance
2025-01-29T19:09:21.822000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.s.b.w.s.f.OrderedRequestContextFilter : Bound request context to thread: org.apache.catalina.core.ApplicationHttpRequest@516ef5
2025-01-29T19:09:21.822000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : "ASYNC" dispatch for POST "/todos/report", parameters={}, headers={masked} in DispatcherServlet 'dispatcherServlet'
2025-01-29T19:09:21.822000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.s.b.f.s.DefaultListableBeanFactory : Returning cached instance of singleton bean 'todoController'
2025-01-29T19:09:21.822000 TRACE 44527 --- [demo] [nio-8080-exec-2] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.example.demo.controller.TodoController#report(HttpServletRequest)
2025-01-29T19:09:21.822000 TRACE 44527 --- [demo] [nio-8080-exec-2] s.w.s.m.m.a.RequestMappingHandlerAdapter : Resume with async result [org.hibernate.sql.exec.ExecutionException: A problem occurred in the SQL executor : Error advancing (next) ResultSet position [The object is already closed [90007-224]]]
2025-01-29T19:09:21.824000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.s.web.method.HandlerMethod : Arguments: []
2025-01-29T19:09:21.825000 DEBUG 44527 --- [demo] [nio-8080-exec-2] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2025-01-29T19:09:21.825000 TRACE 44527 --- [demo] [nio-8080-exec-2] org.hibernate.internal.SessionImpl : Closing session [b7c1d5a5-beb8-45d3-ac2a-45e644108dce]
2025-01-29T19:09:21.825000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@26dd0392]
2025-01-29T19:09:21.825000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.h.r.j.i.ResourceRegistryStandardImpl : Releasing JDBC resources
2025-01-29T19:09:21.825000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.h.r.j.i.LogicalConnectionManagedImpl : Closing logical connection
2025-01-29T19:09:21.825000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.h.r.j.i.ResourceRegistryStandardImpl : Releasing JDBC resources
2025-01-29T19:09:21.826000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.h.r.j.i.LogicalConnectionManagedImpl : Logical connection closed
2025-01-29T19:09:21.826000 DEBUG 44527 --- [demo] [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Unresolved failure from "ASYNC" dispatch: org.hibernate.sql.exec.ExecutionException: A problem occurred in the SQL executor : Error advancing (next) ResultSet position [The object is already closed [90007-224]]
2025-01-29T19:09:21.826000 TRACE 44527 --- [demo] [nio-8080-exec-2] o.s.b.w.s.f.OrderedRequestContextFilter : Cleared thread-bound request context: org.apache.catalina.core.ApplicationHttpRequest@516ef5
2025-01-29T19:09:21.826000 ERROR 44527 --- [demo] [nio-8080-exec-2] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] threw exception
org.h2.jdbc.JdbcSQLNonTransientException: The object is already closed [90007-224]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:566) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:489) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.get(DbException.java:223) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.get(DbException.java:199) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.get(DbException.java:188) ~[h2-2.2.224.jar:2.2.224]
at org.h2.jdbc.JdbcResultSet.checkClosed(JdbcResultSet.java:3536) ~[h2-2.2.224.jar:2.2.224]
at org.h2.jdbc.JdbcResultSet.next(JdbcResultSet.java:124) ~[h2-2.2.224.jar:2.2.224]
at com.zaxxer.hikari.pool.HikariProxyResultSet.next(HikariProxyResultSet.java) ~[HikariCP-5.1.0.jar:na]
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.advanceNext(JdbcValuesResultSetImpl.java:270) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.processNext(JdbcValuesResultSetImpl.java:150) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.sql.results.jdbc.internal.AbstractJdbcValues.next(AbstractJdbcValues.java:19) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.sql.results.internal.RowProcessingStateStandardImpl.next(RowProcessingStateStandardImpl.java:99) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.internal.ScrollableResultsImpl.next(ScrollableResultsImpl.java:51) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.query.internal.ScrollableResultsIterator.hasNext(ScrollableResultsIterator.java:33) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at java.base/java.util.Iterator.forEachRemaining(Iterator.java:132) ~[na:na]
at java.base/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1845) ~[na:na]
at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:762) ~[na:na]
at com.example.demo.controller.TodoController$1.writeTo(TodoController.java:45) ~[main/:na]
at org.springframework.web.servlet.mvc.method.annotation.StreamingResponseBodyReturnValueHandler$StreamingResponseBodyTask.call(StreamingResponseBodyReturnValueHandler.java:110) ~[spring-webmvc-6.1.16.jar:6.1.16]
at org.springframework.web.servlet.mvc.method.annotation.StreamingResponseBodyReturnValueHandler$StreamingResponseBodyTask.call(StreamingResponseBodyReturnValueHandler.java:97) ~[spring-webmvc-6.1.16.jar:6.1.16]
at org.springframework.web.context.request.async.WebAsyncManager.lambda$startCallableProcessing$4(WebAsyncManager.java:367) ~[spring-web-6.1.16.jar:6.1.16]
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264) ~[na:na]
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
at java.base/java.lang.Thread.run(Thread.java:840) ~[na:na]
2025-01-29T19:09:21.826000 ERROR 44527 --- [demo] [nio-8080-exec-2] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: org.hibernate.sql.exec.ExecutionException: A problem occurred in the SQL executor : Error advancing (next) ResultSet position [The object is already closed [90007-224]]] with root cause
org.h2.jdbc.JdbcSQLNonTransientException: The object is already closed [90007-224]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:566) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:489) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.get(DbException.java:223) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.get(DbException.java:199) ~[h2-2.2.224.jar:2.2.224]
at org.h2.message.DbException.get(DbException.java:188) ~[h2-2.2.224.jar:2.2.224]
at org.h2.jdbc.JdbcResultSet.checkClosed(JdbcResultSet.java:3536) ~[h2-2.2.224.jar:2.2.224]
at org.h2.jdbc.JdbcResultSet.next(JdbcResultSet.java:124) ~[h2-2.2.224.jar:2.2.224]
at com.zaxxer.hikari.pool.HikariProxyResultSet.next(HikariProxyResultSet.java) ~[HikariCP-5.1.0.jar:na]
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.advanceNext(JdbcValuesResultSetImpl.java:270) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.processNext(JdbcValuesResultSetImpl.java:150) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.sql.results.jdbc.internal.AbstractJdbcValues.next(AbstractJdbcValues.java:19) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.sql.results.internal.RowProcessingStateStandardImpl.next(RowProcessingStateStandardImpl.java:99) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.internal.ScrollableResultsImpl.next(ScrollableResultsImpl.java:51) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at org.hibernate.query.internal.ScrollableResultsIterator.hasNext(ScrollableResultsIterator.java:33) ~[hibernate-core-6.6.0.Final.jar:6.6.0.Final]
at java.base/java.util.Iterator.forEachRemaining(Iterator.java:132) ~[na:na]
at java.base/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1845) ~[na:na]
at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:762) ~[na:na]
at com.example.demo.controller.TodoController$1.writeTo(TodoController.java:45) ~[main/:na]
at org.springframework.web.servlet.mvc.method.annotation.StreamingResponseBodyReturnValueHandler$StreamingResponseBodyTask.call(StreamingResponseBodyReturnValueHandler.java:110) ~[spring-webmvc-6.1.16.jar:6.1.16]
at org.springframework.web.servlet.mvc.method.annotation.StreamingResponseBodyReturnValueHandler$StreamingResponseBodyTask.call(StreamingResponseBodyReturnValueHandler.java:97) ~[spring-webmvc-6.1.16.jar:6.1.16]
at org.springframework.web.context.request.async.WebAsyncManager.lambda$startCallableProcessing$4(WebAsyncManager.java:367) ~[spring-web-6.1.16.jar:6.1.16]
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264) ~[na:na]
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
at java.base/java.lang.Thread.run(Thread.java:840) ~[na:na]