updates.
[silc.git] / lib / silcutil / silclog.c
index e48bfeed58adef486d6c40e8695a437b0e066473..3bd46b3554b051000903afdf8a1e8ed38aa78f2e 100644 (file)
@@ -21,8 +21,8 @@
 
 #include "silcincludes.h"
 
-/* default flush time (5 minutes) */
-#define SILC_LOG_TIMEOUT 300
+/* Minimum time delay for log flushing calls (in seconds) */
+#define SILC_LOG_FLUSH_MIN_DELAY 2
 
 /* nice macro for looping through all logs -- makes the code more readable */
 #define SILC_FOREACH_LOG(__x__) for (__x__ = 0; __x__ < SILC_LOG_MAX; __x__++)
@@ -32,7 +32,7 @@
 struct SilcLogStruct {
   char *filename;
   FILE *fp;
-  uint32 maxsize;
+  SilcUInt32 maxsize;
   char *typename;
   SilcLogType type;
   SilcLogCb cb;
@@ -40,11 +40,12 @@ struct SilcLogStruct {
 };
 typedef struct SilcLogStruct *SilcLog;
 
-/* These are the known logging channels */
+/* These are the known logging channels.  We initialize this struct with most
+ * of the fields set to NULL, because we'll fill in those values at runtime. */
 static struct SilcLogStruct silclogs[SILC_LOG_MAX] = {
   {NULL, NULL, 0, "Info", SILC_LOG_INFO, NULL, NULL},
-  {NULL, NULL, 0, "Error", SILC_LOG_ERROR, NULL, NULL},
   {NULL, NULL, 0, "Warning", SILC_LOG_WARNING, NULL, NULL},
+  {NULL, NULL, 0, "Error", SILC_LOG_ERROR, NULL, NULL},
   {NULL, NULL, 0, "Fatal", SILC_LOG_FATAL, NULL, NULL},
 };
 
@@ -55,10 +56,13 @@ bool silc_log_quick = FALSE;
 bool silc_debug = FALSE;
 bool silc_debug_hexdump = FALSE;
 
+/* Flush delay (in seconds) */
+long silc_log_flushdelay = 300;
+
 /* Regular pattern matching expression for the debug output */
-static char *silc_log_debug_string = NULL;
+char *silc_log_debug_string = NULL;
 
-/* Debug callbacks. If set these are used instead of default ones. */
+/* Debug callbacks. If set, these are triggered for each specific output. */
 static SilcLogDebugCb silc_log_debug_cb = NULL;
 static void *silc_log_debug_context = NULL;
 static SilcLogHexdumpCb silc_log_hexdump_cb = NULL;
@@ -68,6 +72,9 @@ static void *silc_log_hexdump_context = NULL;
 static bool silc_log_scheduled = FALSE;
 static bool silc_log_no_init = FALSE;
 
+/* This is only needed during starting up -- don't lose any logging message */
+static bool silc_log_starting = TRUE;
+
 /* The type wrapper utility. Translates a SilcLogType id to the corresponding
  * logfile, or NULL if not found. */
 static SilcLog silc_log_find_by_type(SilcLogType type)
@@ -89,7 +96,7 @@ static SilcLog silc_log_find_by_type(SilcLogType type)
 }
 
 /* Given an open log file, checks the size and rotates it if there is a
- * max size set less then the current size */
+ * max size set lower then the current size */
 static void silc_log_checksize(SilcLog log)
 {
   char newname[127];
@@ -97,12 +104,13 @@ static void silc_log_checksize(SilcLog log)
 
   if (!log || !log->fp || !log->maxsize)
     return; /* we are not interested */
+
   if ((size = ftell(log->fp)) < 0) {
     /* OMG, EBADF is here.. we'll try our best.. */
     FILE *oldfp = log->fp;
     fclose(oldfp); /* we can discard the error */
     log->fp = NULL; /* make sure we don't get here recursively */
-    SILC_LOG_ERROR(("Error while checking size of the log file %s, fp=%d",
+    SILC_LOG_ERROR(("Error while checking size of the log file %s, fp=%p",
                    log->filename, oldfp));
     return;
   }
@@ -135,11 +143,13 @@ static bool silc_log_reset(SilcLog log)
     fflush(log->fp);
     fclose(log->fp);
   }
+  if (!log->filename) return FALSE;
   if (!(log->fp = fopen(log->filename, "a+"))) {
     SILC_LOG_WARNING(("Couldn't reset logfile %s for type \"%s\": %s",
-       log->filename, log->typename, strerror(errno)));
+                     log->filename, log->typename, strerror(errno)));
     return FALSE;
   }
+
   return TRUE;
 }
 
@@ -148,29 +158,37 @@ static bool silc_log_reset(SilcLog log)
 SILC_TASK_CALLBACK(silc_log_fflush_callback)
 {
   unsigned int u;
-  if (!silc_log_quick) {
+  if (silc_log_quick) {
     silc_log_flush_all();
     SILC_FOREACH_LOG(u)
       silc_log_checksize(&silclogs[u]);
   }
+  silc_log_starting = FALSE;
+  if (silc_log_flushdelay < SILC_LOG_FLUSH_MIN_DELAY)
+    silc_log_flushdelay = SILC_LOG_FLUSH_MIN_DELAY;
   silc_schedule_task_add((SilcSchedule) context, 0, silc_log_fflush_callback,
-                        context, SILC_LOG_TIMEOUT, 0, SILC_TASK_TIMEOUT,
+                        context, silc_log_flushdelay, 0, SILC_TASK_TIMEOUT,
                         SILC_TASK_PRI_NORMAL);
 }
 
 /* Outputs the log message to the first available channel. Channels are
  * ordered by importance (see SilcLogType documentation).
- * More importants channels can be printed on less important ones, but not
+ * More important channels can be printed on less important ones, but not
  * vice-versa. */
 
 void silc_log_output(SilcLogType type, char *string)
 {
-  char *typename;
+  char *typename = NULL;
+  FILE *fp;
   SilcLog log;
 
   if ((type > SILC_LOG_MAX) || !(log = silc_log_find_by_type(type)))
     goto end;
 
+  /* Save the original typename, because even if we redirect the message
+   * to another channel we'll keep however the original channel name */
+  typename = log->typename;
+
   /* If there is a custom callback set, use it and return. */
   if (log->cb) {
     if ((*log->cb)(type, string, log->context))
@@ -179,23 +197,20 @@ void silc_log_output(SilcLogType type, char *string)
 
   if (!silc_log_scheduled) {
     if (silc_log_no_init == FALSE) {
-      fprintf(stderr, 
+      fprintf(stderr,
              "Warning, trying to output without log files initialization, "
              "log output is going to stderr\n");
       silc_log_no_init = TRUE;
     }
-
-    fprintf(stderr, "%s\n", string);
-    goto end;
+    /* redirect output */
+    fp = stderr;
+    log = NULL;
+    goto found;
   }
 
-  /* save the original typename, because if we redirect the channel we
-   * keep however the original destination channel name */
-  typename = log->typename;
-
   /* ok, now we have to find an open stream */
   while (TRUE) {
-    if (log && log->fp) goto found;
+    if (log && (fp = log->fp)) goto found;
     if (type == 0) break;
     log = silc_log_find_by_type(--type);
   }
@@ -205,13 +220,19 @@ void silc_log_output(SilcLogType type, char *string)
   goto end;
 
  found:
-  fprintf(log->fp, "[%s] [%s] %s\n", silc_get_time(), typename, string);
-  if (silc_log_quick) {
-    fflush(log->fp);
-    silc_log_checksize(log);
+  fprintf(fp, "[%s] [%s] %s\n", silc_get_time(), typename, string);
+  if (silc_log_quick || silc_log_starting) {
+    fflush(fp);
+    if (log) /* we may have been redirected to stderr */
+      silc_log_checksize(log);
   }
 
  end:
+  /* If debugging, also output the logging message to the console */
+  if (typename && silc_debug) {
+    fprintf(stderr, "[Logging] [%s] %s\n", typename, string);
+    fflush(stderr);
+  }
   silc_free(string);
 }
 
@@ -228,7 +249,7 @@ char *silc_log_get_file(SilcLogType type)
 }
 
 /* Set and initialize the specified logging channel. See the API reference */
-bool silc_log_set_file(SilcLogType type, char *filename, uint32 maxsize,
+bool silc_log_set_file(SilcLogType type, char *filename, SilcUInt32 maxsize,
                       SilcSchedule scheduler)
 {
   FILE *fp = NULL;
@@ -250,12 +271,10 @@ bool silc_log_set_file(SilcLogType type, char *filename, uint32 maxsize,
     }
   }
 
-  /* remove old file */
+  /* clean the logging channel */
   if (log->filename) {
-    if (log->fp) {
-      fflush(fp);
-      fclose(fp);
-    }
+    if (log->fp)
+      fclose(log->fp);
     silc_free(log->filename);
     log->filename = NULL;
     log->fp = NULL;
@@ -270,9 +289,9 @@ bool silc_log_set_file(SilcLogType type, char *filename, uint32 maxsize,
   if (silc_log_scheduled)
     return TRUE;
 
-  /* make sure we write to the disk sometimes */
+  /* add schedule hook with a short delay to make sure we'll use right delay */
   silc_schedule_task_add(scheduler, 0, silc_log_fflush_callback,
-                        (void *) scheduler, SILC_LOG_TIMEOUT, 0,
+                        (void *) scheduler, 10, 0,
                         SILC_TASK_TIMEOUT, SILC_TASK_PRI_NORMAL);
 
   silc_log_scheduled = TRUE;
@@ -322,6 +341,8 @@ void silc_log_reset_all() {
   SILC_LOG_DEBUG(("Resetting all logs"));
   SILC_FOREACH_LOG(u)
     silc_log_reset(&silclogs[u]);
+  /* Immediately flush any possible warning message */
+  silc_log_flush_all();
 }
 
 /* Outputs the debug message to stderr. */
@@ -331,18 +352,22 @@ void silc_log_output_debug(char *file, char *function,
 {
   if (!silc_debug)
     goto end;
+
   if (silc_log_debug_string &&
-       !silc_string_regex_match(silc_log_debug_string, file) &&
-       !silc_string_regex_match(silc_log_debug_string, function))
+      !silc_string_regex_match(silc_log_debug_string, file) &&
+      !silc_string_regex_match(silc_log_debug_string, function))
     goto end;
+
   if (silc_log_debug_cb) {
     if ((*silc_log_debug_cb)(file, function, line, string,
                             silc_log_debug_context))
       goto end;
   }
+
   fprintf(stderr, "%s:%d: %s\n", function, line, string);
   fflush(stderr);
-end:
+
+ end:
   silc_free(string);
 }
 
@@ -350,7 +375,7 @@ end:
 
 void silc_log_output_hexdump(char *file, char *function,
                             int line, void *data_in,
-                            uint32 len, char *string)
+                            SilcUInt32 len, char *string)
 {
   int i, k;
   int off, pos, count;
@@ -358,10 +383,12 @@ void silc_log_output_hexdump(char *file, char *function,
 
   if (!silc_debug_hexdump)
     goto end;
+
   if (silc_log_debug_string &&
-       !silc_string_regex_match(silc_log_debug_string, file) &&
-       !silc_string_regex_match(silc_log_debug_string, function))
+      !silc_string_regex_match(silc_log_debug_string, file) &&
+      !silc_string_regex_match(silc_log_debug_string, function))
     goto end;
+
   if (silc_log_hexdump_cb) {
     if ((*silc_log_hexdump_cb)(file, function, line, data_in, len, string,
                               silc_log_hexdump_context))
@@ -369,7 +396,6 @@ void silc_log_output_hexdump(char *file, char *function,
   }
 
   fprintf(stderr, "%s:%d: %s\n", function, line, string);
-  silc_free(string);
 
   k = 0;
   pos = 0;
@@ -425,9 +451,8 @@ void silc_log_output_hexdump(char *file, char *function,
     if (count < 16)
       break;
   }
-  return;
 
-end:
+ end:
   silc_free(string);
 }
 
@@ -459,9 +484,8 @@ void silc_log_reset_debug_callbacks()
 void silc_log_set_debug_string(const char *debug_string)
 {
   silc_free(silc_log_debug_string);
-  if ((strchr(debug_string, '(') &&
-       strchr(debug_string, ')')) ||
-       strchr(debug_string, '$'))
+  if ((strchr(debug_string, '(') && strchr(debug_string, ')')) ||
+      strchr(debug_string, '$'))
     silc_log_debug_string = strdup(debug_string);
   else
     silc_log_debug_string = silc_string_regexify(debug_string);