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