More chnages to use estream. Add a way to replace the standard
[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 unsigned long (*get_tid_callback)(void);
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_get_tid_callback (unsigned long (*cb)(void))
340 {
341   get_tid_callback = 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   assert (logstream);
406   return logstream;
407 }
408
409 static void
410 do_logv (int level, int ignore_arg_ptr, const char *fmt, va_list arg_ptr)
411 {
412   if (!logstream)
413     {
414       log_set_file (NULL); /* Make sure a log stream has been set.  */
415       assert (logstream);
416     }
417
418   es_flockfile (logstream);
419   if (missing_lf && level != JNLIB_LOG_CONT)
420     es_putc_unlocked ('\n', logstream );
421   missing_lf = 0;
422
423   if (level != JNLIB_LOG_CONT)
424     { /* Note this does not work for multiple line logging as we would
425        * need to print to a buffer first */
426       if (with_time && !force_prefixes)
427         {
428           struct tm *tp;
429           time_t atime = time (NULL);
430           
431           tp = localtime (&atime);
432           es_fprintf_unlocked (logstream, "%04d-%02d-%02d %02d:%02d:%02d ",
433                                1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
434                                tp->tm_hour, tp->tm_min, tp->tm_sec );
435         }
436       if (with_prefix || force_prefixes)
437         es_fputs_unlocked (prefix_buffer, logstream);
438       if (with_pid || force_prefixes)
439         {
440           if (get_tid_callback)
441             es_fprintf_unlocked (logstream, "[%u.%lx]", 
442                         (unsigned int)getpid (), get_tid_callback ());
443           else
444             es_fprintf_unlocked (logstream, "[%u]", (unsigned int)getpid ());
445         }
446       if (!with_time || force_prefixes)
447         es_putc_unlocked (':', logstream);
448       /* A leading backspace suppresses the extra space so that we can
449          correctly output, programname, filename and linenumber. */
450       if (fmt && *fmt == '\b')
451         fmt++;
452       else
453         es_putc_unlocked (' ', logstream);
454     }
455
456   switch (level)
457     {
458     case JNLIB_LOG_BEGIN: break;
459     case JNLIB_LOG_CONT: break;
460     case JNLIB_LOG_INFO: break;
461     case JNLIB_LOG_WARN: break;
462     case JNLIB_LOG_ERROR: break;
463     case JNLIB_LOG_FATAL: es_fputs_unlocked ("Fatal: ",logstream ); break;
464     case JNLIB_LOG_BUG:   es_fputs_unlocked ("Ohhhh jeeee: ", logstream); break;
465     case JNLIB_LOG_DEBUG: es_fputs_unlocked ("DBG: ", logstream ); break;
466     default: 
467       es_fprintf_unlocked (logstream,"[Unknown log level %d]: ", level);
468       break;
469     }
470
471   if (fmt)
472     {
473       if (ignore_arg_ptr)
474         es_fputs_unlocked (fmt, logstream);
475       else
476         es_vfprintf_unlocked (logstream, fmt, arg_ptr);
477       if (*fmt && fmt[strlen(fmt)-1] != '\n')
478         missing_lf = 1;
479     }
480
481   if (level == JNLIB_LOG_FATAL)
482     {
483       if (missing_lf)
484         es_putc_unlocked ('\n', logstream);
485       es_funlockfile (logstream);
486       exit (2);
487     }
488   else if (level == JNLIB_LOG_BUG)
489     {
490       if (missing_lf)
491         es_putc_unlocked ('\n', logstream );
492       es_funlockfile (logstream);
493       abort ();
494     }
495   else
496     es_funlockfile (logstream);
497 }
498
499
500 static void
501 do_log (int level, const char *fmt, ...)
502 {
503   va_list arg_ptr ;
504   
505   va_start (arg_ptr, fmt) ;
506   do_logv (level, 0, fmt, arg_ptr);
507   va_end (arg_ptr);
508 }
509
510
511 void
512 log_logv (int level, const char *fmt, va_list arg_ptr)
513 {
514   do_logv (level, 0, fmt, arg_ptr);
515 }
516
517
518 void
519 log_string (int level, const char *string)
520 {
521   /* We need to provide a dummy arg_ptr.  volatile is needed to
522      suppress compiler warnings.  The static is required for gcc 4.4
523      because it seems that it detects that a volatile automatic
524      variable is not any good if not initialized.  */
525   static volatile va_list dummy_arg_ptr;
526
527   do_logv (level, 1, string, dummy_arg_ptr);
528 }
529
530
531 void
532 log_info (const char *fmt, ...)
533 {
534   va_list arg_ptr ;
535   
536   va_start (arg_ptr, fmt);
537   do_logv (JNLIB_LOG_INFO, 0, fmt, arg_ptr);
538   va_end (arg_ptr);
539 }
540
541
542 void
543 log_error (const char *fmt, ...)
544 {
545   va_list arg_ptr ;
546   
547   va_start (arg_ptr, fmt);
548   do_logv (JNLIB_LOG_ERROR, 0, fmt, arg_ptr);
549   va_end (arg_ptr);
550   /* Protect against counter overflow.  */
551   if (errorcount < 30000)
552     errorcount++;
553 }
554
555
556 void
557 log_fatal (const char *fmt, ...)
558 {
559   va_list arg_ptr ;
560   
561   va_start (arg_ptr, fmt);
562   do_logv (JNLIB_LOG_FATAL, 0, fmt, arg_ptr);
563   va_end (arg_ptr);
564   abort (); /* Never called; just to make the compiler happy.  */
565 }
566
567
568 void
569 log_bug (const char *fmt, ...)
570 {
571   va_list arg_ptr ;
572
573   va_start (arg_ptr, fmt);
574   do_logv (JNLIB_LOG_BUG, 0, fmt, arg_ptr);
575   va_end (arg_ptr);
576   abort (); /* Never called; just to make the compiler happy.  */
577 }
578
579
580 void
581 log_debug (const char *fmt, ...)
582 {
583   va_list arg_ptr ;
584   
585   va_start (arg_ptr, fmt);
586   do_logv (JNLIB_LOG_DEBUG, 0, fmt, arg_ptr);
587   va_end (arg_ptr);
588 }
589
590
591 void
592 log_printf (const char *fmt, ...)
593 {
594   va_list arg_ptr;
595   
596   va_start (arg_ptr, fmt);
597   do_logv (fmt ? JNLIB_LOG_CONT : JNLIB_LOG_BEGIN, 0, fmt, arg_ptr);
598   va_end (arg_ptr);
599 }
600
601
602 /* Flush the log - this is useful to make sure that the trailing
603    linefeed has been printed.  */
604 void
605 log_flush (void)
606 {
607   static volatile va_list dummy_arg_ptr;
608   do_logv (JNLIB_LOG_CONT, 1, NULL, dummy_arg_ptr);
609 }
610
611
612 /* Print a hexdump of BUFFER.  With TEXT of NULL print just the raw
613    dump, with TEXT just an empty string, print a trailing linefeed,
614    otherwise print an entire debug line. */
615 void
616 log_printhex (const char *text, const void *buffer, size_t length)
617 {
618   if (text && *text)
619     log_debug ("%s ", text);
620   if (length)
621     {
622       const unsigned char *p = buffer;
623       log_printf ("%02X", *p);
624       for (length--, p++; length--; p++)
625         log_printf (" %02X", *p);
626     }
627   if (text)
628     log_printf ("\n");
629 }
630
631
632 #if __GNUC__ > 2 || (__GNUC__ == 2 && __GNUC_MINOR__ >= 5 )
633 void
634 bug_at( const char *file, int line, const char *func )
635 {
636   do_log (JNLIB_LOG_BUG, ("... this is a bug (%s:%d:%s)\n"), file, line, func);
637   abort (); /* Never called; just to make the compiler happy.  */
638 }
639 #else
640 void
641 bug_at( const char *file, int line )
642 {
643   do_log (JNLIB_LOG_BUG, _("you found a bug ... (%s:%d)\n"), file, line);
644   abort (); /* Never called; just to make the compiler happy.  */
645 }
646 #endif
647