src/util/common_logging.c

   1 /*
   2      This file is part of GNUnet.
   3      Copyright (C) 2006-2013 GNUnet e.V.
   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 3, 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., 51 Franklin Street, Fifth Floor,
  18      Boston, MA 02110-1301, USA.
  19 */
  20
  21 /**
  22  * @file util/common_logging.c
  23  * @brief error handling API
  24  * @author Christian Grothoff
  25  */
  26 #include "platform.h"
  27 #include "gnunet_crypto_lib.h"
  28 #include "gnunet_disk_lib.h"
  29 #include "gnunet_strings_lib.h"
  30 #include <regex.h>
  31
  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 * 1000LL * 1000LL)
  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  * How many log files to keep?
  66  */
  67 #define ROTATION_KEEP 3
  68
  69 #ifndef PATH_MAX
  70 /**
  71  * Assumed maximum path length (for the log file name).
  72  */
  73 #define PATH_MAX 4096
  74 #endif
  75
  76
  77 /**
  78  * Linked list of active loggers.
  79  */
  80 struct CustomLogger
  81 {
  82   /**
  83    * This is a linked list.
  84    */
  85   struct CustomLogger *next;
  86
  87   /**
  88    * Log function.
  89    */
  90   GNUNET_Logger logger;
  91
  92   /**
  93    * Closure for logger.
  94    */
  95   void *logger_cls;
  96 };
  97
  98 /**
  99  * The last "bulk" error message that we have been logging.
 100  * Note that this message maybe truncated to the first BULK_TRACK_SIZE
 101  * characters, in which case it is NOT 0-terminated!
 102  */
 103 static char last_bulk[BULK_TRACK_SIZE];
 104
 105 /**
 106  * Type of the last bulk message.
 107  */
 108 static enum GNUNET_ErrorType last_bulk_kind;
 109
 110 /**
 111  * Time of the last bulk error message (0 for none)
 112  */
 113 static struct GNUNET_TIME_Absolute last_bulk_time;
 114
 115 /**
 116  * Number of times that bulk message has been repeated since.
 117  */
 118 static unsigned int last_bulk_repeat;
 119
 120 /**
 121  * Component when the last bulk was logged.  Will be 0-terminated.
 122  */
 123 static char last_bulk_comp[COMP_TRACK_SIZE + 1];
 124
 125 /**
 126  * Running component.
 127  */
 128 static char *component;
 129
 130 /**
 131  * Running component (without pid).
 132  */
 133 static char *component_nopid;
 134
 135 /**
 136  * Format string describing the name of the log file.
 137  */
 138 static char *log_file_name;
 139
 140 /**
 141  * Minimum log level.
 142  */
 143 static enum GNUNET_ErrorType min_level;
 144
 145 /**
 146  * Linked list of our custom loggres.
 147  */
 148 static struct CustomLogger *loggers;
 149
 150 /**
 151  * Number of log calls to ignore.
 152  */
 153 static int skip_log = 0;
 154
 155 /**
 156  * File descriptor to use for "stderr", or NULL for none.
 157  */
 158 static FILE *GNUNET_stderr;
 159
 160 /**
 161  * Represents a single logging definition
 162  */
 163 struct LogDef
 164 {
 165   /**
 166    * Component name regex
 167    */
 168   regex_t component_regex;
 169
 170   /**
 171    * File name regex
 172    */
 173   regex_t file_regex;
 174
 175   /**
 176    * Function name regex
 177    */
 178   regex_t function_regex;
 179
 180   /**
 181    * Lowest line at which this definition matches.
 182    * Defaults to 0. Must be <= to_line.
 183    */
 184   int from_line;
 185
 186   /**
 187    * Highest line at which this definition matches.
 188    * Defaults to INT_MAX. Must be >= from_line.
 189    */
 190   int to_line;
 191
 192   /**
 193    * Maximal log level allowed for calls that match this definition.
 194    * Calls with higher log level will be disabled.
 195    * Must be >= 0
 196    */
 197   int level;
 198
 199   /**
 200    * 1 if this definition comes from GNUNET_FORCE_LOG, which means that it
 201    * overrides any configuration options. 0 otherwise.
 202    */
 203   int force;
 204 };
 205
 206 /**
 207  * Dynamic array of logging definitions
 208  */
 209 static struct LogDef *logdefs;
 210
 211 /**
 212  * Allocated size of logdefs array (in units)
 213  */
 214 static int logdefs_size;
 215
 216 /**
 217  * The number of units used in logdefs array.
 218  */
 219 static int logdefs_len;
 220
 221 /**
 222  * GNUNET_YES if GNUNET_LOG environment variable is already parsed.
 223  */
 224 static int gnunet_log_parsed;
 225
 226 /**
 227  * GNUNET_YES if GNUNET_FORCE_LOG environment variable is already parsed.
 228  */
 229 static int gnunet_force_log_parsed;
 230
 231 /**
 232  * GNUNET_YES if at least one definition with forced == 1 is available.
 233  */
 234 static int gnunet_force_log_present;
 235
 236 #ifdef WINDOWS
 237 /**
 238  * Contains the number of performance counts per second.
 239  */
 240 static LARGE_INTEGER performance_frequency;
 241 #endif
 242
 243
 244 /**
 245  * Convert a textual description of a loglevel
 246  * to the respective GNUNET_GE_KIND.
 247  *
 248  * @param log loglevel to parse
 249  * @return GNUNET_GE_INVALID if log does not parse
 250  */
 251 static enum GNUNET_ErrorType
 252 get_type (const char *log)
 253 {
 254   if (NULL == log)
 255     return GNUNET_ERROR_TYPE_UNSPECIFIED;
 256   if (0 == strcasecmp (log, _("DEBUG")))
 257     return GNUNET_ERROR_TYPE_DEBUG;
 258   if (0 == strcasecmp (log, _("INFO")))
 259     return GNUNET_ERROR_TYPE_INFO;
 260   if (0 == strcasecmp (log, _("MESSAGE")))
 261     return GNUNET_ERROR_TYPE_MESSAGE;
 262   if (0 == strcasecmp (log, _("WARNING")))
 263     return GNUNET_ERROR_TYPE_WARNING;
 264   if (0 == strcasecmp (log, _("ERROR")))
 265     return GNUNET_ERROR_TYPE_ERROR;
 266   if (0 == strcasecmp (log, _("NONE")))
 267     return GNUNET_ERROR_TYPE_NONE;
 268   return GNUNET_ERROR_TYPE_INVALID;
 269 }
 270
 271
 272 #if !defined(GNUNET_CULL_LOGGING)
 273 /**
 274  * Utility function - reallocates logdefs array to be twice as large.
 275  */
 276 static void
 277 resize_logdefs ()
 278 {
 279   logdefs_size = (logdefs_size + 1) * 2;
 280   logdefs = GNUNET_realloc (logdefs, logdefs_size * sizeof (struct LogDef));
 281 }
 282
 283
 284 /**
 285  * Abort the process, generate a core dump if possible.
 286  */
 287 void
 288 GNUNET_abort_ ()
 289 {
 290 #if WINDOWS
 291   DebugBreak ();
 292 #endif
 293   abort ();
 294 }
 295
 296
 297 #if ! TALER_WALLET_ONLY
 298 /**
 299  * Rotate logs, deleting the oldest log.
 300  *
 301  * @param new_name new name to add to the rotation
 302  */
 303 static void
 304 log_rotate (const char *new_name)
 305 {
 306   static char *rotation[ROTATION_KEEP];
 307   static unsigned int rotation_off;
 308   char *discard;
 309
 310   if ('\0' == *new_name)
 311     return; /* not a real log file name */
 312   discard = rotation[rotation_off % ROTATION_KEEP];
 313   if (NULL != discard)
 314   {
 315     /* Note: can't log errors during logging (recursion!), so this
 316        operation MUST silently fail... */
 317     (void) UNLINK (discard);
 318     GNUNET_free (discard);
 319   }
 320   rotation[rotation_off % ROTATION_KEEP] = GNUNET_strdup (new_name);
 321   rotation_off++;
 322 }
 323
 324
 325 /**
 326  * Setup the log file.
 327  *
 328  * @param tm timestamp for which we should setup logging
 329  * @return #GNUNET_OK on success, #GNUNET_SYSERR on error
 330  */
 331 static int
 332 setup_log_file (const struct tm *tm)
 333 {
 334   static char last_fn[PATH_MAX + 1];
 335   char fn[PATH_MAX + 1];
 336   int altlog_fd;
 337   int dup_return;
 338   FILE *altlog;
 339   char *leftsquare;
 340
 341   if (NULL == log_file_name)
 342     return GNUNET_SYSERR;
 343   if (0 == strftime (fn, sizeof (fn), log_file_name, tm))
 344     return GNUNET_SYSERR;
 345   leftsquare = strrchr (fn, '[');
 346   if ( (NULL != leftsquare) && (']' == leftsquare[1]) )
 347   {
 348     char *logfile_copy = GNUNET_strdup (fn);
 349
 350     logfile_copy[leftsquare - fn] = '\0';
 351     logfile_copy[leftsquare - fn + 1] = '\0';
 352     snprintf (fn,
 353               PATH_MAX,
 354               "%s%d%s",
 355               logfile_copy,
 356               getpid (),
 357               &logfile_copy[leftsquare - fn + 2]);
 358     GNUNET_free (logfile_copy);
 359   }
 360   if (0 == strcmp (fn, last_fn))
 361     return GNUNET_OK; /* no change */
 362   log_rotate (last_fn);
 363   strcpy (last_fn, fn);
 364   if (GNUNET_SYSERR ==
 365       GNUNET_DISK_directory_create_for_file (fn))
 366   {
 367     fprintf (stderr,
 368              "Failed to create directory for `%s': %s\n",
 369              fn,
 370              STRERROR (errno));
 371     return GNUNET_SYSERR;
 372   }
 373 #if WINDOWS
 374   altlog_fd = OPEN (fn, O_APPEND |
 375                         O_BINARY |
 376                         O_WRONLY | O_CREAT,
 377                         _S_IREAD | _S_IWRITE);
 378 #else
 379   altlog_fd = OPEN (fn, O_APPEND |
 380                         O_WRONLY | O_CREAT,
 381                         S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH);
 382 #endif
 383   if (-1 != altlog_fd)
 384   {
 385     if (NULL != GNUNET_stderr)
 386       fclose (GNUNET_stderr);
 387     dup_return = dup2 (altlog_fd, 2);
 388     (void) close (altlog_fd);
 389     if (-1 != dup_return)
 390     {
 391       altlog = fdopen (2, "ab");
 392       if (NULL == altlog)
 393       {
 394         (void) close (2);
 395         altlog_fd = -1;
 396       }
 397     }
 398     else
 399     {
 400       altlog_fd = -1;
 401     }
 402   }
 403   if (-1 == altlog_fd)
 404   {
 405     GNUNET_log_strerror_file (GNUNET_ERROR_TYPE_ERROR, "open", fn);
 406     return GNUNET_SYSERR;
 407   }
 408   GNUNET_stderr = altlog;
 409   return GNUNET_OK;
 410 }
 411 #endif
 412
 413
 414 /**
 415  * Utility function - adds a parsed definition to logdefs array.
 416  *
 417  * @param component see struct LogDef, can't be NULL
 418  * @param file see struct LogDef, can't be NULL
 419  * @param function see struct LogDef, can't be NULL
 420  * @param from_line see struct LogDef
 421  * @param to_line see struct LogDef
 422  * @param level see struct LogDef, must be >= 0
 423  * @param force see struct LogDef
 424  * @return 0 on success, regex-specific error otherwise
 425  */
 426 static int
 427 add_definition (const char *component,
 428                 const char *file,
 429                 const char *function,
 430                 int from_line,
 431                 int to_line,
 432                 int level,
 433                 int force)
 434 {
 435   struct LogDef n;
 436   int r;
 437
 438   if (logdefs_size == logdefs_len)
 439     resize_logdefs ();
 440   memset (&n, 0, sizeof (n));
 441   if (0 == strlen (component))
 442     component = (char *) ".*";
 443   r = regcomp (&n.component_regex, (const char *) component, REG_NOSUB);
 444   if (0 != r)
 445   {
 446     return r;
 447   }
 448   if (0 == strlen (file))
 449     file = (char *) ".*";
 450   r = regcomp (&n.file_regex, (const char *) file, REG_NOSUB);
 451   if (0 != r)
 452   {
 453     regfree (&n.component_regex);
 454     return r;
 455   }
 456   if ((NULL == function) || (0 == strlen (function)))
 457     function = (char *) ".*";
 458   r = regcomp (&n.function_regex, (const char *) function, REG_NOSUB);
 459   if (0 != r)
 460   {
 461     regfree (&n.component_regex);
 462     regfree (&n.file_regex);
 463     return r;
 464   }
 465   n.from_line = from_line;
 466   n.to_line = to_line;
 467   n.level = level;
 468   n.force = force;
 469   logdefs[logdefs_len++] = n;
 470   return 0;
 471 }
 472
 473
 474 /**
 475  * Decides whether a particular logging call should or should not be allowed
 476  * to be made. Used internally by GNUNET_log*()
 477  *
 478  * @param caller_level loglevel the caller wants to use
 479  * @param comp component name the caller uses (NULL means that global
 480  *   component name is used)
 481  * @param file file name containing the logging call, usually __FILE__
 482  * @param function function which tries to make a logging call,
 483  *   usually __FUNCTION__
 484  * @param line line at which the call is made, usually __LINE__
 485  * @return 0 to disallow the call, 1 to allow it
 486  */
 487 int
 488 GNUNET_get_log_call_status (int caller_level,
 489                             const char *comp,
 490                             const char *file,
 491                             const char *function,
 492                             int line)
 493 {
 494   struct LogDef *ld;
 495   int i;
 496   int force_only;
 497
 498   if (NULL == comp)
 499     /* Use default component */
 500     comp = component_nopid;
 501
 502   /* We have no definitions to override globally configured log level,
 503    * so just use it right away.
 504    */
 505   if ( (min_level >= 0) && (GNUNET_NO == gnunet_force_log_present) )
 506     return caller_level <= min_level;
 507
 508   /* Only look for forced definitions? */
 509   force_only = min_level >= 0;
 510   for (i = 0; i < logdefs_len; i++)
 511   {
 512     ld = &logdefs[i];
 513     if (( (!force_only) || ld->force) &&
 514         (line >= ld->from_line && line <= ld->to_line) &&
 515         (0 == regexec (&ld->component_regex, comp, 0, NULL, 0)) &&
 516         (0 == regexec (&ld->file_regex, file, 0, NULL, 0)) &&
 517         (0 == regexec (&ld->function_regex, function, 0, NULL, 0)))
 518     {
 519       /* We're finished */
 520       return caller_level <= ld->level;
 521     }
 522   }
 523   /* No matches - use global level, if defined */
 524   if (min_level >= 0)
 525     return caller_level <= min_level;
 526   /* All programs/services previously defaulted to WARNING.
 527    * Now *we* default to WARNING, and THEY default to NULL.
 528    * Or rather we default to MESSAGE, since things aren't always bad.
 529    */
 530   return caller_level <= GNUNET_ERROR_TYPE_MESSAGE;
 531 }
 532
 533
 534 /**
 535  * Utility function - parses a definition
 536  *
 537  * Definition format:
 538  * component;file;function;from_line-to_line;level[/component...]
 539  * All entries are mandatory, but may be empty.
 540  * Empty entries for component, file and function are treated as
 541  * "matches anything".
 542  * Empty line entry is treated as "from 0 to INT_MAX"
 543  * Line entry with only one line is treated as "this line only"
 544  * Entry for level MUST NOT be empty.
 545  * Entries for component, file and function that consist of a
 546  * single character "*" are treated (at the moment) the same way
 547  * empty entries are treated (wildcard matching is not implemented (yet?)).
 548  * file entry is matched to the end of __FILE__. That is, it might be
 549  * a base name, or a base name with leading directory names (some compilers
 550  * define __FILE__ to absolute file path).
 551  *
 552  * @param constname name of the environment variable from which to get the
 553  *   string to be parsed
 554  * @param force 1 if definitions found in constname are to be forced
 555  * @return number of added definitions
 556  */
 557 static int
 558 parse_definitions (const char *constname, int force)
 559 {
 560   char *def;
 561   const char *tmp;
 562   char *comp = NULL;
 563   char *file = NULL;
 564   char *function = NULL;
 565   char *p;
 566   char *start;
 567   char *t;
 568   short state;
 569   int level;
 570   int from_line, to_line;
 571   int counter = 0;
 572   int keep_looking = 1;
 573
 574   tmp = getenv (constname);
 575   if (NULL == tmp)
 576     return 0;
 577   def = GNUNET_strdup (tmp);
 578   from_line = 0;
 579   to_line = INT_MAX;
 580   for (p = def, state = 0, start = def; keep_looking; p++)
 581   {
 582     switch (p[0])
 583     {
 584     case ';':                  /* found a field separator */
 585       p[0] = '\0';
 586       switch (state)
 587       {
 588       case 0:                  /* within a component name */
 589         comp = start;
 590         break;
 591       case 1:                  /* within a file name */
 592         file = start;
 593         break;
 594       case 2:                  /* within a function name */
 595         /* after a file name there must be a function name */
 596         function = start;
 597         break;
 598       case 3:                  /* within a from-to line range */
 599         if (strlen (start) > 0)
 600         {
 601           errno = 0;
 602           from_line = strtol (start, &t, 10);
 603           if ( (0 != errno) || (from_line < 0) )
 604           {
 605             GNUNET_free (def);
 606             return counter;
 607           }
 608           if ( (t < p) && ('-' == t[0]) )
 609           {
 610             errno = 0;
 611             start = t + 1;
 612             to_line = strtol (start, &t, 10);
 613             if ( (0 != errno) || (to_line < 0) || (t != p) )
 614             {
 615               GNUNET_free (def);
 616               return counter;
 617             }
 618           }
 619           else                  /* one number means "match this line only" */
 620             to_line = from_line;
 621         }
 622         else                    /* default to 0-max */
 623         {
 624           from_line = 0;
 625           to_line = INT_MAX;
 626         }
 627         break;
 628       }
 629       start = p + 1;
 630       state++;
 631       break;
 632     case '\0':                 /* found EOL */
 633       keep_looking = 0;
 634       /* fall through to '/' */
 635     case '/':                  /* found a definition separator */
 636       switch (state)
 637       {
 638       case 4:                  /* within a log level */
 639         p[0] = '\0';
 640         state = 0;
 641         level = get_type ((const char *) start);
 642         if ( (GNUNET_ERROR_TYPE_INVALID == level) ||
 643              (GNUNET_ERROR_TYPE_UNSPECIFIED == level) ||
 644              (0 != add_definition (comp, file, function, from_line, to_line,
 645                                    level, force)) )
 646         {
 647           GNUNET_free (def);
 648           return counter;
 649         }
 650         counter++;
 651         start = p + 1;
 652         break;
 653       default:
 654         break;
 655       }
 656     default:
 657       break;
 658     }
 659   }
 660   GNUNET_free (def);
 661   return counter;
 662 }
 663
 664
 665 /**
 666  * Utility function - parses GNUNET_LOG and GNUNET_FORCE_LOG.
 667  */
 668 static void
 669 parse_all_definitions ()
 670 {
 671   if (GNUNET_NO == gnunet_log_parsed)
 672     parse_definitions ("GNUNET_LOG", 0);
 673   gnunet_log_parsed = GNUNET_YES;
 674   if (GNUNET_NO == gnunet_force_log_parsed)
 675     gnunet_force_log_present =
 676         parse_definitions ("GNUNET_FORCE_LOG", 1) > 0 ? GNUNET_YES : GNUNET_NO;
 677   gnunet_force_log_parsed = GNUNET_YES;
 678 }
 679 #endif
 680
 681
 682 /**
 683  * Setup logging.
 684  *
 685  * @param comp default component to use
 686  * @param loglevel what types of messages should be logged
 687  * @param logfile which file to write log messages to (can be NULL)
 688  * @return #GNUNET_OK on success
 689  */
 690 int
 691 GNUNET_log_setup (const char *comp,
 692                   const char *loglevel,
 693                   const char *logfile)
 694 {
 695   const char *env_logfile;
 696
 697   min_level = get_type (loglevel);
 698 #if !defined(GNUNET_CULL_LOGGING)
 699   parse_all_definitions ();
 700 #endif
 701 #ifdef WINDOWS
 702   QueryPerformanceFrequency (&performance_frequency);
 703 #endif
 704   GNUNET_free_non_null (component);
 705   GNUNET_asprintf (&component, "%s-%d", comp, getpid ());
 706   GNUNET_free_non_null (component_nopid);
 707   component_nopid = GNUNET_strdup (comp);
 708
 709   env_logfile = getenv ("GNUNET_FORCE_LOGFILE");
 710   if ((NULL != env_logfile) && (strlen (env_logfile) > 0))
 711     logfile = env_logfile;
 712   if (NULL == logfile)
 713     return GNUNET_OK;
 714   GNUNET_free_non_null (log_file_name);
 715   log_file_name = GNUNET_STRINGS_filename_expand (logfile);
 716   if (NULL == log_file_name)
 717     return GNUNET_SYSERR;
 718 #if TALER_WALLET_ONLY
 719   /* log file option not allowed for wallet logic */
 720   GNUNET_assert (NULL == logfile);
 721   return GNUNET_OK;
 722 #else
 723   {
 724     time_t t;
 725     const struct tm *tm;
 726
 727     t = time (NULL);
 728     tm = gmtime (&t);
 729     return setup_log_file (tm);
 730   }
 731 #endif
 732 }
 733
 734
 735 /**
 736  * Add a custom logger. Note that installing any custom logger
 737  * will disable the standard logger.  When multiple custom loggers
 738  * are installed, all will be called.  The standard logger will
 739  * only be used if no custom loggers are present.
 740  *
 741  * @param logger log function
 742  * @param logger_cls closure for @a logger
 743  */
 744 void
 745 GNUNET_logger_add (GNUNET_Logger logger,
 746                    void *logger_cls)
 747 {
 748   struct CustomLogger *entry;
 749
 750   entry = GNUNET_new (struct CustomLogger);
 751   entry->logger = logger;
 752   entry->logger_cls = logger_cls;
 753   entry->next = loggers;
 754   loggers = entry;
 755 }
 756
 757
 758 /**
 759  * Remove a custom logger.
 760  *
 761  * @param logger log function
 762  * @param logger_cls closure for @a logger
 763  */
 764 void
 765 GNUNET_logger_remove (GNUNET_Logger logger,
 766                       void *logger_cls)
 767 {
 768   struct CustomLogger *pos;
 769   struct CustomLogger *prev;
 770
 771   prev = NULL;
 772   pos = loggers;
 773   while ((NULL != pos) &&
 774          ((pos->logger != logger) || (pos->logger_cls != logger_cls)))
 775   {
 776     prev = pos;
 777     pos = pos->next;
 778   }
 779   GNUNET_assert (NULL != pos);
 780   if (NULL == prev)
 781     loggers = pos->next;
 782   else
 783     prev->next = pos->next;
 784   GNUNET_free (pos);
 785 }
 786
 787 #if WINDOWS
 788 CRITICAL_SECTION output_message_cs;
 789 #endif
 790
 791
 792 /**
 793  * Actually output the log message.
 794  *
 795  * @param kind how severe was the issue
 796  * @param comp component responsible
 797  * @param datestr current date/time
 798  * @param msg the actual message
 799  */
 800 static void
 801 output_message (enum GNUNET_ErrorType kind,
 802                 const char *comp,
 803                 const char *datestr,
 804                 const char *msg)
 805 {
 806   struct CustomLogger *pos;
 807
 808 #if WINDOWS
 809   EnterCriticalSection (&output_message_cs);
 810 #endif
 811   /* only use the standard logger if no custom loggers are present */
 812   if ( (NULL != GNUNET_stderr) &&
 813        (NULL == loggers) )
 814   {
 815     if (kind == GNUNET_ERROR_TYPE_MESSAGE) {
 816         /* The idea here is to produce "normal" output messages
 817          * for end users while still having the power of the
 818          * logging engine for developer needs. So ideally this
 819          * is what it should look like when CLI tools are used
 820          * interactively, yet the same message shouldn't look
 821          * this way if the output is going to logfiles or robots
 822          * instead. Is this the right place to do this? --lynX
 823          */
 824         FPRINTF (GNUNET_stderr,
 825              "* %s",
 826              msg);
 827     } else {
 828         FPRINTF (GNUNET_stderr,
 829              "%s %s %s %s",
 830              datestr,
 831              comp,
 832              GNUNET_error_type_to_string (kind),
 833              msg);
 834     }
 835     fflush (GNUNET_stderr);
 836   }
 837   pos = loggers;
 838   while (pos != NULL)
 839   {
 840     pos->logger (pos->logger_cls, kind, comp, datestr, msg);
 841     pos = pos->next;
 842   }
 843 #if WINDOWS
 844   LeaveCriticalSection (&output_message_cs);
 845 #endif
 846 }
 847
 848
 849 /**
 850  * Flush an existing bulk report to the output.
 851  *
 852  * @param datestr our current timestamp
 853  */
 854 static void
 855 flush_bulk (const char *datestr)
 856 {
 857   char msg[DATE_STR_SIZE + BULK_TRACK_SIZE + 256];
 858   int rev;
 859   char *last;
 860   const char *ft;
 861
 862   if ( (0 == last_bulk_time.abs_value_us) ||
 863        (0 == last_bulk_repeat) )
 864     return;
 865   rev = 0;
 866   last = memchr (last_bulk, '\0', BULK_TRACK_SIZE);
 867   if (last == NULL)
 868     last = &last_bulk[BULK_TRACK_SIZE - 1];
 869   else if (last != last_bulk)
 870     last--;
 871   if (last[0] == '\n')
 872   {
 873     rev = 1;
 874     last[0] = '\0';
 875   }
 876   ft = GNUNET_STRINGS_relative_time_to_string (GNUNET_TIME_absolute_get_duration
 877                                                (last_bulk_time), GNUNET_YES);
 878   snprintf (msg, sizeof (msg),
 879             _("Message `%.*s' repeated %u times in the last %s\n"),
 880             BULK_TRACK_SIZE, last_bulk, last_bulk_repeat, ft);
 881   if (rev == 1)
 882     last[0] = '\n';
 883   output_message (last_bulk_kind, last_bulk_comp, datestr, msg);
 884   last_bulk_time = GNUNET_TIME_absolute_get ();
 885   last_bulk_repeat = 0;
 886 }
 887
 888
 889 /**
 890  * Ignore the next n calls to the log function.
 891  *
 892  * @param n number of log calls to ignore (could be negative)
 893  * @param check_reset #GNUNET_YES to assert that the log skip counter is currently zero
 894  */
 895 void
 896 GNUNET_log_skip (int n,
 897                  int check_reset)
 898 {
 899   int ok;
 900
 901   if (0 == n)
 902   {
 903     ok = (0 == skip_log);
 904     skip_log = 0;
 905     if (check_reset)
 906       GNUNET_break (ok);
 907   }
 908   else
 909   {
 910     skip_log += n;
 911   }
 912 }
 913
 914
 915 /**
 916  * Get the number of log calls that are going to be skipped
 917  *
 918  * @return number of log calls to be ignored
 919  */
 920 int
 921 GNUNET_get_log_skip ()
 922 {
 923   return skip_log;
 924 }
 925
 926
 927 /**
 928  * Output a log message using the default mechanism.
 929  *
 930  * @param kind how severe was the issue
 931  * @param comp component responsible
 932  * @param message the actual message
 933  * @param va arguments to the format string "message"
 934  */
 935 static void
 936 mylog (enum GNUNET_ErrorType kind,
 937        const char *comp,
 938        const char *message,
 939        va_list va)
 940 {
 941   char date[DATE_STR_SIZE];
 942   char date2[DATE_STR_SIZE];
 943   struct tm *tmptr;
 944   size_t size;
 945   va_list vacp;
 946
 947   va_copy (vacp, va);
 948   size = VSNPRINTF (NULL,
 949                     0,
 950                     message,
 951                     vacp) + 1;
 952   GNUNET_assert (0 != size);
 953   va_end (vacp);
 954   memset (date,
 955           0,
 956           DATE_STR_SIZE);
 957   {
 958     char buf[size];
 959     long long offset;
 960 #ifdef WINDOWS
 961     LARGE_INTEGER pc;
 962     time_t timetmp;
 963
 964     offset = GNUNET_TIME_get_offset ();
 965     time (&timetmp);
 966     timetmp += offset / 1000;
 967     tmptr = localtime (&timetmp);
 968     pc.QuadPart = 0;
 969     QueryPerformanceCounter (&pc);
 970     if (NULL == tmptr)
 971     {
 972       strcpy (date, "localtime error");
 973     }
 974     else
 975     {
 976       strftime (date2,
 977                 DATE_STR_SIZE,
 978                 "%b %d %H:%M:%S-%%020llu",
 979                 tmptr);
 980       snprintf (date,
 981                 sizeof (date),
 982                 date2,
 983                 (long long) (pc.QuadPart /
 984                              (performance_frequency.QuadPart / 1000)));
 985     }
 986 #else
 987     struct timeval timeofday;
 988
 989     gettimeofday (&timeofday, NULL);
 990     offset = GNUNET_TIME_get_offset ();
 991     if (offset > 0)
 992     {
 993       timeofday.tv_sec += offset / 1000LL;
 994       timeofday.tv_usec += (offset % 1000LL) * 1000LL;
 995       if (timeofday.tv_usec > 1000000LL)
 996       {
 997         timeofday.tv_usec -= 1000000LL;
 998         timeofday.tv_sec++;
 999       }
1000     }
1001     else
1002     {
1003       timeofday.tv_sec += offset / 1000LL;
1004       if (timeofday.tv_usec > - (offset % 1000LL) * 1000LL)
1005       {
1006         timeofday.tv_usec += (offset % 1000LL) * 1000LL;
1007       }
1008       else
1009       {
1010         timeofday.tv_usec += 1000000LL + (offset % 1000LL) * 1000LL;
1011         timeofday.tv_sec--;
1012       }
1013     }
1014     tmptr = localtime (&timeofday.tv_sec);
1015     if (NULL == tmptr)
1016     {
1017       strcpy (date,
1018               "localtime error");
1019     }
1020     else
1021     {
1022       strftime (date2,
1023                 DATE_STR_SIZE,
1024                 "%b %d %H:%M:%S-%%06u",
1025                 tmptr);
1026       snprintf (date,
1027                 sizeof (date),
1028                 date2,
1029                 timeofday.tv_usec);
1030     }
1031 #endif
1032     VSNPRINTF (buf, size, message, va);
1033 #if ! TALER_WALLET_ONLY
1034     if (NULL != tmptr)
1035       (void) setup_log_file (tmptr);
1036 #endif
1037     if ((0 != (kind & GNUNET_ERROR_TYPE_BULK)) &&
1038         (0 != last_bulk_time.abs_value_us) &&
1039         (0 == strncmp (buf, last_bulk, sizeof (last_bulk))))
1040     {
1041       last_bulk_repeat++;
1042       if ( (GNUNET_TIME_absolute_get_duration (last_bulk_time).rel_value_us >
1043             BULK_DELAY_THRESHOLD) ||
1044            (last_bulk_repeat > BULK_REPEAT_THRESHOLD) )
1045         flush_bulk (date);
1046       return;
1047     }
1048     flush_bulk (date);
1049     strncpy (last_bulk,
1050              buf,
1051              sizeof (last_bulk));
1052     last_bulk_repeat = 0;
1053     last_bulk_kind = kind;
1054     last_bulk_time = GNUNET_TIME_absolute_get ();
1055     strncpy (last_bulk_comp,
1056              comp,
1057              COMP_TRACK_SIZE);
1058     output_message (kind,
1059                     comp,
1060                     date,
1061                     buf);
1062   }
1063 }
1064
1065
1066 /**
1067  * Main log function.
1068  *
1069  * @param kind how serious is the error?
1070  * @param message what is the message (format string)
1071  * @param ... arguments for format string
1072  */
1073 void
1074 GNUNET_log_nocheck (enum GNUNET_ErrorType kind,
1075                     const char *message, ...)
1076 {
1077   va_list va;
1078
1079   va_start (va, message);
1080   mylog (kind, component, message, va);
1081   va_end (va);
1082 }
1083
1084
1085 /**
1086  * Log function that specifies an alternative component.
1087  * This function should be used by plugins.
1088  *
1089  * @param kind how serious is the error?
1090  * @param comp component responsible for generating the message
1091  * @param message what is the message (format string)
1092  * @param ... arguments for format string
1093  */
1094 void
1095 GNUNET_log_from_nocheck (enum GNUNET_ErrorType kind, const char *comp,
1096                          const char *message, ...)
1097 {
1098   va_list va;
1099   char comp_w_pid[128];
1100
1101   if (comp == NULL)
1102     comp = component_nopid;
1103
1104   va_start (va, message);
1105   GNUNET_snprintf (comp_w_pid, sizeof (comp_w_pid), "%s-%d", comp, getpid ());
1106   mylog (kind, comp_w_pid, message, va);
1107   va_end (va);
1108 }
1109
1110
1111 /**
1112  * Convert error type to string.
1113  *
1114  * @param kind type to convert
1115  * @return string corresponding to the type
1116  */
1117 const char *
1118 GNUNET_error_type_to_string (enum GNUNET_ErrorType kind)
1119 {
1120   if ((kind & GNUNET_ERROR_TYPE_ERROR) > 0)
1121     return _("ERROR");
1122   if ((kind & GNUNET_ERROR_TYPE_WARNING) > 0)
1123     return _("WARNING");
1124   if ((kind & GNUNET_ERROR_TYPE_MESSAGE) > 0)
1125     return _("MESSAGE");
1126   if ((kind & GNUNET_ERROR_TYPE_INFO) > 0)
1127     return _("INFO");
1128   if ((kind & GNUNET_ERROR_TYPE_DEBUG) > 0)
1129     return _("DEBUG");
1130   if ((kind & ~GNUNET_ERROR_TYPE_BULK) == 0)
1131     return _("NONE");
1132   return _("INVALID");
1133 }
1134
1135
1136 /**
1137  * Convert a hash to a string (for printing debug messages).
1138  * This is one of the very few calls in the entire API that is
1139  * NOT reentrant!
1140  *
1141  * @param hc the hash code
1142  * @return string form; will be overwritten by next call to GNUNET_h2s.
1143  */
1144 const char *
1145 GNUNET_h2s (const struct GNUNET_HashCode * hc)
1146 {
1147   static struct GNUNET_CRYPTO_HashAsciiEncoded ret;
1148
1149   GNUNET_CRYPTO_hash_to_enc (hc, &ret);
1150   ret.encoding[8] = '\0';
1151   return (const char *) ret.encoding;
1152 }
1153
1154
1155 /**
1156  * Convert a hash to a string (for printing debug messages).
1157  * This is one of the very few calls in the entire API that is
1158  * NOT reentrant!
1159  *
1160  * @param hc the hash code
1161  * @return string form; will be overwritten by next call to GNUNET_h2s_full.
1162  */
1163 const char *
1164 GNUNET_h2s_full (const struct GNUNET_HashCode * hc)
1165 {
1166   static struct GNUNET_CRYPTO_HashAsciiEncoded ret;
1167
1168   GNUNET_CRYPTO_hash_to_enc (hc, &ret);
1169   ret.encoding[sizeof (ret) - 1] = '\0';
1170   return (const char *) ret.encoding;
1171 }
1172
1173
1174 /**
1175  * Convert a peer identity to a string (for printing debug messages).
1176  * This is one of the very few calls in the entire API that is
1177  * NOT reentrant!
1178  *
1179  * @param pid the peer identity
1180  * @return string form of the pid; will be overwritten by next
1181  *         call to #GNUNET_i2s.
1182  */
1183 const char *
1184 GNUNET_i2s (const struct GNUNET_PeerIdentity *pid)
1185 {
1186   static char buf[256];
1187   char *ret;
1188
1189   ret = GNUNET_CRYPTO_eddsa_public_key_to_string (&pid->public_key);
1190   strcpy (buf, ret);
1191   GNUNET_free (ret);
1192   buf[4] = '\0';
1193   return buf;
1194 }
1195
1196
1197 /**
1198  * Convert a peer identity to a string (for printing debug messages).
1199  * This is one of the very few calls in the entire API that is
1200  * NOT reentrant!
1201  *
1202  * @param pid the peer identity
1203  * @return string form of the pid; will be overwritten by next
1204  *         call to #GNUNET_i2s_full.
1205  */
1206 const char *
1207 GNUNET_i2s_full (const struct GNUNET_PeerIdentity *pid)
1208 {
1209   static char buf[256];
1210   char *ret;
1211
1212   ret = GNUNET_CRYPTO_eddsa_public_key_to_string (&pid->public_key);
1213   strcpy (buf, ret);
1214   GNUNET_free (ret);
1215   return buf;
1216 }
1217
1218
1219 /**
1220  * Convert a "struct sockaddr*" (IPv4 or IPv6 address) to a string
1221  * (for printing debug messages).  This is one of the very few calls
1222  * in the entire API that is NOT reentrant!
1223  *
1224  * @param addr the address
1225  * @param addrlen the length of the address in @a addr
1226  * @return nicely formatted string for the address
1227  *  will be overwritten by next call to #GNUNET_a2s.
1228  */
1229 const char *
1230 GNUNET_a2s (const struct sockaddr *addr,
1231             socklen_t addrlen)
1232 {
1233 #ifndef WINDOWS
1234 #define LEN GNUNET_MAX ((INET6_ADDRSTRLEN + 8),         \
1235                         (1 + sizeof (struct sockaddr_un) - sizeof (sa_family_t)))
1236 #else
1237 #define LEN (INET6_ADDRSTRLEN + 8)
1238 #endif
1239   static char buf[LEN];
1240 #undef LEN
1241   static char b2[6];
1242   const struct sockaddr_in *v4;
1243   const struct sockaddr_un *un;
1244   const struct sockaddr_in6 *v6;
1245   unsigned int off;
1246
1247   if (addr == NULL)
1248     return _("unknown address");
1249   switch (addr->sa_family)
1250   {
1251   case AF_INET:
1252     if (addrlen != sizeof (struct sockaddr_in))
1253       return "<invalid v4 address>";
1254     v4 = (const struct sockaddr_in *) addr;
1255     inet_ntop (AF_INET, &v4->sin_addr, buf, INET_ADDRSTRLEN);
1256     if (0 == ntohs (v4->sin_port))
1257       return buf;
1258     strcat (buf, ":");
1259     GNUNET_snprintf (b2, sizeof (b2), "%u", ntohs (v4->sin_port));
1260     strcat (buf, b2);
1261     return buf;
1262   case AF_INET6:
1263     if (addrlen != sizeof (struct sockaddr_in6))
1264       return "<invalid v4 address>";
1265     v6 = (const struct sockaddr_in6 *) addr;
1266     buf[0] = '[';
1267     inet_ntop (AF_INET6, &v6->sin6_addr, &buf[1], INET6_ADDRSTRLEN);
1268     if (0 == ntohs (v6->sin6_port))
1269       return &buf[1];
1270     strcat (buf, "]:");
1271     GNUNET_snprintf (b2, sizeof (b2), "%u", ntohs (v6->sin6_port));
1272     strcat (buf, b2);
1273     return buf;
1274   case AF_UNIX:
1275     if (addrlen <= sizeof (sa_family_t))
1276       return "<unbound UNIX client>";
1277     un = (const struct sockaddr_un *) addr;
1278     off = 0;
1279     if ('\0' == un->sun_path[0])
1280       off++;
1281     memset (buf, 0, sizeof (buf));
1282     GNUNET_snprintf (buf,
1283                      sizeof (buf),
1284                      "%s%.*s",
1285                      (1 == off) ? "@" : "",
1286                      (int) (addrlen - sizeof (sa_family_t) - off),
1287                      &un->sun_path[off]);
1288     return buf;
1289   default:
1290     return _("invalid address");
1291   }
1292 }
1293
1294
1295 /**
1296  * Log error message about missing configuration option.
1297  *
1298  * @param kind log level
1299  * @param section section with missing option
1300  * @param option name of missing option
1301  */
1302 void
1303 GNUNET_log_config_missing (enum GNUNET_ErrorType kind,
1304                            const char *section,
1305                            const char *option)
1306 {
1307   GNUNET_log (kind,
1308               _("Configuration fails to specify option `%s' in section `%s'!\n"),
1309               option,
1310               section);
1311 }
1312
1313
1314 /**
1315  * Log error message about invalid configuration option value.
1316  *
1317  * @param kind log level
1318  * @param section section with invalid option
1319  * @param option name of invalid option
1320  * @param required what is required that is invalid about the option
1321  */
1322 void
1323 GNUNET_log_config_invalid (enum GNUNET_ErrorType kind,
1324                            const char *section,
1325                            const char *option,
1326                            const char *required)
1327 {
1328   GNUNET_log (kind,
1329               _("Configuration specifies invalid value for option `%s' in section `%s': %s\n"),
1330               option, section, required);
1331 }
1332
1333
1334 /**
1335  * Initializer
1336  */
1337 void __attribute__ ((constructor))
1338 GNUNET_util_cl_init ()
1339 {
1340   GNUNET_stderr = stderr;
1341 #ifdef MINGW
1342   GNInitWinEnv (NULL);
1343 #endif
1344 #if WINDOWS
1345   if (!InitializeCriticalSectionAndSpinCount (&output_message_cs, 0x00000400))
1346     GNUNET_abort_ ();
1347 #endif
1348 }
1349
1350
1351 /**
1352  * Destructor
1353  */
1354 void __attribute__ ((destructor))
1355 GNUNET_util_cl_fini ()
1356 {
1357 #if WINDOWS
1358   DeleteCriticalSection (&output_message_cs);
1359 #endif
1360 #ifdef MINGW
1361   GNShutdownWinEnv ();
1362 #endif
1363 }
1364
1365 /* end of common_logging.c */