jnlib/logging.c

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