Mantis - Resin
Viewing Issue Advanced Details
3617 minor always 07-31-09 15:19 08-06-09 09:19
ferg  
ferg  
normal  
closed 3.1.9  
fixed  
none    
none 3.1.10  
0003617: Session cache state filture
(rep by Chris Pratt)

We are having a problem with the session caching in Resin 3.1 (we've seen it on 3.1.5, 3.1.8 & 3.1.9). The exceptions that are thrown are at the bottom of the email. What other information do you need to help us solve this problem? I've tried stopping the server and deleting the srun.db file, but that doesn't seem to solve the problem. We (VSP) have a service contract with Caucho, is there a service number you require or something? Thanks.
  (*Chris*)
 
[11:42:51.905] Inode.stateError: java.lang.IllegalStateException: Table[srun_client_a1:3]: inode block 42bacb has invalid fragment e5807871007e0e8c
java.lang.IllegalStateException: Table[srun_client_a1:3]: inode block 42bacb has invalid fragment e5807871007e0e8c
        at com.caucho.db.store.Inode.stateError(Inode.java:1177)
        at com.caucho.db.store.Inode.remove(Inode.java:845)
        at com.caucho.db.store.Transaction.writeData(Transaction.java:568)
        at com.caucho.db.sql.QueryContext.unlock(QueryContext.java:537)
        at com.caucho.db.sql.UpdateQuery.execute(UpdateQuery.java:118)
        at com.caucho.db.jdbc.PreparedStatementImpl.execute(PreparedStatementImpl.java:345)
        at com.caucho.db.jdbc.PreparedStatementImpl.executeUpdate(PreparedStatementImpl.java:313)
        at com.caucho.server.cluster.FileBacking.storeSelfUpdate(FileBacking.java:524)
        at com.caucho.server.cluster.FileBacking.storeSelf(FileBacking.java:474)
        at com.caucho.server.cluster.ClusterStore.store(ClusterStore.java:642)
        at com.caucho.server.cluster.ClusterObject.store(ClusterObject.java:436)
        at com.caucho.server.session.SessionImpl.save(SessionImpl.java:952)
        at com.caucho.server.session.SessionImpl.saveAfterRequest(SessionImpl.java:938)
        at com.caucho.server.session.SessionImpl.finish(SessionImpl.java:900)
        at com.caucho.server.connection.AbstractHttpRequest.finishSession(AbstractHttpRequest.java:2530)
        at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:219)
        at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:265)
        at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:273)
        at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682)
        at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:743)
        at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:662)
        at java.lang.Thread.run(Thread.java:595)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} java.lang.IllegalStateException: Table[srun_client_a1:3]: inode block 42bacb has invalid fragment e5807871007e0e8c
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.db.store.Inode.stateError(Inode.java:1177)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.db.store.Inode.remove(Inode.java:845)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.db.store.Transaction.writeData(Transaction.java:568)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.db.sql.QueryContext.unlock(QueryContext.java:537)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.db.sql.UpdateQuery.execute(UpdateQuery.java:118)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.db.jdbc.PreparedStatementImpl.execute(PreparedStatementImpl.java:345)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.db.jdbc.PreparedStatementImpl.executeUpdate(PreparedStatementImpl.java:313)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.FileBacking.storeSelfUpdate(FileBacking.java:524)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.FileBacking.storeSelf(FileBacking.java:474)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.ClusterStore.store(ClusterStore.java:642)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.ClusterObject.store(ClusterObject.java:436)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.session.SessionImpl.save(SessionImpl.java:952)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.session.SessionImpl.saveAfterRequest(SessionImpl.java:938)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.session.SessionImpl.finish(SessionImpl.java:900)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.connection.AbstractHttpRequest.finishSession(AbstractHttpRequest.java:2530)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:219)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:265)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:273)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:743)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:662)
[11:42:52.311] {http-172.22.1.129:443-3$1367891} at java.lang.Thread.run(Thread.java:595)
[11:42:52.343] Inode.remove: java.lang.IllegalStateException: Table[srun_client_a1:3]: inode block 42bacb has invalid fragment e5807871007e0e8c
java.lang.IllegalStateException: Table[srun_client_a1:3]: inode block 42bacb has invalid fragment e5807871007e0e8c
        at com.caucho.db.store.Inode.stateError(Inode.java:1177)
        at com.caucho.db.store.Inode.remove(Inode.java:845)
        at com.caucho.db.store.Transaction.writeData(Transaction.java:568)
        at com.caucho.db.sql.QueryContext.unlock(QueryContext.java:537)
        at com.caucho.db.sql.UpdateQuery.execute(UpdateQuery.java:118)
        at com.caucho.db.jdbc.PreparedStatementImpl.execute(PreparedStatementImpl.java:345)
        at com.caucho.db.jdbc.PreparedStatementImpl.executeUpdate(PreparedStatementImpl.java:313)
        at com.caucho.server.cluster.FileBacking.storeSelfUpdate(FileBacking.java:524)
        at com.caucho.server.cluster.FileBacking.storeSelf(FileBacking.java:474)
        at com.caucho.server.cluster.ClusterStore.store(ClusterStore.java:642)
        at com.caucho.server.cluster.ClusterObject.store(ClusterObject.java:436)
        at com.caucho.server.session.SessionImpl.save(SessionImpl.java:952)
        at com.caucho.server.session.SessionImpl.saveAfterRequest(SessionImpl.java:938)
        at com.caucho.server.session.SessionImpl.finish(SessionImpl.java:900)
        at com.caucho.server.connection.AbstractHttpRequest.finishSession(AbstractHttpRequest.java:2530)
        at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:219)
        at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:265)
        at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:273)
        at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682)
        at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:743)
        at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:662)
        at java.lang.Thread.run(Thread.java:595)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} java.lang.IllegalStateException: Table[srun_client_a1:3]: inode block 42bacb has invalid fragment e5807871007e0e8c
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.db.store.Inode.stateError(Inode.java:1177)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.db.store.Inode.remove(Inode.java:845)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.db.store.Transaction.writeData(Transaction.java:568)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.db.sql.QueryContext.unlock(QueryContext.java:537)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.db.sql.UpdateQuery.execute(UpdateQuery.java:118)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.db.jdbc.PreparedStatementImpl.execute(PreparedStatementImpl.java:345)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.db.jdbc.PreparedStatementImpl.executeUpdate(PreparedStatementImpl.java:313)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.FileBacking.storeSelfUpdate(FileBacking.java:524)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.FileBacking.storeSelf(FileBacking.java:474)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.ClusterStore.store(ClusterStore.java:642)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.cluster.ClusterObject.store(ClusterObject.java:436)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.session.SessionImpl.save(SessionImpl.java:952)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.session.SessionImpl.saveAfterRequest(SessionImpl.java:938)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.session.SessionImpl.finish(SessionImpl.java:900)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.connection.AbstractHttpRequest.finishSession(AbstractHttpRequest.java:2530)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:219)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:265)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:273)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:743)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:662)
[11:42:52.436] {http-172.22.1.129:443-3$1367891} at java.lang.Thread.run(Thread.java:595)

Notes
(0004115)
planetpratt   
08-04-09 09:07   
It appears to be repeatable. I had our IT guys shut down both servers and delete the session cache db's on both servers before restarting. Then I reran the test and got the following on the first try:
  (*Chris*)

[08:57:58.232] {hmux-172.22.1.128:6800-34} java.lang.ArrayIndexOutOfBoundsException: 577339393
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.db.store.Store.deleteFragment(Store.java:1035)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.db.store.Inode.remove(Inode.java:844)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.db.store.Transaction.writeData(Transaction.java:568)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.db.sql.QueryContext.unlock(QueryContext.java:537)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.db.sql.UpdateQuery.execute(UpdateQuery.java:118)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.db.jdbc.PreparedStatementImpl.execute(PreparedStatementImpl.java:345)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.db.jdbc.PreparedStatementImpl.executeUpdate(PreparedStatementImpl.java:313)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.cluster.FileBacking.storeSelfUpdate(FileBacking.java:524)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.cluster.FileBacking.storeSelf(FileBacking.java:474)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.cluster.ClusterStore.storeSelf(ClusterStore.java:1198)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.cluster.ClusterStore.update(ClusterStore.java:1123)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.hmux.HmuxClusterRequest.saveObject(HmuxClusterRequest.java:310)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.hmux.HmuxClusterRequest.handleRequest(HmuxClusterRequest.java:162)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.hmux.HmuxRequest.scanHeaders(HmuxRequest.java:652)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.hmux.HmuxRequest.handleRequest(HmuxRequest.java:362)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.server.port.TcpConnection.run(TcpConnection.java:603)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:721)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:643)
[08:57:58.232] {hmux-172.22.1.128:6800-34} at java.lang.Thread.run(Thread.java:595)