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