Tuesday, April 12, 2011

[TECH] Unbuffered message logging of interactive programs.

We generally use one of the following methods to log the output messages of programs which print a lot of messages.

  •  $ ./program >& message.log 
  •  $ ./program |& tee message.log 
Since stdout is line buffered we expect the same to hold when we re-direct stdout or any other stream. However this is not true if you keep monitoring the program status with tail -f message.log you will not notice any output from the program this is because the redirection is not line buffered. And in certain unfortunate cases when the running program aborts the redirection may not even flush the buffers and you find that message.log is empty and there is NO way to figure out what has happened.

One obvious way to fix this is to put fflush(stdout) after every printf statement you have, this is OK for small programs but for very large programs its really tedious. I came up with the following technique to solve this problem. This solution is generic.

[main.c]

int main(int argc, char **argv){

 ForceLogMessages("message.log");
 ....
 ... 
}

void ForceLogMessages(const char *mesg_file){
    int ret_setvbuf;
    /*close the stdout and re-open a text file*/
    fclose(stdout);
    stdout = fopen(name, "w");
    //make stdout unbuffered
    ret_setvbuf = setvbuf(stdout, (char *) NULL, _IOLBF, 0);   
    if(ret_setvbuf){
        fprintf(stderr, "UNABLE TO MAKE stdout UNBUFFERED %s", strerror(errno));
    }   
    assert(stdout);
}

Now if we run the program and we can monitor the status with tail -f message.log since we have made stdout unbuffered we can see a message in message.log every time a printf is executed in the original program and you can know what exactly is happening.