lib/silcutil/silclog.c

   1 /*
   2
   3   silclog.c
   4
   5   Author: Giovanni Giacobbi <giovanni@giacobbi.net>
   6
   7   Copyright (C) 1997 - 2005 Pekka Riikonen
   8
   9   This program is free software; you can redistribute it and/or modify
  10   it under the terms of the GNU General Public License as published by
  11   the Free Software Foundation; either version 2 of the License, or
  12   (at your option) any later version.
  13
  14   This program is distributed in the hope that it will be useful,
  15   but WITHOUT ANY WARRANTY; without even the implied warranty of
  16   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  17   GNU General Public License for more details.
  18
  19 */
  20 /* $Id$ */
  21
  22 #include "silcincludes.h"
  23
  24 /* Minimum time delay for log flushing calls (in seconds) */
  25 #define SILC_LOG_FLUSH_MIN_DELAY 2
  26
  27 /* nice macro for looping through all logs -- makes the code more readable */
  28 #define SILC_FOREACH_LOG(__x__) for (__x__ = 0; __x__ < SILC_LOG_MAX; __x__++)
  29
  30 /* Our working struct -- at the moment we keep it private, but this could
  31  * change in the future */
  32 struct SilcLogStruct {
  33   char filename[256];
  34   FILE *fp;
  35   SilcUInt32 maxsize;
  36   const char *typename;
  37   SilcLogType type;
  38   SilcLogCb cb;
  39   void *context;
  40 };
  41 typedef struct SilcLogStruct *SilcLog;
  42
  43 /* These are the known logging channels.  We initialize this struct with most
  44  * of the fields set to NULL, because we'll fill in those values at runtime. */
  45 static struct SilcLogStruct silclogs[SILC_LOG_MAX] = {
  46   {"", NULL, 0, "Info", SILC_LOG_INFO, NULL, NULL},
  47   {"", NULL, 0, "Warning", SILC_LOG_WARNING, NULL, NULL},
  48   {"", NULL, 0, "Error", SILC_LOG_ERROR, NULL, NULL},
  49   {"", NULL, 0, "Fatal", SILC_LOG_FATAL, NULL, NULL},
  50 };
  51
  52 /* Causes logging output to contain timestamps */
  53 bool silc_log_timestamp = TRUE;
  54
  55 /* If TRUE, log files will be flushed for each log input */
  56 bool silc_log_quick = FALSE;
  57
  58 /* Set TRUE/FALSE to enable/disable debugging */
  59 bool silc_debug = FALSE;
  60 bool silc_debug_hexdump = FALSE;
  61
  62 /* Flush delay (in seconds) */
  63 long silc_log_flushdelay = 300;
  64
  65 /* Regular pattern matching expression for the debug output */
  66 char silc_log_debug_string[128];
  67
  68 /* Debug callbacks. If set, these are triggered for each specific output. */
  69 static SilcLogDebugCb silc_log_debug_cb = NULL;
  70 static void *silc_log_debug_context = NULL;
  71 static SilcLogHexdumpCb silc_log_hexdump_cb = NULL;
  72 static void *silc_log_hexdump_context = NULL;
  73
  74 /* Did we register already our functions to the scheduler? */
  75 static bool silc_log_scheduled = FALSE;
  76 static bool silc_log_no_init = FALSE;
  77
  78 /* This is only needed during starting up -- don't lose any logging message */
  79 static bool silc_log_starting = TRUE;
  80
  81 /* The type wrapper utility. Translates a SilcLogType id to the corresponding
  82  * logfile, or NULL if not found. */
  83 static SilcLog silc_log_find_by_type(SilcLogType type)
  84 {
  85   /* this is not really needed, but i think it's more secure */
  86   switch (type) {
  87     case SILC_LOG_INFO:
  88       return &silclogs[SILC_LOG_INFO];
  89     case SILC_LOG_WARNING:
  90       return &silclogs[SILC_LOG_WARNING];
  91     case SILC_LOG_ERROR:
  92       return &silclogs[SILC_LOG_ERROR];
  93     case SILC_LOG_FATAL:
  94       return &silclogs[SILC_LOG_FATAL];
  95     default:
  96       return NULL;
  97   }
  98   return NULL;
  99 }
 100
 101 /* Given an open log file, checks the size and rotates it if there is a
 102  * max size set lower then the current size */
 103 static void silc_log_checksize(SilcLog log)
 104 {
 105   char newname[127];
 106   long size;
 107
 108   if (!log || !log->fp || !log->maxsize)
 109     return; /* we are not interested */
 110
 111   if ((size = ftell(log->fp)) < 0) {
 112     /* OMG, EBADF is here.. we'll try our best.. */
 113     FILE *oldfp = log->fp;
 114     fclose(oldfp); /* we can discard the error */
 115     log->fp = NULL; /* make sure we don't get here recursively */
 116     SILC_LOG_ERROR(("Error while checking size of the log file %s, fp=%p",
 117                     log->filename, oldfp));
 118     return;
 119   }
 120   if (size < log->maxsize)
 121     return;
 122
 123   /* It's too big */
 124   fprintf(log->fp, "[%s] [%s] Cycling log file, over max "
 125           "logsize (%lu kilobytes)\n",
 126           silc_get_time(0), log->typename, (unsigned long)log->maxsize / 1024);
 127   fflush(log->fp);
 128   fclose(log->fp);
 129   memset(newname, 0, sizeof(newname));
 130   snprintf(newname, sizeof(newname) - 1, "%s.old", log->filename);
 131   unlink(newname);
 132
 133   /* I heard the following syscall may cause portability issues, but I don't
 134    * have any other solution since SILC library doesn't provide any other
 135    * function like this. -Johnny */
 136   rename(log->filename, newname);
 137   if (!(log->fp = fopen(log->filename, "w")))
 138     SILC_LOG_WARNING(("Couldn't reopen logfile %s for type \"%s\": %s",
 139                       log->filename, log->typename, strerror(errno)));
 140 #ifdef HAVE_CHMOD
 141   chmod(log->filename, 0600);
 142 #endif /* HAVE_CHMOD */
 143 }
 144
 145 /* Reset a logging channel (close and reopen) */
 146
 147 static bool silc_log_reset(SilcLog log)
 148 {
 149   if (!log) return FALSE;
 150   if (log->fp) {
 151     fflush(log->fp);
 152     fclose(log->fp);
 153   }
 154   if (!log->filename[0]) return FALSE;
 155   if (!(log->fp = fopen(log->filename, "a+"))) {
 156     SILC_LOG_WARNING(("Couldn't reset logfile %s for type \"%s\": %s",
 157                       log->filename, log->typename, strerror(errno)));
 158     return FALSE;
 159   }
 160
 161   return TRUE;
 162 }
 163
 164 /* Internal timeout callback to flush log channels and check file sizes */
 165
 166 SILC_TASK_CALLBACK(silc_log_fflush_callback)
 167 {
 168   unsigned int u;
 169   if (!silc_log_quick) {
 170     silc_log_flush_all();
 171     SILC_FOREACH_LOG(u)
 172       silc_log_checksize(&silclogs[u]);
 173   }
 174   silc_log_starting = FALSE;
 175   if (silc_log_flushdelay < SILC_LOG_FLUSH_MIN_DELAY)
 176     silc_log_flushdelay = SILC_LOG_FLUSH_MIN_DELAY;
 177   silc_schedule_task_add((SilcSchedule) context, 0, silc_log_fflush_callback,
 178                          context, silc_log_flushdelay, 0, SILC_TASK_TIMEOUT,
 179                          SILC_TASK_PRI_NORMAL);
 180 }
 181
 182 /* Outputs the log message to the first available channel. Channels are
 183  * ordered by importance (see SilcLogType documentation).
 184  * More important channels can be printed on less important ones, but not
 185  * vice-versa. */
 186
 187 void silc_log_output(SilcLogType type, char *string)
 188 {
 189   const char *typename = NULL;
 190   FILE *fp;
 191   SilcLog log;
 192
 193   if ((type > SILC_LOG_MAX) || !(log = silc_log_find_by_type(type)))
 194     goto end;
 195
 196   /* Save the original typename, because even if we redirect the message
 197    * to another channel we'll keep however the original channel name */
 198   typename = log->typename;
 199
 200   /* If there is a custom callback set, use it and return. */
 201   if (log->cb) {
 202     if ((*log->cb)(type, string, log->context))
 203       goto end;
 204   }
 205
 206   if (!silc_log_scheduled) {
 207     if (silc_log_no_init == FALSE) {
 208       fprintf(stderr,
 209               "Warning, trying to output without log files initialization, "
 210               "log output is going to stderr\n");
 211       silc_log_no_init = TRUE;
 212     }
 213     /* redirect output */
 214     fp = stderr;
 215     log = NULL;
 216     goto found;
 217   }
 218
 219   /* ok, now we have to find an open stream */
 220   while (TRUE) {
 221     if (log && (fp = log->fp)) goto found;
 222     if (type == 0) break;
 223     log = silc_log_find_by_type(--type);
 224   }
 225
 226   /* Couldn't find any open stream.. sorry :( */
 227   SILC_LOG_DEBUG(("Warning! couldn't find any available log channel!"));
 228   goto end;
 229
 230  found:
 231   /* writes the logging string to the selected channel */
 232   if (silc_log_timestamp)
 233     fprintf(fp, "[%s] [%s] %s\n", silc_get_time(0), typename, string);
 234   else
 235     fprintf(fp, "[%s] %s\n", typename, string);
 236
 237   if (silc_log_quick || silc_log_starting) {
 238     fflush(fp);
 239     if (log) /* we may have been redirected to stderr */
 240       silc_log_checksize(log);
 241   }
 242
 243  end:
 244   /* If debugging, also output the logging message to the console */
 245   if (typename && silc_debug) {
 246     fprintf(stderr, "[Logging] [%s] %s\n", typename, string);
 247     fflush(stderr);
 248   }
 249   silc_free(string);
 250 }
 251
 252 /* returns an internally allocated pointer to a logging channel file */
 253 char *silc_log_get_file(SilcLogType type)
 254 {
 255   SilcLog log;
 256
 257   if (!(log = silc_log_find_by_type(type)))
 258     return NULL;
 259   if (log->fp)
 260     return log->filename;
 261   return NULL;
 262 }
 263
 264 /* Set and initialize the specified logging channel. See the API reference */
 265 bool silc_log_set_file(SilcLogType type, char *filename, SilcUInt32 maxsize,
 266                        SilcSchedule scheduler)
 267 {
 268   FILE *fp = NULL;
 269   SilcLog log;
 270
 271   log = silc_log_find_by_type(type);
 272   if (!log)
 273     return FALSE;
 274
 275   SILC_LOG_DEBUG(("Setting \"%s\" file to %s (max size=%d)",
 276                   log->typename, filename, maxsize));
 277
 278   /* before assuming the new file, make sure we can open it */
 279   if (filename) {
 280     if (!(fp = fopen(filename, "a+"))) {
 281       fprintf(stderr, "warning: couldn't open log file %s: %s\n",
 282               filename, strerror(errno));
 283       return FALSE;
 284     }
 285 #ifdef HAVE_CHMOD
 286     chmod(filename, 0600);
 287 #endif /* HAVE_CHMOD */
 288   }
 289
 290   /* clean the logging channel */
 291   if (strlen(log->filename)) {
 292     if (log->fp)
 293       fclose(log->fp);
 294     memset(log->filename, 0, sizeof(log->filename));
 295     log->fp = NULL;
 296   }
 297
 298   if (fp) {
 299     memset(log->filename, 0, sizeof(log->filename));
 300     strncpy(log->filename, filename,
 301             strlen(filename) < sizeof(log->filename) ? strlen(filename) :
 302             sizeof(log->filename) - 1);
 303     log->fp = fp;
 304     log->maxsize = maxsize;
 305   }
 306
 307   if (scheduler) {
 308     if (silc_log_scheduled)
 309       return TRUE;
 310
 311     /* Add schedule hook with a short delay to make sure we'll use
 312        right delay */
 313     silc_schedule_task_add(scheduler, 0, silc_log_fflush_callback,
 314                            (void *) scheduler, 10, 0,
 315                            SILC_TASK_TIMEOUT, SILC_TASK_PRI_NORMAL);
 316     silc_log_scheduled = TRUE;
 317   }
 318
 319   return TRUE;
 320 }
 321
 322 /* Sets a log callback, set callback to NULL to return to default behaviour */
 323
 324 void silc_log_set_callback(SilcLogType type, SilcLogCb cb, void *context)
 325 {
 326   SilcLog log;
 327
 328   if (!(log = silc_log_find_by_type(type)))
 329     return;
 330
 331   log->cb = cb;
 332   log->context = context;
 333 }
 334
 335 /* Resets log callbacks */
 336
 337 void silc_log_reset_callbacks()
 338 {
 339   unsigned int u;
 340   SILC_FOREACH_LOG(u) {
 341     silclogs[u].cb = NULL;
 342     silclogs[u].context = NULL;
 343   }
 344 }
 345
 346 /* Flushes all opened logging channels */
 347
 348 void silc_log_flush_all() {
 349   unsigned int u;
 350   SILC_LOG_DEBUG(("Flushing all logs"));
 351   SILC_FOREACH_LOG(u) {
 352     if (silclogs[u].fp)
 353       fflush(silclogs[u].fp);
 354   }
 355 }
 356
 357 /* Resets all known logging channels */
 358
 359 void silc_log_reset_all() {
 360   unsigned int u;
 361   SILC_LOG_DEBUG(("Resetting all logs"));
 362   SILC_FOREACH_LOG(u)
 363     silc_log_reset(&silclogs[u]);
 364   /* Immediately flush any possible warning message */
 365   silc_log_flush_all();
 366 }
 367
 368 /* Outputs the debug message to stderr. */
 369
 370 void silc_log_output_debug(char *file, const char *function,
 371                            int line, char *string)
 372 {
 373   if (!silc_debug)
 374     goto end;
 375
 376   if (silc_log_debug_string &&
 377       !silc_string_regex_match(silc_log_debug_string, file) &&
 378       !silc_string_regex_match(silc_log_debug_string, function))
 379     goto end;
 380
 381   if (silc_log_debug_cb) {
 382     if ((*silc_log_debug_cb)(file, (char *)function, line, string,
 383                              silc_log_debug_context))
 384       goto end;
 385   }
 386
 387   fprintf(stderr, "%s:%d: %s\n", function, line, string);
 388   fflush(stderr);
 389
 390  end:
 391   silc_free(string);
 392 }
 393
 394 /* Hexdumps a message */
 395
 396 void silc_log_output_hexdump(char *file, const char *function,
 397                              int line, void *data_in,
 398                              SilcUInt32 len, char *string)
 399 {
 400   int i, k;
 401   int off, pos, count;
 402   unsigned char *data = (unsigned char *)data_in;
 403
 404   if (!silc_debug_hexdump)
 405     goto end;
 406
 407   if (silc_log_debug_string &&
 408       !silc_string_regex_match(silc_log_debug_string, file) &&
 409       !silc_string_regex_match(silc_log_debug_string, function))
 410     goto end;
 411
 412   if (silc_log_hexdump_cb) {
 413     if ((*silc_log_hexdump_cb)(file, (char *)function, line,
 414                                data_in, len, string,
 415                                silc_log_hexdump_context))
 416       goto end;
 417   }
 418
 419   fprintf(stderr, "%s:%d: %s\n", function, line, string);
 420
 421   k = 0;
 422   pos = 0;
 423   count = 16;
 424   off = len % 16;
 425   while (1) {
 426     if (off) {
 427       if ((len - pos) < 16 && (len - pos <= len - off))
 428         count = off;
 429     } else {
 430       if (pos == len)
 431         count = 0;
 432     }
 433     if (off == len)
 434       count = len;
 435
 436     if (count)
 437       fprintf(stderr, "%08X  ", k++ * 16);
 438
 439     for (i = 0; i < count; i++) {
 440       fprintf(stderr, "%02X ", data[pos + i]);
 441
 442       if ((i + 1) % 4 == 0)
 443         fprintf(stderr, " ");
 444     }
 445
 446     if (count && count < 16) {
 447       int j;
 448
 449       for (j = 0; j < 16 - count; j++) {
 450         fprintf(stderr, "   ");
 451
 452         if ((j + count + 1) % 4 == 0)
 453           fprintf(stderr, " ");
 454       }
 455     }
 456
 457     for (i = 0; i < count; i++) {
 458       char ch;
 459
 460       if (data[pos] < 32 || data[pos] >= 127)
 461         ch = '.';
 462       else
 463         ch = data[pos];
 464
 465       fprintf(stderr, "%c", ch);
 466       pos++;
 467     }
 468
 469     if (count)
 470       fprintf(stderr, "\n");
 471
 472     if (count < 16)
 473       break;
 474   }
 475
 476  end:
 477   silc_free(string);
 478 }
 479
 480 /* Sets debug callbacks */
 481
 482 void silc_log_set_debug_callbacks(SilcLogDebugCb debug_cb,
 483                                   void *debug_context,
 484                                   SilcLogHexdumpCb hexdump_cb,
 485                                   void *hexdump_context)
 486 {
 487   silc_log_debug_cb = debug_cb;
 488   silc_log_debug_context = debug_context;
 489   silc_log_hexdump_cb = hexdump_cb;
 490   silc_log_hexdump_context = hexdump_context;
 491 }
 492
 493 /* Resets debug callbacks */
 494
 495 void silc_log_reset_debug_callbacks()
 496 {
 497   silc_log_debug_cb = NULL;
 498   silc_log_debug_context = NULL;
 499   silc_log_hexdump_cb = NULL;
 500   silc_log_hexdump_context = NULL;
 501 }
 502
 503 /* Set current debug string */
 504
 505 void silc_log_set_debug_string(const char *debug_string)
 506 {
 507   char *string;
 508   int len;
 509   if ((strchr(debug_string, '(') && strchr(debug_string, ')')) ||
 510       strchr(debug_string, '$'))
 511     string = strdup(debug_string);
 512   else
 513     string = silc_string_regexify(debug_string);
 514   len = strlen(string);
 515   if (len >= sizeof(silc_log_debug_string))
 516     len = sizeof(silc_log_debug_string) - 1;
 517   memset(silc_log_debug_string, 0, sizeof(silc_log_debug_string));
 518   strncpy(silc_log_debug_string, string, len);
 519   silc_free(string);
 520 }