CStoreSCP issue - CMove Delay

[Michael Rutherford]

My code is working except the small snag of it taking 4 minutes no matter if the request is for a single image or 300.

My C-Finds work fine and returns instantly. However, when I make a request for a c-move, it hits the PACS server, PACS makes an association request which is accepted, then it takes exactly 2 minutes before PACS will send me the image, then it takes ANOTHER 2 minutes (exactly) to get the "Success" response to my original request code.

I went back and forth with the PACS server administrator and neither of us could identify the problem from our logs. I thought for sure it was on their end.

Then yesterday, I tested my Fo-Dicom request code, but instead of using my fo-dicom cstore, I used dcm4che's storescp as the listening server and there was no delay whatsoever.

I REALLY want this CStore to work because it's my language and I'd like to capture some data inline, which I can't do without digging further into dcm4che than I want to.

Any help is greatly appreciated. Below are my output logs and code.

CStore Log:

(8/10/2017 6:41:31 PM) Starting C-Store SCP server on port 104
---------------------------------------------------------------------------
(8/10/2017 6:41:44 PM) CStoreSCP Constructor:  
(8/10/2017 6:41:44 PM)     Remote Host: *REMOVED*  
(8/10/2017 6:41:44 PM)      Local Host: *REMOVED*:104
(8/10/2017 6:41:44 PM) Association Request Received
(8/10/2017 6:41:44 PM)        CalledAE: RESEARCH
(8/10/2017 6:41:44 PM)       CallingAE: *REMOVED*
(8/10/2017 6:41:44 PM)          Result: Accept
(8/10/2017 6:41:44 PM) Association Response Sent
(8/10/2017 6:41:44 PM) Connection Closed
---------------------------------------------------------------------------
(8/10/2017 6:43:44 PM) CStoreSCP Constructor:  
(8/10/2017 6:43:44 PM)     Remote Host: *REMOVED*  
(8/10/2017 6:43:44 PM)      Local Host: *REMOVED*
(8/10/2017 6:43:44 PM) Association Request Received
(8/10/2017 6:43:44 PM)        CalledAE: RESEARCH
(8/10/2017 6:43:44 PM)       CallingAE: *REMOVED*
(8/10/2017 6:43:44 PM)          Result: Accept
(8/10/2017 6:43:45 PM) CStoreRequest Received:
(8/10/2017 6:43:45 PM)    AccessionNum: *REMOVED*
(8/10/2017 6:43:45 PM)        StudyNum: 1.2.392.200036.9125.2.212190217157136227.64849465321.25086250
(8/10/2017 6:43:45 PM)       SeriesNum: 1.2.392.200036.9125.3.212190217157136227.64849465321.25086252
(8/10/2017 6:43:45 PM)     InstanceNum: 1.2.392.200036.9125.9.0.420421674.68468436.2648302472
(8/10/2017 6:43:45 PM) CStoreRequest Received:
(8/10/2017 6:43:45 PM)    AccessionNum: *REMOVED*
(8/10/2017 6:43:45 PM)        StudyNum: 1.2.392.200036.9125.2.212190217157136227.64849465321.25086250
(8/10/2017 6:43:45 PM)       SeriesNum: 1.2.392.200036.9125.3.212190217157136227.64849466378.41601774
(8/10/2017 6:43:45 PM)     InstanceNum: 1.2.392.200036.9125.9.0.420422698.85507796.2648302472
(8/10/2017 6:43:45 PM) Association Response Sent
(8/10/2017 6:43:45 PM) Connection Closed

Request Log:

-----------------------------------------------------------------
(8/10/2017 6:41:37 PM) Image Retrieval Starting
-----------------------------------------------------------------
_____________________STUDY_____________________
Patient: *REMOVED*
Patient ID: *REMOVED*
Modalities: CR
Study: XR CHEST AP PORTABLE
Study Number: 0
Accession Number: *REMOVED*
Study Instance ID: 1.2.392.200036.9125.2.212190217157136227.64849465321.25086250
Study Date: *REMOVED* 12:00:00 AM
Series Count: 2

Study Find Response Status: Success

_____________________MOVE_____________________
(8/10/2017 6:41:38 PM) Sending Request for Study: 1.2.392.200036.9125.2.212190217157136227.64849465321.25086250
(8/10/2017 6:41:48 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:41:58 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:42:08 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:42:18 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:42:28 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:42:38 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:42:48 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:42:58 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:43:08 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:43:18 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:43:28 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:43:38 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:43:48 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:43:58 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:44:08 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:44:18 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:44:28 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:44:38 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:44:48 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:44:58 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:45:08 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:45:18 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:45:28 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:45:38 PM) Sending is in progress. please wait.. Pending
(8/10/2017 6:45:45 PM) Move Success: Success


(8/10/2017 6:45:46 PM) Move Complete for Study ID: 1.2.392.200036.9125.2.212190217157136227.64849465321.25086250


All move requests complete

Here's the code for my CStoreSCP Server:

using System;
using System.IO;
using System.Text;
using Dicom.Log;
using Dicom.Network;

namespace Dicom.CStoreSCP
{
    internal class Program
    {
        private static string StoragePath = @"C:\DICOM\Images";
        private static string LogPath = @"C:\DICOM\Log";

        private static void Main(string[] args)
        {
            var dict = DicomDictionary.Default;

            var port = 104;
            Log($"({DateTime.Now}) Starting C-Store SCP server on port {port} ");

            var server = DicomServer.Create<CStoreSCP>(port);

            Console.ReadLine();
        }

        public static void Log(string logMessage)
        {
            Console.WriteLine(logMessage);

            string logFile = Path.Combine(LogPath, DateTime.Now.ToString("yyyyMMdd", System.Globalization.CultureInfo.GetCultureInfo("en-US")) + "_CStoreSCPLog.txt");

            using (FileStream logFileStream = new FileStream(logFile, FileMode.Append, FileAccess.Write, FileShare.Write))
            {
                using (StreamWriter w = new StreamWriter(logFileStream))
                {
                    w.WriteLine(logMessage);
                }
            }
        }

        private class CStoreSCP : DicomService, IDicomServiceProvider, IDicomCStoreProvider, IDicomCEchoProvider
        {
            private static DicomTransferSyntax[] AcceptedTransferSyntaxes = new DicomTransferSyntax[]
                                                                                {
                                                                                    DicomTransferSyntax.ImplicitVRLittleEndian,
                                                                                    DicomTransferSyntax.ExplicitVRLittleEndian,
                                                                                    DicomTransferSyntax.ExplicitVRBigEndian
                                                                                };

            private static DicomTransferSyntax[] AcceptedImageTransferSyntaxes = new DicomTransferSyntax[]
                                                                                     {
                                                                                         // Uncompressed
                                                                                         DicomTransferSyntax.ImplicitVRLittleEndian,
                                                                                         DicomTransferSyntax.ExplicitVRLittleEndian,
                                                                                         DicomTransferSyntax.ExplicitVRBigEndian,

                                                                                         // Lossless
                                                                                         DicomTransferSyntax.JPEGLSLossless,
                                                                                         DicomTransferSyntax.JPEG2000Lossless,
                                                                                         DicomTransferSyntax.JPEGProcess14SV1,
                                                                                         DicomTransferSyntax.JPEGProcess14,
                                                                                         DicomTransferSyntax.RLELossless,

                                                                                         // Lossy
                                                                                         DicomTransferSyntax.JPEGLSNearLossless,
                                                                                         DicomTransferSyntax.JPEG2000Lossy,
                                                                                         DicomTransferSyntax.JPEGProcess1,
                                                                                         DicomTransferSyntax.JPEGProcess2_4,
                                                                                     };


            public CStoreSCP(INetworkStream stream, Encoding fallbackEncoding, Logger log)
                : base(stream, fallbackEncoding, log)
            {
                string logTxt =
                $"--------------------------------------------------------------------------- \r\n" +
                $"({DateTime.Now}) CStoreSCP Constructor:  \r\n" +
                $"({DateTime.Now})     Remote Host: {stream.RemoteHost}:{stream.RemotePort}  \r\n" +
                $"({DateTime.Now})      Local Host: {stream.LocalHost}:{stream.LocalPort}";
                Log(logTxt);
            }

            public void OnReceiveAssociationRequest(DicomAssociation association)
            {
                string logTxt =
                $"({DateTime.Now}) Association Request Received \r\n" +
                $"({DateTime.Now})        CalledAE: {association.CalledAE} \r\n" +
                $"({DateTime.Now})       CallingAE: {association.CallingAE}";
                Log(logTxt);

                if (association.CalledAE != "RESEARCH")
                {
                    SendAssociationReject(
                        DicomRejectResult.Permanent,
                        DicomRejectSource.ServiceUser,
                        DicomRejectReason.CalledAENotRecognized);

                    Log($"({DateTime.Now})      AE Invalid: {association.CalledAE}");

                    return;
                }

                foreach (var pc in association.PresentationContexts)
                {
                    if (pc.AbstractSyntax == DicomUID.Verification)
                    {
                        pc. AcceptTransferSyntaxes(AcceptedTransferSyntaxes);
                    }
                    else if (pc.AbstractSyntax.StorageCategory != DicomStorageCategory.None)
                    {
                        pc.AcceptTransferSyntaxes(AcceptedImageTransferSyntaxes);
                        Log($"({DateTime.Now})          Result: {pc.Result}");
                    }
                }

                SendAssociationAccept(association);
            }

            public void OnReceiveAssociationReleaseRequest()
            {
                Log($"({DateTime.Now}) Association Response Sent");
                SendAssociationReleaseResponse();
            }

            public void OnReceiveAbort(DicomAbortSource source, DicomAbortReason reason)
            {
                Log($"({DateTime.Now}) Receive Aborted: {reason.ToString()}");
            }

            public void OnConnectionClosed(Exception exception)
            {
                Log($"({DateTime.Now}) Connection Closed");
            }

            public DicomCStoreResponse OnCStoreRequest(DicomCStoreRequest request)
            {
                var patientMRN = request.Dataset.Get<string>(DicomTag.PatientID);
                var accessionNum = request.Dataset.Get<string>(DicomTag.AccessionNumber);
                var studyUid = request.Dataset.Get<string>(DicomTag.StudyInstanceUID);
                var seriesUid = request.Dataset.Get<string>(DicomTag.SeriesInstanceUID);
                var instanceUid = request.SOPInstanceUID.UID;

                string logTxt =
                $"({DateTime.Now}) CStoreRequest Received: \r\n" +
                $"({DateTime.Now})    AccessionNum: {accessionNum} \r\n" +
                $"({DateTime.Now})        StudyNum: {studyUid} \r\n" +
                $"({DateTime.Now})       SeriesNum: {seriesUid} \r\n" +
                $"({DateTime.Now})     InstanceNum: {instanceUid}";
                Log(logTxt);

                var path = Path.GetFullPath(Program.StoragePath);
                path = Path.Combine(path, patientMRN, accessionNum, studyUid, seriesUid);

                if (!Directory.Exists(path)) Directory.CreateDirectory(path);

                path = Path.Combine(path, instanceUid) + ".dcm";

                request.File.Save(path);

                return new DicomCStoreResponse(request, DicomStatus.Success);
            }

            public void OnCStoreRequestException(string tempFileName, Exception e)
            {
                Log($"({DateTime.Now}) CStore Request Exception: {e.Message}");
            }

            public DicomCEchoResponse OnCEchoRequest(DicomCEchoRequest request)
            {
                Log($"({DateTime.Now}) CEcho Request");
                return new DicomCEchoResponse(request, DicomStatus.Success);
            }
        }
    }
}

And the code for my request:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
using System.IO;
using System.Data;
using Dicom;
using Dicom.Network;
using Dicom.Log;

namespace DICOM_Image_Work
{
    internal class Program
    {
        private static string LogPath = @"C:\apps\DICOM\Log";
        private static string ServerHost = "**REMOVED**";
        private static int ServerPort = ####;
        private static string ServerAET = "**REMOVED**";

        private static string LocalAET = "RESEARCH";
        private static string AccessionNumber = "62967717";

        static void Main(string[] args)
        {
            Log("-----------------------------------------------------------------");
            Log($"({DateTime.Now}) Image Retrieval Starting");
            Log("-----------------------------------------------------------------");

            FindStudyByAccessionNumber(AccessionNumber);
            Console.ReadLine();
        }


        public static void Log(string logMessage)
        {
            Console.WriteLine(logMessage);

            string logFile = Path.Combine(LogPath, DateTime.Now.ToString("yyyyMMdd", System.Globalization.CultureInfo.GetCultureInfo("en-US")) + "_DicomRequestLog.txt");

            using (TextWriter w = File.AppendText(logFile))
            {
                w.WriteLine(logMessage);
            }
        }

        public static void FindStudyByAccessionNumber(string accessionNumber)
        {
            var cStudyFindRequest = DicomCFindRequest.CreateStudyQuery(accession: AccessionNumber);
            FindStudy(cStudyFindRequest);
        }

        public static void FindStudyByPatientID(string patientID)
        {
            var cStudyFindRequest = DicomCFindRequest.CreateStudyQuery(patientId: PatientID);
            FindStudy(cStudyFindRequest);
        }

        public static void FindStudyByPatientName(string patientName)
        {
            var cStudyFindRequest = DicomCFindRequest.CreateStudyQuery(patientName: PatientName);
            FindStudy(cStudyFindRequest);
        }

        public static void FindStudy(DicomCFindRequest cStudyFindRequest)
        {
            try
            {
                DicomClient client = new DicomClient();
                client.NegotiateAsyncOps();

                Log("_____________________STUDY_____________________ \r\n");

                bool? findComplete = null;

                List<string> studyUids = new List<string>();

                cStudyFindRequest.OnResponseReceived += (DicomCFindRequest study_request, DicomCFindResponse study_response) =>
                {
                    DisplayStudyResponse(study_response);

                    if (study_response.Status.State == DicomState.Pending)
                    {
                        studyUids.Add(study_response.Dataset?.Get<string>(DicomTag.StudyInstanceUID));
                        findComplete = false;
                    }
                    else if (study_response.Status.State == DicomState.Success)
                    {
                        findComplete = true;
                    }
                    else if (study_response.Status.State == DicomState.Failure)
                    {
                        findComplete = true;
                    }
                    else if (study_response.Status.State == DicomState.Warning)
                    {
                        findComplete = false;
                    }
                    else if (study_response.Status.State == DicomState.Cancel)
                    {
                        findComplete = true;
                    }
                };
                client.AddRequest(cStudyFindRequest);
                client.Send(ServerHost, ServerPort, false, LocalAET, ServerAET);

                while (findComplete != true)
                {
                    // Log("waiting...waiting....");
                }

                FindStudySeries(studyUids);
            }
            catch (Exception ex)
            {
                Log("Study Find Exception: " + ex.Message + "\r\n");
            }
        }

        public static void DisplayStudyResponse(DicomCFindResponse response)
        {
            try
            {
                if (response.Status == DicomStatus.Pending)
                {
                    Log($"Patient: {response.Dataset.Get<string>(DicomTag.PatientName)} \r\n" +
                                      $"Patient ID: {response.Dataset.Get<string>(DicomTag.PatientID)} \r\n" +
                                      $"Modalities: {response.Dataset.Get<string>(DicomTag.ModalitiesInStudy)} \r\n" +
                                      $"Study: {response.Dataset.Get<string>(DicomTag.StudyDescription)} \r\n" +
                                      $"Study Number: {response.Dataset.Get<string>(DicomTag.StudyID)} \r\n" +
                                      $"Accession Number: {response.Dataset.Get<string>(DicomTag.AccessionNumber)} \r\n" +
                                      $"Study Instance ID: {response.Dataset.Get<string>(DicomTag.StudyInstanceUID)} \r\n" +
                                      $"Study Date: {response.Dataset.Get<DateTime>(DicomTag.StudyDate)} \r\n" +
                                      $"Series Count: {response.Dataset.Get<string>(DicomTag.NumberOfStudyRelatedSeries)} \r\n");
                }
                else if (response.Status == DicomStatus.Success)
                {
                    Log("Study Find Response Status: " + response.Status.ToString() + "\r\n");
                }
            }
            catch (Exception ex)
            {
                Log("Study Find Response Exception: " + ex.Message + "\r\n");
            }
        }

        public static void FindStudySeries(List<string> studyUids)
        {
            try
            {
                DicomClient client = new DicomClient();
                client.NegotiateAsyncOps();

                foreach (string studyUid in studyUids)
                {
                    Log("_____________________SERIES_____________________ \r\n");

                    var cSeriesFindRequest = DicomCFindRequest.CreateSeriesQuery(studyInstanceUid: studyUid);

                    List<string> seriesUids = new List<string>();

                    bool? findComplete = null;

                    cSeriesFindRequest.OnResponseReceived += (DicomCFindRequest series_request, DicomCFindResponse series_response) =>
                    {
                        DisplaySeriesResponse(series_response);

                        if (series_response.Status.State == DicomState.Pending)
                        {
                            seriesUids.Add(series_response.Dataset?.Get<string>(DicomTag.SeriesInstanceUID));
                            findComplete = false;
                        }
                        else if (series_response.Status.State == DicomState.Success)
                        {
                            findComplete = true;
                        }
                        else if (series_response.Status.State == DicomState.Failure)
                        {
                            findComplete = true;
                        }
                        else if (series_response.Status.State == DicomState.Warning)
                        {
                            findComplete = false;
                        }
                        else if (series_response.Status.State == DicomState.Cancel)
                        {
                            findComplete = true;
                        }
                    };

                    client.AddRequest(cSeriesFindRequest);
                    client.Send(ServerHost, ServerPort, false, LocalAET, ServerAET);

                    while (findComplete != true)
                    {
                        // Log("waiting...waiting....");
                    }

                    //MoveSeriesInstances(studyUid, seriesUids);
                }

                MoveStudyInstances(studyUids);
            }
            catch (Exception ex)
            {
                Log("Series Find Exception: " + ex.Message + "\r\n");
            }
        }
       
        public static void DisplaySeriesResponse(DicomCFindResponse response)
        {
            try
            {
                if (response.Status == DicomStatus.Pending)
                {
                    Log($"Assession Number: {response.Dataset.Get<string>(DicomTag.AccessionNumber)} \r\n" +
                                      $"Series Instance ID: {response.Dataset.Get<string>(DicomTag.SeriesInstanceUID)} \r\n" +
                                      $"Series Number: {response.Dataset.Get<string>(DicomTag.SeriesNumber)} \r\n" +
                                      $"Series Modality: {response.Dataset.Get<string>(DicomTag.Modality)} \r\n" +
                                      $"Series Instances: {response.Dataset.Get<int>(DicomTag.NumberOfSeriesRelatedInstances)} \r\n");
                }
                else if (response.Status == DicomStatus.Success)
                {
                    Log("Series Find Response Status: " + response.Status.ToString() + "\r\n");
                }
            }
            catch (Exception ex)
            {
                Log("Series Find Response Exception: " + ex.Message + "\r\n");
            }
        }

        public static void MoveStudyInstances(List<string> studyUids)
        {
            try
            {
                DicomClient client = new DicomClient();
                client.NegotiateAsyncOps();

                Log("_____________________MOVE_____________________ \r\n");

                foreach (string studyUid in studyUids)
                {
                    var cMoveRequest = new DicomCMoveRequest(LocalAET, studyUid, DicomPriority.High);

                    Log($"({DateTime.Now}) Sending Request for Study: " + studyUid);

                    bool? moveComplete = null;

                    cMoveRequest.OnResponseReceived += (DicomCMoveRequest request, DicomCMoveResponse response) =>
                    {
                        DisplayMoveResponse(response);

                        if (response.Status.State == DicomState.Pending)
                        {
                            moveComplete = false;
                        }
                        else if (response.Status.State == DicomState.Success)
                        {
                            moveComplete = true;
                        }
                        else if (response.Status.State == DicomState.Failure)
                        {
                            moveComplete = true;
                        }
                        else if (response.Status.State == DicomState.Warning)
                        {
                            moveComplete = false;
                        }
                        else if (response.Status.State == DicomState.Cancel)
                        {
                            moveComplete = true;
                        }
                    };


                    client.AddRequest(cMoveRequest);
                    client.Send(ServerHost, ServerPort, false, LocalAET, ServerAET);

                    while (moveComplete != true)
                    {
                        // Log("waiting...waiting....");
                    }

                    Log($"({DateTime.Now}) Move Complete for Study ID: {studyUid} \r\n");
                }

                Log("All move requests complete");
               
            }
            catch (Exception ex)
            {
                Log("Move Exception: " + ex.Message + "\r\n");
            }
        }

        public static void MoveSeriesInstances(string studyUid, List<string> seriesUids)
        {
            try
            {
                DicomClient client = new DicomClient();
                client.NegotiateAsyncOps();

                Log("_____________________MOVE_____________________ \r\n");

                foreach (string seriesUid in seriesUids)
                {
                    var cMoveRequest = new DicomCMoveRequest( LocalAET, studyUid, seriesUid, DicomPriority.High);

                    Log($"({DateTime.Now}) Sending Request for Series: " + seriesUid);

                    bool? moveComplete = null;

                    cMoveRequest.OnResponseReceived += (DicomCMoveRequest request, DicomCMoveResponse response) =>
                    {
                        DisplayMoveResponse(response);

                        if (response.Status.State == DicomState.Pending)
                        {
                            moveComplete = false;
                        }
                        else if (response.Status.State == DicomState.Success)
                        {
                            moveComplete = true;
                        }
                        else if (response.Status.State == DicomState.Failure)
                        {
                            moveComplete = true;
                        }
                        else if (response.Status.State == DicomState.Warning)
                        {
                            moveComplete = false;
                        }
                        else if (response.Status.State == DicomState.Cancel)
                        {
                            moveComplete = true;
                        }
                    };

                    client.AddRequest(cMoveRequest);
                    client.Send(ServerHost, ServerPort, false, LocalAET, ServerAET);

                    while (moveComplete != true)
                    {
                        // Log("waiting...waiting....");
                    }
                }

                Log($"({DateTime.Now}) Move Complete for Study ID: {studyUid} \r\n");
            }
            catch (Exception ex)
            {
                Log("Move Exception: " + ex.Message + "\r\n");
            }
        }


        public static void MoveSingleInstance(string studyUid, string seriesUid, string instanceUid)
        {
            try
            {
                DicomClient client = new DicomClient();
                client.NegotiateAsyncOps();

                Log("_____________________MOVE_____________________ \r\n");

                var cMoveRequest = new DicomCMoveRequest(LocalAET, studyUid, seriesUid, instanceUid, DicomPriority.High);

                Log($"({DateTime.Now}) Sending Request for Instance: {instanceUid}");

                bool? moveComplete = null;

                cMoveRequest.OnResponseReceived += (DicomCMoveRequest request, DicomCMoveResponse response) =>
                {
                    DisplayMoveResponse(response);

                    if (response.Status.State == DicomState.Pending)
                    {
                        moveComplete = false;
                    }
                    else if (response.Status.State == DicomState.Success)
                    {
                        moveComplete = true;
                    }
                    else if (response.Status.State == DicomState.Failure)
                    {
                        moveComplete = true;
                    }
                    else if (response.Status.State == DicomState.Warning)
                    {
                        moveComplete = false;
                    }
                    else if (response.Status.State == DicomState.Cancel)
                    {
                        moveComplete = true;
                    }
                };

                client.AddRequest(cMoveRequest);
                client.Send(ServerHost, ServerPort, false, LocalAET, ServerAET);

                while (moveComplete != true)
                {
                    // Log("waiting...waiting....");
                }

                Log($"({DateTime.Now}) Move Complete for {instanceUid}");
            }
            catch (Exception ex)
            {
                Log("Move Exception: " + ex.Message + "\r\n");
            }
        }


        public static void DisplayMoveResponse(DicomCMoveResponse response)
        {
            try
            {
                if (response.Status.State == DicomState.Pending)
                {
                    Log($"({DateTime.Now}) Sending is in progress. please wait.. {response.Status.Description}");
                }
                else if (response.Status.State == DicomState.Success)
                {
                    Log($"({DateTime.Now}) Move Success: " + response.Status.Description + "\r\n");
                }
                else if (response.Status.State == DicomState.Failure)
                {
                    Log($"({DateTime.Now}) Move Failure: " + response.Status.Description + "\r\n");
                }
                else if (response.Status.State == DicomState.Warning)
                {
                    Log($"({DateTime.Now}) Move Warning: " + response.Status.Description + "\r\n");
                }
                else if (response.Status.State == DicomState.Cancel)
                {
                    Log($"({DateTime.Now}) Move Cancel: " + response.Status.Description + "\r\n");
                }
            }
            catch (Exception ex)
            {
                Log("Move Exception: " + ex.Message + "\r\n");
            }
        }
    }
}

[Anders Gustafsson Cureos AB]

Hi Michael,

as far as I can see, you are sending one C-MOVE request at a time. Does the performance improve if you add all requests in one study or series before you call Send?

Regards,

Anders @ Cureos

[Michael Rutherford]

It does not improve performance.

No matter how formulate the request, I get the delay as soon as I call send.

I hoped to just deal with the wait by requesting a whole study at a time, however, it seems to produce the 2 minute wait for every 2 or 3 series.

I keep coming back to it being something on the pacs server, but I can't make that argument since the transfer using the dcm4che cstore server was practically instant, except a very brief delay if the study is archived, but even then, still faster than fo-dicom.

Thanks for your help.

[Anders Gustafsson Cureos AB]

Which fo-dicom version are you using? You could try out the latest source code in the development branch. I have made some recent changes to ensure that all networking code acts truly asynchronous. It will have minor impact on implementations of IDicomServiceProvider, but it should not be difficult to update.

Regards,

Anders

[Michael Rutherford]

Through Nuget, I first tried the most recent stable build, v3.0.2. Then I tried v3.1.0-alpha with the same results.

I'm willing to give it a try.

[Michael Rutherford]

I pulled, compiled and implemented your code from the development branch. Updated my code to use the Async interface members and return tasks, but unfortunately, it made no difference whatsoever.

Still 2 minute wait before and after.

[Anders Gustafsson Cureos AB]

OK, thanks for trying! Currently I don't have any clue as to why you are experiencing these problems. I will ask the question on the Gitter forum to see if anyone has experienced similar problems.

Regards,

Anders

[Anders Gustafsson Cureos AB]

When looking a little bit closer to your request handlers, I notice that you are treating them as events:

cMoveRequest.OnResponseReceived += 

However, the handlers are not events, but simple delegate function fields, so you should use simple = assignment to define them:

cMoveRequest.OnResponseReceived = 

I have no idea if this will have any impact on the performance, but please give it a try at least.

Regards,

Anders

[Michael Rutherford]

Made the change and unfortunately it made no difference.

Thanks a lot for your help.

[Michael Rutherford]

Just FYI. I just test my fo-dicom request code using the DCMTK storescp and just like when I tested DCM4CHE, the transfer was instant.

The problem HAS to be in my c-store implementation since my request code seems to work great no matter what codebase I use for my c-store, but I only get the delay with fo-dicom c-store.

I just can't seem to pinpoint what is causing the delay.

I guess I have a few alternatives, but didn't want to use multiple codebases.

[CPa]

Dear FoDicom supporters and contributors,

I have the same issue when an echo request or images are coming from a "Central Test Node Software" system. A delay of 30 sec up to some minutes is blocking further actions after "Connection closed" is written by FoDicom lib.

I am trying to get the echo tool to test it by myself, unitl now I only saw it on a remote system.

Thanks in advance for any ideas!

CPa

[Bill]

Michael and others,

Did you ever find a solution to this? This sounds exactly like the issue I'm experiencing. Used the sample CStoreSCP code and with Sectra IDS7 PACS it just hangs 2 minutes exactly so it must be some type of timeout. It looks like others experienced the same with Sectra as well, but I never noticed any solution.

Any help would be greatly appreciated.

I've tried 3.0.2 and 4.0.0 and both have the same effect.

Thanks,

Bill

[Christoph Ernst]

Hi Bill,

i work a lot with Sectra PACS and i know this problem.

I solved it by adding a release for the DICOM association, like this:

client.Send(ServerHost, ServerPort, false, LocalAET, ServerAET);

client.Release(5000);

Try this out!

Christoph

[Bill]

Hi Cristoph!

Thanks for responding!

I tried your solution, but it didn't seem to work. The behavior I am seeing is the the client.Send call never completes so the Release won't ever get called until the Send call completes.

I believe it has to do with with the CStoreSCP implementation as I've used a DCMTK CStoreSCP console test app instead of the FO-DICOM one and it works fine when sending the CMove request through FO-DICOM.

With that being said there might be something in the CMove code that could be changed to make it work, but I'm not sure what I might even try.

Is there anything on the Sectra PACS side that could be changed to allow this to work?

Thanks again,

Bill

[Christoph Ernst]

Hi Bill,

so you mean the C-Move command actually never starts to move images to your SCP?

Does the C-Move command report any errors?

Does the C-Move work with the C-Move application of DCMTK?

Do you have access to the Logfiles of the Sectra PACS?

You could post your code here, i have access to several Sectra PACS test systems (several versions).

Christoph

[Bill]

Hi Cristoph,

I don't believe it's the FO-DICOM C-Move command causing the issue as I've used the DCMTK C-Move command and the behavior is the same when using a FO-DICOM C-Store SCP implementation.

The issue is pretty much identical to the one the original poster Michael Rutherford mentioned and he did a great job debugging and outlining the behavior with additional log information and code.

The C-Move command does an initial association, but then just receives "Pending" C-Move responses for exactly 2 minutes and then another association request is initiated and then data is actually transferred without delay, before the association gets released and waits 2 minutes before more data gets sent. So the C-Move does eventually finish, it just seems like the Sectra PACS gets triggered into some type of waiting/pending state before finally sending over data, but not sure why it is just with the FO-DICOM C-Store implementation, but not with others such as DCMTK.

The only error I see is "[WARNING] No Dicom codecs were found after searching C:\[REMOVED]\cmovescu\Dicom.Native*.dll" which I tried to fix and have the Dicom.Native.dll in that folder, but it refuses to load it.

The C-Move does work with the C-Store SCP application of DCMTK.

At this point, I unfortunately don't have access to the Sectra PACS so can't check settings, logs, etc.

For the C-Store SCP implementation I used the C-Store SCP sample program located here: https://github.com/fo-dicom/fo-dicom-samples/blob/master/Desktop/C-Store%20SCP/Program.cs

The only thing I changed was I removed the Called AE Title check in the OnReceiveAssociationRequestAsync and used a different port. I also set the FO-DICOM logging to be sent to the console by adding this at the top: LogManager.SetImplementation(ConsoleLogManager.Instance);

For the C-Move code I just used the basic example from the repository:

            var client = new DicomClient();
            var cmove = new DicomCMoveRequest(callingAE, studyInstanceUid);
            client.AddRequest(cmove);
            client.Send(pacs_IP, pacs_port, false, callingAE, calledAE);
            client.Release();

The Sectra version I am working against is Sectra Workstation IDS7, Version 20.1.6.2351.

Let me know if you need any additional information.

Again, your help is very much appreciated.

Thanks,

Bill

[Geert Vandenbussche]

Bill, Anders,

This is indeed not caused by the C-MOVE command, but by the following:

After the C-MOVE command Sectra opens an association to check if the SCP supports GSPS objects, even if the study doesn't include this kind of objects.

After the A-RELEASE response, the following is happening on TCP/IP level:

- Sectra sends a [FIN,ACK] indicating that it received the sent packet and wants to close the session.

- an ACK is sent by the SCP to Sectra

- Sectra sends and ACK back, indicating it has received the previous ACK

2 minutes go by ... a time out ...

- Sectra is sending a [RST,ACK] forcibly closing the connection (half-duplex termination)

- Sectra is opening the next association to send the remaining objects

Between the two associations the Sectra wants the TCP session to close, which is a legit action, but the SCP is responding with an [ACK] instead of a

[FIN,ACK]

The fact that the TCP session isn't closed properly causes the delay.

DCMTK and other SCP's will send a [FIN,ACK] after the [FIN,ACK] sent by Sectra, avoiding the time out.

So the actual problem is in the fo-dicom socket handling code.

Clossing the session (stream) doesn't mean the application will stop listening. 

Best regards,

Geert Vandenbussche  

[Christoph Ernst]

Hi Bill,

i can absolutely confirm Geerts explanation. I was able to reproduce this in the testlab.

(The check if the SCP supports Presentation States objects can be disabled by configuration on Sectra PACS side)

So it seems that has to be changed/fixed in the fo-dicom code.

Regards,

Christoph

[Geert Vandenbussche]

Christoph,

Thanks for the confirmation.

If you disable the check, you'll miss the GSPS objects (switch to DICOM overlays), so indeed the potential fix is in the fo-dicom code.

Best regards,

Geert Vandenbussche

[Geert Vandenbussche]

I believe this is related to the following issue:

https://github.com/fo-dicom/fo-dicom/issues/795: DicomServer does not close TCP connection #795, just posted two days ago.

So I think we'll need to wait until this issue is solved.

Best regards,

Geert Vandenbussche

[Bill]

Christoph and Geert,

Thanks so much for the information and looking into this! Definitely shines some light onto what's going on.

And I also saw that issue. Looks like the filer of that issue has some code there to replicate the issue and some hints at where a fix might be. Will have to follow to see how things proceed.

I believe they were recently talking about this on the Gitter chat as well if you guys were looking for more information on it.

I have the fo-dicom code checked out and built and will have to see if I can do any debugging on my end using the code from that issue.

Thanks,

Bill

[Bill]

Looks like mia-san generated a pull request for issue 795 (https://github.com/fo-dicom/fo-dicom/issues/795).

I was able to test the fix and it seemed to fix the issue I was having with the Sectra PACS. Will keep monitoring that issue to see the progress of it.

Unfortunately I'm using a custom build of the 3.0 branch that I pushed a fix to for a previous bug that came up, so I had to port the changes to that branch. Only using desktop version so was able to easily implement the changes to the DesktopNetworkListener.cs and DesktopNetworkStream.cs files. For the DicomServer.cs changes I had to figure out a better way to apply those and ended up applying them to DicomServices.cs on the PduListener in the constructor as this seemed to be similar to what the pull request changes implemented:

            PduListener = ListenAndProcessPDUAsync().ContinueWith(_ => this.Dispose());

Thanks again for the responses to my questions and helping me figure out where the issue was!

-Bill

[Michael Rutherford]

Thank you Geert for pinpointing the problem. I can confirm I no longer encounter this issue in the newest version.