Multi threaded file load crashes due to logging

[budric]

Hi,

I'm loading a folder full of DICOM and I'd like to do it multi-threaded. My program works for one thread but crashes for multiple threads. I have compiled with DCMTK_WITH_THREADS macro.

I am using DcmFileFormat and then DcmItem etc to parse. I believe these classes will work multi threaded - but obviously not same instance shared between threads.

The place it seems to crash (MSVC break point on unhandled exception) is on the line:

Code: Select all

bool
Logger::isEnabledFor (LogLevel ll) const
{
    return value->isEnabledFor (ll);  //value is null for some reason
}

So it seems the logger is not thread safe. Any recommendations?

For the moment I have removed all logging in oflog.h by redefining :

Code: Select all

#define OFLOG_TRACE(logger, msg) 
#define OFLOG_DEBUG(logger, msg) 
#define OFLOG_INFO(logger, msg)  
#define OFLOG_WARN(logger, msg)  
#define OFLOG_ERROR(logger, msg) 
#define OFLOG_FATAL(logger, msg) 

And it seems to work multi threaded, with noticeable performance improvement.

P.S. have you considered using BOOST or Poco utility libraries? It would add to the requirements when compiling DCMTK, but they do provide cross platform threading, synchronization (mutex), networking, logging (Poco). I really do wish for a nice thread support for DIMSE - StoreSCP, FindSCU etc etc.

[Uli Schlachter]

I wrote a small test that starts two threads and let's each of them do some logging output. Works fine here. What am I doing "wrong"?

Code: Select all

#include <dcmtk/oflog/oflog.h>
#include <dcmtk/ofstd/ofstd.h>

#define LOG(msg) OFLOG_FATAL(log, msg)
OFLogger log = OFLog::getLogger("myLog");

class LogThread : public OFThread {
public:
    LogThread(int i) : num_(i) {}
private:
    void run() {
        for (int i = 0; i < 5; i++) {
            LOG("Thread " << num_ << " doing loop " << i);
            OFStandard::sleep(1);
        }
    }

    int num_;
};

int main()
{
    OFLog::configure();
    LOG("Starting...");

    LogThread a(1);
    LogThread b(2);

    a.start();
    b.start();
    LOG("Started!");

    a.join();
    b.join();
    LOG("Done");
    return 0;
}

[budric]

Thanks for your test. I do not have explicit OFLog::configure(); code. The first call to DCMTK library is DcmFileFormat::loadFile() from various threads which then crashes. So maybe the logger is not configured properly. As I mentioned for some reason the value member variable inside Logger is null, so I get a null pointer exception.

I will have a look if calling OFLog::configure() helps.

[budric]

Hi,
Your example works. However the following doesn't.

Code: Select all

#include "dcmtk/dcmdata/dctypes.h"
class LogThread : public OFThread {
public:
    LogThread(int i) : num_(i) {}
private:
    void run() {
        for (int i = 0; i < 5; i++) {
            DCMDATA_DEBUG("Thread " << num_ << " doing loop " << i);
            OFStandard::sleep(1);
        }
    }

    int num_;
};

Looking at the definition:

Code: Select all

#define DCMDATA_DEBUG(msg) OFLOG_DEBUG(DCM_dcmdataGetLogger(), msg)

//definition from dctypes.cc
OFLogger DCM_dcmdataGetLogger()
{
    // We don't just use a global variable, because constructors of globals are
    // executed in random order. This guarantees that the OFLogger is constructed
    // before first use.
    static OFLogger DCM_dcmdataLogger = OFLog::getLogger("dcmtk.dcmdata");
    return DCM_dcmdataLogger;
}

I think that's the problem. I haven't dug much deeper into the code. But basically static variables are not thread safe and I THINK that's the problem.

I recently was dealing with static variables for timing measurements and came across this blog post which talks about why they're not thread safe: http://blogs.msdn.com/b/oldnewthing/arc ... 85901.aspx

P.S.
If you put a DCMDATA_DEBUG("HELLO WORLD"); in main() so that it initializes that static logger variable in main thread, it works without crashing. So another reason that points to that static variable being a problem.

[Uli Schlachter]

Hi,

sorry for the slow reply.

You seem to be right about this problem. However, GCC by default protects the initialization of static local variables with a mutex:
http://arkaitzj.wordpress.com/2009/11/0 ... fety-in-g/

Compiling with -fno-threadsafe-statics I can reproduce this problem with GCC, too.

I'll add this to our bug list.

[budric]

Thanks for looking at the problem. I'm compiling under MSVC. For now I'll just disable the logs.

[Uli Schlachter]

Hi,

we got rid of the static local variables. The logger initialisation should be thread safe now. Details can be found in the git repository:
http://git.dcmtk.org/web?p=dcmtk.git;a= ... e44b1c4a33

Uli

[wollet88]

Hi,

we encountered the same crash.
Since we have DCMJP2K library, how can we workaround the problem?
If we use the commit you signaled we lost JP2K library and I think also this library need to be patched to be thread safe.

How can we solve?

We don't need logging functionality but we seen that disabling is not enough to avoid the crash since some log message are produced without using the log MACRO (e.g. DCMDATA_DEBUG).

Is there a workaround to completely disable the logging?

Thank you

[Michael Onken]

Hi,

for disabling logger output completely, have a look at the logger runtime configuration howto. Hope this works for you!

Michael

[wollet88]

I added the following code (as suggested):

log4cplus::SharedAppenderPtr nullapp(new log4cplus::NullAppender());

/* make sure that only the null logger is used */
log4cplus::Logger log = log4cplus::Logger::getRoot();
log.removeAllAppenders();
log.addAppender(nullapp);

BUT the crash is always present.

Other suggestions?

[Michael Onken]

Yes

Send an email to dicom at offis dot de referring to this topic and I will send you the updated files needed for the logger adaptation in DCMJP2K. Then you can recompile your source. Be sure to use a DCMTK version after 2011-04-18 (e.g. the latest snapshot or an old one from may 2011) since the logger changes in DCMTK were introduced at that date.

Best regards,
Michael