[BitBucket date: 2017-03-21.15:25:37]
I ran into a problem when making concurrent C-MOVE requests using Orthanc. To replicate the issue, try the following:
1. Make an instance-level query. For example:
POST modalities/ClearCanvas/query
Payload: {"Level":"Instance","Query":{"StudyInstanceUID": "1.2.410.200028.479.2015128.135245", "SeriesInstanceUID": "1.2.410.200028.479.2015128.135245.1"}}
2. Get the answers from the query above. For example:
queries/b2e7c2b9-9ff8-452a-afab-736ef73f6587/answers
This will return answers corresponding to our instances.
3. Issue concurrent retrieve requests to download those instances. For example:
POST queries/b2e7c2b9-9ff8-452a-afab-736ef73f6587/answers/0/retrieve
POST queries/b2e7c2b9-9ff8-452a-afab-736ef73f6587/answers/1/retrieve
I wrote a C# client to make sure both requests are sent simultaneously.
The second "retrieve" request will fail. It says "Peer aborted Association (or never connected).
I dived into the code and might have found the bug (not the fix yet). Here is what I discovered:
Whe I make C-MOVE calls, the following function will be invoked:
ReusableDicomUserConnection::Locker locker(context_.GetReusableDicomUserConnection()...);
locker.GetConnection().Move(target, map);
The intention of locker is to protect Move() call with a mutex. Unfortunately, after completing the Move() call, CommandDispatcher::Step() will be triggered again where DUL_PEERREQUESTEDRELEASE message will be received. The T_ASC_Association object will be released as a result.
But if a second move call is initiated AFTER the first Move() call, but BEFORE the CommandDispatcher::Step() call, the second Move() call will try to reuse the original DicomUserConnection object for further communication. When the aforementioned DUL_PEERREQUESTEDRELEASE message arrives, the second move call will fail since the reused T_ASC_Association object is destroyed.
So the fundamental problem of the bug is that locker.GetConnection().Move(target, map) didn't cover all operations related to the move: when the first Move() is still trying to cleanup the association while a second Move() is triggered, we can see crashes every time.
Thanks for your thoughts on how to fix the problem in advance!
Thanks!
Ishaan
[BitBucket user: Alain Mazy]
[BitBucket date: 2017-07-05.21:39:41]
well, I have tried to reproduce the issue with both version 0.9.4 (the default version on my ubuntu system) and with the mainline, with no success.
Here is what I get:
```
I0705 23:37:54.858038 MongooseServer.cpp:721] POST /modalities/orthanc/query
I0705 23:37:54.859574 DicomUserConnection.cpp:803] Opening a DICOM SCU connection from AET "ORTHANC1" to AET "ORTHANC" on host localhost:4242 (manufacturer: Generic)
I0705 23:37:55.942633 MongooseServer.cpp:721] GET /queries/3979b1be-3859-40fb-881c-c4be11133987/answers
I0705 23:37:56.980384 MongooseServer.cpp:721] GET /queries/3979b1be-3859-40fb-881c-c4be11133987/answers/0/content
I0705 23:37:58.004985 MongooseServer.cpp:721] GET /queries/3979b1be-3859-40fb-881c-c4be11133987/answers/1/content
I0705 23:37:59.056584 MongooseServer.cpp:721] POST /queries/3979b1be-3859-40fb-881c-c4be11133987/answers/1/retrieve
W0705 23:37:59.057496 OrthancRestModalities.cpp:480] Driving C-Move SCU on modality: ORTHANC1
I0705 23:37:59.057804 ReusableDicomUserConnection.cpp:57] Reusing the previous SCU connection
I0705 23:37:59.058299 MongooseServer.cpp:721] POST /queries/3979b1be-3859-40fb-881c-c4be11133987/answers/0/retrieve
W0705 23:37:59.058419 OrthancRestModalities.cpp:480] Driving C-Move SCU on modality: ORTHANC1
I0705 23:37:59.076218 CommandDispatcher.cpp:491] Association Received from AET ORTHANC on IP 127.0.0.1
I0705 23:37:59.125741 CommandDispatcher.cpp:684] Association Acknowledged (Max Send PDV: 16372)
I0705 23:38:00.158715 ServerContext.cpp:263] Already stored
I0705 23:38:00.161873 ReusableDicomUserConnection.cpp:57] Reusing the previous SCU connection
I0705 23:38:01.254555 ServerContext.cpp:263] Already stored
I0705 23:38:06.334616 ReusableDicomUserConnection.cpp:94] Closing the global SCU connection after timeout
I0705 23:38:06.335064 CommandDispatcher.cpp:835] DUL Peer Requested Release
I0705 23:38:06.335115 CommandDispatcher.cpp:842] Association Release
```
This output has been produced with this python code:
```
from requests_futures.sessions import FuturesSession
from requests import Session
import time
orthancBaseUrl = "http://localhost:8743"
#perform the C-Find with synchronous requests
syncSession = Session()
queryResponse = syncSession.post(orthancBaseUrl + '/modalities/orthanc/query', json = {"Level": "Study", "Query": {"AccessionNumber": "*", "PatientBirthDate": "*", "PatientID": "*", "PatientName": "0573*", "PatientSex": "*", "StudyDate": "*", "StudyDescription": "*"}})
queryId = queryResponse.json()['ID']
results = []
queryResultsIdResponse = syncSession.get(orthancBaseUrl + '/queries/{queryId}/answers'.format(queryId = queryId))
for queryResultId in queryResultsIdResponse.json():
resultResponse = syncSession.get(orthancBaseUrl + '/queries/{queryId}/answers/{queryResultId}/content?simplify'.format(queryId = queryId, queryResultId = queryResultId)).json()
resultResponse['retrieveUrl'] = '/queries/{queryId}/answers/{queryResultId}/retrieve'.format(queryId = queryId, queryResultId = queryResultId)
results.append(resultResponse)
# perform the retrieve with asynchronous requests
asyncSession = FuturesSession()
# first request is started in background
future_one = asyncSession.post(orthancBaseUrl + results[0]['retrieveUrl'], data = 'ORTHANC1')
# second requests is started immediately
future_two = asyncSession.post(orthancBaseUrl + results[1]['retrieveUrl'], data = 'ORTHANC1')
# wait for the first request to complete, if it hasn't already
response_one = future_one.result()
print('response one status: {0}'.format(response_one.status_code))
print(response_one.content)
# wait for the second request to complete, if it hasn't already
response_two = future_two.result()
print('response two status: {0}'.format(response_two.status_code))
print(response_two.content)
```
[BitBucket user: Alain Mazy]
[BitBucket date: 2017-07-05.21:50:58]
I have tried to configure the remote Orthanc to close the association immediately but, it still has the same effects. The remote Orthanc realizes that the querying Orthanc is still using the previous connection and therefore, does not request to close the connection.
But I understand that your modality may not behave like Orthanc and really closes the connection after the first transfer. I would suggest that you configure your modality to keep the connection alive a bit longer ... however, I'll have a look at the code and at your suggestions to try to solve it without being able to reproduce ...
[BitBucket user: Alain Mazy]
[BitBucket date: 2017-07-05.22:08:37]
I'm afraid there's not much we can do. Since the C-Move come from 2 independent Rest API requests, there is no way we could include them in the same scope and lock the connection for the duration of both moves.
Anyway, I'm not even sure that the ReusableDicomUserConnection::Locker would help if, anyway, the remote modality has requested a connection release @sjodogne any idea ?
@sjodogne: to summarize the events:
- Orthanc performs a C-Move to retrieve a first instance
- Orthanc, when starting the next C-Move realizes that a connection is still open and decide to reuse it.
- At the same time, once the first transfer is complete, the remote modality sends a request to close the connection (the DUL Peer Requested Release)
- Orthanc really closes the connection
- The second C-Move fails
Ideal solution: Orthanc should not allow the connection to close but I don't know if this is allowed by the DICOM protocol (too late to check ...)
[BitBucket user: Sébastien Jodogne]
[BitBucket date: 2019-01-25.13:28:56]
This has most probably been resolved as part of the refactoring of the jobs engine. Since that moment, the DICOM user connections are not stored in a global singleton (class "ReusableDicomUserConnection" has been moved to the graveyard). If the problem persists with Orthanc 1.5.3, please re-open this issue.
