Skip to content

Instantly share code, notes, and snippets.

@tobias
Created August 11, 2015 21:12
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save tobias/620b301c6f1ac9836b8f to your computer and use it in GitHub Desktop.
Save tobias/620b301c6f1ac9836b8f to your computer and use it in GitHub Desktop.
17:08:33.032 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) BaseTransaction.begin
17:08:33.037 TRACE [org.hornetq.core.client] (Thread-13 (HornetQ-server-HornetQServerImpl::serverUUID=5a15f4a9-4069-11e5-a1ca-53aa5290b989-441683672)) Sending packet nonblocking PACKET(NullResponseMessage)[type=21, channelID=10, packetObject=NullResponseMessage] on channeID=10
17:08:33.038 TRACE [org.hornetq.core.client] (Thread-13 (HornetQ-server-HornetQServerImpl::serverUUID=5a15f4a9-4069-11e5-a1ca-53aa5290b989-441683672)) Writing buffer for channelID=10
17:08:33.038 TRACE [org.hornetq.core.server] (Thread-0 (HornetQ-client-global-threads-424743902)) InVMConnection [serverID=0, id=1f35cafb-406d-11e5-b852-e340d91e4477]::Sending inVM packet
17:08:33.038 TRACE [org.hornetq.core.client] (Thread-0 (HornetQ-client-global-threads-424743902)) handling packet PACKET(NullResponseMessage)[type=21, channelID=10, packetObject=NullResponseMessage]
17:08:33.038 TRACE [org.hornetq.core.server] (Thread-0 (HornetQ-client-global-threads-424743902)) InVMConnection [serverID=0, id=1f35cafb-406d-11e5-b852-e340d91e4477]::packet sent done
17:08:33.038 DEBUG [org.hornetq.core.client] (main) calling cleanup on ClientSessionImpl [name=1f35cafd-406d-11e5-b852-e340d91e4477, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=in-vm, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=1db48224-406d-11e5-b852-e340d91e4477, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(jms-session=,)]@7dbae40
17:08:33.039 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) Loading class com.arjuna.ats.arjuna.recovery.ActionStatusService
17:08:33.167 TRACE [org.hornetq.core.server] (main) Connection removed 1f35cafb-406d-11e5-b852-e340d91e4477 from server HornetQServerImpl::serverUUID=5a15f4a9-4069-11e5-a1ca-53aa5290b989
java.lang.Exception: trace
at org.hornetq.core.remoting.server.impl.RemotingServiceImpl.connectionDestroyed(RemotingServiceImpl.java:554) ~[hornetq-server-2.4.5.Final.jar:na]
at org.hornetq.core.remoting.impl.invm.InVMAcceptor$Listener.connectionDestroyed(InVMAcceptor.java:278) ~[hornetq-server-2.4.5.Final.jar:na]
at org.hornetq.core.remoting.impl.invm.InVMConnection.close(InVMConnection.java:118) ~[hornetq-server-2.4.5.Final.jar:na]
at org.hornetq.core.remoting.impl.invm.InVMAcceptor.disconnect(InVMAcceptor.java:231) [hornetq-server-2.4.5.Final.jar:na]
at org.hornetq.core.remoting.impl.invm.InVMConnector$Listener.connectionDestroyed(InVMConnector.java:207) [hornetq-server-2.4.5.Final.jar:na]
at org.hornetq.core.remoting.impl.invm.InVMConnection.close(InVMConnection.java:118) ~[hornetq-server-2.4.5.Final.jar:na]
at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.internalClose(RemotingConnectionImpl.java:619) [hornetq-core-client-2.4.5.Final.jar:na]
at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.destroy(RemotingConnectionImpl.java:374) [hornetq-core-client-2.4.5.Final.jar:na]
at org.hornetq.core.client.impl.ClientSessionFactoryImpl.checkCloseConnection(ClientSessionFactoryImpl.java:1211) [hornetq-core-client-2.4.5.Final.jar:na]
at org.hornetq.core.client.impl.ClientSessionFactoryImpl.closeCleanSessions(ClientSessionFactoryImpl.java:553) [hornetq-core-client-2.4.5.Final.jar:na]
at org.hornetq.core.client.impl.ClientSessionFactoryImpl.interruptConnectAndCloseAllSessions(ClientSessionFactoryImpl.java:522) [hornetq-core-client-2.4.5.Final.jar:na]
at org.hornetq.core.client.impl.ClientSessionFactoryImpl.close(ClientSessionFactoryImpl.java:562) [hornetq-core-client-2.4.5.Final.jar:na]
at org.hornetq.jms.client.HornetQConnection.close(HornetQConnection.java:341) [hornetq-jms-client-2.4.5.Final.jar:na]
at org.projectodd.wunderboss.messaging.WithCloseables.closeCloseables(WithCloseables.java:34) [wunderboss-messaging-1.x.incremental.275.jar:na]
at org.projectodd.wunderboss.messaging.jms.JMSContext.close(JMSContext.java:207) [wunderboss-messaging-1.x.incremental.275.jar:na]
at org.projectodd.wunderboss.messaging.jms.JMSDestination.publish(JMSDestination.java:154) [wunderboss-messaging-1.x.incremental.275.jar:na]
at org.projectodd.wunderboss.messaging.jms.JMSDestination.publish(JMSDestination.java:94) [wunderboss-messaging-1.x.incremental.275.jar:na]
at immutant.messaging.internal$queue_with_meta$reify__1301.publish(internal.clj:48) [na:na]
at immutant.messaging$publish.doInvoke(messaging.clj:171) [na:na]
at clojure.lang.RestFn.invoke(RestFn.java:425) [clojure-1.7.0.jar:na]
at immutant.transactions_test$fn__2134.invoke(transactions_test.clj:164) [na:na]
at clojure.test$test_var$fn__7670.invoke(test.clj:704) [clojure-1.7.0.jar:na]
at clojure.test$test_var.invoke(test.clj:704) [clojure-1.7.0.jar:na]
at clojure.test$test_vars$fn__7692$fn__7697.invoke(test.clj:722) [clojure-1.7.0.jar:na]
at immutant.transactions_test$eval1965$fn__1966.invoke(transactions_test.clj:46) [na:na]
at clojure.test$compose_fixtures$fn__7664$fn__7665.invoke(test.clj:681) [clojure-1.7.0.jar:na]
at clojure.test$default_fixture.invoke(test.clj:674) [clojure-1.7.0.jar:na]
at clojure.test$compose_fixtures$fn__7664.invoke(test.clj:681) [clojure-1.7.0.jar:na]
at clojure.test$test_vars$fn__7692.invoke(test.clj:722) [clojure-1.7.0.jar:na]
at immutant.transactions_test$eval1971$fn__1972.invoke(transactions_test.clj:50) [na:na]
at clojure.test$compose_fixtures$fn__7664$fn__7665.invoke(test.clj:681) [clojure-1.7.0.jar:na]
at clojure.test$default_fixture.invoke(test.clj:674) [clojure-1.7.0.jar:na]
at clojure.test$compose_fixtures$fn__7664.invoke(test.clj:681) [clojure-1.7.0.jar:na]
at clojure.test$test_vars.invoke(test.clj:718) [clojure-1.7.0.jar:na]
at clojure.test$test_all_vars.invoke(test.clj:728) [clojure-1.7.0.jar:na]
at clojure.test$test_ns.invoke(test.clj:747) [clojure-1.7.0.jar:na]
at clojure.core$map$fn__4553.invoke(core.clj:2624) [clojure-1.7.0.jar:na]
at clojure.lang.LazySeq.sval(LazySeq.java:40) [clojure-1.7.0.jar:na]
at clojure.lang.LazySeq.seq(LazySeq.java:49) [clojure-1.7.0.jar:na]
at clojure.lang.Cons.next(Cons.java:39) [clojure-1.7.0.jar:na]
at clojure.lang.RT.boundedLength(RT.java:1735) [clojure-1.7.0.jar:na]
at clojure.lang.RestFn.applyTo(RestFn.java:130) [clojure-1.7.0.jar:na]
at clojure.core$apply.invoke(core.clj:632) [clojure-1.7.0.jar:na]
at clojure.test$run_tests.doInvoke(test.clj:762) [clojure-1.7.0.jar:na]
at clojure.lang.RestFn.applyTo(RestFn.java:137) [clojure-1.7.0.jar:na]
at clojure.core$apply.invoke(core.clj:630) [clojure-1.7.0.jar:na]
at user$eval132$fn__247$fn__298.invoke(form-init6031879332133796352.clj:1) [na:na]
at user$eval132$fn__247$fn__248.invoke(form-init6031879332133796352.clj:1) [na:na]
at user$eval132$fn__247.invoke(form-init6031879332133796352.clj:1) [na:na]
at user$eval132.invoke(form-init6031879332133796352.clj:1) [na:na]
at clojure.lang.Compiler.eval(Compiler.java:6782) [clojure-1.7.0.jar:na]
at clojure.lang.Compiler.eval(Compiler.java:6772) [clojure-1.7.0.jar:na]
at clojure.lang.Compiler.load(Compiler.java:7227) [clojure-1.7.0.jar:na]
at clojure.lang.Compiler.loadFile(Compiler.java:7165) [clojure-1.7.0.jar:na]
at clojure.main$load_script.invoke(main.clj:275) [clojure-1.7.0.jar:na]
at clojure.main$init_opt.invoke(main.clj:280) [clojure-1.7.0.jar:na]
at clojure.main$initialize.invoke(main.clj:308) [clojure-1.7.0.jar:na]
at clojure.main$null_opt.invoke(main.clj:343) [clojure-1.7.0.jar:na]
at clojure.main$main.doInvoke(main.clj:421) [clojure-1.7.0.jar:na]
at clojure.lang.RestFn.invoke(RestFn.java:421) [clojure-1.7.0.jar:na]
at clojure.lang.Var.invoke(Var.java:383) [clojure-1.7.0.jar:na]
at clojure.lang.AFn.applyToHelper(AFn.java:156) [clojure-1.7.0.jar:na]
at clojure.lang.Var.applyTo(Var.java:700) [clojure-1.7.0.jar:na]
at clojure.main.main(main.java:37) [clojure-1.7.0.jar:na]
17:08:33.169 DEBUG [org.hornetq.core.client] (main) Session was already closed, giving up now, this=ClientSessionImpl [name=1f41159e-406d-11e5-b852-e340d91e4477, username=null, closed=true, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=in-vm, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=1db48224-406d-11e5-b852-e340d91e4477, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(jms-session=,)]@5175d9ad
17:08:33.171 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore
17:08:33.306 DEBUG [org.hornetq.core.client] (main) Session was already closed, giving up now, this=ClientSessionImpl [name=1f35cafd-406d-11e5-b852-e340d91e4477, username=null, closed=true, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=in-vm, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=1db48224-406d-11e5-b852-e340d91e4477, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(jms-session=,)]@7dbae40
17:08:33.306 DEBUG [org.hornetq.core.client] (main) Session was already closed, giving up now, this=ClientSessionImpl [name=1f41159e-406d-11e5-b852-e340d91e4477, username=null, closed=true, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=in-vm, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=1db48224-406d-11e5-b852-e340d91e4477, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(jms-session=,)]@5175d9ad
17:08:33,306 MESSAGE SENT
17:08:33.308 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) FileSystemStore.createHierarchy(PutObjectStoreDirHere/ShadowNoFileLockStore/defaultStore/)
17:08:33.312 INFO [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ARJUNA012163: Starting service com.arjuna.ats.arjuna.recovery.ActionStatusService on port 57362
17:08:33.408 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@55d8c2c4]
17:08:33.408 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:33.408 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:33.408 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(798cf6d2){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:33.408 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:33.408 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:33.508 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@1c1fa494]
17:08:33.508 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:33.508 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:33.508 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(77c66a4f){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:33.508 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:33.508 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:33.609 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@649b5891]
17:08:33.609 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:33.609 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:33.609 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(7a3f08b6){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:33.609 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:33.609 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:33.709 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@1be52861]
17:08:33.709 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:33.709 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:33.710 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(5fb5ad40){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:33.710 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:33.710 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:33.810 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@615439f7]
17:08:33.810 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:33.810 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:33.810 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(632cf7d3){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:33.810 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:33.810 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:33.910 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@51b87df7]
17:08:33.910 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:33.910 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:33.910 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(2315052d){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:33.910 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:33.910 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.011 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@634e1b39]
17:08:34.011 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.011 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.011 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(67d8faec){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.011 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.011 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.111 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@751d7425]
17:08:34.111 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.111 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.111 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(7eaa2bc6){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.111 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.111 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.211 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@6dae70f9]
17:08:34.212 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.212 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.212 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(4d81e83a){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.212 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.212 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.312 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@53a301f3]
17:08:34.312 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.312 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.312 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(7cf8f45a){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.312 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.312 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.412 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@62cf6a84]
17:08:34.412 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.412 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.412 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(204d9edf){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.412 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.412 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.513 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@6b2aafbc]
17:08:34.513 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.513 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.513 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(50cbcca7){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.513 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.513 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.613 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@49491770]
17:08:34.613 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.613 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.613 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(5bec3e0){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.613 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.613 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.714 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@3b57dba4]
17:08:34.714 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.714 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.714 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(35f7969d){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.714 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.714 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.814 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@3404e5c4]
17:08:34.814 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.814 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.814 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(47569167){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.814 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.814 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:34.915 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@42d9e8d2]
17:08:34.915 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:34.915 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:34.915 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(4b93dd6a){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:34.915 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:34.915 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.015 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@582a3b19]
17:08:35.015 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.015 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.015 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(2b0454d2){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.015 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.015 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.116 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@2616b618]
17:08:35.116 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.116 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.116 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(73bb573d){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.116 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.116 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.216 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@7ac058a0]
17:08:35.216 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.216 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.216 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(736b21ee){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.216 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.216 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.317 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@60deefed]
17:08:35.317 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.317 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.317 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(49754e74){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.317 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.317 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.417 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@31881aa2]
17:08:35.417 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.417 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.417 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(1b46392c){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.417 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.417 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.517 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@cf01c2e]
17:08:35.518 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.518 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.518 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(6f15f52a){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.518 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.518 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.618 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@1eb9bf60]
17:08:35.618 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.618 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.618 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(341c6ac2){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.618 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.618 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.719 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@38811103]
17:08:35.719 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.719 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.719 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(787d1f9c){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.719 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.719 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.819 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@2becfd4c]
17:08:35.819 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.819 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.819 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(7c71c889){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.819 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.819 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:35.919 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@4cc8d70d]
17:08:35.920 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:35.920 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:35.920 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(5c59a0f7){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:35.920 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:35.920 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.020 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@101330ad]
17:08:36.020 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.020 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.020 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(625487a6){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.020 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.020 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.120 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@682e445e]
17:08:36.120 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.121 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.121 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(79e10fb4){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.121 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.121 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.221 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@70fede7d]
17:08:36.221 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.221 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.221 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(36510e73){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.221 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.221 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.321 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@2c47a053]
17:08:36.321 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.321 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.322 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(5d2a86c0){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.322 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.322 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.422 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@5ba1b62e]
17:08:36.422 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.422 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.422 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(65bd19bf){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.422 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.422 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.522 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@74697863]
17:08:36.522 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.522 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.522 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(7d7ceca8){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.522 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.522 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.623 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@2bba35ef]
17:08:36.623 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.623 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.623 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(26c7b1c6){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.623 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.623 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.723 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@19526f1d]
17:08:36.723 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.723 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.723 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(3d1c933){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.723 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.723 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.824 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@79be91eb]
17:08:36.824 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.824 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.824 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(626c569b){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.824 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.824 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:36.924 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@684ce74c]
17:08:36.924 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:36.924 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:36.924 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(65593327){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:36.924 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:36.924 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.025 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@68e5c7ae]
17:08:37.025 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.025 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.025 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(68bd8ca7){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.025 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.025 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.125 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@6744707b]
17:08:37.125 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.125 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.125 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(4b28a7bf){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.125 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.125 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.225 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@d36c1c3]
17:08:37.226 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.226 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.226 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(96abc76){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.226 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.226 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.326 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@4d69d288]
17:08:37.326 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.326 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.326 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(437281c5){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.326 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.326 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.426 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@787178b1]
17:08:37.427 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.427 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.427 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(24a4e2c5){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.427 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.427 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.527 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@27da994b]
17:08:37.527 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.527 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.527 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(70f148dc){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.527 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.527 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.627 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@3360283]
17:08:37.627 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.628 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.628 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(77aea){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.628 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.628 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.728 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@73e4bb60]
17:08:37.728 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.728 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.728 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(9a9aa68){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.728 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.728 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.828 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@3a3883c4]
17:08:37.828 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.829 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.829 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(1537e43){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.829 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.829 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:37.929 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@573aeab2]
17:08:37.929 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:37.929 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:37.929 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(1304e0d7){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:37.929 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:37.929 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:38.029 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@6ddc67d0]
17:08:38.029 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:38.029 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:38.029 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(7767bd4e){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:38.029 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:38.030 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:38.130 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@7708b66a]
17:08:38.130 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:38.130 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:38.130 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(433ef204){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:38.130 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:38.130 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:38.230 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@4dd2ef54]
17:08:38.230 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:38.230 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:38.230 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(795b66d){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:38.230 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:38.230 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:38.331 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@359ceb13]
17:08:38.331 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:38.331 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:38.331 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(1068176){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:38.331 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:38.331 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:38.401 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) Loading class com.arjuna.ats.internal.arjuna.utils.SocketProcessId
17:08:38.402 INFO [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ARJUNA012337: TransactionStatusManagerItem host: 127.0.0.1 port: 57362
17:08:38.403 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) OutputObjectState::OutputObjectState()
17:08:38.404 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore
17:08:38.404 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) FileSystemStore.createHierarchy(/home/tcrawley/work/clojure/immutant/transactions/ObjectStore/ShadowNoFileLockStore/defaultStore/)
17:08:38.404 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) FileSystemStore.write_committed(0:ffff0a00000a:ec16:55ca6456:0, /Recovery/TransactionStatusManager)
17:08:38.404 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ShadowingStore.write_state(0:ffff0a00000a:ec16:55ca6456:0, /Recovery/TransactionStatusManager, StateType.OS_ORIGINAL)
17:08:38.404 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ShadowingStore.genPathName(0:ffff0a00000a:ec16:55ca6456:0, /Recovery/TransactionStatusManager, StateType.OS_ORIGINAL)
17:08:38.404 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) FileSystemStore.genPathName(0:ffff0a00000a:ec16:55ca6456:0, /Recovery/TransactionStatusManager, 11)
17:08:38.405 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) FileSystemStore.openAndLock(/home/tcrawley/work/clojure/immutant/transactions/ObjectStore/ShadowNoFileLockStore/defaultStore/Recovery/TransactionStatusManager/0_ffff0a00000a_ec16_55ca6456_0, FileLock.F_WRLCK, true)
17:08:38.412 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) FileSystemStore.closeAndUnlock(/home/tcrawley/work/clojure/immutant/transactions/ObjectStore/ShadowNoFileLockStore/defaultStore/Recovery/TransactionStatusManager/0_ffff0a00000a_ec16_55ca6456_0, null, java.io.FileOutputStream@62c4ce9a)
17:08:38.412 INFO [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ARJUNA012170: TransactionStatusManager started on port 57362 and host 127.0.0.1 with service com.arjuna.ats.arjuna.recovery.ActionStatusService
17:08:38.413 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) StateManager::StateManager( 2, 0 )
17:08:38.413 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::BasicAction()
17:08:38.414 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::Begin() for action-id 0:ffff0a00000a:ec16:55ca6456:2
17:08:38.414 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::actionInitialise() for action-id 0:ffff0a00000a:ec16:55ca6456:2
17:08:38.415 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ActionHierarchy::ActionHierarchy(1)
17:08:38.415 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ActionHierarchy::add(0:ffff0a00000a:ec16:55ca6456:2, 1)
17:08:38.416 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::addChildThread () action 0:ffff0a00000a:ec16:55ca6456:2 adding Thread[Thread-1 (HornetQ-client-global-threads-424743902),5,HornetQ-client-global-threads-424743902]
17:08:38.416 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::addChildThread () action 0:ffff0a00000a:ec16:55ca6456:2 adding Thread[Thread-1 (HornetQ-client-global-threads-424743902),5,HornetQ-client-global-threads-424743902] result = true
17:08:38.417 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionReaper::instantiate()
17:08:38.417 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionReaper::TransactionReaper ( 9223372036854775807 )
17:08:38.418 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run ()
17:08:38.418 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ReaperWorkerThread.run ()
17:08:38.418 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,HornetQ-client-global-threads-424743902] sleeping for 9223370597527457389
17:08:38.419 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) Thread Thread[Transaction Reaper Worker 0,5,HornetQ-client-global-threads-424743902] waiting for cancelled TXs
17:08:38.419 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionReaper::insert ( BasicAction: 0:ffff0a00000a:ec16:55ca6456:2 status: ActionStatus.RUNNING, 60 )
17:08:38.419 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) ReaperElement::ReaperElement ( BasicAction: 0:ffff0a00000a:ec16:55ca6456:2 status: ActionStatus.RUNNING, 60 )
17:08:38.419 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run ()
17:08:38.419 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check ()
17:08:38.419 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 1439327378419
17:08:38.419 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,HornetQ-client-global-threads-424743902] sleeping for 60000
17:08:38.419 TRACE [org.infinispan.cache.impl.CacheImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Implicit transaction started! Transaction: TransactionImple < ac, BasicAction: 0:ffff0a00000a:ec16:55ca6456:2 status: ActionStatus.RUNNING >
17:08:38.420 TRACE [org.infinispan.transaction.impl.TransactionTable] (Thread-1 (HornetQ-client-global-threads-424743902)) Created a new local transaction: LocalXaTransaction{xid=null} LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, lockedKeys=null, backupKeyLocks=null, topologyId=-1, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@1
17:08:38.422 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Invoked with command PutKeyValueCommand{key=:a, value=1, flags=null, putIfAbsent=true, valueMatcher=MATCH_EXPECTED, metadata=EmbeddedMetadata{version=null}, successful=true} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@73c1dafe]
17:08:38.423 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
17:08:38.424 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionImple.enlistResource ( TransactionXaAdapter{localTransaction=LocalXaTransaction{xid=null} LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, lockedKeys=null, backupKeyLocks=null, topologyId=-1, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@1} )
17:08:38.424 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
17:08:38.427 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) StateManager::StateManager( 1, 0 )
17:08:38.427 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) AbstractRecord::AbstractRecord (0:ffff0a00000a:ec16:55ca6456:4, 1)
17:08:38.427 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a00000a:ec16:55ca6456:2, node_name=1, branch_uid=0:ffff0a00000a:ec16:55ca6456:3, subordinatenodename=null, eis_name=0 >, TransactionXaAdapter{localTransaction=LocalXaTransaction{xid=null} LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, lockedKeys=null, backupKeyLocks=null, topologyId=-1, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@1} ), record id=0:ffff0a00000a:ec16:55ca6456:4
17:08:38.427 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (Thread-1 (HornetQ-client-global-threads-424743902)) start called on tx GlobalTransaction:<null>:1:local
17:08:38.428 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff0a00000a:ec16:55ca6456:4
17:08:38.429 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Wrapping entry ':a'? true
17:08:38.429 TRACE [org.infinispan.container.EntryFactoryImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Exists in context? null
17:08:38.429 TRACE [org.infinispan.container.EntryFactoryImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:38.429 TRACE [org.infinispan.container.EntryFactoryImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Creating new entry.
17:08:38.430 TRACE [org.infinispan.container.EntryFactoryImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Wrap :a for put. Entry=RepeatableReadEntry(fa3a437){key=:a, value=null, oldValue=null, isCreated=true, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
17:08:38.430 TRACE [org.infinispan.interceptors.CallInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Executing command: PutKeyValueCommand{key=:a, value=1, flags=null, putIfAbsent=true, valueMatcher=MATCH_EXPECTED, metadata=EmbeddedMetadata{version=null}, successful=true}.
17:08:38.430 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) The return value is null
17:08:38.430 TRACE [org.infinispan.transaction.impl.LocalTransaction] (Thread-1 (HornetQ-client-global-threads-424743902)) Adding modification PutKeyValueCommand{key=:a, value=1, flags=null, putIfAbsent=true, valueMatcher=MATCH_EXPECTED, metadata=EmbeddedMetadata{version=null}, successful=true}. Mod list is null
17:08:38.430 TRACE [org.infinispan.cache.impl.CacheImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Committing transaction as it was implicit: TransactionImple < ac, BasicAction: 0:ffff0a00000a:ec16:55ca6456:2 status: ActionStatus.RUNNING >
17:08:38.430 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) BaseTransaction.commit
17:08:38.430 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionImple.commitAndDisassociate
17:08:38.430 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::End() for action-id 0:ffff0a00000a:ec16:55ca6456:2
17:08:38.430 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::onePhaseCommit() for action-id 0:ffff0a00000a:ec16:55ca6456:2
17:08:38.430 TRACE [com.arjuna.ats.jta] (Thread-1 (HornetQ-client-global-threads-424743902)) XAResourceRecord.topLevelOnePhaseCommit for XAResourceRecord < resource:TransactionXaAdapter{localTransaction=LocalXaTransaction{xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a00000a:ec16:55ca6456:2, node_name=1, branch_uid=0:ffff0a00000a:ec16:55ca6456:3, subordinatenodename=null, eis_name=0 >} LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, lockedKeys=null, backupKeyLocks=null, topologyId=-1, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@1}, txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a00000a:ec16:55ca6456:2, node_name=1, branch_uid=0:ffff0a00000a:ec16:55ca6456:3, subordinatenodename=null, eis_name=0 >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@14692f09 >, record id=0:ffff0a00000a:ec16:55ca6456:4
17:08:38.430 TRACE [org.infinispan.transaction.xa.TransactionXaAdapter] (Thread-1 (HornetQ-client-global-threads-424743902)) end called on tx GlobalTransaction:<null>:1:local(tx-test)
17:08:38.431 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (main) Invoked with command GetKeyValueCommand {key=:deliveries, flags=null} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@5bf4764d]
17:08:38.431 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Exists in context? null
17:08:38.431 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Retrieved from container null (forceFetch=false, isLocal=true)
17:08:38.431 TRACE [org.infinispan.container.EntryFactoryImpl] (main) Wrap :deliveries for read. Entry=RepeatableReadEntry(71789580){key=:deliveries, value=null, oldValue=null, isCreated=false, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=null}
17:08:38.431 TRACE [org.infinispan.interceptors.CallInterceptor] (main) Executing command: GetKeyValueCommand {key=:deliveries, flags=null}.
17:08:38.431 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (main) Entry not found
17:08:38.432 TRACE [org.infinispan.transaction.impl.TransactionCoordinator] (Thread-1 (HornetQ-client-global-threads-424743902)) Sending prepare command through the chain: VersionedPrepareCommand {modifications=[PutKeyValueCommand{key=:a, value=1, flags=null, putIfAbsent=true, valueMatcher=MATCH_EXPECTED, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, versionsSeen=null, gtx=GlobalTransaction:<null>:1:local, cacheName='tx-test'}
17:08:38.432 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Invoked with command VersionedPrepareCommand {modifications=[PutKeyValueCommand{key=:a, value=1, flags=null, putIfAbsent=true, valueMatcher=MATCH_EXPECTED, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, versionsSeen=null, gtx=GlobalTransaction:<null>:1:local, cacheName='tx-test'} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@d4cce3a]
17:08:38.432 TRACE [org.infinispan.interceptors.locking.OptimisticLockingInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Not using lock reordering as we have a single key.
lein test :only immutant.transactions-test/non-transactional-writes-in-listener-with-exception
17:08:38.432 TRACE [org.infinispan.interceptors.locking.OptimisticLockingInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Locking key :a, no need to check for pending locks.
17:08:38.432 TRACE [org.infinispan.util.concurrent.locks.LockManagerImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Attempting to lock :a with acquisition timeout of 10000 millis
17:08:38.433 TRACE [org.infinispan.util.concurrent.locks.containers.OwnableReentrantPerEntryLockContainer] (Thread-1 (HornetQ-client-global-threads-424743902)) Creating and acquiring new lock instance for key :a
17:08:38.433 TRACE [org.infinispan.util.concurrent.locks.LockManagerImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Successfully acquired lock :a!
17:08:38.434 TRACE [org.infinispan.transaction.impl.AbstractCacheTransaction] (Thread-1 (HornetQ-client-global-threads-424743902)) Registering locked key: :a
17:08:38.434 TRACE [org.infinispan.interceptors.locking.OptimisticLockingInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Performing local write skew check for key :a
17:08:38.434 TRACE [org.infinispan.container.entries.RepeatableReadEntry] (Thread-1 (HornetQ-client-global-threads-424743902)) Performing local write skew check. actualValue=null, transactionValue=null
17:08:38.434 TRACE [org.infinispan.interceptors.CallInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Suppressing invocation of method handlePrepareCommand.
17:08:38.434 TRACE [org.infinispan.transaction.impl.TransactionCoordinator] (Thread-1 (HornetQ-client-global-threads-424743902)) Committing transaction GlobalTransaction:<null>:1:local
17:08:38.435 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Invoked with command VersionedCommitCommand{gtx=GlobalTransaction:<null>:1:local, cacheName='tx-test', topologyId=-1, updatedVersions=null} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@679f7f58]
17:08:38.435 TRACE [org.infinispan.interceptors.CallInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) Suppressing invocation of method handleCommitCommand.
17:08:38.437 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (Thread-1 (HornetQ-client-global-threads-424743902)) About to commit entry RepeatableReadEntry(fa3a437){key=:a, value=1, oldValue=null, isCreated=true, isChanged=true, isRemoved=false, isValid=true, skipRemoteGet=true, metadata=EmbeddedMetadata{version=null}}
17:08:38.437 TRACE [org.infinispan.statetransfer.CommitManager] (Thread-1 (HornetQ-client-global-threads-424743902)) Trying to commit. Key=:a. Operation Flag=null, L1 invalidation=false
17:08:38.437 TRACE [org.infinispan.statetransfer.CommitManager] (Thread-1 (HornetQ-client-global-threads-424743902)) Committing key=:a. It is a L1 invalidation or a normal put and no tracking is enabled!
17:08:38.438 TRACE [org.infinispan.container.entries.ReadCommittedEntry] (Thread-1 (HornetQ-client-global-threads-424743902)) Updating entry (key=:a removed=false valid=true changed=true created=true loaded=false value=1 metadata=EmbeddedMetadata{version=null}, providedMetadata=null)
FAIL in (non-transactional-writes-in-listener-with-exception) (transactions_test.clj:166)
17:08:38.438 TRACE [org.infinispan.container.DefaultDataContainer] (Thread-1 (HornetQ-client-global-threads-424743902)) Creating new ICE for writing. Existing=null, metadata=EmbeddedMetadata{version=null}, new value=1
17:08:38.439 TRACE [org.infinispan.container.DefaultDataContainer] (Thread-1 (HornetQ-client-global-threads-424743902)) Store ImmortalCacheEntry{key=:a, value=1} in container
17:08:38.440 TRACE [org.infinispan.util.concurrent.locks.LockManagerImpl] (Thread-1 (HornetQ-client-global-threads-424743902)) Attempting to unlock :a
17:08:38.440 TRACE [org.infinispan.util.concurrent.locks.containers.OwnableReentrantPerEntryLockContainer] (Thread-1 (HornetQ-client-global-threads-424743902)) Unlocking lock instance for key :a
17:08:38.441 TRACE [org.infinispan.transaction.impl.AbstractCacheTransaction] (Thread-1 (HornetQ-client-global-threads-424743902)) Clearing locked keys: [:a]
17:08:38.441 TRACE [org.infinispan.transaction.impl.TransactionTable] (Thread-1 (HornetQ-client-global-threads-424743902)) Removed LocalXaTransaction{xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a00000a:ec16:55ca6456:2, node_name=1, branch_uid=0:ffff0a00000a:ec16:55ca6456:3, subordinatenodename=null, eis_name=0 >} LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, lockedKeys=null, backupKeyLocks=null, topologyId=-1, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@1 from transaction table.
17:08:38.441 TRACE [org.infinispan.transaction.impl.AbstractCacheTransaction] (Thread-1 (HornetQ-client-global-threads-424743902)) Transaction GlobalTransaction:<null>:1:local has completed, notifying listening threads.
17:08:38.441 TRACE [org.infinispan.transaction.impl.AbstractEnlistmentAdapter] (Thread-1 (HornetQ-client-global-threads-424743902)) Committed in onePhase? false isOptimistic? true
17:08:38.441 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::End() result for action-id (0:ffff0a00000a:ec16:55ca6456:2) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
17:08:38.441 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::removeChildThread () action 0:ffff0a00000a:ec16:55ca6456:2 removing TSThread:1
17:08:38.441 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) BasicAction::removeChildThread () action 0:ffff0a00000a:ec16:55ca6456:2 removing TSThread:1 result = true
17:08:38.441 TRACE [com.arjuna.ats.arjuna] (Thread-1 (HornetQ-client-global-threads-424743902)) TransactionReaper::remove ( BasicAction: 0:ffff0a00000a:ec16:55ca6456:2 status: ActionStatus.COMMITTED )
17:08:38,441 SWAP-IN post putIfAbsent
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment