3

Objective: Write This line must be printed into log file mib_log_test in case of program hangs/stuck because of some weird reason.

For simplicity, wrote a C program as below:

#include <stdio.h>
#include <stdlib.h>

#define FILE_NAME "./mib_log_test"
FILE *fp = NULL;

int main()
{
    fp = fopen(FILE_NAME, "w+");
    if (fp == NULL) {
        fprintf(stderr, "Unable to open %s file", FILE_NAME);
        exit(EXIT_FAILURE);
    }
    fprintf(fp, "This line must be printed\n");
    while(1);
    return 0;
}

Upon compiling and running above program, it will never be terminated itself because of infinite loop. So I have to press ctrl + c to terminate it. with ctrl + c I do not see This line must be printed gets written in my logfile(mib_log_test)

And If I override default SIGINT handler as shown below, This line must be printed gets written in my logfile(mib_log_test).

#include <stdio.h>
#include <signal.h>
#include <stdlib.h>

#define FILE_NAME "./mib_log_test"
FILE *fp = NULL;

void sigint_handler(int sig_num)
{
    exit(EXIT_FAILURE);
}

int main()
{
    fp = fopen(FILE_NAME, "w+");
    if (fp == NULL) {
        fprintf(stderr, "Unable to open %s file", FILE_NAME);
        exit(EXIT_FAILURE);
    }
    signal(SIGINT, sigint_handler);
    fprintf(fp, "This line must be printed\n");
    while(1);
    return 0;
}

Question : What default SIGINT handler does that leads to not writing log messages in above case?

Raxesh Oriya
  • 383
  • 6
  • 27

2 Answers2

4

The default SIGINT handler terminates the process abnormally. This means _exit is called, which does not flush buffers.

As a side note, calling exit (which does flush buffers) from a signal handler is unsafe (only async-safe functions should be called from signal handlers). So, that's not a real solution to your problem.

You can add an fflush(fp); after the fprintf if you really want it to appear in the log file, even when the process gets terminated abnormally.

Flushing can be rather costly, however. If you want to avoid having to flush every single log line, but still want the log file to be flushed when receiving SIGINT, one approach is :

#include <signal.h>

static volatile sig_atomic_t keepRunning = 1;

void sigHandler(int sig) {
  keepRunning = 0;
}

int main(void) {
  signal(SIGINT, sigHandler);

  while (keepRunning) {
    /* normal operation, including logging */
  }

  /* cleanup */

  return 0; /* this will close (and thus flush) the log file */
}

The key is that the actual cleanup (which is often not async-safe) does not happen in the signal handler itself.

Sander De Dycker
  • 16,053
  • 1
  • 35
  • 40
  • As I said, above is just a sample code, my actual program is quite lengthy and tens of `fprintf` so where should I use `fflush` and is it effective to use multiple times? – Raxesh Oriya May 10 '19 at 08:55
  • @RaxeshOriya : `fflush` has a non-negligible cost, so you use it as often as needed, but no more. How often it's needed is something you'll have to determine for your specific needs. However, for long-running applications, a better approach to dealing with signals, is to set a flag in the signal handler, that then ends the main loop, so proper cleanup can be done before exiting (eg. https://stackoverflow.com/questions/4217037/catch-ctrl-c-in-c). The key here is that the cleanup does not happen in the signal handler. – Sander De Dycker May 10 '19 at 09:56
2

Stdio file buffers are block-buffered by default and when it crashes it doesn't flush the file buffer so that the buffered output gets lost.

One solution is to call fflush(fp) after each fprintf(fp, ...) but that is rather tedious.

Another solution is to use setvbuf to set the file to line-buffered mode immediately after opening the file, so that it flushes the buffer for you on each new-line symbol:

fp = fopen(FILE_NAME, "w+");
setvbuf(fp, NULL, _IOLBF, BUFSIZ);

This also makes tail -f <logfile> output immediate and line by line rather than delayed and in blocks.

Maxim Egorushkin
  • 131,725
  • 17
  • 180
  • 271