identifying Association Releases in logs?

Hi all,

I’m using 1.9.1 and trying to track how long it takes SCU’s / AETs to send images in Orthanc for storage. I am using --verbose-dicom and parse the log file for times, and take the difference in time between Association Received and Association Release.

I0413 14:47:30.926825 CommandDispatcher.cpp:332] (dicom) Association Received from AET [redacted] on IP 10.x.x.x

I0413 14:51:04.876070 CommandDispatcher.cpp:918] (dicom) Association Release

This seems to work well under the assumption that only one SCU / AET is sending data at a time. But I think it could fail (i.e., infer the wrong times) if a second SCU association started from a second AET before the first one has completed, and the log lines were interleaved. Then it would be ambiguous which Association Release goes with which Association Received (because there is no AET or IP information in the release log line).

Is there some way around this ambiguity? I’d rather not use --trace-dicom, too verbose.

–Jeremy

Hello,

I have just committed a change to report AET and IP in the logs of “–verbose-dicom” related to networking:
https://hg.orthanc-server.com/orthanc/rev/926fa5ef8b4f

With this modification, here are the generated logs, which should allow you to measure elapsed time in the presence of multiple associations:

I0415 11:28:41.076884 CommandDispatcher.cpp:332] (dicom) Association Received from AET STORESCU on IP 127.0.0.1
I0415 11:28:41.135232 CommandDispatcher.cpp:663] (dicom) Association Acknowledged (Max Send PDV: 16372) to AET STORESCU on IP 127.0.0.1
I0415 11:28:41.648386 CommandDispatcher.cpp:917] (dicom) Finishing association with AET STORESCU on IP 127.0.0.1: DUL Peer Requested Release
I0415 11:28:41.651087 CommandDispatcher.cpp:925] (dicom) Association Release with AET STORESCU on IP 127.0.0.1

This patch will be part of forthcoming Orthanc 1.9.2 release.

HTH,
Sébastien-