H2 Occasionally throws NPE when used with spring-session

[Wen Bob]

In my project, i configure Embedded h2 as Spring-session backend store, and i find the H2 connection occasionally throws NPE when spring-session try to update session timestamp:

13-Jun-2016 23:35:55.696 SEVERE [http-apr-8080-exec-7] org.apache.catalina.core.StandardWrapperValve.invoke Servlet.service() for servlet [webmvc-dispatcher] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.jdbc.UncategorizedSQLException: PreparedStatementCallback; uncategorized SQLException for SQL []; SQL state [HY000]; error code [50000]; General error: "java.lang.NullPointerException"; SQL statement:

SELECT S.SESSION_ID, S.CREATION_TIME, S.LAST_ACCESS_TIME, S.MAX_INACTIVE_INTERVAL, SA.ATTRIBUTE_NAME, SA.ATTRIBUTE_BYTES FROM TM_SPRING_SESSION S LEFT OUTER JOIN TM_SPRING_SESSION_ATTRIBUTES SA ON S.SESSION_ID = SA.SESSION_ID WHERE S.SESSION_ID = ? [50000-192]; nested exception is org.h2.jdbc.JdbcSQLException: General error: "java.lang.NullPointerException"; SQL statement:

SELECT S.SESSION_ID, S.CREATION_TIME, S.LAST_ACCESS_TIME, S.MAX_INACTIVE_INTERVAL, SA.ATTRIBUTE_NAME, SA.ATTRIBUTE_BYTES FROM TM_SPRING_SESSION S LEFT OUTER JOIN TM_SPRING_SESSION_ATTRIBUTES SA ON S.SESSION_ID = SA.SESSION_ID WHERE S.SESSION_ID = ? [50000-192]] with root cause

 java.lang.NullPointerException

at org.h2.mvstore.db.MVPrimaryIndex.getRow(MVPrimaryIndex.java:213)

at org.h2.mvstore.db.MVTable.getRow(MVTable.java:463)

at org.h2.mvstore.db.MVSecondaryIndex$MVStoreCursor.get(MVSecondaryIndex.java:489)

at org.h2.index.IndexCursor.get(IndexCursor.java:288)

at org.h2.table.TableFilter.getValue(TableFilter.java:1068)

at org.h2.expression.ExpressionColumn.getValue(ExpressionColumn.java:186)

at org.h2.command.dml.Select.queryFlat(Select.java:548)

at org.h2.command.dml.Select.queryWithoutCache(Select.java:654)

at org.h2.command.dml.Query.query(Query.java:341)

at org.h2.command.dml.Query.query(Query.java:309)

at org.h2.command.dml.Query.query(Query.java:36)

at org.h2.command.CommandContainer.query(CommandContainer.java:110)

at org.h2.command.Command.executeQuery(Command.java:201)

at org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:110)

at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)

at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)

at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:688)

at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:629)

at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:680)

at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:707)

at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:757)

at org.springframework.session.jdbc.JdbcOperationsSessionRepository$3.doInTransaction(JdbcOperationsSessionRepository.java:383)

at org.springframework.session.jdbc.JdbcOperationsSessionRepository$3.doInTransaction(JdbcOperationsSessionRepository.java:380)

at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133)

at org.springframework.session.jdbc.JdbcOperationsSessionRepository.getSession(JdbcOperationsSessionRepository.java:380)

at org.springframework.session.jdbc.JdbcOperationsSessionRepository.getSession(JdbcOperationsSessionRepository.java:130)

at org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.getSession(SessionRepositoryFilter.java:326)

at org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.getSession(SessionRepositoryFilter.java:343)

at org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.getSession(SessionRepositoryFilter.java:214)

at org.springframework.web.servlet.support.SessionFlashMapManager.retrieveFlashMaps(SessionFlashMapManager.java:45)

at org.springframework.web.servlet.support.AbstractFlashMapManager.retrieveAndUpdate(AbstractFlashMapManager.java:93)

at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:885)

at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:969)

at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:860)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:622)

at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:845)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:121)

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

at com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:65)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:164)

at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:80)

at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)

at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)

at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)

at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)

at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)

at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)

at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:616)

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:528)

at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1099)

at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:672)

at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2508)

at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2497)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)

at java.lang.Thread.run(Thread.java:745)

H2 version: 1.4.192

H2 connection url: 

jdbc:h2:split:~/.mc-server/data/mc-server;MVCC=TRUE;MV_STORE=TRUE;MULTI_THREADED=TRUE;JMX=TRUE;TRACE_LEVEL_FILE=1;TRACE_LEVEL_SYSTEM_OUT=1;AUTO_SERVER=TRUE;IFEXISTS=TRUE

Spring session schema:

CREATE TABLE TM_SPRING_SESSION (
  SESSION_ID            CHAR(36),
  CREATION_TIME         BIGINT NOT NULL,
  LAST_ACCESS_TIME      BIGINT NOT NULL,
  MAX_INACTIVE_INTERVAL INT    NOT NULL,
  PRINCIPAL_NAME        VARCHAR(100),
  CONSTRAINT TM_SPRING_SESSION_PK PRIMARY KEY (SESSION_ID)
);

CREATE INDEX TM_SPRING_SESSION_IX1 ON TM_SPRING_SESSION (LAST_ACCESS_TIME);

CREATE TABLE TM_SPRING_SESSION_ATTRIBUTES (
  SESSION_ID      CHAR(36),
  ATTRIBUTE_NAME  VARCHAR(200),
  ATTRIBUTE_BYTES LONGVARBINARY,
  CONSTRAINT TM_SPRING_SESSION_ATTRIBUTES_PK PRIMARY KEY (SESSION_ID, ATTRIBUTE_NAME),
  CONSTRAINT TM_SPRING_SESSION_ATTRIBUTES_FK FOREIGN KEY (SESSION_ID) REFERENCES TM_SPRING_SESSION (SESSION_ID) ON DELETE CASCADE
);

CREATE INDEX TM_SPRING_SESSION_ATTRIBUTES_IX1 ON TM_SPRING_SESSION_ATTRIBUTES (SESSION_ID);

Any help?

[Wen Bob]

Screen capture in debug mode:

[Wen Bob]

BTW, if i switch the backend store from h2 to mysql, everything is fine.

[Noel Grandin]

Try dropping the multi-threaded option that is still experimental

On Mon, 13 Jun 2016 at 18:33, Wen Bob <bob...@gmail.com> wrote:

BTW, if i switch the backend store from h2 to mysql, everything is fine.

--
You received this message because you are subscribed to the Google Groups "H2 Database" group.
To unsubscribe from this group and stop receiving emails from it, send an email to h2-database...@googlegroups.com.
To post to this group, send email to h2-da...@googlegroups.com.
Visit this group at https://groups.google.com/group/h2-database.
For more options, visit https://groups.google.com/d/optout.

[Wen Bob]

Seems you are right, after change MULTI_THREADED to false, the NPE does't occur anymore. 

However, the client request take longer to complete(high latency). i think MULTI_THREADED=TRUE is still important feature to keep in my project; 

Is there any plan to fix the problem?

在 2016年6月14日星期二 UTC+8上午3:58:07，Noel Grandin写道：