Thread Logger

Started by
4 comments, last by GameDev.net 17 years, 7 months ago
I was wanted to create a threaded logger for a real-time app. When the user calls logger.Log(message), the function will copy the message to a queue of messages and another thread will actually write them to disk so the real-time thread won't be hit by the slow performance of writing to the disk. My question what is the most effecient way is to store the message in the queue. I don't think option #1 is best b/c of constantly allocating and deallocating memory. Option #2 is probably better, but you have the drawback of potentially storing wasted space in the queue. (I am showing "pseduo" code that has not been compiled.) Option #1
struct LogMessage
{
  Time  time;
  char *message;
};

void Logger::Log(char *message)
{
  if (!message)
    return;

  LogMessage log;
  GetCurrentTime(log.time);
  log.message = new char[strlen(message)+1];
  strcpy(log.message, message);

  AddToQueue(log);
}


Option #2
struct LogMessage
{
  Time  time;
  bool  isPartial;
  char  message[256];
};

void Logger::Log(char *message)
{
  if (!message)
    return;

  LogMessage log;
  int len = strlen(message);
  int MAX_LEN = sizeof(log.message)-1;
  GetCurrentTime(log.time);

  // check if we have to add multiple messages
  if (len <= MAX_LEN)
  {
    log.isPartial = false;
    strcpy(log.message, message);
    AddToQueue(log);
  }
  else
  {
    log.isPartial = true;

    do {
      strncpy(log.message, message, MAX_LEN);
      log.message[MAX_LEN] = '\0';
      AddToQueue(log);
      message += MAX_LEN;
      len -= MAX_LEN;
    } while (len > 0);
  }
}


Advertisement
Rather than a queue of fixed-size message objects, it might be possible to have a single circular buffer packed with variable-sized messages - i.e. something along the lines of
const int buffer_size = 1024*1024;char buffer[buffer_size];int buffer_read_pos = 0;int buffer_write_pos = 0;void AppendToBuffer(char* data, int size){	for (int i = 0; i < size; ++i)	{		buffer[buffer_write_pos] = data;		buffer_write_pos = (buffer_write_pos + 1) % buffer_size;	}}void Logger::Log(char* message){	Time time = ...;	AppendToBuffer(&time, sizeof(time));	int len = strlen(message);	AppendToBuffer(&len, sizeof(len));	AppendToBuffer(message, len);}...void ReadFromBuffer(char* data, int size){	for (int i = 0; i < size; ++i)	{		block while buffer_write_pos == buffer_read_pos;		data = buffer[buffer_read_pos];		buffer_read_pos = (buffer_read_pos + 1) % buffer_size;	}}void PrintLog(){	while (true)	{		Time time;		int len;		ReadFromBuffer(&time, sizeof(time));		ReadFromBuffer(&len, sizeof(len));		char* message = new char[len+1];		ReadFromBuffer(message, len);		message[len] = '\0';		printf("%s", message);		delete[] message;	}}
(plus any necessary synchronisation (particularly if the compiler tries to optimise too much), minus any bugs). The adding-to-buffer thread doesn't have to do any slow memory allocation (which AddToQueue would presumably involve), and the messages don't have to be split into arbitrary fragments. It breaks if the adding-to-buffer thread gets more than buffer_size bytes ahead of the reading-from-buffer thread, but hopefully you can spare the memory for a bigger buffer (or make AppendToBuffer block if it's about to overflow, and wait for the log-printer thread to catch up). (Actually, I don't think that'd be more wasteful of memory than any other system, since the queued not-yet-processed messages have to be stored somewhere in any case - the only difference is that the fixed-size buffer will be that size for the lifetime of the program, which may or may not be worse than a variable-sized queue which will eventually grow to that size. And the maximum size will actually be slightly less than other systems, because there's no wasted space for padding lots of small buffers or managing dynamically-allocated queues.)
std::deque<std::string>.

Wielder of the Sacred Wands
[Work - ArenaNet] [Epoch Language] [Scribblings]

Quote:Original post by ApochPiQ
std::deque<std::string>.


This is essentially the same as Option #1 since the std::string class will have to dynamically allocate space for every log message. This is the overhead (at least I've always heard its an expensive operation) I was trying to avoid.
Your "AddToQueue(log);" function will have to allocate memory. Well, you could preallocate large amounts of memory, but the memory has to be allocated sometime.

What if you include the time of your messages in the message string?

Your queue becomes a std::deque<char> -- fixed sized memory blocks of characters, and it supports insertion iterators.

To avoid any real-time-thread delays, the real-time thread that is doing logging should notice when the logger thread has no more messages to consume, then do a deque swap and wake up the logger thread. Done right, the real-time threads would never block on the non-real-time threads.

A "custom hand-written deque" that has something analagous to vector's "reserve" could also be useful (preallocated buffer space, and avoiding deallocation of unused buffer space). You could implement this easily on a deque -- just keep a high-water-mark of used data, and use the deque's size as it's current capacity.
Quote:Original post by willis
Quote:Original post by ApochPiQ
std::deque<std::string>.


This is essentially the same as Option #1 since the std::string class will have to dynamically allocate space for every log message. This is the overhead (at least I've always heard its an expensive operation) I was trying to avoid.


As much overhead as your allocation really, no bugs in the stl, etc. I really recommend using the std::deque option presented. Don't optomize early like you're doing. These are NOT slow. Trust me, 99% of your code will be a LOT slower.

This topic is closed to new replies.

Advertisement