[infinispan-issues] [JBoss JIRA] Commented: (ISPN-335) EOFException when fetchPersistentState
Galder Zamarreno (JIRA)
jira-events at lists.jboss.org
Wed Jan 20 10:31:47 EST 2010
[ https://jira.jboss.org/jira/browse/ISPN-335?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12507256#action_12507256 ]
Galder Zamarreno commented on ISPN-335:
---------------------------------------
The problem appears to be with the fact that several state transfer requests come in concurrently. As the logs below show, while there's a request being processed, a new one comes in and stops the 1st from generating the persistent state transfer. That's why on the receiving side, when it tries to apply this partial state, it gets an EOF:
// 1st state transfer request comes in:
2010-01-20 15:33:25,920 7814 TRACE [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Received request to generate state for cache named 'nbst-with-loader'. Attempting to generate state.
2010-01-20 15:33:25,921 7815 DEBUG [org.infinispan.statetransfer.StateTransferManagerImpl] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Generating state. Can provide? true
2010-01-20 15:33:25,921 7815 TRACE [org.infinispan.marshall.VersionAwareMarshaller] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Wrote version 400
2010-01-20 15:33:25,922 7816 DEBUG [org.infinispan.statetransfer.StateTransferManagerImpl] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Writing 1 StoredEntries to stream
// Just as it's written a cache entry in memory to the stream, another request comes in:
2010-01-20 15:33:26,057 7951 TRACE [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Received request to generate state for cache named 'nbst-with-loader'. Attempting to generate state.
2010-01-20 15:33:26,058 7952 DEBUG [org.infinispan.statetransfer.StateTransferManagerImpl] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Generating state. Can provide? false
2010-01-20 15:33:26,058 7952 TRACE [org.infinispan.marshall.VersionAwareMarshaller] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Wrote version 400
2010-01-20 15:33:26,058 7952 DEBUG [org.infinispan.statetransfer.StateTransferManagerImpl] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Not providing state!
2010-01-20 15:33:27,922 9816 TRACE [org.infinispan.statetransfer.StateTransferManagerImpl] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Generate persistent state
1295:2010-01-20 15:33:27,930 9824 TRACE [org.infinispan.loaders.file.FileCacheStore] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) List of files is [/home/g/ttarget/tempFiles/1/StateTransferFileCacheStoreFunctionalTest/nbst-with-loader/-1407191419, /home/g/ttarget/tempFiles/1/StateTransferFileCacheStoreFunctionalTest/nbst-with-loader/95467907, /home/g/ttarget/tempFiles/1/StateTransferFileCacheStoreFunctionalTest/nbst-with-loader/-1293255100, /home/g/ttarget/tempFiles/1/StateTransferFileCacheStoreFunctionalTest/nbst-with-loader/-1292331579, /home/g/ttarget/tempFiles/1/StateTransferFileCacheStoreFunctionalTest/nbst-with-loader/-1435820570]
...
Now, the funny thing here is that the log above seems to come from two different threads. Why am I saying this? Check this out:
infinispan.log:1251:2010-01-20 15:33:26,058 7952 DEBUG [org.infinispan.statetransfer.StateTransferManagerImpl] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Not providing state!
infinispan.log:1294:2010-01-20 15:33:27,922 9816 TRACE [org.infinispan.statetransfer.StateTransferManagerImpl] (STREAMING_STATE_TRANSFER sender,Infinispan-Cluster,eq-45685:) Generate persistent state
The second message comes from line 160 in StateTransferManagerImpl and the one before comes from line 154 and afaik this is not being called in a loop or similar.
...
if (persistentState) generatePersistentState(oo);
delimit(oo);
generateTransactionLog(oo);
if (log.isDebugEnabled()) log.debug("State generated, closing object stream");
} else {
if (log.isDebugEnabled()) log.debug("Not providing state!");
....
I suspect that JGroups is using the same thread name for two different threads.... I'm investigating
> EOFException when fetchPersistentState
> --------------------------------------
>
> Key: ISPN-335
> URL: https://jira.jboss.org/jira/browse/ISPN-335
> Project: Infinispan
> Issue Type: Bug
> Components: Loaders and Stores
> Affects Versions: 4.0.0.CR3
> Environment: Windows 7, Mac OS X, Ubuntu, RHEL 4
> Reporter: Huu-Dong Quach
> Assignee: Galder Zamarreno
> Fix For: 4.0.0.GA
>
>
> In a clustered replicated cache, when I flag the fetchPersistentState attribute to true for a FileStore, Infinispan generate an exception.
> 2010-01-20 15:33:27,935 9829 ERROR [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-1,Infinispan-Cluster,eq-65253:) Caught while requesting or applying state
> org.infinispan.statetransfer.StateTransferException: java.io.EOFException: Read past end of file
> at org.infinispan.statetransfer.StateTransferManagerImpl.assertDelimited(StateTransferManagerImpl.java:382)
> at org.infinispan.statetransfer.StateTransferManagerImpl.applyState(StateTransferManagerImpl.java:307)
> at org.infinispan.remoting.InboundInvocationHandlerImpl.applyState(InboundInvocationHandlerImpl.java:73)
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.setState(JGroupsTransport.java:564)
> at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.handleUpEvent(MessageDispatcher.java:655)
> at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:715)
> at org.jgroups.JChannel.up(JChannel.java:1413)
> at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:829)
> at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:489)
> at org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.connectToStateProvider(STREAMING_STATE_TRANSFER.java:526)
> at org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.handleStateRsp(STREAMING_STATE_TRANSFER.java:465)
> at org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.up(STREAMING_STATE_TRANSFER.java:230)
> at org.jgroups.protocols.FRAG2.up(FRAG2.java:188)
> at org.jgroups.protocols.FC.up(FC.java:470)
> at org.jgroups.protocols.pbcast.GMS.up(GMS.java:890)
> at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:236)
> at org.jgroups.protocols.UNICAST.handleDataReceived(UNICAST.java:588)
> at org.jgroups.protocols.UNICAST.up(UNICAST.java:275)
> at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:692)
> at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:132)
> at org.jgroups.protocols.FD.up(FD.java:259)
> at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:269)
> at org.jgroups.stack.Protocol.up(Protocol.java:340)
> at org.jgroups.protocols.Discovery.up(Discovery.java:277)
> at org.jgroups.protocols.TP.passMessageUp(TP.java:953)
> at org.jgroups.protocols.TP.access$100(TP.java:53)
> at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1457)
> at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1439)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:636)
> Caused by: java.io.EOFException: Read past end of file
> at org.jboss.marshalling.AbstractUnmarshaller.eofOnRead(AbstractUnmarshaller.java:184)
> at org.jboss.marshalling.AbstractUnmarshaller.readUnsignedByteDirect(AbstractUnmarshaller.java:312)
> at org.jboss.marshalling.AbstractUnmarshaller.readUnsignedByte(AbstractUnmarshaller.java:280)
> at org.jboss.marshalling.river.RiverUnmarshaller.doReadObject(RiverUnmarshaller.java:207)
> at org.jboss.marshalling.AbstractUnmarshaller.readObject(AbstractUnmarshaller.java:85)
> at org.infinispan.marshall.jboss.JBossMarshaller.objectFromObjectStream(JBossMarshaller.java:207)
> at org.infinispan.marshall.VersionAwareMarshaller.objectFromObjectStream(VersionAwareMarshaller.java:171)
> at org.infinispan.statetransfer.StateTransferManagerImpl.assertDelimited(StateTransferManagerImpl.java:380)
> ... 30 more
> Unrelated: Also, if I set the preload attribute to true, I expect the store to fetch the persistant state before loading the data from the store but that's not the case.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the infinispan-issues
mailing list