#image cannot not be shown in web

291 views
Skip to first unread message

roadm...@gmail.com

unread,
Jan 14, 2013, 1:09:38 AM1/14/13
to dcm...@googlegroups.com
i got error that the images are all successfully received, however the #image shown in the dcm4che-web is not correct (it show 0).
I further checked the log it show the following:

http://org.dcm4chex.archive.dcm.storescp.StoreScpService failed to update DB Series Recordhttp://iuid=1.3.12.2.1107.5.2.32.35166.30000012122901371814000001609 - retry
org.jboss.tm.JBossTransactionRolledbackException: null; nested exception is: 
java.lang.IllegalStateException: http://com.arjuna.ats.internal.jta.transaction.arjunacore.inactivehttp://com.arjuna.ats.internal.jta.transaction.arjunacore.inactive The transaction is not active!; - nested throwable: (java.lang.IllegalStateException:http://com.arjuna.ats.internal.jta.transaction.arjunacore.inactive http://com.arjuna.ats.internal.jta.transaction.arjunacore.inactive The transaction is not active!)
at org.jboss.ejb.plugins.TxInterceptorCMT.throwJBossException(TxInterceptorCMT.java:574)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:522)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:361)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at sun.reflect.GeneratedMethodAccessor192.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
at org.jboss.invocation.local.LocalInvoker$MBeanServerAction.invoke(LocalInvoker.java:169)
at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:118)
at org.jboss.invocation.InvokerInterceptor.invokeLocal(InvokerInterceptor.java:209)
at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:195)
at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:61)
at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:70)
at org.jboss.proxy.ejb.StatelessSessionInterceptor.invoke(StatelessSessionInterceptor.java:112)
at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:100)
at $Proxy214.updateSeries(Unknown Source)
at org.dcm4chex.archive.dcm.storescp.StoreScp.updateDBSeries(StoreScp.java:1136)
at org.dcm4chex.archive.dcm.storescp.StoreScp.doAfterSeriesIsStored(StoreScp.java:1086)
at org.dcm4chex.archive.dcm.storescp.StoreScp.closing(StoreScp.java:1050)
at org.dcm4cheri.net.Multicaster.closing(Multicaster.java:122)
at org.dcm4cheri.net.Multicaster.closing(Multicaster.java:121)
at org.dcm4cheri.net.FsmImpl$1.entry(FsmImpl.java:969)
at org.dcm4cheri.net.FsmImpl.changeState(FsmImpl.java:464)
at org.dcm4cheri.net.FsmImpl.access$300(FsmImpl.java:76)
at org.dcm4cheri.net.FsmImpl$13.entry(FsmImpl.java:1502)
at org.dcm4cheri.net.FsmImpl.changeState(FsmImpl.java:464)
at org.dcm4cheri.net.FsmImpl.access$300(FsmImpl.java:76)
at org.dcm4cheri.net.FsmImpl$8.write(FsmImpl.java:1341)
at org.dcm4cheri.net.FsmImpl.write(FsmImpl.java:630)
at org.dcm4cheri.net.DimseReaderImpl.nextPDataTF(DimseReaderImpl.java:197)
at org.dcm4cheri.net.DimseReaderImpl.nextPDV(DimseReaderImpl.java:168)
at org.dcm4cheri.net.DimseReaderImpl.read(DimseReaderImpl.java:78)
at org.dcm4cheri.net.AssociationImpl.read(AssociationImpl.java:312)
at org.dcm4cheri.net.ActiveAssociationImpl.run(ActiveAssociationImpl.java:212)
at org.dcm4cheri.util.LF_ThreadPool.join(LF_ThreadPool.java:174)
at org.dcm4cheri.net.ActiveAssociationImpl.run(ActiveAssociationImpl.java:157)
at org.dcm4cheri.server.DcmHandlerImpl.handle(DcmHandlerImpl.java:249)
at org.dcm4cheri.server.ServerImpl.run(ServerImpl.java:279)
at org.dcm4cheri.util.LF_ThreadPool.join(LF_ThreadPool.java:174)
at org.dcm4cheri.util.LF_ThreadPool$1.run(LF_ThreadPool.java:221)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.IllegalStateException: http://com.arjuna.ats.internal.jta.transaction.arjunacore.inactivehttp://com.arjuna.ats.internal.jta.transaction.arjunacore.inactive The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
... 49 more

roadm...@gmail.com

unread,
Jan 14, 2013, 9:51:44 PM1/14/13
to dcm...@googlegroups.com
The dcm4chee-web (2.13.4) is run on window 2008, 64bit. Anyone get idea?

roadm...@gmail.com

unread,
Jan 16, 2013, 9:27:56 PM1/16/13
to dcm...@googlegroups.com
Urgent!

Mark Messer

unread,
Jan 18, 2013, 6:41:29 PM1/18/13
to dcm...@googlegroups.com
After an image is received, dcm4chee starts a timer. If the timeout elapses without another image for the same series being received, dcm4chee assumes the entire series has been received and does some processing. In this case, it looks like the process is wrapped in a transaction. The transaction fails, and rollback fails. 

Is this standard dcm4chee?

I found this ancient document that describes Arjuna.

http://www.google.com/url?sa=t&rct=j&q=&esrc=s&source=web&cd=4&sqi=2&ved=0CEUQFjAD&url=http%3A%2F%2Fciteseerx.ist.psu.edu%2Fviewdoc%2Fdownload%3Fdoi%3D10.1.1.64.3983%26rep%3Drep1%26type%3Dpdf&ei=v9r5UImBBbDmiwKusIHIBg&usg=AFQjCNHh2omZXSdBQWzNxz96R6GqpaEICg&bvm=bv.41248874,d.cGE&cad=rja


roadm...@gmail.com

unread,
Jan 22, 2013, 11:33:57 PM1/22/13
to dcm...@googlegroups.com
what do you mean by "standard dcm4chee"?
We are using dcm4chee 2.13.x (a very old version).

what seem to be the root cause?

Mark Messer

unread,
Jan 23, 2013, 10:13:03 AM1/23/13
to dcm...@googlegroups.com

The root cause is that arjuna transaction manager is not running.

I don't recognize arjuna. I was wondering if it is part of dcm4chee, part of JBoss, or something custom for that installation.

roadm...@gmail.com

unread,
Jan 24, 2013, 1:13:53 AM1/24/13
to dcm...@googlegroups.com
this issue occur not very frequent. In what situation of dcm4chee could trigger this error?

Mark Messer

unread,
Jan 24, 2013, 8:18:34 AM1/24/13
to dcm...@googlegroups.com
I googled arjuna The transaction is not active.
 
It seems to be part of JBoss. See this post

roadm...@gmail.com

unread,
Jan 28, 2013, 12:53:03 AM1/28/13
to dcm...@googlegroups.com
Thank for your reply again.
I would like to know the scenario causing this error so that i could reproduce it in the testing environment.
This is the ensure the correct fix be tested before applying to production

Mark Messer

unread,
Jan 28, 2013, 11:44:53 AM1/28/13
to dcm...@googlegroups.com
For an intermittent bug, finding the cause so you can reproduce it is often the key to fixing it. Unfortunately, it is not always easy.
 
From the log, this is a problem that occurs after a series is received. You say it does not happen frequently. Do you mean that every so often, one series fails, but the series before and after succeed? Or does the problem persist for a few series, and then go away? Does it persist for every series in the same study? Or does it start, and then not go away until you restart dcm4chee? Any pattern like this may help troubleshoot.
 
The snippet from the log shows an exception. This is useful information, but it is all information from the end of the failure. It does not show problems that lead up to the failure. It is like a photo of a car crashed into a tree. The cause may have been a blown out tire that made the car swerve, or perhaps it was an oil slick on the road. The photo may not show enough to help figure it out. If the log is not too large, attach the whole thing. Otherwise, extract all the lines pertaining to the study that had the problem, and attach them to a post.
 

roadm...@gmail.com

unread,
Jan 30, 2013, 4:54:10 AM1/30/13
to dcm...@googlegroups.com
Sorry, i tried to attach a file but its failed many times.

2012-12-29 21:33:24,019 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4cheri.net.FsmImpl] received [pc-3] 12:C_STORE_RQ with Dataset
class: 1.2.840.10008.5.1.4.1.1.4/MR Image Storage
inst: 1.3.12.2.1107.5.2.32.35166.30013012122903482487500000399/?
2012-12-29 21:33:24,988 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.dcm.storescp.StoreScpService] M-WRITE file:D:\dcm4chee-mysql-2.13.4\server\default\archive\2012\12\30\21\073A3BED\FD635DA8\FD635DC9
2012-12-29 21:33:24,988 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserting instance FileMetaInfo[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000399
class=1.2.840.10008.5.1.4.1.1.4/MR Image Storage
ts=1.2.840.10008.1.2.4.70/JPEG Lossless, Non- Hierarchical, First-Order Prediction (Process 14 [Selection Value 1])
impl=1.2.40.0.13.1.1-dcm4che-1.4.16]
2012-12-29 21:33:26,067 WARN  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.StudyBean] Coerce (0032,000A) Study Status ID,CS,*0,#0,[] to (0032,000A) Study Status ID,CS,*1,#8,[MATCHED ]
2012-12-29 21:33:26,082 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.InstanceBean] Created Instance[pk=724203, iuid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000399, cuid=1.2.840.10008.5.1.4.1.1.4, series->ejb/Series:11329]
2012-12-29 21:33:26,082 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.FileBean] Created File[pk=726137, filepath=2012/12/29/21/073A3BED/FD635DA8/FD635DC9, tsuid=1.2.840.10008.1.2.4.70, filesystem->ejb/FileSystem:1, inst->ejb/Instance:724203]
2012-12-29 21:33:26,082 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserted records for instance[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000399]
2012-12-29 21:33:26,129 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4cheri.net.FsmImpl] sending [pc-3] 12:C_STORE_RSP
class: 1.2.840.10008.5.1.4.1.1.4/MR Image Storage
inst: 1.3.12.2.1107.5.2.32.35166.30013012122903482487500000399/?
status: 0
2012-12-29 21:33:26,145 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4cheri.net.FsmImpl] received [pc-3] 13:C_STORE_RQ with Dataset
class: 1.2.840.10008.5.1.4.1.1.4/MR Image Storage
inst: 1.3.12.2.1107.5.2.32.35166.30013012122903482487500000400/?
2012-12-29 21:33:27,036 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.dcm.storescp.StoreScpService] M-WRITE file:D:\dcm4chee-mysql-2.13.4\server\default\archive\2012\12\30\21\073A3BED\FD635DA8\FD63606A
2012-12-29 21:33:27,051 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserting instance FileMetaInfo[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000400
class=1.2.840.10008.5.1.4.1.1.4/MR Image Storage
ts=1.2.840.10008.1.2.4.70/JPEG Lossless, Non- Hierarchical, First-Order Prediction (Process 14 [Selection Value 1])
impl=1.2.40.0.13.1.1-dcm4che-1.4.16]
2012-12-29 21:33:28,098 WARN  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.StudyBean] Coerce (0032,000A) Study Status ID,CS,*0,#0,[] to (0032,000A) Study Status ID,CS,*1,#8,[MATCHED ]
2012-12-29 21:33:28,098 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.InstanceBean] Created Instance[pk=724204, iuid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000400, cuid=1.2.840.10008.5.1.4.1.1.4, series->ejb/Series:11329]
2012-12-29 21:33:28,098 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.FileBean] Created File[pk=726138, filepath=2012/12/29/21/073A3BED/FD635DA8/FD63606A, tsuid=1.2.840.10008.1.2.4.70, filesystem->ejb/FileSystem:1, inst->ejb/Instance:724204]
2012-12-29 21:33:28,098 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserted records for instance[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000400]
2012-12-29 21:33:28,114 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4cheri.net.FsmImpl] sending [pc-3] 13:C_STORE_RSP
class: 1.2.840.10008.5.1.4.1.1.4/MR Image Storage
inst: 1.3.12.2.1107.5.2.32.35166.30013012122903482487500000400/?
status: 0
2012-12-29 21:33:28,130 ERROR SOURCE1->DESTINATION2 (TCPServer-1-87) [org.jboss.ejb.plugins.cmp.jdbc.JDBCJBossQLQuery.Series#ejbSelectNumberOfSeriesRelatedInstancesOnMediaWithStatus] Find failed
org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6791 status: ActionStatus.ABORTING >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6791 status: ActionStatus.ABORTING >)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:225)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:144)
at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCSelectorBridge.execute(JDBCSelectorBridge.java:113)
at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCSelectorBridge.invoke(JDBCSelectorBridge.java:83)
at org.jboss.ejb.plugins.cmp.bridge.EntityBridgeInvocationHandler.invoke(EntityBridgeInvocationHandler.java:105)
at org.jboss.proxy.compiler.Runtime.invoke(Runtime.java:76)
at org.dcm4chex.archive.ejb.entity.SeriesCMP$Proxy.ejbSelectNumberOfSeriesRelatedInstancesOnMediaWithStatus(<generated>)
at org.dcm4chex.archive.ejb.entity.SeriesBean.updateFilesetId(SeriesBean.java:746)
at org.dcm4chex.archive.ejb.entity.SeriesBean.updateDerivedFields(SeriesBean.java:784)
at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.EntityContainer$ContainerInterceptor.invoke(EntityContainer.java:1187)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCRelationInterceptor.invoke(JDBCRelationInterceptor.java:87)
at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invoke(EntitySynchronizationInterceptor.java:284)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:126)
at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:278)
at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:104)
at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:76)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:527)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:65)
at $Proxy152.updateDerivedFields(Unknown Source)
at org.dcm4chex.archive.ejb.session.StorageBean.updateSeries(StorageBean.java:519)
at sun.reflect.GeneratedMethodAccessor256.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6791 status: ActionStatus.ABORTING >
at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:304)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:396)
at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
... 92 more
2012-12-29 21:33:28,130 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id -5faba6b1:e74b:50c29cdd:5f6a21 invoked while multiple threads active within it.
2012-12-29 21:33:28,130 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action -5faba6b1:e74b:50c29cdd:5f6a21 aborting with 1 threads active!
2012-12-29 21:33:28,130 ERROR SOURCE1->DESTINATION2 (TCPServer-1-87) [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackException in method: public abstract void org.dcm4chex.archive.ejb.interfaces.Storage.updateSeries(java.lang.String) throws javax.ejb.FinderException,java.rmi.RemoteException, causedBy:
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
2012-12-29 21:33:28,130 WARN  SOURCE1->DESTINATION2 (TCPServer-1-87) [org.dcm4chex.archive.dcm.storescp.StoreScpService] failed to update DB Series Record [iuid=1.3.12.2.1107.5.2.32.35166.30000012122901371814000001609] - retry
org.jboss.tm.JBossTransactionRolledbackException: null; nested exception is: 
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!; - nested throwable: (java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!)
Caused by: java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
... 49 more
2012-12-29 21:33:28,145 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4cheri.net.FsmImpl] received [pc-3] 14:C_STORE_RQ with Dataset
class: 1.2.840.10008.5.1.4.1.1.4/MR Image Storage
inst: 1.3.12.2.1107.5.2.32.35166.30013012122903482487500000401/?
2012-12-29 21:33:28,161 ERROR SOURCE1->DESTINATION2 (TCPServer-1-84) [org.jboss.ejb.plugins.cmp.jdbc.JDBCJBossQLQuery.Series#ejbSelectAvailability] Find failed
org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6a21 status: ActionStatus.ABORTING >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6a21 status: ActionStatus.ABORTING >)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:225)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:144)
at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCSelectorBridge.execute(JDBCSelectorBridge.java:113)
at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCSelectorBridge.invoke(JDBCSelectorBridge.java:83)
at org.jboss.ejb.plugins.cmp.bridge.EntityBridgeInvocationHandler.invoke(EntityBridgeInvocationHandler.java:105)
at org.jboss.proxy.compiler.Runtime.invoke(Runtime.java:76)
at org.dcm4chex.archive.ejb.entity.SeriesCMP$Proxy.ejbSelectAvailability(<generated>)
at org.dcm4chex.archive.ejb.entity.SeriesBean.updateAvailability(SeriesBean.java:722)
at org.dcm4chex.archive.ejb.entity.SeriesBean.updateDerivedFields(SeriesBean.java:786)
at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.EntityContainer$ContainerInterceptor.invoke(EntityContainer.java:1187)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCRelationInterceptor.invoke(JDBCRelationInterceptor.java:87)
at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invoke(EntitySynchronizationInterceptor.java:284)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:126)
at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:278)
at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:104)
at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:76)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:527)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:65)
at $Proxy152.updateDerivedFields(Unknown Source)
at org.dcm4chex.archive.ejb.session.StorageBean.updateSeries(StorageBean.java:519)
at sun.reflect.GeneratedMethodAccessor256.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6a21 status: ActionStatus.ABORTING >
at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:304)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:396)
at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
... 92 more
2012-12-29 21:33:28,161 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id -5faba6b1:e74b:50c29cdd:5f6f44 invoked while multiple threads active within it.
2012-12-29 21:33:28,161 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action -5faba6b1:e74b:50c29cdd:5f6f44 aborting with 1 threads active!
2012-12-29 21:33:28,161 ERROR SOURCE1->DESTINATION2 (TCPServer-1-84) [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackException in method: public abstract void org.dcm4chex.archive.ejb.interfaces.Storage.updateSeries(java.lang.String) throws javax.ejb.FinderException,java.rmi.RemoteException, causedBy:
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
2012-12-29 21:33:28,161 WARN  SOURCE1->DESTINATION2 (TCPServer-1-84) [org.dcm4chex.archive.dcm.storescp.StoreScpService] failed to update DB Series Record [iuid=1.3.12.2.1107.5.2.32.35166.30000012122901371814000001769] - retry
org.jboss.tm.JBossTransactionRolledbackException: null; nested exception is: 
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!; - nested throwable: (java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!)
Caused by: java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
... 49 more
2012-12-29 21:33:28,176 ERROR SOURCE1->DESTINATION2 (TCPServer-1-86) [org.jboss.ejb.plugins.cmp.jdbc.JDBCJBossQLQuery.Series#ejbSelectAvailability] Find failed
org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6f44 status: ActionStatus.ABORTING >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6f44 status: ActionStatus.ABORTING >)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:225)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCAbstractQueryCommand.execute(JDBCAbstractQueryCommand.java:144)
at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCSelectorBridge.execute(JDBCSelectorBridge.java:113)
at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCSelectorBridge.invoke(JDBCSelectorBridge.java:83)
at org.jboss.ejb.plugins.cmp.bridge.EntityBridgeInvocationHandler.invoke(EntityBridgeInvocationHandler.java:105)
at org.jboss.proxy.compiler.Runtime.invoke(Runtime.java:76)
at org.dcm4chex.archive.ejb.entity.SeriesCMP$Proxy.ejbSelectAvailability(<generated>)
at org.dcm4chex.archive.ejb.entity.SeriesBean.updateAvailability(SeriesBean.java:722)
at org.dcm4chex.archive.ejb.entity.SeriesBean.updateDerivedFields(SeriesBean.java:786)
at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.EntityContainer$ContainerInterceptor.invoke(EntityContainer.java:1187)
at org.jboss.ejb.plugins.cmp.jdbc.JDBCRelationInterceptor.invoke(JDBCRelationInterceptor.java:87)
at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invoke(EntitySynchronizationInterceptor.java:284)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:126)
at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:278)
at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:104)
at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:76)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:527)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:65)
at $Proxy152.updateDerivedFields(Unknown Source)
at org.dcm4chex.archive.ejb.session.StorageBean.updateSeries(StorageBean.java:519)
at sun.reflect.GeneratedMethodAccessor256.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6f44 status: ActionStatus.ABORTING >
at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:304)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:396)
at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
... 92 more
2012-12-29 21:33:28,176 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id -5faba6b1:e74b:50c29cdd:5f7818 invoked while multiple threads active within it.
2012-12-29 21:33:28,176 ERROR SOURCE1->DESTINATION2 (TCPServer-1-86) [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackException in method: public abstract void org.dcm4chex.archive.ejb.interfaces.Storage.updateSeries(java.lang.String) throws javax.ejb.FinderException,java.rmi.RemoteException, causedBy:
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
2012-12-29 21:33:28,176 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action -5faba6b1:e74b:50c29cdd:5f7818 aborting with 1 threads active!
2012-12-29 21:33:28,176 WARN  SOURCE1->DESTINATION2 (TCPServer-1-86) [org.dcm4chex.archive.dcm.storescp.StoreScpService] failed to update DB Series Record [iuid=1.3.12.2.1107.5.2.32.35166.3.2012122912131770964116975.0.0.0] - retry
org.jboss.tm.JBossTransactionRolledbackException: null; nested exception is: 
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!; - nested throwable: (java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!)
Caused by: java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commit(TransactionImple.java:225)
at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:501)
... 49 more
2012-12-29 21:33:29,036 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.dcm.storescp.StoreScpService] M-WRITE file:D:\dcm4chee-mysql-2.13.4\server\default\archive\2012\12\30\21\073A3BED\FD635DA8\FD63606B
2012-12-29 21:33:29,052 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserting instance FileMetaInfo[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000401
class=1.2.840.10008.5.1.4.1.1.4/MR Image Storage
ts=1.2.840.10008.1.2.4.70/JPEG Lossless, Non- Hierarchical, First-Order Prediction (Process 14 [Selection Value 1])
impl=1.2.40.0.13.1.1-dcm4che-1.4.16]
2012-12-29 21:33:29,099 INFO  SOURCE1->DESTINATION2 (TCPServer-1-83) [org.dcm4chex.archive.dcm.movescu.ForwardService2] 


2012-12-29 21:33:29,099 INFO  SOURCE1->DESTINATION2 (TCPServer-1-83) [org.dcm4chex.archive.dcm.movescu.ForwardService2] 


2012-12-29 21:33:29,099 INFO  SOURCE1->DESTINATION2 (TCPServer-1-83) [org.dcm4chex.archive.dcm.movescu.MoveScuService] Schedule order: MoveOrder[1 Series, dest=LOSSY01, qrscp=null, priority=0, failureCount=0]
2012-12-29 21:33:30,067 WARN  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.StudyBean] Coerce (0032,000A) Study Status ID,CS,*0,#0,[] to (0032,000A) Study Status ID,CS,*1,#8,[MATCHED ]
2012-12-29 21:33:30,067 INFO  -> (MessageListenerThread - MoveScu) [org.dcm4chex.archive.dcm.movescu.MoveScuService] 


2012-12-29 21:33:30,067 INFO  -> (MessageListenerThread - MoveScu) [org.dcm4chex.archive.dcm.movescu.MoveScuService] Start processing MoveOrder[1 Series, dest=LOSSY01, qrscp=null, priority=0, failureCount=0]
2012-12-29 21:33:30,067 INFO  -> (TCPServer-1-95) [org.dcm4cheri.server.ServerImpl] handle - Socket[addr=/160.128.128.79,port=561234,localport=48000]
2012-12-29 21:33:30,067 INFO  -> (TCPServer-1-95) [org.dcm4cheri.net.FsmImpl] Socket[addr=/160.128.128.79,port=561234,localport=48000]
2012-12-29 21:33:30,067 INFO  -> (MessageListenerThread - MoveScu) [org.dcm4cheri.net.FsmImpl] Socket[addr=/160.128.128.79,port=43000,localport=561234]
2012-12-29 21:33:30,067 INFO  DESTINATION2->DESTINATION2 (MessageListenerThread - MoveScu) [org.dcm4cheri.net.FsmImpl] sending AAssociateRQ
appCtxName: 1.2.840.10008.3.1.1.1/DICOM Application Context Name
implClass: 1.2.40.0.13.1.1
implVersion: dcm4che-1.4.16
calledAET: DESTINATION2
callingAET: DESTINATION2
maxPDULen: 16352
asyncOpsWindow:
pc-1: as=1.2.840.10008.5.1.4.1.2.1.2/Patient Root Query/Retrieve Information Model - MOVE
ts=1.2.840.10008.1.2/Implicit VR Little Endian
2012-12-29 21:33:30,067 INFO  DESTINATION2->DESTINATION2 (TCPServer-1-95) [org.dcm4cheri.net.FsmImpl] received AAssociateRQ
appCtxName: 1.2.840.10008.3.1.1.1/DICOM Application Context Name
implClass: 1.2.40.0.13.1.1
implVersion: dcm4che-1.4.16
calledAET: DESTINATION2
callingAET: DESTINATION2
maxPDULen: 16352
asyncOpsWindow:
pc-1: as=1.2.840.10008.5.1.4.1.2.1.2/Patient Root Query/Retrieve Information Model - MOVE
ts=1.2.840.10008.1.2/Implicit VR Little Endian
2012-12-29 21:33:30,067 INFO  DESTINATION2->DESTINATION2 (TCPServer-1-95) [org.dcm4cheri.net.FsmImpl] sending AAssociateAC
appCtxName: 1.2.840.10008.3.1.1.1/DICOM Application Context Name
implClass: 1.2.40.0.13.1.1
implVersion: dcm4che-1.4.16
calledAET: DESTINATION2
callingAET: DESTINATION2
maxPDULen: 16352
asyncOpsWindow:
pc-1: 0 - acceptance
ts=1.2.840.10008.1.2/Implicit VR Little Endian
2012-12-29 21:33:30,067 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.InstanceBean] Created Instance[pk=724205, iuid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000401, cuid=1.2.840.10008.5.1.4.1.1.4, series->ejb/Series:11329]
2012-12-29 21:33:30,067 INFO  DESTINATION2->DESTINATION2 (MessageListenerThread - MoveScu) [org.dcm4cheri.net.FsmImpl] received AAssociateAC
appCtxName: 1.2.840.10008.3.1.1.1/DICOM Application Context Name
implClass: 1.2.40.0.13.1.1
implVersion: dcm4che-1.4.16
calledAET: DESTINATION2
callingAET: DESTINATION2
maxPDULen: 16352
asyncOpsWindow:
pc-1: 0 - acceptance
ts=1.2.840.10008.1.2/Implicit VR Little Endian
2012-12-29 21:33:30,067 INFO  DESTINATION2->DESTINATION2 (MessageListenerThread - MoveScu) [org.dcm4cheri.net.FsmImpl] sending [pc-1] 1:C_MOVE_RQ with Dataset
class: 1.2.840.10008.5.1.4.1.2.1.2/Patient Root Query/Retrieve Information Model - MOVE
move dest: LOSSY01
2012-12-29 21:33:30,067 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.FileBean] Created File[pk=726139, filepath=2012/12/29/21/073A3BED/FD635DA8/FD63606B, tsuid=1.2.840.10008.1.2.4.70, filesystem->ejb/FileSystem:1, inst->ejb/Instance:724205]
2012-12-29 21:33:30,067 INFO  DESTINATION2->DESTINATION2 (TCPServer-1-95) [org.dcm4cheri.net.FsmImpl] received [pc-1] 1:C_MOVE_RQ with Dataset
class: 1.2.840.10008.5.1.4.1.2.1.2/Patient Root Query/Retrieve Information Model - MOVE
move dest: LOSSY01
2012-12-29 21:33:30,067 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserted records for instance[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000401]
2012-12-29 21:33:30,067 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4cheri.net.FsmImpl] sending [pc-3] 14:C_STORE_RSP
class: 1.2.840.10008.5.1.4.1.1.4/MR Image Storage
inst: 1.3.12.2.1107.5.2.32.35166.30013012122903482487500000401/?
status: 0
2012-12-29 21:33:30,083 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4cheri.net.FsmImpl] received [pc-3] 15:C_STORE_RQ with Dataset
class: 1.2.840.10008.5.1.4.1.1.4/MR Image Storage
inst: 1.3.12.2.1107.5.2.32.35166.30013012122903482487500000402/?
2012-12-29 21:33:31,083 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.dcm.storescp.StoreScpService] M-WRITE file:D:\dcm4chee-mysql-2.13.4\server\default\archive\2012\12\30\21\073A3BED\FD635DA8\FD63606C
2012-12-29 21:33:31,083 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserting instance FileMetaInfo[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000402
class=1.2.840.10008.5.1.4.1.1.4/MR Image Storage
ts=1.2.840.10008.1.2.4.70/JPEG Lossless, Non- Hierarchical, First-Order Prediction (Process 14 [Selection Value 1])
impl=1.2.40.0.13.1.1-dcm4che-1.4.16]
2012-12-29 21:33:31,130 WARN  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.StudyBean] Coerce (0032,000A) Study Status ID,CS,*0,#0,[] to (0032,000A) Study Status ID,CS,*1,#8,[MATCHED ]
2012-12-29 21:33:32,037 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.InstanceBean] Created Instance[pk=724206, iuid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000402, cuid=1.2.840.10008.5.1.4.1.1.4, series->ejb/Series:11329]
2012-12-29 21:33:32,052 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.entity.FileBean] Created File[pk=726140, filepath=2012/12/29/21/073A3BED/FD635DA8/FD63606C, tsuid=1.2.840.10008.1.2.4.70, filesystem->ejb/FileSystem:1, inst->ejb/Instance:724206]
2012-12-29 21:33:32,052 INFO  SOURCE1->DESTINATION2 (TCPServer-1-90) [org.dcm4chex.archive.ejb.session.StorageBean] inserted records for instance[uid=1.3.12.2.1107.5.2.32.35166.30013012122903482487500000402]

Mark Messer

unread,
Jan 30, 2013, 12:16:26 PM1/30/13
to dcm...@googlegroups.com
This snippet helps, but I think the entire log will be needed to understand the problem. I expect it is huge. The size may be the reason you cannot attach it. Perhaps Damien can help with this? Is there a way to make large files available in the Google Group?
---
The first thing to notice is that several DICOM associations are being processed at the same time. The logs statements are interleaved. The associations are identified by (TCPServer-1-83), (TCPServer-1-84), (TCPServer-1-86), (TCPServer-1-87), (TCPServer-1-90), and (TCPServer-1-95). A few log statements are identified with (MessageListenerThread - MoveScu) or (Thread-3).
Most statements are from (TCPServer-1-90). It is storing images. If you extract those statments from the log, you will see that this association is not affected by the errors.
(MessageListenerThread - MoveScu) is processing a move order that starts up (TCPServer-1-95) near the end of the snippet. This does not appear to be affected by errors.
The exceptions are from (TCPServer-1-84), (TCPServer-1-86), and (TCPServer-1-87). The (Thread-3) statements are from Arjuna trying to roll back transactions. If the exceptions are removed, these statements are much shorter.
 2012-12-29 21:33:28,130 ERROR SOURCE1->DESTINATION2 (TCPServer-1-87) [org.jboss.ejb.plugins.cmp.jdbc.JDBCJBossQLQuery.Series#ejbSelectNumberOfSeriesRelatedInstancesOnMediaWithStatus] Find failed
 2012-12-29 21:33:28,130 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id -5faba6b1:e74b:50c29cdd:5f6a21 invoked while multiple threads active within it.
 2012-12-29 21:33:28,130 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action -5faba6b1:e74b:50c29cdd:5f6a21 aborting with 1 threads active!
 2012-12-29 21:33:28,130 ERROR SOURCE1->DESTINATION2 (TCPServer-1-87) [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackException in method: public abstract void
 2012-12-29 21:33:28,130 WARN  SOURCE1->DESTINATION2 (TCPServer-1-87) [org.dcm4chex.archive.dcm.storescp.StoreScpService] failed to update DB Series Record [iuid=1.3.12.2.1107.5.2.32.35166.30000012122901371814000001609] - retry
 2012-12-29 21:33:28,161 ERROR SOURCE1->DESTINATION2 (TCPServer-1-84) [org.jboss.ejb.plugins.cmp.jdbc.JDBCJBossQLQuery.Series#ejbSelectAvailability] Find failed
 2012-12-29 21:33:28,161 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id -5faba6b1:e74b:50c29cdd:5f6f44 invoked while multiple threads active within it.
 2012-12-29 21:33:28,161 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action -5faba6b1:e74b:50c29cdd:5f6f44 aborting with 1 threads active!
 2012-12-29 21:33:28,161 ERROR SOURCE1->DESTINATION2 (TCPServer-1-84) [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackException in method: public abstract void
 2012-12-29 21:33:28,161 WARN  SOURCE1->DESTINATION2 (TCPServer-1-84) [org.dcm4chex.archive.dcm.storescp.StoreScpService] failed to update DB Series Record [iuid=1.3.12.2.1107.5.2.32.35166.30000012122901371814000001769] - retry
 2012-12-29 21:33:28,176 ERROR SOURCE1->DESTINATION2 (TCPServer-1-86) [org.jboss.ejb.plugins.cmp.jdbc.JDBCJBossQLQuery.Series#ejbSelectAvailability] Find failed
 2012-12-29 21:33:28,176 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id -5faba6b1:e74b:50c29cdd:5f7818 invoked while multiple threads active within it.
 2012-12-29 21:33:28,176 ERROR SOURCE1->DESTINATION2 (TCPServer-1-86) [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackException in method: public abstract void
 2012-12-29 21:33:28,176 WARN  -> (Thread-3) [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action -5faba6b1:e74b:50c29cdd:5f7818 aborting with 1 threads active!
 2012-12-29 21:33:28,176 WARN  SOURCE1->DESTINATION2 (TCPServer-1-86) [org.dcm4chex.archive.dcm.storescp.StoreScpService] failed to update DB Series Record
(TCPServer-1-83) is the earliest association, even though its statements are after the others. Perhaps the problem started here. It is interesting that qrscp=null. On the other hand, (TCPServer-1-83) is forwarding images. This is typically done after a series is received. Perhaps the problem started when the series was received.

roadm...@gmail.com

unread,
Feb 6, 2013, 4:28:42 AM2/6/13
to dcm...@googlegroups.com
i am not sure if it is relate to the busy of mysql db...
Sigh, still cant figure out what it is

roadm...@gmail.com

unread,
Feb 8, 2013, 4:49:19 AM2/8/13
to dcm...@googlegroups.com
anyone know how to check mysql log under the dcm4chee?

roadm...@gmail.com

unread,
Feb 19, 2013, 4:48:42 AM2/19/13
to dcm...@googlegroups.com
I checked that the dcm4chee throws exception when perform the following action (before update the series#)


"[org.jboss.ejb.plugins.cmp.jdbc.JDBCJBossQLQuery.Series#ejbSelectNumberOfSeriesRelatedInstancesOnMediaWithStatus] Find failed
org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6791 status: ActionStatus.ABORTING >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -5faba6b1:e74b:50c29cdd:5f6791 status: ActionStatus.ABORTING >)"

this give a hint that there may be timeout from MySQL

roadm...@gmail.com

unread,
Apr 28, 2013, 11:25:42 PM4/28/13
to
Still no idea, even i turned on the logging in mySQL. Anyone could help?

btw, the "Handler_read_rnd_next" of mySQL is high..as some SQL statement from dcm4che does not use the index. Is it normal?

roadm...@gmail.com

unread,
Apr 28, 2013, 11:26:35 PM4/28/13
to dcm...@googlegroups.com
Anyone could help?


On Friday, April 19, 2013 4:16:39 PM UTC+8, roadm...@gmail.com wrote:
Still no idea, even i turned on the logging in mySQL. Anyone could help?

btw, the "Handler_read_rnd_next" of mySQL is high..as some SQL statement from dcm4che does not use the index. Is it normal?

On Tuesday, February 19, 2013 5:48:42 PM UTC+8, roadm...@gmail.com wrote:
Reply all
Reply to author
Forward
0 new messages