How to make sure a chained logging statement is atomic?

Question

I have a logging class which has operator<< overloaded. So I can do things like this:

oLogger << "Log this" << " and this" << " and " << 10 << endl;
oLogger`<< "Something else" << endl;

The logger does this without any problems. But, I want the logger object to be shared among threads. Then, I don't want it printing out something like this:

//LogFILE
Log this and this Something else
 and 10

So, I need to lock a whole chain of operator<<s. I am guessing this can be done with RAII, I haven't given it much thought yet. In the meantime, is there any traditional way of getting this done? (Except ending input with a manipulator?)

Answer 1

Slight alternative to Nim's answer:

Create

class LockedLog {
    static MutEx mutex; // global mutex for logging
    ScopedLock lock; // some scoped locker to hold the mutex
    Logger &oLogger; // reference to the log writer itself
public:
    LockedLog(Logger &oLogger) : oLogger(oLogger), lock(mutex) {}
    template <typename T>
    LockedLog &operator<<(const T &value) { oLogger << value; return *this; }
};

And either just do:

LockedLog(oLogger) << "Log this" << " and this " << " and " << 10 << endl;

Or change Logger::operator<< to normal method, call this method in LockedLog::operator<<, add cast-operator to Logger:

operator LockedLog() { return LockedLog(*this); }

and that should add locking to your current code.

Update: That locks across all the calls to operator<< and may even lock around evaluation of their arguments (depends on whether compiler will evaluate left or right argument first and it may choose). To reduce that, one could:

class LockedLog {
    static MutEx mutex; // global mutex for logging
    std::stringstream buffer; // temporary formatting buffer;
    Logger &oLogger; // reference to the log writer itself
public:
    LockedLog(Logger &oLogger) : oLogger(oLogger), lock(mutex) {}
    template <typename T> 
    LockedLog &operator<<(const T &value) { buffer << value; return *this; }
    ~LockedLog() { ScopedLock lock(mutex); oLogger << buffer.str() << std::flush; }
};

But the stringstream adds another overhead.

Answer 2

One approach is to use a macro, i.e.

#define LOG(x) \
{\
  <acquire scoped lock> \
  oLogger << x; \
}

then

LOG("Log this" << " and this" << " and " << 10 << endl);

I've also done it using the manipulator approach that you mention above, however the problem is that you need to have operator<< implemented for all the types (i.e. can't use the standard operators that exist)

EDIT: to reduce the time the lock is held, consider something like this:

#define LOG(x) \
{\
  std::ostringstream str; \
  str << x; \       // the streaming happens in local scope, no need for lock
  oLogger.write(str.str()); \ // ensure the write method acquires a lock
}

Answer 3

As I have to internationalize logs, I prefer things like :

oLogger << myAutosprintf(_("My wonderful %s ! I have %d apples"), name, nbApple);

It is way better for translation :) And it will solve your problem. _() is a shortcut for the translation stuff.

You can use gnu::autosprintf, boost.format (thanks to Jan Huec), or write your own.

my2c

NB: Edited after good remarks (was too fast, thank you for the comments). I have erased the wrong "first part" statement

Answer 4

I've found that the best solution is to write a class buffer so that

buffer(oLogger) << "Log this" << " and this" << " and " << 10 << endl;

creates a temporary buffer object, captures and formats the output and writes it to oLogger in its destructor. This is trivially done by wrapping a stringstream. Because every thread has its own buffers, formatting is independent.

For extra fanciness, buffer::~buffer can use several different mechanisms to prevent thread-unsafe access of oLogger. You assumed that operator<< calls from multiple threads might be interleaved. In fact, it's worse; they can be concurrent. You could get "LSoogm ethhiinsg else". Makeing sure that only one buffer flushes to oLogger at a time prevents this.

Answer 5

I would probably use expression templates here.

The main idea is that it's bloody stupid to acquire the lock during the formatting phase, especially since there might be function calls during this formatting.

You need to use two different phases:

• format the log
• atomically post the log

This can be accomplished with expression templates:

1. First call to Logger::operator<< yields a LoggerBuffer that embeds a reference to Logger.
2. Subsequent calls are performed on LoggerBuffer which deals with all the formatting mess
3. Upon destruction of LoggerBuffer (at the end of the statement), it locks Logger, pass the formatted string, and unlocks (unless you've got a lock-free queue or something)