utility/log.c

   1 /***********************************************************************
   2  Freeciv - Copyright (C) 1996 - A Kjeldberg, L Gregersen, P Unold
   3    This program is free software; you can redistribute it and/or modify
   4    it under the terms of the GNU General Public License as published by
   5    the Free Software Foundation; either version 2, or (at your option)
   6    any later version.
   7
   8    This program is distributed in the hope that it will be useful,
   9    but WITHOUT ANY WARRANTY; without even the implied warranty of
  10    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  11    GNU General Public License for more details.
  12 ***********************************************************************/
  13
  14 #ifdef HAVE_CONFIG_H
  15 #include <fc_config.h>
  16 #endif
  17
  18 #include <signal.h>
  19 #include <stdarg.h>
  20 #include <stdio.h>
  21 #include <string.h>
  22
  23 /* utility */
  24 #include "fciconv.h"
  25 #include "fcintl.h"
  26 #include "fcthread.h"
  27 #include "mem.h"
  28 #include "shared.h"
  29 #include "support.h"
  30
  31 #include "log.h"
  32
  33 #define MAX_LEN_LOG_LINE 5120
  34
  35 static void log_write(FILE *fs, enum log_level level, bool print_from_where,
  36                       const char *where, const char *message);
  37 static void log_real(enum log_level level, bool print_from_where,
  38                      const char *where, const char *msg);
  39
  40 static char *log_filename = NULL;
  41 static log_pre_callback_fn log_pre_callback = log_real;
  42 static log_callback_fn log_callback = NULL;
  43 static log_prefix_fn log_prefix = NULL;
  44
  45 static fc_mutex logfile_mutex;
  46
  47 #ifdef FREECIV_DEBUG
  48 static const enum log_level max_level = LOG_DEBUG;
  49 #else
  50 static const enum log_level max_level = LOG_VERBOSE;
  51 #endif /* FREECIV_DEBUG */
  52
  53 static enum log_level fc_log_level = LOG_NORMAL;
  54 static int fc_fatal_assertions = -1;
  55
  56 #ifdef FREECIV_DEBUG
  57 struct log_fileinfo {
  58   char *name;
  59   enum log_level level;
  60   int min;
  61   int max;
  62 };
  63 static int log_num_files = 0;
  64 static struct log_fileinfo *log_files = NULL;
  65 #endif /* FREECIV_DEBUG */
  66
  67 static char *log_level_names[] = {
  68   "Fatal", "Error", "Warning", "Normal", "Verbose", "Debug", NULL
  69 };
  70
  71 /* A helper variable to indicate that there is no log message. The '%s' is
  72  * added to use it as format string as well as the argument. */
  73 const char *nologmsg = "nologmsg:%s";
  74
  75 /**************************************************************************
  76   level_str should be either "0", "1", "2", "3", "4" or
  77   "4:filename" or "4:file1:file2" or "4:filename,100,200" etc
  78
  79   If everything goes ok, returns TRUE. If there was a parsing problem,
  80   prints to stderr, and returns FALSE.
  81
  82   Return in ret_level the requested level only if level_str is a simple
  83   number (like "0", "1", "2").
  84
  85   Also sets up the log_files data structure. Does _not_ set fc_log_level.
  86 **************************************************************************/
  87 bool log_parse_level_str(const char *level_str, enum log_level *ret_level)
  88 {
  89   const char *c;
  90   int n = 0;                    /* number of filenames */
  91   int level;
  92   int ln;
  93   int first_len = -1;
  94 #ifdef FREECIV_DEBUG
  95   const char *tok;
  96   int i;
  97   char *dupled;
  98   bool ret = TRUE;
  99 #endif /* FREECIV_DEBUG */
 100
 101   c = level_str;
 102   n = 0;
 103   while ((c = strchr(c, ':'))) {
 104     if (first_len < 0) {
 105       first_len = c - level_str;
 106     }
 107     c++;
 108     n++;
 109   }
 110   if (n == 0) {
 111     /* Global log level. */
 112     if (!str_to_int(level_str, &level)) {
 113       level = -1;
 114       for (ln = 0; log_level_names[ln] != NULL && level < 0; ln++) {
 115         if (!fc_strncasecmp(level_str, log_level_names[ln], strlen(level_str))) {
 116           level = ln;
 117         }
 118       }
 119       if (level < 0) {
 120         fc_fprintf(stderr, _("Bad log level \"%s\".\n"), level_str);
 121         return FALSE;
 122       }
 123     }
 124     if (level >= LOG_FATAL && level <= max_level) {
 125       if (NULL != ret_level) {
 126         *ret_level = level;
 127       }
 128       return TRUE;
 129     } else {
 130       fc_fprintf(stderr, _("Bad log level %d in \"%s\".\n"),
 131                  level, level_str);
 132 #ifndef FREECIV_DEBUG
 133       if (level == max_level + 1) {
 134         fc_fprintf(stderr,
 135                    _("Freeciv must be compiled with the FREECIV_DEBUG flag "
 136                      "to use debug level %d.\n"), max_level + 1);
 137       }
 138 #endif /* FREECIV_DEBUG */
 139       return FALSE;
 140     }
 141   }
 142
 143 #ifdef FREECIV_DEBUG
 144   c = level_str;
 145   level = -1;
 146   if (first_len > 0) {
 147     for (ln = 0; log_level_names[ln] != NULL && level < 0; ln++) {
 148       if (!fc_strncasecmp(level_str, log_level_names[ln], first_len)) {
 149         level = ln;
 150       }
 151     }
 152   }
 153   if (level < 0) {
 154     level = c[0] - '0';
 155     if (c[1] == ':') {
 156       if (level < LOG_FATAL || level > max_level) {
 157         fc_fprintf(stderr, _("Bad log level %c in \"%s\".\n"),
 158                    c[0], level_str);
 159         return FALSE;
 160       }
 161     } else {
 162       fc_fprintf(stderr, _("Badly formed log level argument \"%s\".\n"),
 163                  level_str);
 164       return FALSE;
 165     }
 166   }
 167   i = log_num_files;
 168   log_num_files += n;
 169   log_files = fc_realloc(log_files,
 170                          log_num_files * sizeof(struct log_fileinfo));
 171
 172   dupled = fc_strdup(c + 2);
 173   tok = strtok(dupled, ":");
 174
 175   if (!tok) {
 176     fc_fprintf(stderr, _("Badly formed log level argument \"%s\".\n"),
 177                level_str);
 178     ret = FALSE;
 179     goto out;
 180   }
 181   do {
 182     struct log_fileinfo *pfile = log_files + i;
 183     char *d = strchr(tok, ',');
 184
 185     pfile->min = 0;
 186     pfile->max = 0;
 187     pfile->level = level;
 188     if (d) {
 189       char *pc = d + 1;
 190
 191       d[0] = '\0';
 192       d = strchr(d + 1, ',');
 193       if (d && *pc != '\0' && d[1] != '\0') {
 194         d[0] = '\0';
 195         if (!str_to_int(pc, &pfile->min)) {
 196           fc_fprintf(stderr, _("Not an integer: '%s'\n"), pc);
 197           ret = FALSE;
 198           goto out;
 199         }
 200         if (!str_to_int(d + 1, &pfile->max)) {
 201           fc_fprintf(stderr, _("Not an integer: '%s'\n"), d + 1);
 202           ret = FALSE;
 203           goto out;
 204         }
 205       }
 206     }
 207     if (strlen(tok) == 0) {
 208       fc_fprintf(stderr, _("Empty filename in log level argument \"%s\".\n"),
 209                  level_str);
 210       ret = FALSE;
 211       goto out;
 212     }
 213     pfile->name = fc_strdup(tok);
 214     i++;
 215     tok = strtok(NULL, ":");
 216   } while (tok);
 217
 218   if (i != log_num_files) {
 219     fc_fprintf(stderr, _("Badly formed log level argument \"%s\".\n"),
 220                level_str);
 221     ret = FALSE;
 222     goto out;
 223   }
 224
 225 out:
 226   free(dupled);
 227   return ret;
 228 #else  /* FREECIV_DEBUG */
 229   fc_fprintf(stderr,
 230              _("Freeciv must be compiled with the FREECIV_DEBUG flag "
 231                "to use advanced log levels based on files.\n"));
 232   return FALSE;
 233 #endif /* FREECIV_DEBUG */
 234 }
 235
 236 /**************************************************************************
 237   Initialise the log module. Either 'filename' or 'callback' may be NULL.
 238   If both are NULL, print to stderr. If both are non-NULL, both callback,
 239   and fprintf to file.  Pass -1 for fatal_assertions to don't raise any
 240   signal on failed assertion.
 241 **************************************************************************/
 242 void log_init(const char *filename, enum log_level initial_level,
 243               log_callback_fn callback, log_prefix_fn prefix,
 244               int fatal_assertions)
 245 {
 246   fc_log_level = initial_level;
 247   if (log_filename) {
 248     free(log_filename);
 249     log_filename = NULL;
 250   }
 251   if (filename && strlen(filename) > 0) {
 252     log_filename = fc_strdup(filename);
 253   } else {
 254     log_filename = NULL;
 255   }
 256   log_callback = callback;
 257   log_prefix = prefix;
 258   fc_fatal_assertions = fatal_assertions;
 259   fc_init_mutex(&logfile_mutex);
 260   log_verbose("log started");
 261   log_debug("LOG_DEBUG test");
 262 }
 263
 264 /**************************************************************************
 265    Deinitialize logging module.
 266 **************************************************************************/
 267 void log_close(void)
 268 {
 269   fc_destroy_mutex(&logfile_mutex);
 270 }
 271
 272 /*****************************************************************************
 273   Adjust the log preparation callback function.
 274 *****************************************************************************/
 275 log_pre_callback_fn log_set_pre_callback(log_pre_callback_fn precallback)
 276 {
 277   log_pre_callback_fn old = log_pre_callback;
 278
 279   log_pre_callback = precallback;
 280
 281   return old;
 282 }
 283
 284 /*****************************************************************************
 285   Adjust the callback function after initial log_init().
 286 *****************************************************************************/
 287 log_callback_fn log_set_callback(log_callback_fn callback)
 288 {
 289   log_callback_fn old = log_callback;
 290
 291   log_callback = callback;
 292
 293   return old;
 294 }
 295
 296 /**************************************************************************
 297   Adjust the prefix callback function after initial log_init().
 298 **************************************************************************/
 299 log_prefix_fn log_set_prefix(log_prefix_fn prefix)
 300 {
 301   log_prefix_fn old = log_prefix;
 302
 303   log_prefix = prefix;
 304
 305   return old;
 306 }
 307
 308 /**************************************************************************
 309   Adjust the logging level after initial log_init().
 310 **************************************************************************/
 311 void log_set_level(enum log_level level)
 312 {
 313   fc_log_level = level;
 314 }
 315
 316 /**************************************************************************
 317   Returns the current log level.
 318 **************************************************************************/
 319 enum log_level log_get_level(void)
 320 {
 321   return fc_log_level;
 322 }
 323
 324 /**************************************************************************
 325   Return name of the given log level
 326 **************************************************************************/
 327 const char *log_level_name(enum log_level lvl)
 328 {
 329   if (lvl < LOG_FATAL || lvl > LOG_DEBUG) {
 330     return NULL;
 331   }
 332
 333   return log_level_names[lvl];
 334 }
 335
 336 #ifdef FREECIV_DEBUG
 337 /**************************************************************************
 338   Returns wether we should do an output for this level, in this file,
 339   at this line.
 340 **************************************************************************/
 341 bool log_do_output_for_level_at_location(enum log_level level,
 342                                          const char *file, int line)
 343 {
 344   struct log_fileinfo *pfile;
 345   int i;
 346
 347   for (i = 0, pfile = log_files; i < log_num_files; i++, pfile++) {
 348     if (pfile->level >= level
 349         && 0 == strcmp(pfile->name, file)
 350         && ((0 == pfile->min && 0 == pfile->max)
 351             || (pfile->min <= line && pfile->max >= line))) {
 352       return TRUE;
 353     }
 354   }
 355   return (fc_log_level >= level);
 356 }
 357 #endif /* FREECIV_DEBUG */
 358
 359 /*****************************************************************************
 360   Unconditionally print a simple string.
 361   Let the callback do its own level formatting and add a '\n' if it wants.
 362 *****************************************************************************/
 363 static void log_write(FILE *fs, enum log_level level, bool print_from_where,
 364                       const char *where, const char *message)
 365 {
 366   if (log_filename || (!log_callback)) {
 367     char prefix[128];
 368
 369     if (log_prefix) {
 370       /* Get the log prefix. */
 371       fc_snprintf(prefix, sizeof(prefix), "[%s] ", log_prefix());
 372     } else {
 373       prefix[0] = '\0';
 374     }
 375
 376     if (log_filename || (print_from_where && where)) {
 377       fc_fprintf(fs, "%d: %s%s%s\n", level, prefix, where, message);
 378     } else {
 379       fc_fprintf(fs, "%d: %s%s\n", level, prefix, message);
 380     }
 381     fflush(fs);
 382   }
 383
 384   if (log_callback) {
 385     if (print_from_where) {
 386       char buf[MAX_LEN_LOG_LINE];
 387
 388       fc_snprintf(buf, sizeof(buf), "%s%s", where, message);
 389       log_callback(level, buf, log_filename != NULL);
 390     } else {
 391       log_callback(level, message, log_filename != NULL);
 392     }
 393   }
 394 }
 395
 396 /*****************************************************************************
 397   Unconditionally print a log message. This function is usually protected
 398   by do_log_for().
 399 *****************************************************************************/
 400 void vdo_log(const char *file, const char *function, int line,
 401              bool print_from_where, enum log_level level,
 402              char *buf, int buflen, const char *message, va_list args)
 403 {
 404   char buf_where[MAX_LEN_LOG_LINE];
 405
 406   /* There used to be check against recursive logging here, but
 407    * the way it worked prevented any kind of simultaneous logging,
 408    * not just recursive. Multiple threads should be able to log
 409    * simultaneously. */
 410
 411   fc_vsnprintf(buf, buflen, message, args);
 412   fc_snprintf(buf_where, sizeof(buf_where), "in %s() [%s::%d]: ",
 413               function, file, line);
 414
 415   /* In the default configuration log_pre_callback is equal to log_real(). */
 416   if (log_pre_callback) {
 417     log_pre_callback(level, print_from_where, buf_where, buf);
 418   }
 419 }
 420
 421 /*****************************************************************************
 422   Really print a log message.
 423   For repeat message, may wait and print instead "last message repeated ..."
 424   at some later time.
 425   Calls log_callback if non-null, else prints to stderr.
 426 *****************************************************************************/
 427 static void log_real(enum log_level level, bool print_from_where,
 428                      const char *where, const char *msg)
 429 {
 430   static char last_msg[MAX_LEN_LOG_LINE] = "";
 431   static unsigned int repeated = 0; /* total times current message repeated */
 432   static unsigned int next = 2; /* next total to print update */
 433   static unsigned int prev = 0; /* total on last update */
 434   /* only count as repeat if same level */
 435   static enum log_level prev_level = -1;
 436   char buf[MAX_LEN_LOG_LINE];
 437   FILE *fs;
 438
 439   if (log_filename) {
 440     fc_allocate_mutex(&logfile_mutex);
 441     if (!(fs = fc_fopen(log_filename, "a"))) {
 442       fc_fprintf(stderr,
 443                  _("Couldn't open logfile: %s for appending \"%s\".\n"),
 444                  log_filename, msg);
 445       exit(EXIT_FAILURE);
 446     }
 447   } else {
 448     fs = stderr;
 449   }
 450
 451   if (level == prev_level && 0 == strncmp(msg, last_msg,
 452                                           MAX_LEN_LOG_LINE - 1)){
 453     repeated++;
 454     if (repeated == next) {
 455       fc_snprintf(buf, sizeof(buf),
 456                   PL_("last message repeated %d time",
 457                       "last message repeated %d times",
 458                       repeated-prev), repeated-prev);
 459       if (repeated > 2) {
 460         cat_snprintf(buf, sizeof(buf),
 461                      PL_(" (total %d repeat)",
 462                          " (total %d repeats)",
 463                          repeated), repeated);
 464       }
 465       log_write(fs, prev_level, print_from_where, where, buf);
 466       prev = repeated;
 467       next *= 2;
 468     }
 469   } else {
 470     if (repeated > 0 && repeated != prev) {
 471       if (repeated == 1) {
 472         /* just repeat the previous message: */
 473         log_write(fs, prev_level, print_from_where, where, last_msg);
 474       } else {
 475         fc_snprintf(buf, sizeof(buf),
 476                     PL_("last message repeated %d time",
 477                         "last message repeated %d times",
 478                         repeated - prev), repeated - prev);
 479         if (repeated > 2) {
 480           cat_snprintf(buf, sizeof(buf),
 481                        PL_(" (total %d repeat)", " (total %d repeats)",
 482                            repeated),  repeated);
 483         }
 484         log_write(fs, prev_level, print_from_where, where, buf);
 485       }
 486     }
 487     prev_level = level;
 488     repeated = 0;
 489     next = 2;
 490     prev = 0;
 491     log_write(fs, level, print_from_where, where, msg);
 492   }
 493   /* Save last message. */
 494   sz_strlcpy(last_msg, msg);
 495
 496   fflush(fs);
 497   if (log_filename) {
 498     fclose(fs);
 499     fc_release_mutex(&logfile_mutex);
 500   }
 501 }
 502
 503 /**************************************************************************
 504   Unconditionally print a log message. This function is usually protected
 505   by do_log_for().
 506   For repeat message, may wait and print instead
 507   "last message repeated ..." at some later time.
 508   Calls log_callback if non-null, else prints to stderr.
 509 **************************************************************************/
 510 void do_log(const char *file, const char *function, int line,
 511             bool print_from_where, enum log_level level,
 512             const char *message, ...)
 513 {
 514   char buf[MAX_LEN_LOG_LINE];
 515   va_list args;
 516
 517   va_start(args, message);
 518   vdo_log(file, function, line, print_from_where, level,
 519           buf, MAX_LEN_LOG_LINE, message, args);
 520   va_end(args);
 521 }
 522
 523 /**************************************************************************
 524   Set what signal the fc_assert* macros should raise on failed assertion
 525   (-1 to disable).
 526 **************************************************************************/
 527 void fc_assert_set_fatal(int fatal_assertions)
 528 {
 529   fc_fatal_assertions = fatal_assertions;
 530 }
 531
 532 #ifndef FREECIV_NDEBUG
 533 /**************************************************************************
 534   Returns wether the fc_assert* macros should raise a signal on failed
 535   assertion.
 536 **************************************************************************/
 537 void fc_assert_fail(const char *file, const char *function, int line,
 538                     const char *assertion, const char *message, ...)
 539 {
 540   enum log_level level = (0 <= fc_fatal_assertions ? LOG_FATAL : LOG_ERROR);
 541
 542   if (NULL != assertion) {
 543     do_log(file, function, line, TRUE, level,
 544            "assertion '%s' failed.", assertion);
 545   }
 546
 547   if (NULL != message && NOLOGMSG != message) {
 548     /* Additional message. */
 549     char buf[MAX_LEN_LOG_LINE];
 550     va_list args;
 551
 552     va_start(args, message);
 553     vdo_log(file, function, line, FALSE, level, buf, MAX_LEN_LOG_LINE,
 554             message, args);
 555     va_end(args);
 556   }
 557
 558   do_log(file, function, line, FALSE, level,
 559          /* TRANS: No full stop after the URL, could cause confusion. */
 560          _("Please report this message at %s"), BUG_URL);
 561
 562   if (0 <= fc_fatal_assertions) {
 563     /* Emit a signal. */
 564     raise(fc_fatal_assertions);
 565   }
 566 }
 567 #endif /* FREECIV_NDEBUG */