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