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