Posts by mbuiter

    Dear Marcel,

    One of my colleagues pointed me to some LUA runtime errors he saw in serverstatus.log, for our clinical server.

    I looked into it and he meant the following error:

    [CONQUESTSRV1] *** lua run error [string "local first=true; local ae=[[DICOMHOST]];..."]:1: attempt to index field '?' (a nil value) in 'local first=true; local ae=[[DICOMHOST]];local level=[[PATIENT]];local q={QueryRetrieveLevel=[[PATIENT]],PatientID=[[1*]],PatientName=[[]],};local q2=DicomObject:new(); for k,v in pairs(q) do q2[k]=v end;local r2=dicomquery(ae, level, q2);local s=tempfile("txt") f=io.open(s, "wb");if r2==nil then f:write("no connection with "..ae.."\n") returnfile=s f:close() return end; local r = loadstring("return "..r2:Serialize())();r[1].QueryRetrieveLevel=nil; r[1].TransferSyntaxUID=nil; local keys={} for k,v in pairs(r[1]) do if type(v)~="table" then keys[#keys+1]=k end end; table.sort(keys, function(a, b) return string.sub(a, 1, 7)<string.sub(b, 1, 7) end); if first then for k,v in ipairs(keys) do f:write(v.." ") end f:write("\n") end if first then f:write("---------------------------------------------------------------------------------------------------------------------------------------------------------------\n") end for k,v in ipairs(r) do for k2,v2 in ipairs(keys) do f:write("["..v[v2].."] ") end f:write("\n") end returnfile=s f:close();'

    I had seen this error before, and know it comes up when a user performs a DICOM query in the Conquest GUI for which the (local or remote) queried server has no results. It does not appear to be problematic, it only appears in serverstatus.log, conquestdicomserver.log and PacsTrouble.log, but it did worry my colleague :)

    I think I have traced it back to LUA code in "Serverdriver.pas", procedure TForm1.QueryButtonClick(). I think the LUA code is trying to index and parse fields from rows that are not present when the queryresult is empty. The error does not appear when the query-result contains at least one record. Is this indeed a "tiny bug"? I see this behaviour in Conquest 1.5.0b and 1.5.0e alike. I think it is a common issue, so apologies if this has been reported before.

    Steps to reproduce:

    1) Install Conquest (SQLite database, create tables, hostname, et cetera)

    2) Open the GUI

    3) Query the local or a remote DICOM system on a data-item you know is not there (non-existing patientID, for example)

    4) Look on "Server status" tab for last entries in serverstatus.log, or open serverstatus.log, conquestdicomserver.log or PacsTrouble.log.

    Kind regards, and keep up the good work!

    Maarten Buiter

    Hi Marcel,

    I find myself looking at the contents of rather large serverstatus.log files quite a lot, either to find out how something went, when something happened, and what a sequence of events might or could have been. Although this type of analysis is usually very well doable, and a good timeline can be reconstructed based upon the contents of serverstatus.log (in non-debugging mode, production-mode), on a busy server it happens very often that threads run in parallel, and it is not always clear which line in serverstatus.log is output by which thread. This, sometimes, makes things a lot more difficult to reconstruct when multiple threads are active outputting to serverstatus.log "at the same time".

    Thread-start and thread-stop messages always appear in the serverstatus.log file, too, with on each of those lines the ID of the started or stopped thread. Would it be possible to include the ID of the thread that outputs a line to serverstatus.log on each of those lines? That would make logfile analysis more easy to do as the actions of a single thread are immediately identifiable as performed by that thread, and an even more accurate sequence of events can be deducted, even when multiple threads in parallel output lines "at the same time" to serverstatus.log.

    Kind regards, and all the best,

    Maarten Buiter

    Hi Marcel,

    Thanks for all the answers to our question. We are still investigating this problem, but indeed it seems that your (3) situation mentioned above is part of our problem; the main PACS seems to, under unknown conditions, return different PatientID-values for query and retrieves. This is still a hypothesis, of course, and we don't know what causes it.

    To gain more insight into how and when this issue occurs we have implemented a QueryResultConverter0, as follows:

    [lua]

    QueryResultConverter0 = if ((Data.PatientID ~= nil) and (#Data.PatientID >8) and (tonumber(Data.PatientID) ~= nil)) then print('QueryResultConverter0 should destroy '..Data.PatientID..' requested by '..Association.Calling..' and '..Association.Called ) end

    This converter prints (to serverstatus.log) a logging-line with information about caller-AE, called-AE, and identified PatientID (SSN) when there is a PatientID in the recordset, that PatientID consists of more than 8 digits and all of those digits are numeric. We hope to be able to use this logging to find out which application, when and under what circumstances, this issue occurs. We are also aware that by modifying this QueryResultConverter0 as follows we can block the SSN from entering our systems if it is returned as a result of a query:

    [lua]

    QueryResultConverter0 = if ((Data.PatientID ~= nil) and (#Data.PatientID >8) and (tonumber(Data.PatientID) ~= nil)) then print('QueryResultConverter0 should destroy '..Data.PatientID..' requested by '..Association.Calling..' and '..Association.Called ); destroy(); end

    We have tested this, and it seems to work when actively querying data on SSN. We are now monitoring and waiting to "catch" a few occurrences.

    When we know more about the how and when of this problem, and possible long-term solutions, we will update this thread again.

    Kind regards,

    Maarten

    Hello Marcel,

    Sure... I have removed the more sensitive information and the main routing rules, but this will hopefully show our main (mostly default, I believe) configuration. If too much detail is missing I can message you privately.

    In the meantime we have found out that whenever a host queries our DICOM Router for data, but uses a wrong or unknown (return) AE-title in the process, the DICOM router logs the retrieve request, also logs "Host ... did not accept the connection' when it tries to deliver the data to the host, but a corresponding record does get inserted into the Conquest database (without the data being available on disk). We do see this happen sometimes in our production serverstatus.log files, so this is something we will look into as well.

    Thanks, and groetjes,

    Maarten

    Dear Marcel,

    We have a strange issue with our DICOM router, based on Conquest 1.5.0b. We use use the (DICOM) PatientID (0010,0020) as the primary patient identifier. Secondary to this, data stored on our main PACS is encoded with the patient’s SSN (BSN), always in the “OtherPatientIDs” sequence, with IssuerOfPatientID=’NLMINBIZA’. Our DICOM router is configured as a caching proxy (VirtualServerFor0) for our main PACS.

    # Configuration of the virtual server

    CacheVirtualData = 1

    OverlapVirtualGet = 0

    VirtualServerFor0 = MAINPACS,FIXKODAK,CACHESTUDIES

    Every so often we find that we cannot push data to our DICOM router, and the router complains about a

    ***Refused to enter inconsistent link PatientID into DICOMStudies: PatientID = 'XXXXXXXX' StudyInsta = '2.16.840.1.113883(…)019', Old='YYYYYYYYY', Refused='XXXXXXXX'

    where XXXXXXXX is our primary PatientID, and YYYYYYYYY is the patient’s SSN (BSN), which means the DICOM router is telling us that it already has data in its database (Microsoft SQL Server) for the given StudyInstanceUID, but for a patient identified by his SSN instead of his PatientID. Using the Conquest GUI we can navigate to this record (and delete it thus solving the collision), which usually seems to be an RTPLAN object, but the underlying (DICOM) image (.dcm) file seems to be never present. Digging through our history (months, years) of Conquest logfiles we can never find a line in serverstatus.log that reports ‘Written file D:\Dicom\Data\YYYYYYYYY\(……).dcm’, which gives us the idea that we never received any data (-slices, -objects, from the main PACS or any other system in our landscape) that had the patient’s SSN as its primary PatientID. If we use our Conquest to query our main PACS using not the PatientID but the patient’s SSN instead, we also get that patient’s data, but a retrieve command does write lines like ‘Written file D:\Dicom\Data\YYYYYYYYY\(…).dcm’ into our serverstatus.log files, showing somebody retrieved data using the SSN as a PatientID. So, somebody accidentally retrieving data from our main PACS, through our DICOM router, using the SSN as PatientID seems to be unlikely (as we never see this happen in the logfiles).

    We are wondering how this conflicting record (the one encoded by the patient’s SSN) can end up in our database. We have done some digging through Conquest’s source code and found the possibly related “VirtualQueryToDb()” function, which can be used to trigger QueryConverter0 and QueryResultConverter0, but we are not sure about the conditions under which possibly this mechanism could save query-results, perhaps containing SSN-information, into our database, setting the stage for a later collision. We have only Import- and ExportConverters, no Query(Result)Converters or anything else.

    Could you help us by pointing us into a direction that we could further investigate? We would like to run our DICOM router in a higher debug level to get more internal operational information, but we are hesitant to do so because of its high load.

    Kinds regards,

    Maarten

    Hello Marcel,

    I have found that Conquest (version 1.5.0d, but also version 1.5.0b and earlier) does not delete temporary files created in the printer_files directory when using a "process with" ImportConverter statement.

    I have attached an out of the box dicom.ini with which this behavior can be reproduced. It uses one ImportConverter, "process with C:\Windows\System32\ping.exe" (just some random executable on a Windows system). All incoming slices trigger this ImportConverter, and Conquest leaves a copy of each incoming slice in its $INSTALLBASE$\data\printer_files\ directory, of course next to storing it in the right locations (database and patient directory). On our production servers, the configured nightly cleans don't remove these temporary files, and with high throughput, the printer_files directory can get quite large with hundreds of thousands of files.

    I am not sure if this behavior is desired. We have scripts running to clean up after some time, but it would seem nicer if Conquest could clean up these files itself when the ImportConverter finishes.

    Kind regards, and many thanks in advance,

    Maarten Buiter