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