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