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