src/util/common_logging.c

   1 /*
   2      This file is part of GNUnet.
   3      (C) 2006, 2008, 2009 Christian Grothoff (and other contributing authors)
   4
   5      GNUnet is free software; you can redistribute it and/or modify
   6      it under the terms of the GNU General Public License as published
   7      by the Free Software Foundation; either version 2, or (at your
   8      option) any later version.
   9
  10      GNUnet is distributed in the hope that it will be useful, but
  11      WITHOUT ANY WARRANTY; without even the implied warranty of
  12      MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  13      General Public License for more details.
  14
  15      You should have received a copy of the GNU General Public License
  16      along with GNUnet; see the file COPYING.  If not, write to the
  17      Free Software Foundation, Inc., 59 Temple Place - Suite 330,
  18      Boston, MA 02111-1307, USA.
  19 */
  20
  21 /**
  22  * @file util/common_logging.c
  23  * @brief error handling API
  24  *
  25  * @author Christian Grothoff
  26  */
  27 #include "platform.h"
  28 #include "gnunet_common.h"
  29 #include "gnunet_crypto_lib.h"
  30 #include "gnunet_strings_lib.h"
  31 #include "gnunet_time_lib.h"
  32
  33 /**
  34  * After how many milliseconds do we always print
  35  * that "message X was repeated N times"?  Use 12h.
  36  */
  37 #define BULK_DELAY_THRESHOLD (12 * 60 * 60 * 1000)
  38
  39 /**
  40  * After how many repetitions do we always print
  41  * that "message X was repeated N times"? (even if
  42  * we have not yet reached the delay threshold)
  43  */
  44 #define BULK_REPEAT_THRESHOLD 1000
  45
  46 /**
  47  * How many characters do we use for matching of
  48  * bulk messages?
  49  */
  50 #define BULK_TRACK_SIZE 256
  51
  52 /**
  53  * How many characters do we use for matching of
  54  * bulk components?
  55  */
  56 #define COMP_TRACK_SIZE 32
  57
  58 /**
  59  * How many characters can a date/time string
  60  * be at most?
  61  */
  62 #define DATE_STR_SIZE 64
  63
  64 /**
  65  * Linked list of active loggers.
  66  */
  67 struct CustomLogger
  68 {
  69   /**
  70    * This is a linked list.
  71    */
  72   struct CustomLogger *next;
  73
  74   /**
  75    * Log function.
  76    */
  77   GNUNET_Logger logger;
  78
  79   /**
  80    * Closure for logger.
  81    */
  82   void *logger_cls;
  83 };
  84
  85 /**
  86  * The last "bulk" error message that we have been logging.
  87  * Note that this message maybe truncated to the first BULK_TRACK_SIZE
  88  * characters, in which case it is NOT 0-terminated!
  89  */
  90 static char last_bulk[BULK_TRACK_SIZE];
  91
  92 /**
  93  * Type of the last bulk message.
  94  */
  95 static enum GNUNET_ErrorType last_bulk_kind;
  96
  97 /**
  98  * Time of the last bulk error message (0 for none)
  99  */
 100 static struct GNUNET_TIME_Absolute last_bulk_time;
 101
 102 /**
 103  * Number of times that bulk message has been repeated since.
 104  */
 105 static unsigned int last_bulk_repeat;
 106
 107 /**
 108  * Component when the last bulk was logged.  Will be 0-terminated.
 109  */
 110 static char last_bulk_comp[COMP_TRACK_SIZE+1];
 111
 112 /**
 113  * Running component.
 114  */
 115 static char *component;
 116
 117 /**
 118  * Minimum log level.
 119  */
 120 static enum GNUNET_ErrorType min_level;
 121
 122 /**
 123  * Linked list of our custom loggres.
 124  */
 125 static struct CustomLogger *loggers;
 126
 127 /**
 128  * Number of log calls to ignore.
 129  */
 130 static unsigned int skip_log;
 131
 132 /**
 133  * File descriptor to use for "stderr", or NULL for none.
 134  */
 135 static FILE *GNUNET_stderr;
 136
 137 #ifdef WINDOWS
 138 /**
 139  * Contains the number of performance counts per second.
 140  */
 141 LARGE_INTEGER performance_frequency;
 142 #endif
 143
 144 /**
 145  * Convert a textual description of a loglevel
 146  * to the respective GNUNET_GE_KIND.
 147  *
 148  * @param log loglevel to parse
 149  * @return GNUNET_GE_INVALID if log does not parse
 150  */
 151 static enum GNUNET_ErrorType
 152 get_type (const char *log)
 153 {
 154   if (0 == strcasecmp (log, _("DEBUG")))
 155     return GNUNET_ERROR_TYPE_DEBUG;
 156   if (0 == strcasecmp (log, _("INFO")))
 157     return GNUNET_ERROR_TYPE_INFO;
 158   if (0 == strcasecmp (log, _("WARNING")))
 159     return GNUNET_ERROR_TYPE_WARNING;
 160   if (0 == strcasecmp (log, _("ERROR")))
 161     return GNUNET_ERROR_TYPE_ERROR;
 162   if (0 == strcasecmp (log, _("NONE")))
 163     return GNUNET_ERROR_TYPE_NONE;
 164   return GNUNET_ERROR_TYPE_INVALID;
 165 }
 166
 167
 168 /**
 169  * Setup logging.
 170  *
 171  * @param comp default component to use
 172  * @param loglevel what types of messages should be logged
 173  * @param logfile which file to write log messages to (can be NULL)
 174  * @return GNUNET_OK on success
 175  */
 176 int
 177 GNUNET_log_setup (const char *comp, const char *loglevel, const char *logfile)
 178 {
 179   FILE *altlog;
 180   int dirwarn;
 181   char *fn;
 182   const char *env_loglevel;
 183   int env_minlevel = 0;
 184   int env_min_force_level = 100000;
 185
 186 #ifdef WINDOWS
 187   QueryPerformanceFrequency (&performance_frequency);
 188 #endif
 189   GNUNET_free_non_null (component);
 190   GNUNET_asprintf (&component,
 191                    "%s-%d",
 192                    comp,
 193                    getpid());
 194   env_loglevel = getenv ("GNUNET_LOGLEVEL");
 195   if (env_loglevel != NULL)
 196     env_minlevel = get_type (env_loglevel);
 197   env_loglevel = getenv ("GNUNET_FORCE_LOGLEVEL");
 198   if (env_loglevel != NULL)
 199     env_min_force_level = get_type (env_loglevel);
 200   min_level = get_type (loglevel);
 201   if (env_minlevel > min_level)
 202     min_level = env_minlevel;
 203   if (env_min_force_level < min_level)
 204     min_level = env_min_force_level;
 205   if (logfile == NULL)
 206     return GNUNET_OK;
 207   fn = GNUNET_STRINGS_filename_expand (logfile);
 208   if (NULL == fn)
 209     return GNUNET_SYSERR;
 210   dirwarn = (GNUNET_OK !=  GNUNET_DISK_directory_create_for_file (fn));
 211   altlog = FOPEN (fn, "a");
 212   if (altlog == NULL)
 213     {
 214       GNUNET_log_strerror_file (GNUNET_ERROR_TYPE_ERROR, "fopen", fn);
 215       if (dirwarn)
 216         GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
 217                     _("Failed to create or access directory for log file `%s'\n"),
 218                     fn);
 219       GNUNET_free (fn);
 220       return GNUNET_SYSERR;
 221     }
 222   GNUNET_free (fn);
 223   if (GNUNET_stderr != NULL)
 224     fclose (GNUNET_stderr);
 225   GNUNET_stderr = altlog;
 226   return GNUNET_OK;
 227 }
 228
 229 /**
 230  * Add a custom logger.
 231  *
 232  * @param logger log function
 233  * @param logger_cls closure for logger
 234  */
 235 void
 236 GNUNET_logger_add (GNUNET_Logger logger, void *logger_cls)
 237 {
 238   struct CustomLogger *entry;
 239
 240   entry = GNUNET_malloc (sizeof (struct CustomLogger));
 241   entry->logger = logger;
 242   entry->logger_cls = logger_cls;
 243   entry->next = loggers;
 244   loggers = entry;
 245 }
 246
 247 /**
 248  * Remove a custom logger.
 249  *
 250  * @param logger log function
 251  * @param logger_cls closure for logger
 252  */
 253 void
 254 GNUNET_logger_remove (GNUNET_Logger logger, void *logger_cls)
 255 {
 256   struct CustomLogger *pos;
 257   struct CustomLogger *prev;
 258
 259   prev = NULL;
 260   pos = loggers;
 261   while ((pos != NULL) &&
 262          ((pos->logger != logger) || (pos->logger_cls != logger_cls)))
 263     {
 264       prev = pos;
 265       pos = pos->next;
 266     }
 267   GNUNET_assert (pos != NULL);
 268   if (prev == NULL)
 269     loggers = pos->next;
 270   else
 271     prev->next = pos->next;
 272   GNUNET_free (pos);
 273 }
 274
 275
 276 /**
 277  * Actually output the log message.
 278  *
 279  * @param kind how severe was the issue
 280  * @param comp component responsible
 281  * @param datestr current date/time
 282  * @param msg the actual message
 283  */
 284 static void
 285 output_message (enum GNUNET_ErrorType kind,
 286                 const char *comp, const char *datestr, const char *msg)
 287 {
 288   struct CustomLogger *pos;
 289   if (GNUNET_stderr != NULL)
 290     {
 291       fprintf (GNUNET_stderr, "%s %s %s %s", datestr, comp,
 292                GNUNET_error_type_to_string (kind), msg);
 293       fflush (GNUNET_stderr);
 294     }
 295   pos = loggers;
 296   while (pos != NULL)
 297     {
 298       pos->logger (pos->logger_cls, kind, comp, datestr, msg);
 299       pos = pos->next;
 300     }
 301 }
 302
 303
 304 /**
 305  * Flush an existing bulk report to the output.
 306  *
 307  * @param datestr our current timestamp
 308  */
 309 static void
 310 flush_bulk (const char *datestr)
 311 {
 312   char msg[DATE_STR_SIZE + BULK_TRACK_SIZE + 256];
 313   int rev;
 314   char *last;
 315   char *ft;
 316
 317   if ((last_bulk_time.abs_value == 0) || (last_bulk_repeat == 0))
 318     return;
 319   rev = 0;
 320   last = memchr (last_bulk, '\0', BULK_TRACK_SIZE);
 321   if (last == NULL)
 322     last = &last_bulk[BULK_TRACK_SIZE - 1];
 323   else if (last != last_bulk)
 324     last--;
 325   if (last[0] == '\n')
 326     {
 327       rev = 1;
 328       last[0] = '\0';
 329     }
 330   ft =
 331     GNUNET_STRINGS_relative_time_to_string (GNUNET_TIME_absolute_get_duration
 332                                             (last_bulk_time));
 333   snprintf (msg, sizeof (msg),
 334             _("Message `%.*s' repeated %u times in the last %s\n"),
 335             BULK_TRACK_SIZE, last_bulk, last_bulk_repeat, ft);
 336   GNUNET_free (ft);
 337   if (rev == 1)
 338     last[0] = '\n';
 339   output_message (last_bulk_kind, last_bulk_comp, datestr, msg);
 340   last_bulk_time = GNUNET_TIME_absolute_get ();
 341   last_bulk_repeat = 0;
 342 }
 343
 344
 345 /**
 346  * Ignore the next n calls to the log function.
 347  *
 348  * @param n number of log calls to ignore
 349  * @param check_reset GNUNET_YES to assert that the log skip counter is currently zero
 350  */
 351 void
 352 GNUNET_log_skip (unsigned int n, int check_reset)
 353 {
 354   if (n == 0)
 355     {
 356       int ok;
 357
 358       ok = (0 == skip_log);
 359       skip_log = 0;
 360       if (check_reset)
 361         GNUNET_assert (ok);
 362     }
 363   else
 364     skip_log += n;
 365 }
 366
 367
 368 /**
 369  * Output a log message using the default mechanism.
 370  *
 371  * @param kind how severe was the issue
 372  * @param comp component responsible
 373  * @param message the actual message
 374  * @param va arguments to the format string "message"
 375  */
 376 static void
 377 mylog (enum GNUNET_ErrorType kind,
 378        const char *comp, const char *message, va_list va)
 379 {
 380   char date[DATE_STR_SIZE];
 381   char date2[DATE_STR_SIZE];
 382   time_t timetmp;
 383   struct timeval timeofday;
 384   struct tm *tmptr;
 385   size_t size;
 386   char *buf;
 387   va_list vacp;
 388
 389   if (skip_log > 0)
 390     {
 391       skip_log--;
 392       return;
 393     }
 394   if ((kind & (~GNUNET_ERROR_TYPE_BULK)) > min_level)
 395     return;
 396   va_copy (vacp, va);
 397   size = VSNPRINTF (NULL, 0, message, vacp) + 1;
 398   va_end (vacp);
 399   buf = malloc (size);
 400   if (buf == NULL)
 401     return;                     /* oops */
 402   VSNPRINTF (buf, size, message, va);
 403   time (&timetmp);
 404   memset (date, 0, DATE_STR_SIZE);
 405   tmptr = localtime (&timetmp);
 406   gettimeofday(&timeofday, NULL);
 407   if (NULL != tmptr)
 408   {
 409 #ifdef WINDOWS
 410     LARGE_INTEGER pc;
 411     pc.QuadPart = 0;
 412     QueryPerformanceCounter (&pc);
 413     strftime (date2, DATE_STR_SIZE, "%b %d %H:%M:%S-%%020llu", tmptr);
 414     snprintf (date, sizeof (date), date2, (long long) (pc.QuadPart / (performance_frequency.QuadPart / 1000)));
 415 #else
 416     strftime (date2, DATE_STR_SIZE, "%b %d %H:%M:%S-%%06u", tmptr);
 417     snprintf (date, sizeof (date), date2, timeofday.tv_usec);
 418 #endif
 419   }
 420   else
 421     strcpy (date, "localtime error");
 422   if ((0 != (kind & GNUNET_ERROR_TYPE_BULK)) &&
 423       (last_bulk_time.abs_value != 0) &&
 424       (0 == strncmp (buf, last_bulk, sizeof (last_bulk))))
 425     {
 426       last_bulk_repeat++;
 427       if ((GNUNET_TIME_absolute_get_duration (last_bulk_time).rel_value >
 428            BULK_DELAY_THRESHOLD)
 429           || (last_bulk_repeat > BULK_REPEAT_THRESHOLD))
 430         flush_bulk (date);
 431       free (buf);
 432       return;
 433     }
 434   flush_bulk (date);
 435   strncpy (last_bulk, buf, sizeof (last_bulk));
 436   last_bulk_repeat = 0;
 437   last_bulk_kind = kind;
 438   last_bulk_time = GNUNET_TIME_absolute_get ();
 439   strncpy (last_bulk_comp, comp, COMP_TRACK_SIZE);
 440   output_message (kind, comp, date, buf);
 441   free (buf);
 442 }
 443
 444
 445 /**
 446  * Main log function.
 447  *
 448  * @param kind how serious is the error?
 449  * @param message what is the message (format string)
 450  * @param ... arguments for format string
 451  */
 452 void
 453 GNUNET_log (enum GNUNET_ErrorType kind, const char *message, ...)
 454 {
 455   va_list va;
 456   va_start (va, message);
 457   mylog (kind, component, message, va);
 458   va_end (va);
 459 }
 460
 461
 462 /**
 463  * Log function that specifies an alternative component.
 464  * This function should be used by plugins.
 465  *
 466  * @param kind how serious is the error?
 467  * @param comp component responsible for generating the message
 468  * @param message what is the message (format string)
 469  * @param ... arguments for format string
 470  */
 471 void
 472 GNUNET_log_from (enum GNUNET_ErrorType kind,
 473                  const char *comp, const char *message, ...)
 474 {
 475   va_list va;
 476   char comp_w_pid[128];
 477
 478   va_start (va, message);
 479   GNUNET_snprintf (comp_w_pid,
 480                    sizeof (comp_w_pid),
 481                    "%s-%d",
 482                    comp,
 483                    getpid());
 484   mylog (kind, comp_w_pid, message, va);
 485   va_end (va);
 486 }
 487
 488
 489 /**
 490  * Convert error type to string.
 491  *
 492  * @param kind type to convert
 493  * @return string corresponding to the type
 494  */
 495 const char *
 496 GNUNET_error_type_to_string (enum GNUNET_ErrorType kind)
 497 {
 498   if ((kind & GNUNET_ERROR_TYPE_ERROR) > 0)
 499     return _("ERROR");
 500   if ((kind & GNUNET_ERROR_TYPE_WARNING) > 0)
 501     return _("WARNING");
 502   if ((kind & GNUNET_ERROR_TYPE_INFO) > 0)
 503     return _("INFO");
 504   if ((kind & GNUNET_ERROR_TYPE_DEBUG) > 0)
 505     return _("DEBUG");
 506   return _("INVALID");
 507 }
 508
 509
 510 /**
 511  * Convert a hash to a string (for printing debug messages).
 512  * This is one of the very few calls in the entire API that is
 513  * NOT reentrant!
 514  *
 515  * @param hc the hash code
 516  * @return string form; will be overwritten by next call to GNUNET_h2s.
 517  */
 518 const char *
 519 GNUNET_h2s (const GNUNET_HashCode * hc)
 520 {
 521   static struct GNUNET_CRYPTO_HashAsciiEncoded ret;
 522
 523   GNUNET_CRYPTO_hash_to_enc (hc, &ret);
 524   ret.encoding[8] = '\0';
 525   return (const char *) ret.encoding;
 526 }
 527
 528 /**
 529  * Convert a hash to a string (for printing debug messages).
 530  * This is one of the very few calls in the entire API that is
 531  * NOT reentrant!
 532  *
 533  * @param hc the hash code
 534  * @return string form; will be overwritten by next call to GNUNET_h2s_full.
 535  */
 536 const char *
 537 GNUNET_h2s_full (const GNUNET_HashCode * hc)
 538 {
 539   static struct GNUNET_CRYPTO_HashAsciiEncoded ret;
 540
 541   GNUNET_CRYPTO_hash_to_enc (hc, &ret);
 542   ret.encoding[sizeof(ret)-1] = '\0';
 543   return (const char *) ret.encoding;
 544 }
 545
 546 /**
 547  * Convert a peer identity to a string (for printing debug messages).
 548  * This is one of the very few calls in the entire API that is
 549  * NOT reentrant!
 550  *
 551  * @param pid the peer identity
 552  * @return string form of the pid; will be overwritten by next
 553  *         call to GNUNET_i2s.
 554  */
 555 const char *
 556 GNUNET_i2s (const struct GNUNET_PeerIdentity *pid)
 557 {
 558   static struct GNUNET_CRYPTO_HashAsciiEncoded ret;
 559
 560   GNUNET_CRYPTO_hash_to_enc (&pid->hashPubKey, &ret);
 561   ret.encoding[4] = '\0';
 562   return (const char *) ret.encoding;
 563 }
 564
 565
 566
 567 /**
 568  * Convert a "struct sockaddr*" (IPv4 or IPv6 address) to a string
 569  * (for printing debug messages).  This is one of the very few calls
 570  * in the entire API that is NOT reentrant!
 571  *
 572  * @param addr the address
 573  * @param addrlen the length of the address
 574  * @return nicely formatted string for the address
 575  *  will be overwritten by next call to GNUNET_a2s.
 576  */
 577 const char *
 578 GNUNET_a2s (const struct sockaddr *addr, socklen_t addrlen)
 579 {
 580   static char buf[INET6_ADDRSTRLEN + 8];
 581   static char b2[6];
 582   const struct sockaddr_in *v4;
 583   const struct sockaddr_un *un;
 584   const struct sockaddr_in6 *v6;
 585   unsigned int off;
 586
 587   if (addr == NULL)
 588     return _("unknown address");
 589   switch (addr->sa_family)
 590     {
 591     case AF_INET:
 592       if (addrlen != sizeof (struct sockaddr_in))
 593         return "<invalid v4 address>";
 594       v4 = (const struct sockaddr_in *) addr;
 595       inet_ntop (AF_INET, &v4->sin_addr, buf, INET_ADDRSTRLEN);
 596       if (0 == ntohs (v4->sin_port))
 597         return buf;
 598       strcat (buf, ":");
 599       GNUNET_snprintf (b2, sizeof(b2), "%u", ntohs (v4->sin_port));
 600       strcat (buf, b2);
 601       return buf;
 602     case AF_INET6:
 603       if (addrlen != sizeof (struct sockaddr_in6))
 604         return "<invalid v4 address>";
 605       v6 = (const struct sockaddr_in6 *) addr;
 606       buf[0] = '[';
 607       inet_ntop (AF_INET6, &v6->sin6_addr, &buf[1], INET6_ADDRSTRLEN);
 608       if (0 == ntohs (v6->sin6_port))
 609         return &buf[1];
 610       strcat (buf, "]:");
 611       GNUNET_snprintf (b2, sizeof(b2), "%u", ntohs (v6->sin6_port));
 612       strcat (buf, b2);
 613       return buf;
 614     case AF_UNIX:
 615       if (addrlen <= sizeof (sa_family_t))
 616         return "<unbound UNIX client>";
 617       un = (const struct sockaddr_un*) addr;
 618       off = 0;
 619       if (un->sun_path[0] == '\0') off++;
 620       snprintf (buf,
 621                 sizeof (buf),
 622                 "%s%.*s",
 623                 (off == 1) ? "@" : "",
 624                 (int) (addrlen - sizeof (sa_family_t) - 1 - off),
 625                 &un->sun_path[off]);
 626       return buf;
 627     default:
 628       return _("invalid address");
 629     }
 630 }
 631
 632
 633 /**
 634  * Initializer
 635  */
 636 void __attribute__ ((constructor)) GNUNET_util_cl_init ()
 637 {
 638   GNUNET_stderr = stderr;
 639 #ifdef MINGW
 640   GNInitWinEnv (NULL);
 641 #endif
 642 }
 643
 644
 645 /**
 646  * Destructor
 647  */
 648 void __attribute__ ((destructor)) GNUNET_util_cl_fini ()
 649 {
 650 #ifdef MINGW
 651   GNShutdownWinEnv ();
 652 #endif
 653 }
 654
 655 /* end of common_logging.c */