common/logging.c

   1 /* logging.c - Useful logging functions
   2  * Copyright (C) 1998, 1999, 2000, 2001, 2003, 2004, 2005, 2006,
   3  *               2009, 2010 Free Software Foundation, Inc.
   4  *
   5  * This file is part of GnuPG.
   6  *
   7  * GnuPG is free software; you can redistribute and/or modify this
   8  * part of GnuPG under the terms of either
   9  *
  10  *   - the GNU Lesser General Public License as published by the Free
  11  *     Software Foundation; either version 3 of the License, or (at
  12  *     your option) any later version.
  13  *
  14  * or
  15  *
  16  *   - the GNU General Public License as published by the Free
  17  *     Software Foundation; either version 2 of the License, or (at
  18  *     your option) any later version.
  19  *
  20  * or both in parallel, as here.
  21  *
  22  * GnuPG is distributed in the hope that it will be useful, but
  23  * WITHOUT ANY WARRANTY; without even the implied warranty of
  24  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  25  * General Public License for more details.
  26  *
  27  * You should have received a copies of the GNU General Public License
  28  * and the GNU Lesser General Public License along with this program;
  29  * if not, see <https://www.gnu.org/licenses/>.
  30  */
  31
  32
  33 #include <config.h>
  34 #include <stdlib.h>
  35 #include <stdio.h>
  36 #include <string.h>
  37 #include <stdarg.h>
  38 #include <stddef.h>
  39 #include <errno.h>
  40 #include <time.h>
  41 #include <sys/types.h>
  42 #include <sys/stat.h>
  43 #ifdef HAVE_W32_SYSTEM
  44 # ifdef HAVE_WINSOCK2_H
  45 #  include <winsock2.h>
  46 # endif
  47 # include <windows.h>
  48 #else /*!HAVE_W32_SYSTEM*/
  49 # include <sys/socket.h>
  50 # include <sys/un.h>
  51 # include <netinet/in.h>
  52 # include <arpa/inet.h>
  53 #endif /*!HAVE_W32_SYSTEM*/
  54 #include <unistd.h>
  55 #include <fcntl.h>
  56 #include <assert.h>
  57 /* #include <execinfo.h> */
  58
  59 #define GNUPG_COMMON_NEED_AFLOCAL 1
  60 #include "util.h"
  61 #include "i18n.h"
  62 #include "common-defs.h"
  63 #include "logging.h"
  64 #include "sysutils.h"
  65
  66 #ifdef HAVE_W32_SYSTEM
  67 # ifndef S_IRWXG
  68 #  define S_IRGRP S_IRUSR
  69 #  define S_IWGRP S_IWUSR
  70 # endif
  71 # ifndef S_IRWXO
  72 #  define S_IROTH S_IRUSR
  73 #  define S_IWOTH S_IWUSR
  74 # endif
  75 #endif
  76
  77
  78 #ifdef HAVE_W32CE_SYSTEM
  79 # define isatty(a)  (0)
  80 #endif
  81
  82 #undef WITH_IPV6
  83 #if defined (AF_INET6) && defined(PF_INET) \
  84     && defined (INET6_ADDRSTRLEN) && defined(HAVE_INET_PTON)
  85 # define WITH_IPV6 1
  86 #endif
  87
  88 #ifndef EAFNOSUPPORT
  89 # define EAFNOSUPPORT EINVAL
  90 #endif
  91 #ifndef INADDR_NONE  /* Slowaris is missing that.  */
  92 #define INADDR_NONE  ((unsigned long)(-1))
  93 #endif /*INADDR_NONE*/
  94
  95 #ifdef HAVE_W32_SYSTEM
  96 #define sock_close(a)  closesocket(a)
  97 #else
  98 #define sock_close(a)  close(a)
  99 #endif
 100
 101
 102 static estream_t logstream;
 103 static int log_socket = -1;
 104 static char prefix_buffer[80];
 105 static int with_time;
 106 static int with_prefix;
 107 static int with_pid;
 108 #ifdef HAVE_W32_SYSTEM
 109 static int no_registry;
 110 #endif
 111 static int (*get_pid_suffix_cb)(unsigned long *r_value);
 112 static const char * (*socket_dir_cb)(void);
 113 static int running_detached;
 114 static int force_prefixes;
 115
 116 static int missing_lf;
 117 static int errorcount;
 118
 119
 120 int
 121 log_get_errorcount (int clear)
 122 {
 123     int n = errorcount;
 124     if( clear )
 125         errorcount = 0;
 126     return n;
 127 }
 128
 129 void
 130 log_inc_errorcount (void)
 131 {
 132    errorcount++;
 133 }
 134
 135
 136 /* The following 3 functions are used by es_fopencookie to write logs
 137    to a socket.  */
 138 struct fun_cookie_s
 139 {
 140   int fd;
 141   int quiet;
 142   int want_socket;
 143   int is_socket;
 144 #ifdef HAVE_W32CE_SYSTEM
 145   int use_writefile;
 146 #endif
 147   char name[1];
 148 };
 149
 150
 151 /* Write NBYTES of BUFFER to file descriptor FD. */
 152 static int
 153 writen (int fd, const void *buffer, size_t nbytes, int is_socket)
 154 {
 155   const char *buf = buffer;
 156   size_t nleft = nbytes;
 157   int nwritten;
 158 #ifndef HAVE_W32_SYSTEM
 159   (void)is_socket; /* Not required.  */
 160 #endif
 161
 162   while (nleft > 0)
 163     {
 164 #ifdef HAVE_W32_SYSTEM
 165       if (is_socket)
 166         nwritten = send (fd, buf, nleft, 0);
 167       else
 168 #endif
 169         nwritten = write (fd, buf, nleft);
 170
 171       if (nwritten < 0 && errno == EINTR)
 172         continue;
 173       if (nwritten < 0)
 174         return -1;
 175       nleft -= nwritten;
 176       buf = buf + nwritten;
 177     }
 178
 179   return 0;
 180 }
 181
 182
 183 /* Returns true if STR represents a valid port number in decimal
 184    notation and no garbage is following.  */
 185 static int
 186 parse_portno (const char *str, unsigned short *r_port)
 187 {
 188   unsigned int value;
 189
 190   for (value=0; *str && (*str >= '0' && *str <= '9'); str++)
 191     {
 192       value = value * 10 + (*str - '0');
 193       if (value > 65535)
 194         return 0;
 195     }
 196   if (*str || !value)
 197     return 0;
 198
 199   *r_port = value;
 200   return 1;
 201 }
 202
 203
 204 static gpgrt_ssize_t
 205 fun_writer (void *cookie_arg, const void *buffer, size_t size)
 206 {
 207   struct fun_cookie_s *cookie = cookie_arg;
 208
 209   /* FIXME: Use only estream with a callback for socket writing.  This
 210      avoids the ugly mix of fd and estream code.  */
 211
 212   /* Note that we always try to reconnect to the socket but print
 213      error messages only the first time an error occurred.  If
 214      RUNNING_DETACHED is set we don't fall back to stderr and even do
 215      not print any error messages.  This is needed because detached
 216      processes often close stderr and by writing to file descriptor 2
 217      we might send the log message to a file not intended for logging
 218      (e.g. a pipe or network connection). */
 219   if (cookie->want_socket && cookie->fd == -1)
 220     {
 221 #ifdef WITH_IPV6
 222       struct sockaddr_in6 srvr_addr_in6;
 223 #endif
 224       struct sockaddr_in srvr_addr_in;
 225 #ifndef HAVE_W32_SYSTEM
 226       struct sockaddr_un srvr_addr_un;
 227 #endif
 228       const char *name_for_err = "";
 229       size_t addrlen;
 230       struct sockaddr *srvr_addr = NULL;
 231       unsigned short port = 0;
 232       int af = AF_LOCAL;
 233       int pf = PF_LOCAL;
 234       const char *name = cookie->name;
 235
 236       /* Not yet open or meanwhile closed due to an error. */
 237       cookie->is_socket = 0;
 238
 239       /* Check whether this is a TCP socket or a local socket.  */
 240       if (!strncmp (name, "tcp://", 6) && name[6])
 241         {
 242           name += 6;
 243           af = AF_INET;
 244           pf = PF_INET;
 245         }
 246 #ifndef HAVE_W32_SYSTEM
 247       else if (!strncmp (name, "socket://", 9))
 248         name += 9;
 249 #endif
 250
 251       if (af == AF_LOCAL)
 252         {
 253           addrlen = 0;
 254 #ifndef HAVE_W32_SYSTEM
 255           memset (&srvr_addr, 0, sizeof srvr_addr);
 256           srvr_addr_un.sun_family = af;
 257           if (!*name && (name = socket_dir_cb ()) && *name)
 258             {
 259               if (strlen (name) + 7 < sizeof (srvr_addr_un.sun_path)-1)
 260                 {
 261                   strncpy (srvr_addr_un.sun_path,
 262                            name, sizeof (srvr_addr_un.sun_path)-1);
 263                   strcat (srvr_addr_un.sun_path, "/S.log");
 264                   srvr_addr_un.sun_path[sizeof (srvr_addr_un.sun_path)-1] = 0;
 265                   srvr_addr = (struct sockaddr *)&srvr_addr_un;
 266                   addrlen = SUN_LEN (&srvr_addr_un);
 267                   name_for_err = srvr_addr_un.sun_path;
 268                 }
 269             }
 270           else
 271             {
 272               if (*name && strlen (name) < sizeof (srvr_addr_un.sun_path)-1)
 273                 {
 274                   strncpy (srvr_addr_un.sun_path,
 275                            name, sizeof (srvr_addr_un.sun_path)-1);
 276                   srvr_addr_un.sun_path[sizeof (srvr_addr_un.sun_path)-1] = 0;
 277                   srvr_addr = (struct sockaddr *)&srvr_addr_un;
 278                   addrlen = SUN_LEN (&srvr_addr_un);
 279                 }
 280             }
 281 #endif /*!HAVE_W32SYSTEM*/
 282         }
 283       else
 284         {
 285           char *addrstr, *p;
 286 #ifdef HAVE_INET_PTON
 287           void *addrbuf = NULL;
 288 #endif /*HAVE_INET_PTON*/
 289
 290           addrstr = xtrymalloc (strlen (name) + 1);
 291           if (!addrstr)
 292             addrlen = 0; /* This indicates an error.  */
 293           else if (*name == '[')
 294             {
 295               /* Check for IPv6 literal address.  */
 296               strcpy (addrstr, name+1);
 297               p = strchr (addrstr, ']');
 298               if (!p || p[1] != ':' || !parse_portno (p+2, &port))
 299                 {
 300                   gpg_err_set_errno (EINVAL);
 301                   addrlen = 0;
 302                 }
 303               else
 304                 {
 305                   *p = 0;
 306 #ifdef WITH_IPV6
 307                   af = AF_INET6;
 308                   pf = PF_INET6;
 309                   memset (&srvr_addr_in6, 0, sizeof srvr_addr_in6);
 310                   srvr_addr_in6.sin6_family = af;
 311                   srvr_addr_in6.sin6_port = htons (port);
 312 #ifdef HAVE_INET_PTON
 313                   addrbuf = &srvr_addr_in6.sin6_addr;
 314 #endif /*HAVE_INET_PTON*/
 315                   srvr_addr = (struct sockaddr *)&srvr_addr_in6;
 316                   addrlen = sizeof srvr_addr_in6;
 317 #else
 318                   gpg_err_set_errno (EAFNOSUPPORT);
 319                   addrlen = 0;
 320 #endif
 321                 }
 322             }
 323           else
 324             {
 325               /* Check for IPv4 literal address.  */
 326               strcpy (addrstr, name);
 327               p = strchr (addrstr, ':');
 328               if (!p || !parse_portno (p+1, &port))
 329                 {
 330                   gpg_err_set_errno (EINVAL);
 331                   addrlen = 0;
 332                 }
 333               else
 334                 {
 335                   *p = 0;
 336                   memset (&srvr_addr_in, 0, sizeof srvr_addr_in);
 337                   srvr_addr_in.sin_family = af;
 338                   srvr_addr_in.sin_port = htons (port);
 339 #ifdef HAVE_INET_PTON
 340                   addrbuf = &srvr_addr_in.sin_addr;
 341 #endif /*HAVE_INET_PTON*/
 342                   srvr_addr = (struct sockaddr *)&srvr_addr_in;
 343                   addrlen = sizeof srvr_addr_in;
 344                 }
 345             }
 346
 347           if (addrlen)
 348             {
 349 #ifdef HAVE_INET_PTON
 350               if (inet_pton (af, addrstr, addrbuf) != 1)
 351                 addrlen = 0;
 352 #else /*!HAVE_INET_PTON*/
 353               /* We need to use the old function.  If we are here v6
 354                  support isn't enabled anyway and thus we can do fine
 355                  without.  Note that Windows has a compatible inet_pton
 356                  function named inetPton, but only since Vista.  */
 357               srvr_addr_in.sin_addr.s_addr = inet_addr (addrstr);
 358               if (srvr_addr_in.sin_addr.s_addr == INADDR_NONE)
 359                 addrlen = 0;
 360 #endif /*!HAVE_INET_PTON*/
 361             }
 362
 363           xfree (addrstr);
 364         }
 365
 366       cookie->fd = addrlen? socket (pf, SOCK_STREAM, 0) : -1;
 367       if (cookie->fd == -1)
 368         {
 369           if (!cookie->quiet && !running_detached
 370               && isatty (es_fileno (es_stderr)))
 371             es_fprintf (es_stderr, "failed to create socket for logging: %s\n",
 372                         strerror(errno));
 373         }
 374       else
 375         {
 376           if (connect (cookie->fd, srvr_addr, addrlen) == -1)
 377             {
 378               if (!cookie->quiet && !running_detached
 379                   && isatty (es_fileno (es_stderr)))
 380                 es_fprintf (es_stderr, "can't connect to '%s%s': %s\n",
 381                             cookie->name, name_for_err, strerror(errno));
 382               sock_close (cookie->fd);
 383               cookie->fd = -1;
 384             }
 385         }
 386
 387       if (cookie->fd == -1)
 388         {
 389           if (!running_detached)
 390             {
 391               /* Due to all the problems with apps not running
 392                  detached but being called with stderr closed or used
 393                  for a different purposes, it does not make sense to
 394                  switch to stderr.  We therefore disable it. */
 395               if (!cookie->quiet)
 396                 {
 397                   /* fputs ("switching logging to stderr\n", stderr);*/
 398                   cookie->quiet = 1;
 399                 }
 400               cookie->fd = -1; /*fileno (stderr);*/
 401             }
 402         }
 403       else /* Connection has been established. */
 404         {
 405           cookie->quiet = 0;
 406           cookie->is_socket = 1;
 407         }
 408     }
 409
 410   log_socket = cookie->fd;
 411   if (cookie->fd != -1)
 412     {
 413 #ifdef HAVE_W32CE_SYSTEM
 414       if (cookie->use_writefile)
 415         {
 416           DWORD nwritten;
 417
 418           WriteFile ((HANDLE)cookie->fd, buffer, size, &nwritten, NULL);
 419           return (gpgrt_ssize_t)size; /* Okay.  */
 420         }
 421 #endif
 422       if (!writen (cookie->fd, buffer, size, cookie->is_socket))
 423         return (gpgrt_ssize_t)size; /* Okay. */
 424     }
 425
 426   if (!running_detached && cookie->fd != -1
 427       && isatty (es_fileno (es_stderr)))
 428     {
 429       if (*cookie->name)
 430         es_fprintf (es_stderr, "error writing to '%s': %s\n",
 431                     cookie->name, strerror(errno));
 432       else
 433         es_fprintf (es_stderr, "error writing to file descriptor %d: %s\n",
 434                     cookie->fd, strerror(errno));
 435     }
 436   if (cookie->is_socket && cookie->fd != -1)
 437     {
 438       sock_close (cookie->fd);
 439       cookie->fd = -1;
 440       log_socket = -1;
 441     }
 442
 443   return (gpgrt_ssize_t)size;
 444 }
 445
 446
 447 static int
 448 fun_closer (void *cookie_arg)
 449 {
 450   struct fun_cookie_s *cookie = cookie_arg;
 451
 452   if (cookie->fd != -1 && cookie->fd != 2)
 453     sock_close (cookie->fd);
 454   xfree (cookie);
 455   log_socket = -1;
 456   return 0;
 457 }
 458
 459
 460 /* Common function to either set the logging to a file or a file
 461    descriptor. */
 462 static void
 463 set_file_fd (const char *name, int fd)
 464 {
 465   estream_t fp;
 466   int want_socket;
 467 #ifdef HAVE_W32CE_SYSTEM
 468   int use_writefile = 0;
 469 #endif
 470   struct fun_cookie_s *cookie;
 471
 472   /* Close an open log stream.  */
 473   if (logstream)
 474     {
 475       if (logstream != es_stderr)
 476         es_fclose (logstream);
 477       logstream = NULL;
 478     }
 479
 480   /* Figure out what kind of logging we want.  */
 481   if (name && !strcmp (name, "-"))
 482     {
 483       name = NULL;
 484       fd = es_fileno (es_stderr);
 485     }
 486
 487   want_socket = 0;
 488   if (name && !strncmp (name, "tcp://", 6) && name[6])
 489     want_socket = 1;
 490 #ifndef HAVE_W32_SYSTEM
 491   else if (name && !strncmp (name, "socket://", 9))
 492     want_socket = 2;
 493 #endif /*HAVE_W32_SYSTEM*/
 494 #ifdef HAVE_W32CE_SYSTEM
 495   else if (name && !strcmp (name, "GPG2:"))
 496     {
 497       HANDLE hd;
 498
 499       ActivateDevice (L"Drivers\\"GNUPG_NAME"_Log", 0);
 500       /* Ignore a filename and write the debug output to the GPG2:
 501          device.  */
 502       hd = CreateFile (L"GPG2:", GENERIC_WRITE,
 503                        FILE_SHARE_READ | FILE_SHARE_WRITE,
 504                        NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
 505       fd = (hd == INVALID_HANDLE_VALUE)? -1 : (int)hd;
 506       name = NULL;
 507       force_prefixes = 1;
 508       use_writefile = 1;
 509     }
 510 #endif /*HAVE_W32CE_SYSTEM*/
 511
 512   /* Setup a new stream.  */
 513
 514   /* The xmalloc below is justified because we can expect that this
 515      function is called only during initialization and there is no
 516      easy way out of this error condition.  */
 517   cookie = xmalloc (sizeof *cookie + (name? strlen (name):0));
 518   strcpy (cookie->name, name? name:"");
 519   cookie->quiet = 0;
 520   cookie->is_socket = 0;
 521   cookie->want_socket = want_socket;
 522 #ifdef HAVE_W32CE_SYSTEM
 523   cookie->use_writefile = use_writefile;
 524 #endif
 525   if (!name)
 526     cookie->fd = fd;
 527   else if (want_socket)
 528     cookie->fd = -1;
 529   else
 530     {
 531       do
 532         cookie->fd = open (name, O_WRONLY|O_APPEND|O_CREAT,
 533                            (S_IRUSR|S_IRGRP|S_IROTH|S_IWUSR|S_IWGRP|S_IWOTH));
 534       while (cookie->fd == -1 && errno == EINTR);
 535     }
 536   log_socket = cookie->fd;
 537
 538   {
 539     es_cookie_io_functions_t io = { NULL };
 540     io.func_write = fun_writer;
 541     io.func_close = fun_closer;
 542
 543     fp = es_fopencookie (cookie, "w", io);
 544   }
 545
 546   /* On error default to a stderr based estream.  */
 547   if (!fp)
 548     fp = es_stderr;
 549
 550   es_setvbuf (fp, NULL, _IOLBF, 0);
 551
 552   logstream = fp;
 553
 554   /* We always need to print the prefix and the pid for socket mode,
 555      so that the server reading the socket can do something
 556      meaningful. */
 557   force_prefixes = want_socket;
 558
 559   missing_lf = 0;
 560 }
 561
 562
 563 /* Set the file to write log to.  The special names NULL and "-" may
 564    be used to select stderr and names formatted like
 565    "socket:///home/foo/mylogs" may be used to write the logging to the
 566    socket "/home/foo/mylogs".  If the connection to the socket fails
 567    or a write error is detected, the function writes to stderr and
 568    tries the next time again to connect the socket.
 569   */
 570 void
 571 log_set_file (const char *name)
 572 {
 573   set_file_fd (name? name: "-", -1);
 574 }
 575
 576 void
 577 log_set_fd (int fd)
 578 {
 579   if (! gnupg_fd_valid (fd))
 580     log_fatal ("logger-fd is invalid: %s\n", strerror (errno));
 581
 582   set_file_fd (NULL, fd);
 583 }
 584
 585
 586 /* Set a function to retrieve the directory name of a socket if
 587  * only "socket://" has been given to log_set_file.  */
 588 void
 589 log_set_socket_dir_cb (const char *(*fnc)(void))
 590 {
 591   socket_dir_cb = fnc;
 592 }
 593
 594
 595 void
 596 log_set_pid_suffix_cb (int (*cb)(unsigned long *r_value))
 597 {
 598   get_pid_suffix_cb = cb;
 599 }
 600
 601
 602 void
 603 log_set_prefix (const char *text, unsigned int flags)
 604 {
 605   if (text)
 606     {
 607       strncpy (prefix_buffer, text, sizeof (prefix_buffer)-1);
 608       prefix_buffer[sizeof (prefix_buffer)-1] = 0;
 609     }
 610
 611   with_prefix = (flags & GPGRT_LOG_WITH_PREFIX);
 612   with_time = (flags & GPGRT_LOG_WITH_TIME);
 613   with_pid  = (flags & GPGRT_LOG_WITH_PID);
 614   running_detached = (flags & GPGRT_LOG_RUN_DETACHED);
 615 #ifdef HAVE_W32_SYSTEM
 616   no_registry = (flags & GPGRT_LOG_NO_REGISTRY);
 617 #endif
 618 }
 619
 620
 621 const char *
 622 log_get_prefix (unsigned int *flags)
 623 {
 624   if (flags)
 625     {
 626       *flags = 0;
 627       if (with_prefix)
 628         *flags |= GPGRT_LOG_WITH_PREFIX;
 629       if (with_time)
 630         *flags |= GPGRT_LOG_WITH_TIME;
 631       if (with_pid)
 632         *flags |= GPGRT_LOG_WITH_PID;
 633       if (running_detached)
 634         *flags |= GPGRT_LOG_RUN_DETACHED;
 635 #ifdef HAVE_W32_SYSTEM
 636       if (no_registry)
 637         *flags |= GPGRT_LOG_NO_REGISTRY;
 638 #endif
 639     }
 640   return prefix_buffer;
 641 }
 642
 643 /* This function returns true if the file descriptor FD is in use for
 644    logging.  This is preferable over a test using log_get_fd in that
 645    it allows the logging code to use more then one file descriptor.  */
 646 int
 647 log_test_fd (int fd)
 648 {
 649   if (logstream)
 650     {
 651       int tmp = es_fileno (logstream);
 652       if ( tmp != -1 && tmp == fd)
 653         return 1;
 654     }
 655   if (log_socket != -1 && log_socket == fd)
 656     return 1;
 657   return 0;
 658 }
 659
 660 int
 661 log_get_fd ()
 662 {
 663   return logstream? es_fileno(logstream) : -1;
 664 }
 665
 666 estream_t
 667 log_get_stream ()
 668 {
 669   if (!logstream)
 670     {
 671       log_set_file (NULL); /* Make sure a log stream has been set.  */
 672       assert (logstream);
 673     }
 674   return logstream;
 675 }
 676
 677
 678 static void
 679 print_prefix (int level, int leading_backspace)
 680 {
 681   if (level != GPGRT_LOG_CONT)
 682     { /* Note this does not work for multiple line logging as we would
 683        * need to print to a buffer first */
 684       if (with_time && !force_prefixes)
 685         {
 686           struct tm *tp;
 687           time_t atime = time (NULL);
 688
 689           tp = localtime (&atime);
 690           es_fprintf_unlocked (logstream, "%04d-%02d-%02d %02d:%02d:%02d ",
 691                                1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
 692                                tp->tm_hour, tp->tm_min, tp->tm_sec );
 693         }
 694       if (with_prefix || force_prefixes)
 695         es_fputs_unlocked (prefix_buffer, logstream);
 696       if (with_pid || force_prefixes)
 697         {
 698           unsigned long pidsuf;
 699           int pidfmt;
 700
 701           if (get_pid_suffix_cb && (pidfmt=get_pid_suffix_cb (&pidsuf)))
 702             es_fprintf_unlocked (logstream, pidfmt == 1? "[%u.%lu]":"[%u.%lx]",
 703                                  (unsigned int)getpid (), pidsuf);
 704           else
 705             es_fprintf_unlocked (logstream, "[%u]", (unsigned int)getpid ());
 706         }
 707       if ((!with_time && (with_prefix || with_pid)) || force_prefixes)
 708         es_putc_unlocked (':', logstream);
 709       /* A leading backspace suppresses the extra space so that we can
 710          correctly output, programname, filename and linenumber. */
 711       if (!leading_backspace
 712           && (with_time || with_prefix || with_pid || force_prefixes))
 713         es_putc_unlocked (' ', logstream);
 714     }
 715
 716   switch (level)
 717     {
 718     case GPGRT_LOG_BEGIN: break;
 719     case GPGRT_LOG_CONT: break;
 720     case GPGRT_LOG_INFO: break;
 721     case GPGRT_LOG_WARN: break;
 722     case GPGRT_LOG_ERROR: break;
 723     case GPGRT_LOG_FATAL: es_fputs_unlocked ("Fatal: ",logstream ); break;
 724     case GPGRT_LOG_BUG:   es_fputs_unlocked ("Ohhhh jeeee: ", logstream); break;
 725     case GPGRT_LOG_DEBUG: es_fputs_unlocked ("DBG: ", logstream ); break;
 726     default:
 727       es_fprintf_unlocked (logstream,"[Unknown log level %d]: ", level);
 728       break;
 729     }
 730 }
 731
 732
 733 static void
 734 do_logv (int level, int ignore_arg_ptr, const char *extrastring,
 735          const char *prefmt, const char *fmt, va_list arg_ptr)
 736 {
 737   int leading_backspace = (fmt && *fmt == '\b');
 738
 739   if (!logstream)
 740     {
 741 #ifdef HAVE_W32_SYSTEM
 742       char *tmp;
 743
 744       tmp = (no_registry
 745              ? NULL
 746              : read_w32_registry_string (NULL, GNUPG_REGISTRY_DIR,
 747                                          "DefaultLogFile"));
 748       log_set_file (tmp && *tmp? tmp : NULL);
 749       xfree (tmp);
 750 #else
 751       log_set_file (NULL); /* Make sure a log stream has been set.  */
 752 #endif
 753       assert (logstream);
 754     }
 755
 756   es_flockfile (logstream);
 757   if (missing_lf && level != GPGRT_LOG_CONT)
 758     es_putc_unlocked ('\n', logstream );
 759   missing_lf = 0;
 760
 761   print_prefix (level, leading_backspace);
 762   if (leading_backspace)
 763     fmt++;
 764
 765   if (fmt)
 766     {
 767       if (prefmt)
 768         es_fputs_unlocked (prefmt, logstream);
 769
 770       if (ignore_arg_ptr)
 771         { /* This is used by log_string and comes with the extra
 772            * feature that after a LF the next line is indent at the
 773            * length of the prefix.  Note that we do not yet include
 774            * the length of the timestamp and pid in the indent
 775            * computation.  */
 776           const char *p, *pend;
 777
 778           for (p = fmt; (pend = strchr (p, '\n')); p = pend+1)
 779             es_fprintf_unlocked (logstream, "%*s%.*s",
 780                                  (int)((p != fmt
 781                                         && (with_prefix || force_prefixes))
 782                                        ?strlen (prefix_buffer)+2:0), "",
 783                                  (int)(pend - p)+1, p);
 784           es_fputs_unlocked (p, logstream);
 785         }
 786       else
 787         es_vfprintf_unlocked (logstream, fmt, arg_ptr);
 788       if (*fmt && fmt[strlen(fmt)-1] != '\n')
 789         missing_lf = 1;
 790     }
 791
 792   /* If we have an EXTRASTRING print it now while we still hold the
 793    * lock on the logstream.  */
 794   if (extrastring)
 795     {
 796       int c;
 797
 798       if (missing_lf)
 799         {
 800           es_putc_unlocked ('\n', logstream);
 801           missing_lf = 0;
 802         }
 803       print_prefix (level, leading_backspace);
 804       es_fputs_unlocked (">> ", logstream);
 805       missing_lf = 1;
 806       while ((c = *extrastring++))
 807         {
 808           missing_lf = 1;
 809           if (c == '\\')
 810             es_fputs_unlocked ("\\\\", logstream);
 811           else if (c == '\r')
 812             es_fputs_unlocked ("\\r", logstream);
 813           else if (c == '\n')
 814             {
 815               es_fputs_unlocked ("\\n\n", logstream);
 816               if (*extrastring)
 817                 {
 818                   print_prefix (level, leading_backspace);
 819                   es_fputs_unlocked (">> ", logstream);
 820                 }
 821               else
 822                 missing_lf = 0;
 823             }
 824           else
 825             es_putc_unlocked (c, logstream);
 826         }
 827       if (missing_lf)
 828         {
 829           es_putc_unlocked ('\n', logstream);
 830           missing_lf = 0;
 831         }
 832     }
 833
 834   if (level == GPGRT_LOG_FATAL)
 835     {
 836       if (missing_lf)
 837         es_putc_unlocked ('\n', logstream);
 838       es_funlockfile (logstream);
 839       exit (2);
 840     }
 841   else if (level == GPGRT_LOG_BUG)
 842     {
 843       if (missing_lf)
 844         es_putc_unlocked ('\n', logstream );
 845       es_funlockfile (logstream);
 846       /* Using backtrace requires a configure test and to pass
 847        * -rdynamic to gcc.  Thus we do not enable it now.  */
 848       /* { */
 849       /*   void *btbuf[20]; */
 850       /*   int btidx, btlen; */
 851       /*   char **btstr; */
 852
 853       /*   btlen = backtrace (btbuf, DIM (btbuf)); */
 854       /*   btstr = backtrace_symbols (btbuf, btlen); */
 855       /*   if (btstr) */
 856       /*     for (btidx=0; btidx < btlen; btidx++) */
 857       /*       log_debug ("[%d] %s\n", btidx, btstr[btidx]); */
 858       /* } */
 859       abort ();
 860     }
 861   else
 862     es_funlockfile (logstream);
 863 }
 864
 865
 866 void
 867 log_log (int level, const char *fmt, ...)
 868 {
 869   va_list arg_ptr ;
 870
 871   va_start (arg_ptr, fmt) ;
 872   do_logv (level, 0, NULL, NULL, fmt, arg_ptr);
 873   va_end (arg_ptr);
 874 }
 875
 876
 877 void
 878 log_logv (int level, const char *fmt, va_list arg_ptr)
 879 {
 880   do_logv (level, 0, NULL, NULL, fmt, arg_ptr);
 881 }
 882
 883
 884 /* Same as log_logv but PREFIX is printed immediately before FMT.
 885  * Note that PREFIX is an additional string and independent of the
 886  * prefix set by log_set_prefix.  */
 887 void
 888 log_logv_with_prefix (int level, const char *prefix,
 889                       const char *fmt, va_list arg_ptr)
 890 {
 891   do_logv (level, 0, NULL, prefix, fmt, arg_ptr);
 892 }
 893
 894
 895 static void
 896 do_log_ignore_arg (int level, const char *str, ...)
 897 {
 898   va_list arg_ptr;
 899   va_start (arg_ptr, str);
 900   do_logv (level, 1, NULL, NULL, str, arg_ptr);
 901   va_end (arg_ptr);
 902 }
 903
 904
 905 /* Log STRING at LEVEL but indent from the second line on by the
 906  * length of the prefix.  */
 907 void
 908 log_string (int level, const char *string)
 909 {
 910   /* We need a dummy arg_ptr, but there is no portable way to create
 911    * one.  So we call the do_logv function through a variadic wrapper. */
 912   do_log_ignore_arg (level, string);
 913 }
 914
 915
 916 void
 917 log_info (const char *fmt, ...)
 918 {
 919   va_list arg_ptr ;
 920
 921   va_start (arg_ptr, fmt);
 922   do_logv (GPGRT_LOG_INFO, 0, NULL, NULL, fmt, arg_ptr);
 923   va_end (arg_ptr);
 924 }
 925
 926
 927 void
 928 log_error (const char *fmt, ...)
 929 {
 930   va_list arg_ptr ;
 931
 932   va_start (arg_ptr, fmt);
 933   do_logv (GPGRT_LOG_ERROR, 0, NULL, NULL, fmt, arg_ptr);
 934   va_end (arg_ptr);
 935   /* Protect against counter overflow.  */
 936   if (errorcount < 30000)
 937     errorcount++;
 938 }
 939
 940
 941 void
 942 log_fatal (const char *fmt, ...)
 943 {
 944   va_list arg_ptr ;
 945
 946   va_start (arg_ptr, fmt);
 947   do_logv (GPGRT_LOG_FATAL, 0, NULL, NULL, fmt, arg_ptr);
 948   va_end (arg_ptr);
 949   abort (); /* Never called; just to make the compiler happy.  */
 950 }
 951
 952
 953 void
 954 log_bug (const char *fmt, ...)
 955 {
 956   va_list arg_ptr ;
 957
 958   va_start (arg_ptr, fmt);
 959   do_logv (GPGRT_LOG_BUG, 0, NULL, NULL, fmt, arg_ptr);
 960   va_end (arg_ptr);
 961   abort (); /* Never called; just to make the compiler happy.  */
 962 }
 963
 964
 965 void
 966 log_debug (const char *fmt, ...)
 967 {
 968   va_list arg_ptr ;
 969
 970   va_start (arg_ptr, fmt);
 971   do_logv (GPGRT_LOG_DEBUG, 0, NULL, NULL, fmt, arg_ptr);
 972   va_end (arg_ptr);
 973 }
 974
 975
 976 /* The same as log_debug but at the end of the output STRING is
 977  * printed with LFs expanded to include the prefix and a final --end--
 978  * marker.  */
 979 void
 980 log_debug_with_string (const char *string, const char *fmt, ...)
 981 {
 982   va_list arg_ptr ;
 983
 984   va_start (arg_ptr, fmt);
 985   do_logv (GPGRT_LOG_DEBUG, 0, string, NULL, fmt, arg_ptr);
 986   va_end (arg_ptr);
 987 }
 988
 989
 990 void
 991 log_printf (const char *fmt, ...)
 992 {
 993   va_list arg_ptr;
 994
 995   va_start (arg_ptr, fmt);
 996   do_logv (fmt ? GPGRT_LOG_CONT : GPGRT_LOG_BEGIN, 0, NULL, NULL, fmt, arg_ptr);
 997   va_end (arg_ptr);
 998 }
 999
1000
1001 /* Flush the log - this is useful to make sure that the trailing
1002    linefeed has been printed.  */
1003 void
1004 log_flush (void)
1005 {
1006   do_log_ignore_arg (GPGRT_LOG_CONT, NULL);
1007 }
1008
1009
1010 /* Print a hexdump of BUFFER.  With TEXT of NULL print just the raw
1011    dump, with TEXT just an empty string, print a trailing linefeed,
1012    otherwise print an entire debug line. */
1013 void
1014 log_printhex (const char *text, const void *buffer, size_t length)
1015 {
1016   if (text && *text)
1017     log_debug ("%s ", text);
1018   if (length)
1019     {
1020       const unsigned char *p = buffer;
1021       log_printf ("%02X", *p);
1022       for (length--, p++; length--; p++)
1023         log_printf (" %02X", *p);
1024     }
1025   if (text)
1026     log_printf ("\n");
1027 }
1028
1029
1030 /*
1031 void
1032 log_printcanon () {}
1033 is found in sexputils.c
1034 */
1035
1036 /*
1037 void
1038 log_printsexp () {}
1039 is found in sexputils.c
1040 */
1041
1042
1043 void
1044 log_clock (const char *string)
1045 {
1046 #if 0
1047   static unsigned long long initial;
1048   struct timespec tv;
1049   unsigned long long now;
1050
1051   if (clock_gettime (CLOCK_REALTIME, &tv))
1052     {
1053       log_debug ("error getting the realtime clock value\n");
1054       return;
1055     }
1056   now = tv.tv_sec * 1000000000ull;
1057   now += tv.tv_nsec;
1058
1059   if (!initial)
1060     initial = now;
1061
1062   log_debug ("[%6llu] %s", (now - initial)/1000, string);
1063 #else
1064   /* You need to link with -ltr to enable the above code.  */
1065   log_debug ("[not enabled in the source] %s", string);
1066 #endif
1067 }
1068
1069
1070 #ifdef GPGRT_HAVE_MACRO_FUNCTION
1071 void
1072 bug_at( const char *file, int line, const char *func )
1073 {
1074   log_log (GPGRT_LOG_BUG, "... this is a bug (%s:%d:%s)\n", file, line, func);
1075   abort (); /* Never called; just to make the compiler happy.  */
1076 }
1077 #else /*!GPGRT_HAVE_MACRO_FUNCTION*/
1078 void
1079 bug_at( const char *file, int line )
1080 {
1081   log_log (GPGRT_LOG_BUG, "you found a bug ... (%s:%d)\n", file, line);
1082   abort (); /* Never called; just to make the compiler happy.  */
1083 }
1084 #endif /*!GPGRT_HAVE_MACRO_FUNCTION*/
1085
1086
1087 #ifdef GPGRT_HAVE_MACRO_FUNCTION
1088 void
1089 _log_assert (const char *expr, const char *file, int line, const char *func)
1090 {
1091   log_log (GPGRT_LOG_BUG, "Assertion \"%s\" in %s failed (%s:%d)\n",
1092            expr, func, file, line);
1093   abort (); /* Never called; just to make the compiler happy.  */
1094 }
1095 #else /*!GPGRT_HAVE_MACRO_FUNCTION*/
1096 void
1097 _log_assert (const char *expr, const char *file, int line)
1098 {
1099   log_log (GPGRT_LOG_BUG, "Assertion \"%s\" failed (%s:%d)\n",
1100            expr, file, line);
1101   abort (); /* Never called; just to make the compiler happy.  */
1102 }
1103 #endif /*!GPGRT_HAVE_MACRO_FUNCTION*/