Merged Dirmngr with GnuPG.
[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 JNLIB.
6  *
7  * JNLIB is free software; you can redistribute it and/or modify it
8  * under the terms of the GNU Lesser General Public License as
9  * published by the Free Software Foundation; either version 3 of
10  * the License, or (at your option) any later version.
11  *
12  * JNLIB is distributed in the hope that it will be useful, but
13  * WITHOUT ANY WARRANTY; without even the implied warranty of
14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
15  * Lesser General Public License for more details.
16  *
17  * You should have received a copy of the GNU Lesser General Public
18  * License along with this program; if not, see <http://www.gnu.org/licenses/>.
19  */
20
21
22 #include <config.h>
23 #include <stdlib.h>
24 #include <stdio.h>
25 #include <string.h>
26 #include <stdarg.h>
27 #include <stddef.h>
28 #include <errno.h>
29 #include <time.h>
30 #include <sys/types.h>
31 #include <sys/stat.h>
32 #ifndef HAVE_W32_SYSTEM
33 # include <sys/socket.h>
34 # include <sys/un.h>
35 #endif /*HAVE_W32_SYSTEM*/
36 #include <unistd.h>
37 #include <fcntl.h>
38 #include <assert.h>
39
40
41
42 #define JNLIB_NEED_LOG_LOGV 1
43 #define JNLIB_NEED_AFLOCAL 1
44 #include "libjnlib-config.h"
45 #include "logging.h"
46
47 #ifdef HAVE_W32_SYSTEM
48 # define S_IRGRP S_IRUSR
49 # define S_IROTH S_IRUSR
50 # define S_IWGRP S_IWUSR
51 # define S_IWOTH S_IWUSR
52 #endif
53
54
55 #ifdef HAVE_W32CE_SYSTEM
56 # define isatty(a)  (0)
57 #endif
58
59
60 static estream_t logstream;
61 static int log_socket = -1;
62 static char prefix_buffer[80];
63 static int with_time;
64 static int with_prefix;
65 static int with_pid;
66 static int (*get_pid_suffix_cb)(unsigned long *r_value);
67 static int running_detached;
68 static int force_prefixes;
69
70 static int missing_lf;
71 static int errorcount;
72
73
74 int
75 log_get_errorcount (int clear)
76 {
77     int n = errorcount;
78     if( clear )
79         errorcount = 0;
80     return n;
81 }
82
83 void
84 log_inc_errorcount (void)
85 {
86    errorcount++;
87 }
88
89
90 /* The following 3 functions are used by es_fopencookie to write logs
91    to a socket.  */
92 struct fun_cookie_s
93 {
94   int fd;
95   int quiet;
96   int want_socket;
97   int is_socket;
98   char name[1];
99 };
100
101
102 /* Write NBYTES of BUFFER to file descriptor FD. */
103 static int
104 writen (int fd, const void *buffer, size_t nbytes)
105 {
106   const char *buf = buffer;
107   size_t nleft = nbytes;
108   int nwritten;
109   
110   while (nleft > 0)
111     {
112       nwritten = write (fd, buf, nleft);
113       if (nwritten < 0 && errno == EINTR)
114         continue;
115       if (nwritten < 0)
116         return -1;
117       nleft -= nwritten;
118       buf = buf + nwritten;
119     }
120   
121   return 0;
122 }
123
124
125 static ssize_t 
126 fun_writer (void *cookie_arg, const void *buffer, size_t size)
127 {
128   struct fun_cookie_s *cookie = cookie_arg;
129
130   /* Note that we always try to reconnect to the socket but print
131      error messages only the first time an error occured.  If
132      RUNNING_DETACHED is set we don't fall back to stderr and even do
133      not print any error messages.  This is needed because detached
134      processes often close stderr and by writing to file descriptor 2
135      we might send the log message to a file not intended for logging
136      (e.g. a pipe or network connection). */
137 #ifndef HAVE_W32_SYSTEM
138   if (cookie->want_socket && cookie->fd == -1)
139     {
140       /* Not yet open or meanwhile closed due to an error. */
141       cookie->is_socket = 0;
142       cookie->fd = socket (PF_LOCAL, SOCK_STREAM, 0);
143       if (cookie->fd == -1)
144         {
145           if (!cookie->quiet && !running_detached
146               && isatty (es_fileno (es_stderr)))
147             es_fprintf (es_stderr, "failed to create socket for logging: %s\n",
148                         strerror(errno));
149         }
150       else
151         {
152           struct sockaddr_un addr;
153           size_t addrlen;
154           
155           memset (&addr, 0, sizeof addr);
156           addr.sun_family = PF_LOCAL;
157           strncpy (addr.sun_path, cookie->name, sizeof (addr.sun_path)-1);
158           addr.sun_path[sizeof (addr.sun_path)-1] = 0;
159           addrlen = SUN_LEN (&addr);
160       
161           if (connect (cookie->fd, (struct sockaddr *) &addr, addrlen) == -1)
162             {
163               if (!cookie->quiet && !running_detached
164                   && isatty (es_fileno (es_stderr)))
165                 es_fprintf (es_stderr, "can't connect to `%s': %s\n",
166                             cookie->name, strerror(errno));
167               close (cookie->fd);
168               cookie->fd = -1;
169             }
170         }
171       
172       if (cookie->fd == -1)
173         {
174           if (!running_detached)
175             {
176               /* Due to all the problems with apps not running
177                  detached but being called with stderr closed or
178                  used for a different purposes, it does not make
179                  sense to switch to stderr.  We therefore disable it. */
180               if (!cookie->quiet)
181                 {
182                   /* fputs ("switching logging to stderr\n", stderr);*/
183                   cookie->quiet = 1;
184                 }
185               cookie->fd = -1; /*fileno (stderr);*/
186             }
187         }
188       else /* Connection has been established. */
189         {
190           cookie->quiet = 0;
191           cookie->is_socket = 1;
192         }
193     }
194 #endif /*HAVE_W32_SYSTEM*/
195
196   log_socket = cookie->fd;
197   if (cookie->fd != -1 && !writen (cookie->fd, buffer, size))
198     return (ssize_t)size; /* Okay. */ 
199
200   if (!running_detached && cookie->fd != -1
201       && isatty (es_fileno (es_stderr)))
202     {
203       if (*cookie->name)
204         es_fprintf (es_stderr, "error writing to `%s': %s\n",
205                     cookie->name, strerror(errno));
206       else
207         es_fprintf (es_stderr, "error writing to file descriptor %d: %s\n",
208                     cookie->fd, strerror(errno));
209     }
210   if (cookie->is_socket && cookie->fd != -1)
211     {
212       close (cookie->fd);
213       cookie->fd = -1;
214       log_socket = -1;
215     }
216
217   return (ssize_t)size;
218 }
219
220
221 static int
222 fun_closer (void *cookie_arg)
223 {
224   struct fun_cookie_s *cookie = cookie_arg;
225
226   if (cookie->fd != -1 && cookie->fd != 2)
227     close (cookie->fd);
228   jnlib_free (cookie);
229   log_socket = -1;
230   return 0;
231 }
232
233
234 /* Common function to either set the logging to a file or a file
235    descriptor. */
236 static void
237 set_file_fd (const char *name, int fd) 
238 {
239   estream_t fp;
240   int want_socket;
241   struct fun_cookie_s *cookie;
242
243   /* Close an open log stream.  */
244   if (logstream)
245     {
246       es_fclose (logstream);
247       logstream = NULL;
248     }
249
250   /* Figure out what kind of logging we want.  */
251   if (name && !strcmp (name, "-"))
252     {
253       name = NULL;
254       fd = es_fileno (es_stderr);
255     }
256
257 #ifndef HAVE_W32_SYSTEM
258   if (name)
259     {
260       want_socket = (!strncmp (name, "socket://", 9) && name[9]);
261       if (want_socket)
262         name += 9;
263     }
264   else
265 #endif /*HAVE_W32_SYSTEM*/
266     {
267       want_socket = 0;
268     }
269
270   /* Setup a new stream.  */
271
272   /* The xmalloc below is justified because we can expect that this
273      function is called only during initialization and there is no
274      easy way out of this error condition.  */
275   cookie = jnlib_xmalloc (sizeof *cookie + (name? strlen (name):0));
276   strcpy (cookie->name, name? name:"");
277   cookie->quiet = 0;
278   cookie->is_socket = 0;
279   cookie->want_socket = want_socket;
280   if (!name)
281     cookie->fd = fd;
282   else if (want_socket)
283     cookie->fd = -1;
284   else
285     {
286       do
287         cookie->fd = open (name, O_WRONLY|O_APPEND|O_CREAT,
288                            (S_IRUSR|S_IRGRP|S_IROTH|S_IWUSR|S_IWGRP|S_IWOTH));
289       while (cookie->fd == -1 && errno == EINTR);
290     }
291   log_socket = cookie->fd;
292
293   {
294     es_cookie_io_functions_t io = { NULL };
295     io.func_write = fun_writer;
296     io.func_close = fun_closer;
297     
298     fp = es_fopencookie (cookie, "w", io);
299   }
300
301   /* On error default to a stderr based estream.  */
302   if (!fp)
303     fp = es_stderr;
304
305   es_setvbuf (fp, NULL, _IOLBF, 0);
306   
307   logstream = fp;
308
309   /* We always need to print the prefix and the pid for socket mode,
310      so that the server reading the socket can do something
311      meaningful. */
312   force_prefixes = want_socket;
313
314   missing_lf = 0;
315 }
316
317
318 /* Set the file to write log to.  The special names NULL and "-" may
319    be used to select stderr and names formatted like
320    "socket:///home/foo/mylogs" may be used to write the logging to the
321    socket "/home/foo/mylogs".  If the connection to the socket fails
322    or a write error is detected, the function writes to stderr and
323    tries the next time again to connect the socket.
324   */
325 void
326 log_set_file (const char *name) 
327 {
328   set_file_fd (name? name: "-", -1);
329 }
330
331 void
332 log_set_fd (int fd)
333 {
334   set_file_fd (NULL, fd);
335 }
336
337
338 void
339 log_set_pid_suffix_cb (int (*cb)(unsigned long *r_value))
340 {
341   get_pid_suffix_cb = cb;
342 }
343
344
345 void
346 log_set_prefix (const char *text, unsigned int flags)
347 {
348   if (text)
349     {
350       strncpy (prefix_buffer, text, sizeof (prefix_buffer)-1);
351       prefix_buffer[sizeof (prefix_buffer)-1] = 0;
352     }
353   
354   with_prefix = (flags & JNLIB_LOG_WITH_PREFIX);
355   with_time = (flags & JNLIB_LOG_WITH_TIME);
356   with_pid  = (flags & JNLIB_LOG_WITH_PID);
357   running_detached = (flags & JNLIB_LOG_RUN_DETACHED);
358 }
359
360
361 const char *
362 log_get_prefix (unsigned int *flags)
363 {
364   if (flags)
365     {
366       *flags = 0;
367       if (with_prefix)
368         *flags |= JNLIB_LOG_WITH_PREFIX;
369       if (with_time)
370         *flags |= JNLIB_LOG_WITH_TIME;
371       if (with_pid)
372         *flags |= JNLIB_LOG_WITH_PID;
373       if (running_detached)
374         *flags |= JNLIB_LOG_RUN_DETACHED;
375     }
376   return prefix_buffer;
377 }
378
379 /* This function returns true if the file descriptor FD is in use for
380    logging.  This is preferable over a test using log_get_fd in that
381    it allows the logging code to use more then one file descriptor.  */
382 int
383 log_test_fd (int fd)
384 {
385   if (logstream)
386     {
387       int tmp = es_fileno (logstream);
388       if ( tmp != -1 && tmp == fd)
389         return 1;
390     }
391   if (log_socket != -1 && log_socket == fd)
392     return 1;
393   return 0;
394 }
395
396 int
397 log_get_fd ()
398 {
399   return logstream? es_fileno(logstream) : -1;
400 }
401
402 estream_t
403 log_get_stream ()
404 {
405   if (!logstream)
406     {
407       log_set_file (NULL); /* Make sure a log stream has been set.  */
408       assert (logstream);
409     }
410   return logstream;
411 }
412
413 static void
414 do_logv (int level, int ignore_arg_ptr, const char *fmt, va_list arg_ptr)
415 {
416   if (!logstream)
417     {
418       log_set_file (NULL); /* Make sure a log stream has been set.  */
419       assert (logstream);
420     }
421
422   es_flockfile (logstream);
423   if (missing_lf && level != JNLIB_LOG_CONT)
424     es_putc_unlocked ('\n', logstream );
425   missing_lf = 0;
426
427   if (level != JNLIB_LOG_CONT)
428     { /* Note this does not work for multiple line logging as we would
429        * need to print to a buffer first */
430       if (with_time && !force_prefixes)
431         {
432           struct tm *tp;
433           time_t atime = time (NULL);
434           
435           tp = localtime (&atime);
436           es_fprintf_unlocked (logstream, "%04d-%02d-%02d %02d:%02d:%02d ",
437                                1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
438                                tp->tm_hour, tp->tm_min, tp->tm_sec );
439         }
440       if (with_prefix || force_prefixes)
441         es_fputs_unlocked (prefix_buffer, logstream);
442       if (with_pid || force_prefixes)
443         {
444           unsigned long pidsuf;
445           int pidfmt;
446
447           if (get_pid_suffix_cb && (pidfmt=get_pid_suffix_cb (&pidsuf)))
448             es_fprintf_unlocked (logstream, pidfmt == 1? "[%u.%lu]":"[%u.%lx]",
449                                  (unsigned int)getpid (), pidsuf);
450           else
451             es_fprintf_unlocked (logstream, "[%u]", (unsigned int)getpid ());
452         }
453       if (!with_time || force_prefixes)
454         es_putc_unlocked (':', logstream);
455       /* A leading backspace suppresses the extra space so that we can
456          correctly output, programname, filename and linenumber. */
457       if (fmt && *fmt == '\b')
458         fmt++;
459       else
460         es_putc_unlocked (' ', logstream);
461     }
462
463   switch (level)
464     {
465     case JNLIB_LOG_BEGIN: break;
466     case JNLIB_LOG_CONT: break;
467     case JNLIB_LOG_INFO: break;
468     case JNLIB_LOG_WARN: break;
469     case JNLIB_LOG_ERROR: break;
470     case JNLIB_LOG_FATAL: es_fputs_unlocked ("Fatal: ",logstream ); break;
471     case JNLIB_LOG_BUG:   es_fputs_unlocked ("Ohhhh jeeee: ", logstream); break;
472     case JNLIB_LOG_DEBUG: es_fputs_unlocked ("DBG: ", logstream ); break;
473     default: 
474       es_fprintf_unlocked (logstream,"[Unknown log level %d]: ", level);
475       break;
476     }
477
478   if (fmt)
479     {
480       if (ignore_arg_ptr)
481         es_fputs_unlocked (fmt, logstream);
482       else
483         es_vfprintf_unlocked (logstream, fmt, arg_ptr);
484       if (*fmt && fmt[strlen(fmt)-1] != '\n')
485         missing_lf = 1;
486     }
487
488   if (level == JNLIB_LOG_FATAL)
489     {
490       if (missing_lf)
491         es_putc_unlocked ('\n', logstream);
492       es_funlockfile (logstream);
493       exit (2);
494     }
495   else if (level == JNLIB_LOG_BUG)
496     {
497       if (missing_lf)
498         es_putc_unlocked ('\n', logstream );
499       es_funlockfile (logstream);
500       abort ();
501     }
502   else
503     es_funlockfile (logstream);
504 }
505
506
507 static void
508 do_log (int level, const char *fmt, ...)
509 {
510   va_list arg_ptr ;
511   
512   va_start (arg_ptr, fmt) ;
513   do_logv (level, 0, fmt, arg_ptr);
514   va_end (arg_ptr);
515 }
516
517
518 void
519 log_logv (int level, const char *fmt, va_list arg_ptr)
520 {
521   do_logv (level, 0, fmt, arg_ptr);
522 }
523
524
525 static void
526 do_log_ignore_arg (int level, const char *str, ...)
527 {
528   va_list arg_ptr;
529   va_start (arg_ptr, str);
530   do_logv (level, 1, str, arg_ptr);
531   va_end (arg_ptr);
532 }
533
534
535 void
536 log_string (int level, const char *string)
537 {
538   /* We need a dummy arg_ptr, but there is no portable way to create
539      one.  So we call the do_logv function through a variadic wrapper.
540      MB: Why not just use "%s"?  */
541   do_log_ignore_arg (level, string);
542 }
543
544
545 void
546 log_info (const char *fmt, ...)
547 {
548   va_list arg_ptr ;
549   
550   va_start (arg_ptr, fmt);
551   do_logv (JNLIB_LOG_INFO, 0, fmt, arg_ptr);
552   va_end (arg_ptr);
553 }
554
555
556 void
557 log_error (const char *fmt, ...)
558 {
559   va_list arg_ptr ;
560   
561   va_start (arg_ptr, fmt);
562   do_logv (JNLIB_LOG_ERROR, 0, fmt, arg_ptr);
563   va_end (arg_ptr);
564   /* Protect against counter overflow.  */
565   if (errorcount < 30000)
566     errorcount++;
567 }
568
569
570 void
571 log_fatal (const char *fmt, ...)
572 {
573   va_list arg_ptr ;
574   
575   va_start (arg_ptr, fmt);
576   do_logv (JNLIB_LOG_FATAL, 0, fmt, arg_ptr);
577   va_end (arg_ptr);
578   abort (); /* Never called; just to make the compiler happy.  */
579 }
580
581
582 void
583 log_bug (const char *fmt, ...)
584 {
585   va_list arg_ptr ;
586
587   va_start (arg_ptr, fmt);
588   do_logv (JNLIB_LOG_BUG, 0, fmt, arg_ptr);
589   va_end (arg_ptr);
590   abort (); /* Never called; just to make the compiler happy.  */
591 }
592
593
594 void
595 log_debug (const char *fmt, ...)
596 {
597   va_list arg_ptr ;
598   
599   va_start (arg_ptr, fmt);
600   do_logv (JNLIB_LOG_DEBUG, 0, fmt, arg_ptr);
601   va_end (arg_ptr);
602 }
603
604
605 void
606 log_printf (const char *fmt, ...)
607 {
608   va_list arg_ptr;
609   
610   va_start (arg_ptr, fmt);
611   do_logv (fmt ? JNLIB_LOG_CONT : JNLIB_LOG_BEGIN, 0, fmt, arg_ptr);
612   va_end (arg_ptr);
613 }
614
615
616 /* Flush the log - this is useful to make sure that the trailing
617    linefeed has been printed.  */
618 void
619 log_flush (void)
620 {
621   do_log_ignore_arg (JNLIB_LOG_CONT, NULL);
622 }
623
624
625 /* Print a hexdump of BUFFER.  With TEXT of NULL print just the raw
626    dump, with TEXT just an empty string, print a trailing linefeed,
627    otherwise print an entire debug line. */
628 void
629 log_printhex (const char *text, const void *buffer, size_t length)
630 {
631   if (text && *text)
632     log_debug ("%s ", text);
633   if (length)
634     {
635       const unsigned char *p = buffer;
636       log_printf ("%02X", *p);
637       for (length--, p++; length--; p++)
638         log_printf (" %02X", *p);
639     }
640   if (text)
641     log_printf ("\n");
642 }
643
644
645 #if __GNUC__ > 2 || (__GNUC__ == 2 && __GNUC_MINOR__ >= 5 )
646 void
647 bug_at( const char *file, int line, const char *func )
648 {
649   do_log (JNLIB_LOG_BUG, ("... this is a bug (%s:%d:%s)\n"), file, line, func);
650   abort (); /* Never called; just to make the compiler happy.  */
651 }
652 #else
653 void
654 bug_at( const char *file, int line )
655 {
656   do_log (JNLIB_LOG_BUG, _("you found a bug ... (%s:%d)\n"), file, line);
657   abort (); /* Never called; just to make the compiler happy.  */
658 }
659 #endif
660