common: New function log_logv_with_prefix.
[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 *prefmt, 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 (prefmt)
763         es_fputs_unlocked (prefmt, logstream);
764
765       if (ignore_arg_ptr)
766         { /* This is used by log_string and comes with the extra
767            * feature that after a LF the next line is indent at the
768            * length of the prefix.  Note that we do not yet include
769            * the length of the timestamp and pid in the indent
770            * computation.  */
771           const char *p, *pend;
772
773           for (p = fmt; (pend = strchr (p, '\n')); p = pend+1)
774             es_fprintf_unlocked (logstream, "%*s%.*s",
775                                  (int)((p != fmt
776                                         && (with_prefix || force_prefixes))
777                                        ?strlen (prefix_buffer)+2:0), "",
778                                  (int)(pend - p)+1, p);
779           es_fputs_unlocked (p, logstream);
780         }
781       else
782         es_vfprintf_unlocked (logstream, fmt, arg_ptr);
783       if (*fmt && fmt[strlen(fmt)-1] != '\n')
784         missing_lf = 1;
785     }
786
787   /* If we have an EXTRASTRING print it now while we still hold the
788    * lock on the logstream.  */
789   if (extrastring)
790     {
791       int c;
792
793       if (missing_lf)
794         {
795           es_putc_unlocked ('\n', logstream);
796           missing_lf = 0;
797         }
798       print_prefix (level, leading_backspace);
799       es_fputs_unlocked (">> ", logstream);
800       missing_lf = 1;
801       while ((c = *extrastring++))
802         {
803           missing_lf = 1;
804           if (c == '\\')
805             es_fputs_unlocked ("\\\\", logstream);
806           else if (c == '\r')
807             es_fputs_unlocked ("\\r", logstream);
808           else if (c == '\n')
809             {
810               es_fputs_unlocked ("\\n\n", logstream);
811               if (*extrastring)
812                 {
813                   print_prefix (level, leading_backspace);
814                   es_fputs_unlocked (">> ", logstream);
815                 }
816               else
817                 missing_lf = 0;
818             }
819           else
820             es_putc_unlocked (c, logstream);
821         }
822       if (missing_lf)
823         {
824           es_putc_unlocked ('\n', logstream);
825           missing_lf = 0;
826         }
827     }
828
829   if (level == GPGRT_LOG_FATAL)
830     {
831       if (missing_lf)
832         es_putc_unlocked ('\n', logstream);
833       es_funlockfile (logstream);
834       exit (2);
835     }
836   else if (level == GPGRT_LOG_BUG)
837     {
838       if (missing_lf)
839         es_putc_unlocked ('\n', logstream );
840       es_funlockfile (logstream);
841       /* Using backtrace requires a configure test and to pass
842        * -rdynamic to gcc.  Thus we do not enable it now.  */
843       /* { */
844       /*   void *btbuf[20]; */
845       /*   int btidx, btlen; */
846       /*   char **btstr; */
847
848       /*   btlen = backtrace (btbuf, DIM (btbuf)); */
849       /*   btstr = backtrace_symbols (btbuf, btlen); */
850       /*   if (btstr) */
851       /*     for (btidx=0; btidx < btlen; btidx++) */
852       /*       log_debug ("[%d] %s\n", btidx, btstr[btidx]); */
853       /* } */
854       abort ();
855     }
856   else
857     es_funlockfile (logstream);
858 }
859
860
861 void
862 log_log (int level, const char *fmt, ...)
863 {
864   va_list arg_ptr ;
865
866   va_start (arg_ptr, fmt) ;
867   do_logv (level, 0, NULL, NULL, fmt, arg_ptr);
868   va_end (arg_ptr);
869 }
870
871
872 void
873 log_logv (int level, const char *fmt, va_list arg_ptr)
874 {
875   do_logv (level, 0, NULL, NULL, fmt, arg_ptr);
876 }
877
878
879 /* Same as log_logv but PREFIX is printed immediately before FMT.
880  * Note that PREFIX is an additional string and independent of the
881  * prefix set by log_set_prefix.  */
882 void
883 log_logv_with_prefix (int level, const char *prefix,
884                       const char *fmt, va_list arg_ptr)
885 {
886   do_logv (level, 0, NULL, prefix, fmt, arg_ptr);
887 }
888
889
890 static void
891 do_log_ignore_arg (int level, const char *str, ...)
892 {
893   va_list arg_ptr;
894   va_start (arg_ptr, str);
895   do_logv (level, 1, NULL, NULL, str, arg_ptr);
896   va_end (arg_ptr);
897 }
898
899
900 /* Log STRING at LEVEL but indent from the second line on by the
901  * length of the prefix.  */
902 void
903 log_string (int level, const char *string)
904 {
905   /* We need a dummy arg_ptr, but there is no portable way to create
906    * one.  So we call the do_logv function through a variadic wrapper. */
907   do_log_ignore_arg (level, string);
908 }
909
910
911 void
912 log_info (const char *fmt, ...)
913 {
914   va_list arg_ptr ;
915
916   va_start (arg_ptr, fmt);
917   do_logv (GPGRT_LOG_INFO, 0, NULL, NULL, fmt, arg_ptr);
918   va_end (arg_ptr);
919 }
920
921
922 void
923 log_error (const char *fmt, ...)
924 {
925   va_list arg_ptr ;
926
927   va_start (arg_ptr, fmt);
928   do_logv (GPGRT_LOG_ERROR, 0, NULL, NULL, fmt, arg_ptr);
929   va_end (arg_ptr);
930   /* Protect against counter overflow.  */
931   if (errorcount < 30000)
932     errorcount++;
933 }
934
935
936 void
937 log_fatal (const char *fmt, ...)
938 {
939   va_list arg_ptr ;
940
941   va_start (arg_ptr, fmt);
942   do_logv (GPGRT_LOG_FATAL, 0, NULL, NULL, fmt, arg_ptr);
943   va_end (arg_ptr);
944   abort (); /* Never called; just to make the compiler happy.  */
945 }
946
947
948 void
949 log_bug (const char *fmt, ...)
950 {
951   va_list arg_ptr ;
952
953   va_start (arg_ptr, fmt);
954   do_logv (GPGRT_LOG_BUG, 0, NULL, NULL, fmt, arg_ptr);
955   va_end (arg_ptr);
956   abort (); /* Never called; just to make the compiler happy.  */
957 }
958
959
960 void
961 log_debug (const char *fmt, ...)
962 {
963   va_list arg_ptr ;
964
965   va_start (arg_ptr, fmt);
966   do_logv (GPGRT_LOG_DEBUG, 0, NULL, NULL, fmt, arg_ptr);
967   va_end (arg_ptr);
968 }
969
970
971 /* The same as log_debug but at the end of the output STRING is
972  * printed with LFs expanded to include the prefix and a final --end--
973  * marker.  */
974 void
975 log_debug_with_string (const char *string, const char *fmt, ...)
976 {
977   va_list arg_ptr ;
978
979   va_start (arg_ptr, fmt);
980   do_logv (GPGRT_LOG_DEBUG, 0, string, NULL, fmt, arg_ptr);
981   va_end (arg_ptr);
982 }
983
984
985 void
986 log_printf (const char *fmt, ...)
987 {
988   va_list arg_ptr;
989
990   va_start (arg_ptr, fmt);
991   do_logv (fmt ? GPGRT_LOG_CONT : GPGRT_LOG_BEGIN, 0, NULL, NULL, fmt, arg_ptr);
992   va_end (arg_ptr);
993 }
994
995
996 /* Flush the log - this is useful to make sure that the trailing
997    linefeed has been printed.  */
998 void
999 log_flush (void)
1000 {
1001   do_log_ignore_arg (GPGRT_LOG_CONT, NULL);
1002 }
1003
1004
1005 /* Print a hexdump of BUFFER.  With TEXT of NULL print just the raw
1006    dump, with TEXT just an empty string, print a trailing linefeed,
1007    otherwise print an entire debug line. */
1008 void
1009 log_printhex (const char *text, const void *buffer, size_t length)
1010 {
1011   if (text && *text)
1012     log_debug ("%s ", text);
1013   if (length)
1014     {
1015       const unsigned char *p = buffer;
1016       log_printf ("%02X", *p);
1017       for (length--, p++; length--; p++)
1018         log_printf (" %02X", *p);
1019     }
1020   if (text)
1021     log_printf ("\n");
1022 }
1023
1024
1025 /*
1026 void
1027 log_printcanon () {}
1028 is found in sexputils.c
1029 */
1030
1031 /*
1032 void
1033 log_printsexp () {}
1034 is found in sexputils.c
1035 */
1036
1037
1038 void
1039 log_clock (const char *string)
1040 {
1041 #if 0
1042   static unsigned long long initial;
1043   struct timespec tv;
1044   unsigned long long now;
1045
1046   if (clock_gettime (CLOCK_REALTIME, &tv))
1047     {
1048       log_debug ("error getting the realtime clock value\n");
1049       return;
1050     }
1051   now = tv.tv_sec * 1000000000ull;
1052   now += tv.tv_nsec;
1053
1054   if (!initial)
1055     initial = now;
1056
1057   log_debug ("[%6llu] %s", (now - initial)/1000, string);
1058 #else
1059   /* You need to link with -ltr to enable the above code.  */
1060   log_debug ("[not enabled in the source] %s", string);
1061 #endif
1062 }
1063
1064
1065 #ifdef GPGRT_HAVE_MACRO_FUNCTION
1066 void
1067 bug_at( const char *file, int line, const char *func )
1068 {
1069   log_log (GPGRT_LOG_BUG, "... this is a bug (%s:%d:%s)\n", file, line, func);
1070   abort (); /* Never called; just to make the compiler happy.  */
1071 }
1072 #else /*!GPGRT_HAVE_MACRO_FUNCTION*/
1073 void
1074 bug_at( const char *file, int line )
1075 {
1076   log_log (GPGRT_LOG_BUG, "you found a bug ... (%s:%d)\n", file, line);
1077   abort (); /* Never called; just to make the compiler happy.  */
1078 }
1079 #endif /*!GPGRT_HAVE_MACRO_FUNCTION*/
1080
1081
1082 #ifdef GPGRT_HAVE_MACRO_FUNCTION
1083 void
1084 _log_assert (const char *expr, const char *file, int line, const char *func)
1085 {
1086   log_log (GPGRT_LOG_BUG, "Assertion \"%s\" in %s failed (%s:%d)\n",
1087            expr, func, file, line);
1088   abort (); /* Never called; just to make the compiler happy.  */
1089 }
1090 #else /*!GPGRT_HAVE_MACRO_FUNCTION*/
1091 void
1092 _log_assert (const char *expr, const char *file, int line)
1093 {
1094   log_log (GPGRT_LOG_BUG, "Assertion \"%s\" failed (%s:%d)\n",
1095            expr, file, line);
1096   abort (); /* Never called; just to make the compiler happy.  */
1097 }
1098 #endif /*!GPGRT_HAVE_MACRO_FUNCTION*/