Performance questions ...

Google Groups archive
1

During my test of Orthanc as a PACS replacement for our old and now dead ClearCanvasServer, I noticed a slowdown on querys that I don’t undestand why … so increased the log level with --trace, and got this:

I0502 16:38:39.940242 5974 CommandDispatcher.cpp:266] Association Received
I0502 16:38:39.940793 5974 CommandDispatcher.cpp:445] Association Acknowledged (Max Send PDV: 16372)
I0502 16:38:39.979681 5997 OrthancFindRequestHandler.cpp:485] DICOM C-Find request at level: Study
I0502 16:38:39.979709 5997 OrthancFindRequestHandler.cpp:491] (0008,0052) QueryRetrieveLevel = STUDY
I0502 16:38:39.979722 5997 OrthancFindRequestHandler.cpp:491] (0010,0020) PatientID = mico
I0502 16:38:39.979734 5997 OrthancFindRequestHandler.cpp:491] (5555,0010) PrivateCreator = AETMED RETRIEVE INFO
I0502 16:38:39.979841 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:39.979925 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:39.979950 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:39.979974 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:39.979991 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:39.980015 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:39.980032 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?

[…]

I0502 16:38:40.169436 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:40.169448 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:40.169458 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:40.169467 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:40.169477 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE resourceType=?
I0502 16:38:40.182185 5997 OrthancFindRequestHandler.cpp:543] Number of candidate resources after exact filtering: 13109

I’m new to Orthanc … and I must admit that still have not take a look at the code … but why is that query repeated for EACH resource that it’s stored on the BD?

After that queries … apears some more … repeated more, and more …

I0502 16:38:40.182261 5997 Statement.cpp:116] SQLite::Statement::Step SELECT internalId, resourceType FROM Resources WHERE publicId=?
I0502 16:38:40.182302 5997 Statement.cpp:116] SQLite::Statement::Step SELECT internalId, resourceType FROM Resources WHERE publicId=?
I0502 16:38:40.182342 5997 Statement.cpp:116] SQLite::Statement::Step SELECT resourceType FROM Resources WHERE internalId=?
I0502 16:38:40.182399 5997 Statement.cpp:116] SQLite::Statement::Step SELECT a.internalId FROM Resources AS a, Resources AS b WHERE a.parentId = b.internal
Id AND b.internalId = ?
I0502 16:38:40.182421 5997 Statement.cpp:116] SQLite::Statement::Step SELECT a.internalId FROM Resources AS a, Resources AS b WHERE a.parentId = b.internal
Id AND b.internalId = ?
I0502 16:38:40.182446 5997 Statement.cpp:116] SQLite::Statement::Step SELECT a.internalId FROM Resources AS a, Resources AS b WHERE a.parentId = b.internal
Id AND b.internalId = ?
I0502 16:38:40.182451 5997 Statement.cpp:116] SQLite::Statement::Step SELECT a.internalId FROM Resources AS a, Resources AS b WHERE a.parentId = b.internal
Id AND b.internalId = ?
I0502 16:38:40.182462 5997 Statement.cpp:116] SQLite::Statement::Step SELECT resourceType FROM Resources WHERE internalId=?
I0502 16:38:40.182477 5997 Statement.cpp:116] SQLite::Statement::Step SELECT a.internalId FROM Resources AS a, Resources AS b WHERE a.parentId = b.internal
Id AND b.internalId = ?
I0502 16:38:40.182489 5997 Statement.cpp:116] SQLite::Statement::Step SELECT a.internalId FROM Resources AS a, Resources AS b WHERE a.parentId = b.internal
Id AND b.internalId = ?
I0502 16:38:40.182499 5997 Statement.cpp:116] SQLite::Statement::Step SELECT resourceType FROM Resources WHERE internalId=?
I0502 16:38:40.182533 5997 Statement.cpp:116] SQLite::Statement::Step SELECT publicId FROM Resources WHERE internalId=?
I0502 16:38:40.182553 5997 Statement.cpp:116] SQLite::Statement::Step SELECT resourceType FROM Resources WHERE internalId=?
I0502 16:38:40.182566 5997 Statement.cpp:116] SQLite::Statement::Step SELECT a.internalId FROM Resources AS a, Resources AS b WHERE a.parentId = b.internal
Id AND b.internalId = ?

[…]

Where could I star to debug and trace that queries ? … why params of the query are not show on the log?

Best regards

2

Hello,

It is really hard for me to give you any hint, without having access to your SQLite database.

What is your DICOM client? How many patients/studies/series/instances are stored on your system (this information can be found by querying http://localhost:8042/statistics)? Your experienced slowdown might be tightly linked to the behavior your DICOM client.

In my own opinion, this is quite normal to have a lot similar SQLite requests. The first query is issued by your DICOM client to retrieve the list of studies of the patient whose ID is “mico”. Then, for each of these studies, your DICOM client issues a request to get the series of this study.

When you type an exact Patient ID, without wildcards (such as “Amicon”), you should notice an huge improvement in speed.

Sébastien-