Avoid output interleaving

Question

I'm working on a multithread c++ application and actually I'm facing the problem of interleaved console output, caused by concurrent thread calls to cout/cerr. Note: I can't use boost/QT/other frameworks, but only standard c++.

As a temporary fix I'm using this class: (actually this is a win32 code snippet, that's why the use of CRITICAL_SECTION as temp workaround);

class SyncLogger
{
public:
    SyncLogger() { InitializeCriticalSection(&crit); }
    ~SyncLogger() { DeleteCriticalSection(&crit); }
    void print(std::ostringstream &os) {
        EnterCriticalSection(&crit);
        std::cout << os.str();
        os.str("");   // clean stream
        LeaveCriticalSection(&crit);
    }
private:
    CRITICAL_SECTION crit;
};

The usage is the following:

...
ostringstream ss;
ss << "Hello world, I'm a thread!" << endl;
syncLogger.print(ss);

I think this is very ugly, but it seems to work.

Btw thanks to this other question ( Best way to add a "prompt" message to std::cout) I have created the following logging class:

class MyLogger
{
    std::ostream & out;
    std::string const msg;
public:
    MyLogger(std::ostream & o, std::string s)
    : out(o)
    , msg(std::move(s))
    { }

    template <typename T>
    std::ostream & operator<<(T const & x)
    {
        return out << msg << x;
    }
};

So, does exist a way to provide built-in locking within the class MyLogger (using critical section or win32 mutex)? My best whish is that any thread will be able to print messages in a sync way, simply using

myLog << "thread foo log message" << endl;

and without the need to create an ostringstream object every time.

Thanks in advance.

Answer 1

I think the best way to go about this would be to have a message queue. You make sure only one thread can write to the queue at a time by using a mutex, and you have another thread reading from the queue and actually doing the output. This way, your worker threads wont have to wait for the console output to be written. This is especially important if multiple worker threads are trying to do output, since then they won't just have to wait on their own output to be done, but also for the output of the other threads, which could potentially seriously slow down your program.

Answer 2

That as soon as you start doing asynchronous logging, you also risk losing the last few log entries if your app crashes. So you must catches SIGSEGV and other fatal signals (not SIGINT) and logs them before exiting. The message queue solution(The logger thread should be encapsuled within an active object) just transfers the contention on the lock/mutex outside to a separate background thread. It's possible to implement lock-free queues in C++ and that they are great for logging. But if you don't care about performance and scalability, only try to avoid output interleaving, you can do as Mats Petersson says. It's kind of like this:

class AsyncLogFile {
public:
  void write( string str )
    { a.Send( [=] { log.write( str ); } ); }
private:
  File log;    // private file
  ActiveObject a;    // private helper (queue+thread)
};
AsyncLogFile logFile;

// Each caller just uses the active object directly
string temp = …;
temp.append( … );
temp.append( … );
logFile.write( temp );

Answer 3

Adding a mutex to the logging mechanism shouldn't be that hard.

Assuming there is only ONE instance of MyLogger, then something like this should work:

class MyLogger
{
    std::ostream & out;
    std::string const msg;
    HANDLE mutex;
public:
    MyLogger(std::ostream & o, std::string s)
    : out(o)
    , msg(std::move(s))
    { 
       mutex = CreateMutex(0, FALSE, 0);
    }

    template <typename T>
    std::ostream & operator<<(T const & x)
    {
        WaitForSingleObject(mutex, INFINITE);
        out << msg << x;
        ReleaseMutex(mutex);
        return out;
    }
};

If there are multiple instances of MyLogger, then you need to make HANDLE mutex into static HANDLE mutex;, add a HANDLE MyLogger::mutex = 0; somewhere in a suitable .cpp file, and then use:

    MyLogger(std::ostream & o, std::string s)
    : out(o)
    , msg(std::move(s))
    { 
       if (!mutex) { 
           HANDLE tmp = CreateMutex(0, FALSE, "MyLoggerMutex");
           if (tmp) 
           {
              mutex = tmp;
           }
       }
    }

By using a name and a temporary variable, we avoid race conditions in creating more than one mutex (because there can only be one MyLoggerMutex in the system. [It gets more complicated if you also have multiple instances of your application running at the same time!]. And since I've assumed that there is only ever one instance of the application, I've also not taken into account that the mutex may be already existing... Or how to destroy the last instance... It will get destroyed when the application exits...

I do like dasblinkenlight's solution in the comment - it is a good solution.