src/log.c

   1 #include "common.h"
   2
   3 const char *program_name = "";
   4 unsigned long long debug_flags = DEBUG;
   5
   6 int access_log_syslog = 1;
   7 int error_log_syslog = 1;
   8 int output_log_syslog = 1;      // debug log
   9
  10 int stdaccess_fd = -1;
  11 FILE *stdaccess = NULL;
  12
  13 const char *stdaccess_filename = NULL;
  14 const char *stderr_filename = NULL;
  15 const char *stdout_filename = NULL;
  16
  17 void syslog_init(void) {
  18     static int i = 0;
  19
  20     if(!i) {
  21         openlog(program_name, LOG_PID, LOG_DAEMON);
  22         i = 1;
  23     }
  24 }
  25
  26 int open_log_file(int fd, FILE **fp, const char *filename, int *enabled_syslog) {
  27     int f, t;
  28
  29     if(!filename || !*filename || !strcmp(filename, "none"))
  30         filename = "/dev/null";
  31
  32     if(!strcmp(filename, "syslog")) {
  33         filename = "/dev/null";
  34         syslog_init();
  35         if(enabled_syslog) *enabled_syslog = 1;
  36     }
  37     else if(enabled_syslog) *enabled_syslog = 0;
  38
  39     // don't do anything if the user is willing
  40     // to have the standard one
  41     if(!strcmp(filename, "system"))
  42         return fd;
  43
  44     if(!strcmp(filename, "stdout"))
  45         f = STDOUT_FILENO;
  46
  47     else if(!strcmp(filename, "stderr"))
  48         f = STDERR_FILENO;
  49
  50     else {
  51         f = open(filename, O_WRONLY | O_APPEND | O_CREAT, 0664);
  52         if(f == -1) {
  53             error("Cannot open file '%s'. Leaving %d to its default.", filename, fd);
  54             return fd;
  55         }
  56     }
  57
  58     // if there is a level-2 file pointer
  59     // flush it before switching the level-1 fds
  60     if(fp && *fp)
  61         fflush(*fp);
  62
  63     if(fd != f && fd != -1) {
  64         // it automatically closes
  65         t = dup2(f, fd);
  66         if (t == -1) {
  67             error("Cannot dup2() new fd %d to old fd %d for '%s'", f, fd, filename);
  68             close(f);
  69             return fd;
  70         }
  71         // info("dup2() new fd %d to old fd %d for '%s'", f, fd, filename);
  72         close(f);
  73     }
  74     else fd = f;
  75
  76     if(fp && *fp == NULL) {
  77         // info("fdopen(%d) on filename '%s'", fd, filename);
  78
  79         FILE *n = fdopen(fd, "a");
  80         if (!n)
  81             error("Cannot fdopen() fd %d ('%s')", fd, filename);
  82
  83         else {
  84             if (setvbuf(n, NULL, _IOLBF, 0) != 0)
  85                 error("Cannot set line buffering on fd %d ('%s')", fd, filename);
  86
  87             if(!*fp)
  88                 *fp = n;
  89             else {
  90                 FILE *o = *fp;
  91                 *fp = n;
  92                 fclose(o);
  93             }
  94         }
  95     }
  96
  97     return fd;
  98 }
  99
 100 void reopen_all_log_files() {
 101     if(stdout_filename)
 102         open_log_file(STDOUT_FILENO, &stdout, stdout_filename, &output_log_syslog);
 103
 104     if(stderr_filename)
 105         open_log_file(STDERR_FILENO, &stderr, stderr_filename, &error_log_syslog);
 106
 107     if(stdaccess_filename)
 108         stdaccess_fd = open_log_file(stdaccess_fd, &stdaccess, stdaccess_filename, &access_log_syslog);
 109 }
 110
 111 void open_all_log_files() {
 112     // disable stdin
 113     open_log_file(STDIN_FILENO, &stdin, "/dev/null", NULL);
 114
 115     open_log_file(STDOUT_FILENO, &stdout, stdout_filename, &output_log_syslog);
 116     open_log_file(STDERR_FILENO, &stderr, stderr_filename, &error_log_syslog);
 117     stdaccess_fd = open_log_file(stdaccess_fd, &stdaccess, stdaccess_filename, &access_log_syslog);
 118 }
 119
 120 // ----------------------------------------------------------------------------
 121 // error log throttling
 122
 123 time_t error_log_throttle_period = 1200;
 124 unsigned long error_log_errors_per_period = 200;
 125
 126 int error_log_limit(int reset) {
 127         static time_t start = 0;
 128         static unsigned long counter = 0, prevented = 0;
 129
 130         // do not throttle if the period is 0
 131         if(error_log_throttle_period == 0)
 132                 return 0;
 133
 134         // prevent all logs if the errors per period is 0
 135         if(error_log_errors_per_period == 0)
 136                 return 1;
 137
 138         time_t now = time(NULL);
 139         if(!start) start = now;
 140
 141         if(reset) {
 142                 if(prevented) {
 143                         log_date(stderr);
 144                         fprintf(stderr, "%s: Resetting logging for process '%s' (prevented %lu logs in the last %ld seconds).\n"
 145                                         , program_name
 146                                 , program_name
 147                                         , prevented
 148                                         , now - start
 149                         );
 150                 }
 151
 152                 start = now;
 153                 counter = 0;
 154                 prevented = 0;
 155         }
 156
 157         // detect if we log too much
 158         counter++;
 159
 160         if(now - start > error_log_throttle_period) {
 161                 if(prevented) {
 162                         log_date(stderr);
 163                         fprintf(stderr, "%s: Resuming logging from process '%s' (prevented %lu logs in the last %ld seconds).\n"
 164                                         , program_name
 165                                 , program_name
 166                                         , prevented
 167                                         , error_log_throttle_period
 168                         );
 169                 }
 170
 171                 // restart the period accounting
 172                 start = now;
 173                 counter = 1;
 174                 prevented = 0;
 175
 176                 // log this error
 177                 return 0;
 178         }
 179
 180         if(counter > error_log_errors_per_period) {
 181                 if(!prevented) {
 182                         log_date(stderr);
 183                         fprintf(stderr, "%s: Too many logs (%lu logs in %ld seconds, threshold is set to %lu logs in %ld seconds). Preventing more logs from process '%s' for %ld seconds.\n"
 184                                         , program_name
 185                                 , counter
 186                                 , now - start
 187                                 , error_log_errors_per_period
 188                                 , error_log_throttle_period
 189                                 , program_name
 190                                         , start + error_log_throttle_period - now);
 191                 }
 192
 193                 prevented++;
 194
 195                 // prevent logging this error
 196                 return 1;
 197         }
 198
 199         return 0;
 200 }
 201
 202 // ----------------------------------------------------------------------------
 203 // print the date
 204
 205 // FIXME
 206 // this should print the date in a buffer the way it
 207 // is now, logs from multiple threads may be multiplexed
 208
 209 void log_date(FILE *out)
 210 {
 211                 char outstr[24];
 212                 time_t t;
 213                 struct tm *tmp, tmbuf;
 214
 215                 t = time(NULL);
 216                 tmp = localtime_r(&t, &tmbuf);
 217
 218                 if (tmp == NULL) return;
 219                 if (unlikely(strftime(outstr, sizeof(outstr), "%y-%m-%d %H:%M:%S", tmp) == 0)) return;
 220
 221                 fprintf(out, "%s: ", outstr);
 222 }
 223
 224 // ----------------------------------------------------------------------------
 225 // debug log
 226
 227 void debug_int( const char *file, const char *function, const unsigned long line, const char *fmt, ... )
 228 {
 229         va_list args;
 230
 231         log_date(stdout);
 232         va_start( args, fmt );
 233         printf("DEBUG (%04lu@%-10.10s:%-15.15s): %s: ", line, file, function, program_name);
 234         vprintf(fmt, args);
 235         va_end( args );
 236         putchar('\n');
 237
 238         if(output_log_syslog) {
 239                 va_start( args, fmt );
 240                 vsyslog(LOG_ERR,  fmt, args );
 241                 va_end( args );
 242         }
 243
 244         fflush(stdout);
 245 }
 246
 247 // ----------------------------------------------------------------------------
 248 // info log
 249
 250 void info_int( const char *file, const char *function, const unsigned long line, const char *fmt, ... )
 251 {
 252         va_list args;
 253
 254         // prevent logging too much
 255         if(error_log_limit(0)) return;
 256
 257         log_date(stderr);
 258
 259         va_start( args, fmt );
 260         if(debug_flags) fprintf(stderr, "INFO (%04lu@%-10.10s:%-15.15s): %s: ", line, file, function, program_name);
 261         else            fprintf(stderr, "INFO: %s: ", program_name);
 262         vfprintf( stderr, fmt, args );
 263         va_end( args );
 264
 265         fputc('\n', stderr);
 266
 267         if(error_log_syslog) {
 268                 va_start( args, fmt );
 269                 vsyslog(LOG_INFO,  fmt, args );
 270                 va_end( args );
 271         }
 272 }
 273
 274 // ----------------------------------------------------------------------------
 275 // error log
 276
 277 void error_int( const char *prefix, const char *file, const char *function, const unsigned long line, const char *fmt, ... )
 278 {
 279         va_list args;
 280
 281         // prevent logging too much
 282         if(error_log_limit(0)) return;
 283
 284         log_date(stderr);
 285
 286         va_start( args, fmt );
 287         if(debug_flags) fprintf(stderr, "%s (%04lu@%-10.10s:%-15.15s): %s: ", prefix, line, file, function, program_name);
 288         else            fprintf(stderr, "%s: %s: ", prefix, program_name);
 289         vfprintf( stderr, fmt, args );
 290         va_end( args );
 291
 292         if(errno) {
 293                 char buf[1024];
 294                 fprintf(stderr, " (errno %d, %s)\n", errno, strerror_r(errno, buf, 1023));
 295                 errno = 0;
 296         }
 297         else
 298                 fputc('\n', stderr);
 299
 300         if(error_log_syslog) {
 301                 va_start( args, fmt );
 302                 vsyslog(LOG_ERR,  fmt, args );
 303                 va_end( args );
 304         }
 305 }
 306
 307 void fatal_int( const char *file, const char *function, const unsigned long line, const char *fmt, ... )
 308 {
 309         va_list args;
 310
 311         log_date(stderr);
 312
 313         va_start( args, fmt );
 314         if(debug_flags) fprintf(stderr, "FATAL (%04lu@%-10.10s:%-15.15s): %s: ", line, file, function, program_name);
 315         else            fprintf(stderr, "FATAL: %s: ", program_name);
 316         vfprintf( stderr, fmt, args );
 317         va_end( args );
 318
 319         perror(" # ");
 320         fputc('\n', stderr);
 321
 322         if(error_log_syslog) {
 323                 va_start( args, fmt );
 324                 vsyslog(LOG_CRIT,  fmt, args );
 325                 va_end( args );
 326         }
 327
 328         netdata_cleanup_and_exit(1);
 329 }
 330
 331 // ----------------------------------------------------------------------------
 332 // access log
 333
 334 void log_access( const char *fmt, ... )
 335 {
 336         va_list args;
 337
 338         if(stdaccess) {
 339                 log_date(stdaccess);
 340
 341                 va_start( args, fmt );
 342                 vfprintf( stdaccess, fmt, args );
 343                 va_end( args );
 344                 fputc('\n', stdaccess);
 345         }
 346
 347         if(access_log_syslog) {
 348                 va_start( args, fmt );
 349                 vsyslog(LOG_INFO,  fmt, args );
 350                 va_end( args );
 351         }
 352 }
 353