src/log.c

   1 #include "common.h"
   2
   3 const char *program_name = "";
   4 uint64_t 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;
  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         if(fd != -1) return fd;
  43         filename = "stdout";
  44     }
  45
  46     if(!strcmp(filename, "stdout"))
  47         f = STDOUT_FILENO;
  48
  49     else if(!strcmp(filename, "stderr"))
  50         f = STDERR_FILENO;
  51
  52     else {
  53         f = open(filename, O_WRONLY | O_APPEND | O_CREAT, 0664);
  54         if(f == -1) {
  55             error("Cannot open file '%s'. Leaving %d to its default.", filename, fd);
  56             return fd;
  57         }
  58     }
  59
  60     // if there is a level-2 file pointer
  61     // flush it before switching the level-1 fds
  62     if(fp && *fp)
  63         fflush(*fp);
  64
  65     if(fd != f && fd != -1) {
  66         // it automatically closes
  67         int t = dup2(f, fd);
  68         if (t == -1) {
  69             error("Cannot dup2() new fd %d to old fd %d for '%s'", f, fd, filename);
  70             close(f);
  71             return fd;
  72         }
  73         // info("dup2() new fd %d to old fd %d for '%s'", f, fd, filename);
  74         close(f);
  75     }
  76     else fd = f;
  77
  78     if(fp && !*fp) {
  79         *fp = fdopen(fd, "a");
  80         if (!*fp)
  81             error("Cannot fdopen() fd %d ('%s')", fd, filename);
  82         else {
  83             if (setvbuf(*fp, NULL, _IOLBF, 0) != 0)
  84                 error("Cannot set line buffering on fd %d ('%s')", fd, filename);
  85         }
  86     }
  87
  88     return fd;
  89 }
  90
  91 void reopen_all_log_files() {
  92     if(stdout_filename)
  93         open_log_file(STDOUT_FILENO, (FILE **)&stdout, stdout_filename, &output_log_syslog);
  94
  95     if(stderr_filename)
  96         open_log_file(STDERR_FILENO, (FILE **)&stderr, stderr_filename, &error_log_syslog);
  97
  98     if(stdaccess_filename)
  99         stdaccess_fd = open_log_file(stdaccess_fd, (FILE **)&stdaccess, stdaccess_filename, &access_log_syslog);
 100 }
 101
 102 void open_all_log_files() {
 103     // disable stdin
 104     open_log_file(STDIN_FILENO, (FILE **)&stdin, "/dev/null", NULL);
 105
 106     open_log_file(STDOUT_FILENO, (FILE **)&stdout, stdout_filename, &output_log_syslog);
 107     open_log_file(STDERR_FILENO, (FILE **)&stderr, stderr_filename, &error_log_syslog);
 108     stdaccess_fd = open_log_file(stdaccess_fd, (FILE **)&stdaccess, stdaccess_filename, &access_log_syslog);
 109 }
 110
 111 // ----------------------------------------------------------------------------
 112 // error log throttling
 113
 114 time_t error_log_throttle_period_backup = 0;
 115 time_t error_log_throttle_period = 1200;
 116 unsigned long error_log_errors_per_period = 200;
 117
 118 int error_log_limit(int reset) {
 119     static time_t start = 0;
 120     static unsigned long counter = 0, prevented = 0;
 121
 122     // do not throttle if the period is 0
 123     if(error_log_throttle_period == 0)
 124         return 0;
 125
 126     // prevent all logs if the errors per period is 0
 127     if(error_log_errors_per_period == 0)
 128 #ifdef NETDATA_INTERNAL_CHECKS
 129         return 0;
 130 #else
 131         return 1;
 132 #endif
 133
 134     time_t now = now_monotonic_sec();
 135     if(!start) start = now;
 136
 137     if(reset) {
 138         if(prevented) {
 139             log_date(stderr);
 140             fprintf(stderr, "%s: Resetting logging for process '%s' (prevented %lu logs in the last %ld seconds).\n"
 141                     , program_name
 142                     , program_name
 143                     , prevented
 144                     , now - start
 145             );
 146         }
 147
 148         start = now;
 149         counter = 0;
 150         prevented = 0;
 151     }
 152
 153     // detect if we log too much
 154     counter++;
 155
 156     if(now - start > error_log_throttle_period) {
 157         if(prevented) {
 158             log_date(stderr);
 159             fprintf(stderr, "%s: Resuming logging from process '%s' (prevented %lu logs in the last %ld seconds).\n"
 160                     , program_name
 161                     , program_name
 162                     , prevented
 163                     , error_log_throttle_period
 164             );
 165         }
 166
 167         // restart the period accounting
 168         start = now;
 169         counter = 1;
 170         prevented = 0;
 171
 172         // log this error
 173         return 0;
 174     }
 175
 176     if(counter > error_log_errors_per_period) {
 177         if(!prevented) {
 178             log_date(stderr);
 179             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"
 180                     , program_name
 181                     , counter
 182                     , now - start
 183                     , error_log_errors_per_period
 184                     , error_log_throttle_period
 185                     , program_name
 186                     , start + error_log_throttle_period - now);
 187         }
 188
 189         prevented++;
 190
 191         // prevent logging this error
 192 #ifdef NETDATA_INTERNAL_CHECKS
 193         return 0;
 194 #else
 195         return 1;
 196 #endif
 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[26];
 212         time_t t;
 213         struct tm *tmp, tmbuf;
 214
 215         t = now_realtime_sec();
 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("%s: DEBUG (%04lu@%-10.10s:%-15.15s): ", program_name, line, file, function);
 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, "%s: INFO : (%04lu@%-10.10s:%-15.15s): ", program_name, line, file, function);
 261     else            fprintf(stderr, "%s: INFO : ", 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 #if defined(STRERROR_R_CHAR_P)
 278 // GLIBC version of strerror_r
 279 static const char *strerror_result(const char *a, const char *b) { (void)b; return a; }
 280 #elif defined(HAVE_STRERROR_R)
 281 // POSIX version of strerror_r
 282 static const char *strerror_result(int a, const char *b) { (void)a; return b; }
 283 #elif defined(HAVE_C__GENERIC)
 284
 285 // what a trick!
 286 // http://stackoverflow.com/questions/479207/function-overloading-in-c
 287 static const char *strerror_result_int(int a, const char *b) { (void)a; return b; }
 288 static const char *strerror_result_string(const char *a, const char *b) { (void)b; return a; }
 289
 290 #define strerror_result(a, b) _Generic((a), \
 291     int: strerror_result_int, \
 292     char *: strerror_result_string \
 293     )(a, b)
 294
 295 #else
 296 #error "cannot detect the format of function strerror_r()"
 297 #endif
 298
 299 void error_int( const char *prefix, const char *file, const char *function, const unsigned long line, const char *fmt, ... )
 300 {
 301     va_list args;
 302
 303     // prevent logging too much
 304     if(error_log_limit(0)) return;
 305
 306     log_date(stderr);
 307
 308     va_start( args, fmt );
 309     if(debug_flags) fprintf(stderr, "%s: %s: (%04lu@%-10.10s:%-15.15s): ", program_name, prefix, line, file, function);
 310     else            fprintf(stderr, "%s: %s: ", program_name, prefix);
 311     vfprintf( stderr, fmt, args );
 312     va_end( args );
 313
 314     if(errno) {
 315         char buf[1024];
 316         fprintf(stderr, " (errno %d, %s)\n", errno, strerror_result(strerror_r(errno, buf, 1023), buf));
 317         errno = 0;
 318     }
 319     else
 320         fputc('\n', stderr);
 321
 322     if(error_log_syslog) {
 323         va_start( args, fmt );
 324         vsyslog(LOG_ERR,  fmt, args );
 325         va_end( args );
 326     }
 327 }
 328
 329 void fatal_int( const char *file, const char *function, const unsigned long line, const char *fmt, ... )
 330 {
 331     va_list args;
 332
 333     log_date(stderr);
 334
 335     va_start( args, fmt );
 336     if(debug_flags) fprintf(stderr, "%s: FATAL: (%04lu@%-10.10s:%-15.15s): ", program_name, line, file, function);
 337     else            fprintf(stderr, "%s: FATAL: ", program_name);
 338     vfprintf( stderr, fmt, args );
 339     va_end( args );
 340
 341     perror(" # ");
 342     fputc('\n', stderr);
 343
 344     if(error_log_syslog) {
 345         va_start( args, fmt );
 346         vsyslog(LOG_CRIT,  fmt, args );
 347         va_end( args );
 348     }
 349
 350     netdata_cleanup_and_exit(1);
 351 }
 352
 353 // ----------------------------------------------------------------------------
 354 // access log
 355
 356 void log_access( const char *fmt, ... )
 357 {
 358     va_list args;
 359
 360     if(stdaccess) {
 361         log_date(stdaccess);
 362
 363         va_start( args, fmt );
 364         vfprintf( stdaccess, fmt, args );
 365         va_end( args );
 366         fputc('\n', stdaccess);
 367     }
 368
 369     if(access_log_syslog) {
 370         va_start( args, fmt );
 371         vsyslog(LOG_INFO,  fmt, args );
 372         va_end( args );
 373     }
 374 }
 375