C: Thread Safe Logging to a File

Question

I am trying to write a thread-safe C logging function, and I am having some serious problems with the file IO. So, basically, I start with an interesting fopen call that lets me open the log in binary update mode:

FILE *log, *start;
int timeout = 0, error;

//make file (fails if file exists)
log = fopen(LOG_FILE, "wx");

//Close the file if a new one was created
if(log)
   fclose(log);

//Open file in update mode (it must exist for this)
log = fopen(LOG_FILE, "rb+");

Next, I lock the file, incorporating a timeout if another thread locks it for too long:

//Init other file pointer
start = log;

//Lock file (with timeout)
rewind(start);
error = lockf(fileno(start), F_TLOCK, 0);
while( error == EACCES || error == EAGAIN)
{
  //sleep for a bit
  usleep(LOCKED_FILE_RETRY_TIME);

  //Incremement timeout
  timeout += LOCKED_FILE_RETRY_TIME;

  //Check for time out
  if(timeout > LOCKED_FILE_TIMEOUT)
  {
     return;
  }

  //Retry the lock operation
  error = lockf(fileno(start), F_TLOCK, 0);
}

And finally, I add the required message to the end of the file, unlock it and close the file:

//Print log entry
fseek(log, 0, SEEK_END);
fwrite((const void*) log_msg, 1, strlen(log_msg), log);

//Unlock the block
rewind(start);
lockf(fileno(start), F_ULOCK, 0);

//Close file
fclose(log);

However, it seems like the majority of the messages are overwritten in the log, rather than appended, almost as if fopen took a "snapshot" of the file, waited for it to be unlocked, and wrote to where the end of the file would have been if another process didn't add to it. Does anyone have any idea as to how I could go about fixing this problem?

As an aside, I want to be in binary update mode because I will eventually add some trimming functionality that will ensure the log file does not exceed a certain size, and this is easier for me to accomplish with working fseek calls and R/W functionality.

Any tips are appreciated. Thanks beforehand!

Answer 1

You didn't call fflush() on the file pointer before unlocking. That way your log message remained in a stdio buffer, to be written out in fclose(), at a time when the lock is no longer being held.

To fix the problem, either add an fflush(log) before the unlock operation, or simply move the fclose(log) before it.