java.net.SocketTimeoutException: Read timed out

  • Hi,


    When I'm trying to pull large studies(12GB or more) from conquest to another PACS, it's throwing the socket time out error. Can you please let me know, what might be causing the issue?

    It works fine with smaller studies.



    Thanks,

    Rohan

  • It happens whenever we are sending multiple studies and one or more among the studies are large in size.

    Can we modify the default time out seconds?

    I'm using version: 1.4.19b


    This is the error description, we are getting:


    2019-02-11 11:47:06 EST ERROR-|DicomServiceTemplate:248| Exception while read operation: Read timed out

    java.net.SocketTimeoutException: Read timed out

    at java.net.SocketInputStream.socketRead0(Native Method)[:1.8.0_65]

    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)[:1.8.0_65]

    at java.net.SocketInputStream.read(SocketInputStream.java:170)[:1.8.0_65]

    at java.net.SocketInputStream.read(SocketInputStream.java:141)[:1.8.0_65]

    at com.archimed.dicom.network.PduBuffer.readFully(PduBuffer.java:94)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    at com.archimed.dicom.network.PduBuffer.read(PduBuffer.java:71)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    at com.archimed.dicom.network.PduReader.read(PduReader.java:25)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    at com.archimed.dicom.network.AssociationIO.read(AssociationIO.java:87)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    ........

    ........

    .......

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]

    at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]

    Caused by: java.net.SocketTimeoutException: Read timed out

    at java.net.SocketInputStream.socketRead0(Native Method)[:1.8.0_65]

    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)[:1.8.0_65]

    at java.net.SocketInputStream.read(SocketInputStream.java:170)[:1.8.0_65]

    at java.net.SocketInputStream.read(SocketInputStream.java:141)[:1.8.0_65]

    at com.archimed.dicom.network.PduBuffer.readFully(PduBuffer.java:94)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    at com.archimed.dicom.network.PduBuffer.read(PduBuffer.java:71)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    at com.archimed.dicom.network.PduReader.read(PduReader.java:25)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    at com.archimed.dicom.network.AssociationIO.read(AssociationIO.java:87)[109:dicom-services-dicom-runtime-assembly:18.1.0]

    ....

  • Hi Marcel,


    Following is the Log from Conquest:


    [CONQUEST7119C] Monitoring for files in: d:\dicomserver\dicomserver1419d1\data\incoming

    [CONQUEST7119C] DGATE (1.5.0-alpha-test1, build Mon Mar 18 11:19:20 2019, bits 64) is running as threaded server

    [CONQUEST7119C] Database type: built-in SQLite driver

    [CONQUEST7119C] User interface test: local server is running!

    [CONQUEST7119C]

    [CONQUEST7119C] UPACS THREAD 1: STARTED AT: Tue May 14 11:48:21 2019

    [CONQUEST7119C] Calling Application Title : "EDGE"

    [CONQUEST7119C] Called Application Title : "CONQUEST7119C "

    [CONQUEST7119C] Application Context : "1.2.840.10008.3.1.1.1", PDU length: 64234

    [CONQUEST7119C] Presentation Context 0 "1.2.840.10008.5.1.4.1.2.2.1" 1

    [CONQUEST7119C] (StudyRootQuery) search level: STUDY

    [CONQUEST7119C] C-Find (StudyRoot) located 1 records

    [CONQUEST7119C] UPACS THREAD 1: ENDED AT: Tue May 14 11:48:22 2019

    [CONQUEST7119C] UPACS THREAD 1: TOTAL RUNNING TIME: 1 SECONDS

    [CONQUEST7119C]

    [CONQUEST7119C] UPACS THREAD 12: STARTED AT: Tue May 14 11:48:55 2019

    [CONQUEST7119C] Calling Application Title : "EDGE "

    [CONQUEST7119C] Called Application Title : "CONQUEST7119C "

    [CONQUEST7119C] Application Context : "1.2.840.10008.3.1.1.1", PDU length: 64234

    [CONQUEST7119C] Presentation Context 0 "1.2.840.10008.5.1.4.1.2.2.2" 1

    [CONQUEST7119C] C-Move Destination: "EDGE "

    [CONQUEST7119C] Number of Images to send: 97

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000001_15566491930000.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000002_15566491990001.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000003_15566492140002.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000004_15566492170003.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000005_15566492170004.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000006_15566492170005.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000007_15566492170006.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000008_15566492170007.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000009_15566492280008.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000010_15566492340009.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000011_1556649242000a.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000012_1556649243000b.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000013_1556649244000c.dcm

    [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000014_1556649249000d.dcm

    [CONQUEST7119C] ***VR:ReAlloc out of memory allocating 249521472 bytes

    [CONQUEST7119C] ***A fatal error occurred (out of memory) - closing server

  • Ah,


    that is a lot clearer. Can you run this on the command line (in the server folder) when the server is running?


    dgate --checklargestmalloc:


    This should printour how much memory is free. 249521472 bytes is a lot but not crazy. it should just do this.


    Marcel

    Marcel van Herk is developer of the Conquest DICOM server together with Lambert Zijp.

  • Hm,


    there may be a memory leak. Your error according at 250MB, yet this check showns 5000MB free. Can you restart the server and look at memory consumption in task manager as it runs.


    Thanks,


    Marcel

    Marcel van Herk is developer of the Conquest DICOM server together with Lambert Zijp.

  • Hello Mercel,


    The memory peaked at 97% while transferring the files. Following is the error it generated while kept the debugging level at "1":


    5/15/2019 12:28:53 PM [CONQUEST7119C] Sending file : d:\dicomserver\dicomserver1419d1\data\xxxxxxxxx\1.2.840.710410.0.785.32755.6926805104.189.7_0000_000009_15566492280008.dcm

    5/15/2019 12:28:53 PM [CONQUEST7119C] Image Loaded from Read Ahead Thread, returning TRUE

    5/15/2019 12:28:58 PM [CONQUEST7119C] ReadAheadThread: readahead > 0020

    5/15/2019 12:29:00 PM [CONQUEST7119C] ReadAheadThread: warning - resolving deadlock due to erratic incoming order

    5/15/2019 12:29:00 PM [CONQUEST7119C] ReadAheadThread: readahead > 0021

    5/15/2019 12:29:01 PM [CONQUEST7119C] ReadAheadThread: warning - resolving deadlock due to erratic incoming order

    5/15/2019 12:29:02 PM [CONQUEST7119C] ReadAheadThread: readahead > 0022

    5/15/2019 12:29:03 PM [CONQUEST7119C] ReadAheadThread: warning - resolving deadlock due to erratic incoming order

    5/15/2019 12:29:18 PM [CONQUEST7119C] ReadAheadThread: readahead > 0023

    5/15/2019 12:29:20 PM [CONQUEST7119C] ReadAheadThread: warning - resolving deadlock due to erratic incoming order

    5/15/2019 12:29:40 PM [CONQUEST7119C] Protocol error 0 in PDU:Read

    5/15/2019 12:29:40 PM [CONQUEST7119C] Retrieve: remote connection dropped after 8 images, 89 not sent


    Thanks,

    Rohan

  • Hi Marcel,


    Our application has 60 sec timeout.

    The Protocol error time difference is inconsistent:

    5/15/2019 12:48:15 PM [CONQUEST7119C] ReadAheadThread: warning - resolving deadlock due to erratic incoming order

    5/15/2019 12:48:23 PM [CONQUEST7119C] Protocol error 0 in PDU:Read



    Thanks,

    Rohan

  • Hi,


    what worries me also is that there are different errors. In any caes the "resolving deadlock" messgae is not an issue, that is an internal thing, But can you chnage the timout on the java side?


    Marcel

    Marcel van Herk is developer of the Conquest DICOM server together with Lambert Zijp.

  • # This file contains configuration information for the DICOM server

    # Do not edit unless you know what you are doing


    [sscscp]

    MicroPACS = sscscp


    # Network configuration: server name and TCP/IP port#

    MyACRNema = CONQUEST7119C

    TCPPort = 5679


    # Host, database, username and password for database

    SQLHost = localhost

    SQLServer = D:\dicomserver\dicomserver1419d1\Data\dbase\conquest.db3

    Username =

    Password =

    SqLite = 1

    DoubleBackSlashToDB = 0

    UseEscapeStringConstants = 0


    # Configure server

    ImportExportDragAndDrop = 1

    ZipTime = 05:

    UIDPrefix = 1.2.826.0.1.3680043.2.135.737131.84593541

    EnableComputedFields = 1


    FileNameSyntax = 4


    # Configuration of compression for incoming images and archival

    DroppedFileCompression = un

    IncomingCompression = un

    ArchiveCompression = as


    # For debug information

    PACSName = CONQUEST7119C

    OperatorConsole = 127.0.0.1

    DebugLevel = 1


    # Configuration of disk(s) to store images

    MAGDeviceFullThreshHold = 30

    MAGDevices = 1

    MAGDevice0 = d:\dicomserver\dicomserver1419d1\data\

  • Ok,


    nothing special. But where is the JK compression configured? And xan you see if the memory issue goes up per image, over over receiving multiple images, or for a single image. I assume it goes up when you are reading stuff from conquest.


    Marcel

    Marcel van Herk is developer of the Conquest DICOM server together with Lambert Zijp.

  • Hi,


    You can also try to add "ReadAheadThread=0" to the main section of dicom.ini. This would limit memory use. I have never seen issues with it though, but maybe when you are loading lots of very big objects at once and compressing them.


    Marcel

    Marcel van Herk is developer of the Conquest DICOM server together with Lambert Zijp.

  • Hello Marcel,


    It happens when we are trying to download multiple images. For example, the size of one study is 13 gb containing 97 images. I’ll try with the “read ahead thread”.


    Thanks,

    Rohan

  • Hi Marcel,


    We increased the memory from 4GB to 8GB. Still the read time out error is occurring. We tried with the ReadAhead thread = 0 as well, still didn't work.

    I've attached the screenshots for your reference.

    Here one thing I would like to mention is that, the OS(Windows memory manager) is probably killing the threads whenever CONQUEST is flooding the memory and reaching 100% usage. Can we limit the memory usage in any of the CONQUEST library files and compile the codes?


    Please let us know.


    Thanks,

    Rohan