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