ERROR org.nrg.dcm.CStoreService - C-STORE operation failed

[Ben Wagner]

Still trying to work out bugs in DICOM import to XNAT 1.6.5.  Left for the turkey day weekend and came back and noticed the error below.  I have a custom importer and recently updated to 1.6.5.  Maybe I missed something in the upgrade. the dicom-import-context.xml and the java code I run are included below.

Ben

2015-12-02 09:56:57,903 [pool-1-thread-8] ERROR org.nrg.dcm.CStoreService - C-STORE operation failed
org.nrg.action.ServerException: java.io.IOException: Invalid argument
        at org.nrg.xnat.archive.GradualDicomImporter.call(GradualDicomImporter.java:460)
        at org.nrg.dcm.CStoreService.doCStore(CStoreService.java:232)
        at org.nrg.dcm.CStoreService.cstore(CStoreService.java:195)
        at org.dcm4che2.net.DicomServiceRegistry.process(DicomServiceRegistry.java:238)
        at org.dcm4che2.net.NetworkApplicationEntity.perform(NetworkApplicationEntity.java:1158)
        at org.dcm4che2.net.Association.onDimseRQ(Association.java:979)
        at org.dcm4che2.net.PDUDecoder.decodeDIMSE(PDUDecoder.java:530)
        at org.dcm4che2.net.Association.onPDataTF(Association.java:956)
        at org.dcm4che2.net.State$Sta6.receivedPDataTF(State.java:239)
        at org.dcm4che2.net.Association.receivedPDataTF(Association.java:952)
        at org.dcm4che2.net.PDUDecoder.nextPDU(PDUDecoder.java:231)
        at org.dcm4che2.net.Association.run(Association.java:851)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: Invalid argument
        at sun.nio.ch.FileDispatcherImpl.lock0(Native Method)
        at sun.nio.ch.FileDispatcherImpl.lock(FileDispatcherImpl.java:90)
        at sun.nio.ch.FileChannelImpl.tryLock(FileChannelImpl.java:1063)
        at java.nio.channels.FileChannel.tryLock(FileChannel.java:1154)
        at org.nrg.xnat.helpers.prearchive.PrearcUtils.lockFile(PrearcUtils.java:737)
        at org.nrg.xnat.archive.GradualDicomImporter.call(GradualDicomImporter.java:455)
        ... 14 more


====================================================

[ansir_ext@ansir /XNAT/EXTERNAL/XNAT_BUILD/current]$cat plugin-resources/conf/dicom-import-context.xml
<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:context="http://www.springframework.org/schema/context"
xmlns:util="http://www.springframework.org/schema/util"
xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context.xsd http://www.springframework.org/schema/util http://www.springframework.org/schema/util/spring-util.xsd">
 
<bean name="dicomObjectIdentifier" class="org.nrg.dcm.id.ClassicDicomObjectIdentifier">
    <property name="userProvider" ref="receivedFileUserProvider" />
</bean>
 
<bean name="dicomSCPExecutor" class="java.util.concurrent.Executors"
factory-method="newCachedThreadPool" />
 
<bean name="ResearchProjectIdent" class="org.nrg.dcm.id.ResearchProjectIdentifer">
    <constructor-arg value=""/> <!--default project to go into if there is no match -->
</bean>
 
<bean name="baseSubjectIdent" class="org.nrg.dcm.id.ClassicDicomObjectIdentifier" factory-method="getSubjectExtractors"/>
<bean name="baseSessionIdent" class="org.nrg.dcm.id.ClassicDicomObjectIdentifier" factory-method="getSessionExtractors"/>
<bean name="baseAAIdent" class="org.nrg.dcm.id.ClassicDicomObjectIdentifier" factory-method="getAAExtractors"/>
 
<bean name="ResearchObjectIdent" class="org.nrg.dcm.id.CompositeDicomObjectIdentifier">
    <constructor-arg ref="ResearchProjectIdent"/>
    <constructor-arg ref="baseSubjectIdent"/>
    <constructor-arg ref="baseSessionIdent"/>
    <constructor-arg ref="baseAAIdent"/>
    <property name="userProvider" ref="receivedFileUserProvider"/>
</bean>
 
<util:map id="cstores">
    <entry key="RESEARCH" value-ref="ResearchObjectIdent"/>
    <entry key="XNAT" value-ref="dicomObjectIdentifier"/>
</util:map>
 
<bean name="dicomSCP" class="org.nrg.dcm.DicomSCP" factory-method="create">
    <constructor-arg ref="dicomSCPExecutor" />
    <constructor-arg value="4006" />
    <constructor-arg ref="receivedFileUserProvider" />
    <constructor-arg ref="cstores"/>
</bean>

<bean name="dicomSCPManager" class="org.nrg.dcm.DicomSCPManager">
  <constructor-arg ref="dicomSCP" />
</bean>

<bean name="sessionDataFactoryClasses" class="java.util.ArrayList" />

</beans>

====================================================

[ansir_ext@ansir /XNAT/EXTERNAL/XNAT_BUILD/current]$cat plugin-resources/webapp/xnat/java/org/nrg/dcm/id/ResearchProjectIdentifer.java
/**
 * 2013-04-03 BCW
 */
package org.nrg.dcm.id;

import org.dcm4che2.data.DicomObject;
import org.nrg.xdat.om.XnatProjectdata;
import org.nrg.xdat.security.XDATUser;

import java.util.SortedSet;
import java.util.TreeSet;
import org.dcm4che2.data.Tag;
import java.util.Hashtable;
import java.util.Enumeration;

//For Properties...
import java.io.FileInputStream;
import java.io.IOException;
import java.util.Properties;
import org.nrg.xft.XFT;


public final class ResearchProjectIdentifer implements DicomProjectIdentifier
{
        static org.apache.log4j.Logger logger = org.apache.log4j.Logger.getLogger(ResearchProjectIdentifer.class);

        private final String name;

        public ResearchProjectIdentifer(final String name)
        {
                this.name = name;
        }

        public SortedSet<Integer> getTags()
        {
                return new TreeSet<Integer>();
        }

        public XnatProjectdata apply(XDATUser user, DicomObject o)
        {
                Hashtable<String,String> projectMappings = new Hashtable();

                Properties prop = new Properties();
                try
                {
                        //load a properties file
                        prop.load(new FileInputStream(XFT.GetConfDir()+"ResearchNamePrefixMapping.properties"));
                }
                catch (IOException ex)
                {
                        ex.printStackTrace();
                }

                logger.debug("Read " + prop.size() + " project mappingfrom properties file");


                String patName = o.getString(Tag.PatientName);
                Enumeration e = prop.propertyNames();
                while (e.hasMoreElements())
                {
                        String key = (String) e.nextElement();
                        String value = prop.getProperty(key);
                        logger.debug("Checking patient name '"+ patName +"' to project "+ key);

                        if (patName.length() < key.length())
                                continue;
                        if (patName.substring(0,key.length()).toUpperCase().equals(key.toUpperCase()))
                        {
                                logger.info("Matched patient name '"+ patName +"' to project "+ key);
                                return XnatProjectdata.getProjectByIDorAlias(value, user, false);
                        }
                }
                logger.info("No matches for patient name '"+ patName +"' in " + prop.size() + " projects");
                return XnatProjectdata.getProjectByIDorAlias(name, user, false);
        }
}

[Herrick, Rick]

That’s really weird. Assuming your PrearcUtils code is in sync, this is where that failure is occurring:

lock=channel.tryLock();

Searching for that exception and message coming out of that code turns up some pretty old bugs in OpenJDK and some possible issues with how Windows handles file locking, but you’re not on Windows and the bugs I found are marked as fixed as far back as versions of OpenJDK 5. I don’t think it’s related to your custom importer at all, since I think that this is all happening before any custom importers would even be invoked.

Man Ben, I think you were born under a bad sign or something :)

-- 

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

(314) 740-5961

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

 

---

The materials in this message are private and may contain Protected Healthcare Information or other information of a sensitive nature. If you are not the intended recipient, be advised that any unauthorized use, disclosure, copying or the taking of any action in reliance on the contents of this information is strictly prohibited. If you have received this email in error, please immediately notify the sender via telephone or return mail.

[Ben Wagner]

Some sort of nasty sign......  On another installation I'm getting this now.  I think I need a redo of today.....

2015-12-02 11:42:17,528 [pool-1-thread-3] ERROR org.nrg.dcm.CStoreService - C-STORE operation failed
org.nrg.action.ServerException: java.io.IOException: No locks available

        at org.nrg.xnat.archive.GradualDicomImporter.call(GradualDicomImporter.java:460)
        at org.nrg.dcm.CStoreService.doCStore(CStoreService.java:232)
        at org.nrg.dcm.CStoreService.cstore(CStoreService.java:195)
        at org.dcm4che2.net.DicomServiceRegistry.process(DicomServiceRegistry.java:238)
        at org.dcm4che2.net.NetworkApplicationEntity.perform(NetworkApplicationEntity.java:1158)
        at org.dcm4che2.net.Association.onDimseRQ(Association.java:979)
        at org.dcm4che2.net.PDUDecoder.decodeDIMSE(PDUDecoder.java:530)
        at org.dcm4che2.net.Association.onPDataTF(Association.java:956)
        at org.dcm4che2.net.State$Sta6.receivedPDataTF(State.java:239)
        at org.dcm4che2.net.Association.receivedPDataTF(Association.java:952)
        at org.dcm4che2.net.PDUDecoder.nextPDU(PDUDecoder.java:231)
        at org.dcm4che2.net.Association.run(Association.java:851)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)

Caused by: java.io.IOException: No locks available

[Ben Wagner]

I thought this might have something to do with a storage migration that happened over the weekend.  I just tried changing (via the UI) the location of the pre-archive to local storage and get the same error (Invalid Argument [from first email]).

I have also cleaned up java mess.  RHEL makes me install OpenJDK (1.8) with tomcat.  However, I have tomcat using Oracle (1.7).  

I'm at a complete loss, but have got to get this thing moving soon.

Ben

[Ben Wagner]

Hi Rick,

OK, the storage issue seems to have cleared the issue with the "org.nrg.action.ServerException: java.io.IOException: No locks available".  I'm still experiencing the "org.nrg.action.ServerException: java.io.IOException: Invalid argument".

I'd setup another instance on this server to see if it something messed up in the config of this instance, but I can't do that because of that odd PostgresQL case issue oddity.

Ben

[Ben Wagner]

Hi Rick,

  Just some final follow up.  Both issues were cleared when our host providers changed some settings with file locking.  On system had the storage mounted via NFS and the other via CIFS.  Firewall issues cause the need for different mounting.  

Now back to the One Session Problem.....

Ugh,

Ben