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