common: Rename remaining symbols in ksba-io-support.
[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 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*/