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