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   set_file_fd (NULL, fd);
 574 }
 575
 576
 577 /* Set a function to retrieve the directory name of a socket if
 578  * only "socket://" has been given to log_set_file.  */
 579 void
 580 log_set_socket_dir_cb (const char *(*fnc)(void))
 581 {
 582   socket_dir_cb = fnc;
 583 }
 584
 585
 586 void
 587 log_set_pid_suffix_cb (int (*cb)(unsigned long *r_value))
 588 {
 589   get_pid_suffix_cb = cb;
 590 }
 591
 592
 593 void
 594 log_set_prefix (const char *text, unsigned int flags)
 595 {
 596   if (text)
 597     {
 598       strncpy (prefix_buffer, text, sizeof (prefix_buffer)-1);
 599       prefix_buffer[sizeof (prefix_buffer)-1] = 0;
 600     }
 601
 602   with_prefix = (flags & GPGRT_LOG_WITH_PREFIX);
 603   with_time = (flags & GPGRT_LOG_WITH_TIME);
 604   with_pid  = (flags & GPGRT_LOG_WITH_PID);
 605   running_detached = (flags & GPGRT_LOG_RUN_DETACHED);
 606 #ifdef HAVE_W32_SYSTEM
 607   no_registry = (flags & GPGRT_LOG_NO_REGISTRY);
 608 #endif
 609 }
 610
 611
 612 const char *
 613 log_get_prefix (unsigned int *flags)
 614 {
 615   if (flags)
 616     {
 617       *flags = 0;
 618       if (with_prefix)
 619         *flags |= GPGRT_LOG_WITH_PREFIX;
 620       if (with_time)
 621         *flags |= GPGRT_LOG_WITH_TIME;
 622       if (with_pid)
 623         *flags |= GPGRT_LOG_WITH_PID;
 624       if (running_detached)
 625         *flags |= GPGRT_LOG_RUN_DETACHED;
 626 #ifdef HAVE_W32_SYSTEM
 627       if (no_registry)
 628         *flags |= GPGRT_LOG_NO_REGISTRY;
 629 #endif
 630     }
 631   return prefix_buffer;
 632 }
 633
 634 /* This function returns true if the file descriptor FD is in use for
 635    logging.  This is preferable over a test using log_get_fd in that
 636    it allows the logging code to use more then one file descriptor.  */
 637 int
 638 log_test_fd (int fd)
 639 {
 640   if (logstream)
 641     {
 642       int tmp = es_fileno (logstream);
 643       if ( tmp != -1 && tmp == fd)
 644         return 1;
 645     }
 646   if (log_socket != -1 && log_socket == fd)
 647     return 1;
 648   return 0;
 649 }
 650
 651 int
 652 log_get_fd ()
 653 {
 654   return logstream? es_fileno(logstream) : -1;
 655 }
 656
 657 estream_t
 658 log_get_stream ()
 659 {
 660   if (!logstream)
 661     {
 662       log_set_file (NULL); /* Make sure a log stream has been set.  */
 663       assert (logstream);
 664     }
 665   return logstream;
 666 }
 667
 668
 669 static void
 670 print_prefix (int level, int leading_backspace)
 671 {
 672   if (level != GPGRT_LOG_CONT)
 673     { /* Note this does not work for multiple line logging as we would
 674        * need to print to a buffer first */
 675       if (with_time && !force_prefixes)
 676         {
 677           struct tm *tp;
 678           time_t atime = time (NULL);
 679
 680           tp = localtime (&atime);
 681           es_fprintf_unlocked (logstream, "%04d-%02d-%02d %02d:%02d:%02d ",
 682                                1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
 683                                tp->tm_hour, tp->tm_min, tp->tm_sec );
 684         }
 685       if (with_prefix || force_prefixes)
 686         es_fputs_unlocked (prefix_buffer, logstream);
 687       if (with_pid || force_prefixes)
 688         {
 689           unsigned long pidsuf;
 690           int pidfmt;
 691
 692           if (get_pid_suffix_cb && (pidfmt=get_pid_suffix_cb (&pidsuf)))
 693             es_fprintf_unlocked (logstream, pidfmt == 1? "[%u.%lu]":"[%u.%lx]",
 694                                  (unsigned int)getpid (), pidsuf);
 695           else
 696             es_fprintf_unlocked (logstream, "[%u]", (unsigned int)getpid ());
 697         }
 698       if ((!with_time && (with_prefix || with_pid)) || force_prefixes)
 699         es_putc_unlocked (':', logstream);
 700       /* A leading backspace suppresses the extra space so that we can
 701          correctly output, programname, filename and linenumber. */
 702       if (!leading_backspace
 703           && (with_time || with_prefix || with_pid || force_prefixes))
 704         es_putc_unlocked (' ', logstream);
 705     }
 706
 707   switch (level)
 708     {
 709     case GPGRT_LOG_BEGIN: break;
 710     case GPGRT_LOG_CONT: break;
 711     case GPGRT_LOG_INFO: break;
 712     case GPGRT_LOG_WARN: break;
 713     case GPGRT_LOG_ERROR: break;
 714     case GPGRT_LOG_FATAL: es_fputs_unlocked ("Fatal: ",logstream ); break;
 715     case GPGRT_LOG_BUG:   es_fputs_unlocked ("Ohhhh jeeee: ", logstream); break;
 716     case GPGRT_LOG_DEBUG: es_fputs_unlocked ("DBG: ", logstream ); break;
 717     default:
 718       es_fprintf_unlocked (logstream,"[Unknown log level %d]: ", level);
 719       break;
 720     }
 721 }
 722
 723
 724 static void
 725 do_logv (int level, int ignore_arg_ptr, const char *extrastring,
 726          const char *fmt, va_list arg_ptr)
 727 {
 728   int leading_backspace = (fmt && *fmt == '\b');
 729
 730   if (!logstream)
 731     {
 732 #ifdef HAVE_W32_SYSTEM
 733       char *tmp;
 734
 735       tmp = (no_registry
 736              ? NULL
 737              : read_w32_registry_string (NULL, GNUPG_REGISTRY_DIR,
 738                                          "DefaultLogFile"));
 739       log_set_file (tmp && *tmp? tmp : NULL);
 740       xfree (tmp);
 741 #else
 742       log_set_file (NULL); /* Make sure a log stream has been set.  */
 743 #endif
 744       assert (logstream);
 745     }
 746
 747   es_flockfile (logstream);
 748   if (missing_lf && level != GPGRT_LOG_CONT)
 749     es_putc_unlocked ('\n', logstream );
 750   missing_lf = 0;
 751
 752   print_prefix (level, leading_backspace);
 753   if (leading_backspace)
 754     fmt++;
 755
 756   if (fmt)
 757     {
 758       if (ignore_arg_ptr)
 759         { /* This is used by log_string and comes with the extra
 760            * feature that after a LF the next line is indent at the
 761            * length of the prefix.  Note that we do not yet include
 762            * the length of the timestamp and pid in the indent
 763            * computation.  */
 764           const char *p, *pend;
 765
 766           for (p = fmt; (pend = strchr (p, '\n')); p = pend+1)
 767             es_fprintf_unlocked (logstream, "%*s%.*s",
 768                                  (int)((p != fmt
 769                                         && (with_prefix || force_prefixes))
 770                                        ?strlen (prefix_buffer)+2:0), "",
 771                                  (int)(pend - p)+1, p);
 772           es_fputs_unlocked (p, logstream);
 773         }
 774       else
 775         es_vfprintf_unlocked (logstream, fmt, arg_ptr);
 776       if (*fmt && fmt[strlen(fmt)-1] != '\n')
 777         missing_lf = 1;
 778     }
 779
 780   /* If we have an EXTRASTRING print it now while we still hold the
 781    * lock on the logstream.  */
 782   if (extrastring)
 783     {
 784       int c;
 785
 786       if (missing_lf)
 787         {
 788           es_putc_unlocked ('\n', logstream);
 789           missing_lf = 0;
 790         }
 791       print_prefix (level, leading_backspace);
 792       es_fputs_unlocked (">> ", logstream);
 793       missing_lf = 1;
 794       while ((c = *extrastring++))
 795         {
 796           missing_lf = 1;
 797           if (c == '\\')
 798             es_fputs_unlocked ("\\\\", logstream);
 799           else if (c == '\r')
 800             es_fputs_unlocked ("\\r", logstream);
 801           else if (c == '\n')
 802             {
 803               es_fputs_unlocked ("\\n\n", logstream);
 804               if (*extrastring)
 805                 {
 806                   print_prefix (level, leading_backspace);
 807                   es_fputs_unlocked (">> ", logstream);
 808                 }
 809               else
 810                 missing_lf = 0;
 811             }
 812           else
 813             es_putc_unlocked (c, logstream);
 814         }
 815       if (missing_lf)
 816         {
 817           es_putc_unlocked ('\n', logstream);
 818           missing_lf = 0;
 819         }
 820     }
 821
 822   if (level == GPGRT_LOG_FATAL)
 823     {
 824       if (missing_lf)
 825         es_putc_unlocked ('\n', logstream);
 826       es_funlockfile (logstream);
 827       exit (2);
 828     }
 829   else if (level == GPGRT_LOG_BUG)
 830     {
 831       if (missing_lf)
 832         es_putc_unlocked ('\n', logstream );
 833       es_funlockfile (logstream);
 834       /* Using backtrace requires a configure test and to pass
 835        * -rdynamic to gcc.  Thus we do not enable it now.  */
 836       /* { */
 837       /*   void *btbuf[20]; */
 838       /*   int btidx, btlen; */
 839       /*   char **btstr; */
 840
 841       /*   btlen = backtrace (btbuf, DIM (btbuf)); */
 842       /*   btstr = backtrace_symbols (btbuf, btlen); */
 843       /*   if (btstr) */
 844       /*     for (btidx=0; btidx < btlen; btidx++) */
 845       /*       log_debug ("[%d] %s\n", btidx, btstr[btidx]); */
 846       /* } */
 847       abort ();
 848     }
 849   else
 850     es_funlockfile (logstream);
 851 }
 852
 853
 854 void
 855 log_log (int level, const char *fmt, ...)
 856 {
 857   va_list arg_ptr ;
 858
 859   va_start (arg_ptr, fmt) ;
 860   do_logv (level, 0, NULL, fmt, arg_ptr);
 861   va_end (arg_ptr);
 862 }
 863
 864
 865 void
 866 log_logv (int level, const char *fmt, va_list arg_ptr)
 867 {
 868   do_logv (level, 0, NULL, fmt, arg_ptr);
 869 }
 870
 871
 872 static void
 873 do_log_ignore_arg (int level, const char *str, ...)
 874 {
 875   va_list arg_ptr;
 876   va_start (arg_ptr, str);
 877   do_logv (level, 1, NULL, str, arg_ptr);
 878   va_end (arg_ptr);
 879 }
 880
 881
 882 /* Log STRING at LEVEL but indent from the second line on by the
 883  * length of the prefix.  */
 884 void
 885 log_string (int level, const char *string)
 886 {
 887   /* We need a dummy arg_ptr, but there is no portable way to create
 888    * one.  So we call the do_logv function through a variadic wrapper. */
 889   do_log_ignore_arg (level, string);
 890 }
 891
 892
 893 void
 894 log_info (const char *fmt, ...)
 895 {
 896   va_list arg_ptr ;
 897
 898   va_start (arg_ptr, fmt);
 899   do_logv (GPGRT_LOG_INFO, 0, NULL, fmt, arg_ptr);
 900   va_end (arg_ptr);
 901 }
 902
 903
 904 void
 905 log_error (const char *fmt, ...)
 906 {
 907   va_list arg_ptr ;
 908
 909   va_start (arg_ptr, fmt);
 910   do_logv (GPGRT_LOG_ERROR, 0, NULL, fmt, arg_ptr);
 911   va_end (arg_ptr);
 912   /* Protect against counter overflow.  */
 913   if (errorcount < 30000)
 914     errorcount++;
 915 }
 916
 917
 918 void
 919 log_fatal (const char *fmt, ...)
 920 {
 921   va_list arg_ptr ;
 922
 923   va_start (arg_ptr, fmt);
 924   do_logv (GPGRT_LOG_FATAL, 0, NULL, fmt, arg_ptr);
 925   va_end (arg_ptr);
 926   abort (); /* Never called; just to make the compiler happy.  */
 927 }
 928
 929
 930 void
 931 log_bug (const char *fmt, ...)
 932 {
 933   va_list arg_ptr ;
 934
 935   va_start (arg_ptr, fmt);
 936   do_logv (GPGRT_LOG_BUG, 0, NULL, fmt, arg_ptr);
 937   va_end (arg_ptr);
 938   abort (); /* Never called; just to make the compiler happy.  */
 939 }
 940
 941
 942 void
 943 log_debug (const char *fmt, ...)
 944 {
 945   va_list arg_ptr ;
 946
 947   va_start (arg_ptr, fmt);
 948   do_logv (GPGRT_LOG_DEBUG, 0, NULL, fmt, arg_ptr);
 949   va_end (arg_ptr);
 950 }
 951
 952
 953 /* The same as log_debug but at the end of the output STRING is
 954  * printed with LFs expanded to include the prefix and a final --end--
 955  * marker.  */
 956 void
 957 log_debug_with_string (const char *string, const char *fmt, ...)
 958 {
 959   va_list arg_ptr ;
 960
 961   va_start (arg_ptr, fmt);
 962   do_logv (GPGRT_LOG_DEBUG, 0, string, fmt, arg_ptr);
 963   va_end (arg_ptr);
 964 }
 965
 966
 967 void
 968 log_printf (const char *fmt, ...)
 969 {
 970   va_list arg_ptr;
 971
 972   va_start (arg_ptr, fmt);
 973   do_logv (fmt ? GPGRT_LOG_CONT : GPGRT_LOG_BEGIN, 0, NULL, fmt, arg_ptr);
 974   va_end (arg_ptr);
 975 }
 976
 977
 978 /* Flush the log - this is useful to make sure that the trailing
 979    linefeed has been printed.  */
 980 void
 981 log_flush (void)
 982 {
 983   do_log_ignore_arg (GPGRT_LOG_CONT, NULL);
 984 }
 985
 986
 987 /* Print a hexdump of BUFFER.  With TEXT of NULL print just the raw
 988    dump, with TEXT just an empty string, print a trailing linefeed,
 989    otherwise print an entire debug line. */
 990 void
 991 log_printhex (const char *text, const void *buffer, size_t length)
 992 {
 993   if (text && *text)
 994     log_debug ("%s ", text);
 995   if (length)
 996     {
 997       const unsigned char *p = buffer;
 998       log_printf ("%02X", *p);
 999       for (length--, p++; length--; p++)
1000         log_printf (" %02X", *p);
1001     }
1002   if (text)
1003     log_printf ("\n");
1004 }
1005
1006
1007 /*
1008 void
1009 log_printcanon () {}
1010 is found in sexputils.c
1011 */
1012
1013 /*
1014 void
1015 log_printsexp () {}
1016 is found in sexputils.c
1017 */
1018
1019
1020 void
1021 log_clock (const char *string)
1022 {
1023 #if 0
1024   static unsigned long long initial;
1025   struct timespec tv;
1026   unsigned long long now;
1027
1028   if (clock_gettime (CLOCK_REALTIME, &tv))
1029     {
1030       log_debug ("error getting the realtime clock value\n");
1031       return;
1032     }
1033   now = tv.tv_sec * 1000000000ull;
1034   now += tv.tv_nsec;
1035
1036   if (!initial)
1037     initial = now;
1038
1039   log_debug ("[%6llu] %s", (now - initial)/1000, string);
1040 #else
1041   /* You need to link with -ltr to enable the above code.  */
1042   log_debug ("[not enabled in the source] %s", string);
1043 #endif
1044 }
1045
1046
1047 #ifdef GPGRT_HAVE_MACRO_FUNCTION
1048 void
1049 bug_at( const char *file, int line, const char *func )
1050 {
1051   log_log (GPGRT_LOG_BUG, "... this is a bug (%s:%d:%s)\n", file, line, func);
1052   abort (); /* Never called; just to make the compiler happy.  */
1053 }
1054 #else /*!GPGRT_HAVE_MACRO_FUNCTION*/
1055 void
1056 bug_at( const char *file, int line )
1057 {
1058   log_log (GPGRT_LOG_BUG, "you found a bug ... (%s:%d)\n", file, line);
1059   abort (); /* Never called; just to make the compiler happy.  */
1060 }
1061 #endif /*!GPGRT_HAVE_MACRO_FUNCTION*/
1062
1063
1064 #ifdef GPGRT_HAVE_MACRO_FUNCTION
1065 void
1066 _log_assert (const char *expr, const char *file, int line, const char *func)
1067 {
1068   log_log (GPGRT_LOG_BUG, "Assertion \"%s\" in %s failed (%s:%d)\n",
1069            expr, func, file, line);
1070   abort (); /* Never called; just to make the compiler happy.  */
1071 }
1072 #else /*!GPGRT_HAVE_MACRO_FUNCTION*/
1073 void
1074 _log_assert (const char *expr, const char *file, int line)
1075 {
1076   log_log (GPGRT_LOG_BUG, "Assertion \"%s\" failed (%s:%d)\n",
1077            expr, file, line);
1078   abort (); /* Never called; just to make the compiler happy.  */
1079 }
1080 #endif /*!GPGRT_HAVE_MACRO_FUNCTION*/