lib/silcutil/silclog.c

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