Changeset fed0d5d2bff89cbba5ece81f815d8e9a51fd8560

Show
Ignore:
Timestamp:
07/30/10 15:47:19 (3 years ago)
Author:
Theo Schlossnagle <jesus@omniti.com>
git-committer:
Theo Schlossnagle <jesus@omniti.com> 1280504839 +0000
git-parent:

[15d06bff275aeaf7ede0668111821c63343ffac0]

git-author:
Theo Schlossnagle <jesus@omniti.com> 1280504839 +0000
Message:

much better support for timestamps and debugging information, refs #87

Files:

Legend:

Unmodified
Added
Removed
Modified
Copied
Moved

  • src/noit_conf.c

    r44fa704 rfed0d5d  
    878878    char name[256], type[256], path[256]; 
    879879    noit_hash_table *config; 
    880     noit_boolean disabled; 
    881     noit_boolean debug; 
     880    noit_boolean disabled, debug, timestamps; 
    882881 
    883882    if(!noit_conf_get_stringbuf(log_configs[i], 
    …… 
    915914                             &debug) && debug) 
    916915      ls->debug = 1; 
     916       
     917    if(noit_conf_get_boolean(log_configs[i], 
     918                             "ancestor-or-self::node()/@timestamps", 
     919                             &timestamps) && timestamps) 
     920      ls->timestamps = 1; 
    917921       
    918922    outlets = noit_conf_get_sections(log_configs[i], 

  • src/noit_console.c

    rff59a23 rfed0d5d  
    513513  noit_console_logio_reopen, 
    514514  noit_console_logio_write, 
     515  NULL, 
    515516  noit_console_logio_close, 
     517  NULL, 
    516518  NULL 
    517519}; 

  • src/noit_livestream_listener.c

    r5bb306c rfed0d5d  
    133133  noit_livestream_logio_reopen, 
    134134  noit_livestream_logio_write, 
     135  NULL, 
    135136  noit_livestream_logio_close, 
     137  NULL, 
    136138  NULL 
    137139}; 

  • src/utils/noit_log.c

    r48a51fb rfed0d5d  
    3737#include <fcntl.h> 
    3838#include <unistd.h> 
     39#include <sys/uio.h> 
    3940#include <sys/time.h> 
    4041#include <assert.h> 
    …… 
    7374  unsigned enabled:1; 
    7475  unsigned debug:1; 
     76  unsigned timestamps:1; 
    7577  /* Above is exposed... */ 
    7678  char *type; 
    …… 
    8385  struct _noit_log_stream_outlet_list *outlets; 
    8486  pthread_rwlock_t *lock; 
     87  unsigned deps_materialized:1; 
     88  unsigned debug_below:1; 
     89  unsigned timestamps_below:1; 
    8590}; 
    8691 
    …… 
    95100} 
    96101 
     102#define MATERIALIZE_DEPS(ls) do { \ 
     103  if(!(ls)->deps_materialized) materialize_deps(ls); \ 
     104} while(0) 
     105 
     106static void materialize_deps(noit_log_stream_t ls) { 
     107  if(ls->deps_materialized) return; 
     108  if(ls->debug) ls->debug_below = 1; 
     109  if(ls->timestamps) ls->timestamps_below = 1; 
     110  if(ls->debug_below == 0 || ls->timestamps_below == 0) { 
     111    /* we might have children than need these */ 
     112    struct _noit_log_stream_outlet_list *node; 
     113    for(node = ls->outlets; node; node = node->next) { 
     114      MATERIALIZE_DEPS(node->outlet); 
     115      if(!ls->debug) ls->debug_below = node->outlet->debug; 
     116      if(!ls->timestamps) ls->timestamps_below = node->outlet->timestamps; 
     117    } 
     118  } 
     119  ls->deps_materialized = 1; 
     120} 
    97121static int 
    98122posix_logio_open(noit_log_stream_t ls) { 
    …… 
    111135posix_logio_reopen(noit_log_stream_t ls) { 
    112136  if(ls->path) { 
    113     int newfd, oldfd; 
     137    int newfd, oldfd, rv = -1; 
     138    if(ls->lock) pthread_rwlock_wrlock(ls->lock); 
    114139    oldfd = (int)(vpsized_int)ls->op_ctx; 
    115140    newfd = open(ls->path, O_CREAT|O_WRONLY|O_APPEND, ls->mode); 
    …… 
    117142      ls->op_ctx = (void *)(vpsized_int)newfd; 
    118143      if(oldfd >= 0) close(oldfd); 
    119       return 0; 
    120     } 
     144      rv = 0; 
     145    } 
     146    if(ls->lock) pthread_rwlock_unlock(ls->lock); 
     147    return rv; 
    121148  } 
    122149  return -1; 
    …… 
    124151static int 
    125152posix_logio_write(noit_log_stream_t ls, const void *buf, size_t len) { 
    126   int fd; 
     153  int fd, rv = -1; 
     154  if(ls->lock) pthread_rwlock_rdlock(ls->lock); 
    127155  fd = (int)(vpsized_int)ls->op_ctx; 
    128156  debug_printf("writing to %d\n", fd); 
    129   if(fd < 0) return -1; 
    130   return write(fd, buf, len); 
     157  if(fd >= 0) rv = write(fd, buf, len); 
     158  if(ls->lock) pthread_rwlock_unlock(ls->lock); 
     159  return rv; 
     160} 
     161static int 
     162posix_logio_writev(noit_log_stream_t ls, const struct iovec *iov, int iovcnt) { 
     163  int fd, rv = -1; 
     164  if(ls->lock) pthread_rwlock_rdlock(ls->lock); 
     165  fd = (int)(vpsized_int)ls->op_ctx; 
     166  debug_printf("writ(v)ing to %d\n", fd); 
     167  if(fd >= 0) rv = writev(fd, iov, iovcnt); 
     168  if(ls->lock) pthread_rwlock_unlock(ls->lock); 
     169  return rv; 
    131170} 
    132171static int 
    133172posix_logio_close(noit_log_stream_t ls) { 
    134   int fd; 
     173  int fd, rv; 
     174  if(ls->lock) pthread_rwlock_wrlock(ls->lock); 
    135175  fd = (int)(vpsized_int)ls->op_ctx; 
    136   return close(fd); 
     176  rv = close(fd); 
     177  if(ls->lock) pthread_rwlock_unlock(ls->lock); 
     178  return rv; 
    137179} 
    138180static size_t 
    139181posix_logio_size(noit_log_stream_t ls) { 
    140182  int fd; 
     183  size_t s = -1; 
    141184  struct stat sb; 
     185  if(ls->lock) pthread_rwlock_rdlock(ls->lock); 
    142186  fd = (int)(vpsized_int)ls->op_ctx; 
    143187  if(fstat(fd, &sb) == 0) { 
    144     return (size_t)sb.st_size; 
    145   } 
     188    s = (size_t)sb.st_size; 
     189  } 
     190  if(ls->lock) pthread_rwlock_unlock(ls->lock); 
     191  return s; 
     192} 
     193static int 
     194posix_logio_rename(noit_log_stream_t ls, const char *name) { 
     195  int rv = 0; 
     196  if(!strcmp(name, ls->path)) return 0; /* noop */ 
     197  if(ls->lock) pthread_rwlock_rdlock(ls->lock); 
     198  rv = rename(ls->path, name); 
     199  if(ls->lock) pthread_rwlock_unlock(ls->lock); 
    146200  return -1; 
    147201} 
    …… 
    150204  posix_logio_reopen, 
    151205  posix_logio_write, 
     206  posix_logio_writev, 
    152207  posix_logio_close, 
    153   posix_logio_size 
     208  posix_logio_size, 
     209  posix_logio_rename 
    154210}; 
    155211 
    …… 
    329385  return size; 
    330386} 
     387static int 
     388jlog_logio_rename(noit_log_stream_t ls, const char *newname) { 
     389  /* Not supported (and makes no sense) */ 
     390  return -1; 
     391} 
    331392static logops_t jlog_logio_ops = { 
    332393  jlog_logio_open, 
    333394  jlog_logio_reopen, 
    334395  jlog_logio_write, 
     396  NULL, 
    335397  jlog_logio_close, 
    336   jlog_logio_size 
     398  jlog_logio_size, 
     399  jlog_logio_rename 
    337400}; 
    338401 
    …… 
    344407  noit_register_logops("jlog", &jlog_logio_ops); 
    345408  noit_stderr = noit_log_stream_new_on_fd("stderr", 2, NULL); 
     409  noit_stderr->timestamps = 1; 
    346410  noit_error = noit_log_stream_new("error", NULL, NULL, NULL, NULL); 
    347411  noit_debug = noit_log_stream_new("debug", NULL, NULL, NULL, NULL); 
    …… 
    522586} 
    523587 
     588int noit_log_stream_rename(noit_log_stream_t ls, const char *newname) { 
     589  return (ls->ops && ls->ops->renameop) ? ls->ops->renameop(ls, newname) : -1; 
     590} 
     591 
    524592void 
    525593noit_log_stream_close(noit_log_stream_t ls) { 
    …… 
    557625 
    558626static int 
    559 noit_log_line(noit_log_stream_t ls, char *buffer, size_t len) { 
     627noit_log_writev(noit_log_stream_t ls, const struct iovec *iov, int iovcnt) { 
     628  /* This emulates writev into a buffer for ops that don't support it */ 
     629  char stackbuff[4096], *tofree = NULL, *buff = NULL; 
     630  int i, s = 0, ins = 0; 
     631 
     632  if(!ls->ops) return -1; 
     633  if(ls->ops->writevop) return ls->ops->writevop(ls, iov, iovcnt); 
     634  if(!ls->ops->writeop) return -1; 
     635  if(iovcnt == 1) return ls->ops->writeop(ls, iov[0].iov_base, iov[0].iov_len); 
     636 
     637  for(i=0;i<iovcnt;i++) s+=iov[i].iov_len; 
     638  if(s > sizeof(stackbuff)) { 
     639    tofree = buff = malloc(s); 
     640    if(tofree == NULL) return -1; 
     641  } 
     642  else buff = stackbuff; 
     643  for(i=0;i<iovcnt;i++) { 
     644    memcpy(buff + ins, iov[i].iov_base, iov[i].iov_len); 
     645    ins += iov[i].iov_len; 
     646  } 
     647  i = ls->ops->writeop(ls, buff, s); 
     648  if(tofree) free(tofree); 
     649  return i; 
     650} 
     651 
     652static int 
     653noit_log_line(noit_log_stream_t ls, 
     654              const char *timebuf, int timebuflen, 
     655              const char *debugbuf, int debugbuflen, 
     656              const char *buffer, size_t len) { 
    560657  int rv = 0; 
    561658  struct _noit_log_stream_outlet_list *node; 
    562   if(ls->ops) 
    563     rv = ls->ops->writeop(ls, buffer, len); /* Not much one can do about errors */ 
     659  if(ls->ops) { 
     660    int iovcnt = 0; 
     661    struct iovec iov[3]; 
     662    if(ls->timestamps) { 
     663      iov[iovcnt].iov_base = (void *)timebuf; 
     664      iov[iovcnt].iov_len = timebuflen; 
     665      iovcnt++; 
     666    } 
     667    if(ls->debug) { 
     668      iov[iovcnt].iov_base = (void *)debugbuf; 
     669      iov[iovcnt].iov_len = debugbuflen; 
     670      iovcnt++; 
     671    } 
     672    iov[iovcnt].iov_base = (void *)buffer; 
     673    iov[iovcnt].iov_len = len; 
     674    iovcnt++; 
     675    rv = noit_log_writev(ls, iov, iovcnt); 
     676  } 
    564677  for(node = ls->outlets; node; node = node->next) { 
    565678    int srv = 0; 
    566679    debug_printf(" %s -> %s\n", ls->name, node->outlet->name); 
    567     srv = noit_log_line(node->outlet, buffer, len); 
     680    srv = noit_log_line(node->outlet, timebuf, timebuflen, debugbuf, debugbuflen, buffer, len); 
    568681    if(srv) rv = srv; 
    569682  } 
    …… 
    576689  int rv = 0, allocd = 0; 
    577690  char buffer[4096], *dynbuff = NULL; 
    578   char fbuf[1024]; 
    579691#ifdef va_copy 
    580692  va_list copy; 
    …… 
    583695  if(ls->enabled || NOIT_LOG_LOG_ENABLED()) { 
    584696    int len; 
    585     if(ls->debug) { 
     697    char tbuf[48], dbuf[80]; 
     698    int tbuflen = 0, dbuflen = 0; 
     699    MATERIALIZE_DEPS(ls); 
     700    if(ls->timestamps_below) { 
    586701      struct tm _tm, *tm; 
    587       char tbuf[32]; 
     702      char tempbuf[32]; 
    588703      time_t s = (time_t)now->tv_sec; 
    589704      tm = localtime_r(&s, &_tm); 
    590       strftime(tbuf, sizeof(tbuf), "%Y-%m-%d %H:%M:%S", tm); 
    591       snprintf(fbuf, sizeof(fbuf), "[%s.%06d %s:%d] %s", 
    592                tbuf, (int)now->tv_usec, file, line, format); 
    593       format = fbuf; 
    594     } 
     705      strftime(tempbuf, sizeof(tempbuf), "%Y-%m-%d %H:%M:%S", tm); 
     706      snprintf(tbuf, sizeof(tbuf), "[%s.%06d] ", tempbuf, (int)now->tv_usec); 
     707      tbuflen = strlen(tbuf); 
     708    } 
     709    else tbuf[0] = '\0'; 
     710    if(ls->debug_below) { 
     711      snprintf(dbuf, sizeof(dbuf), "[%s:%d] ", file, line); 
     712      dbuflen = strlen(dbuf); 
     713    } 
     714    else dbuf[0] = '\0'; 
    595715#ifdef va_copy 
    596716    va_copy(copy, arg); 
    …… 
    617737      NOIT_LOG_LOG(ls->name, (char *)file, line, dynbuff); 
    618738      if(ls->enabled) 
    619         rv = noit_log_line(ls, dynbuff, len); 
     739        rv = noit_log_line(ls, tbuf, tbuflen, dbuf, dbuflen, dynbuff, len); 
    620740      free(dynbuff); 
    621741    } 
    …… 
    623743      NOIT_LOG_LOG(ls->name, (char *)file, line, buffer); 
    624744      if(ls->enabled) 
    625         rv = noit_log_line(ls, buffer, len); 
     745        rv = noit_log_line(ls, tbuf, tbuflen, dbuf, dbuflen, buffer, len); 
    626746    } 
    627747    if(rv == len) return 0; 

  • src/utils/noit_log.h

    r3f527b7 rfed0d5d  
    3737#include <pthread.h> 
    3838#include <stdarg.h> 
     39#include <sys/uio.h> 
    3940#include <sys/time.h> 
    4041#include "utils/noit_hash.h" 
    …… 
    4950  int (*reopenop)(struct _noit_log_stream *); 
    5051  int (*writeop)(struct _noit_log_stream *, const void *, size_t); 
     52  int (*writevop)(struct _noit_log_stream *, const struct iovec *iov, int iovcnt); 
    5153  int (*closeop)(struct _noit_log_stream *); 
    5254  size_t (*sizeop)(struct _noit_log_stream *); 
     55  int (*renameop)(struct _noit_log_stream *, const char *); 
    5356} logops_t; 
    5457 
    …… 
    5962  unsigned enabled:1; 
    6063  unsigned debug:1; 
     64  unsigned timestamps:1; 
    6165  /* totally private type, don't even think about it */ 
    6266} * noit_log_stream_t; 
    …… 
    9296                                               const char *name); 
    9397API_EXPORT(void) noit_log_stream_reopen(noit_log_stream_t ls); 
     98API_EXPORT(int) noit_log_stream_rename(noit_log_stream_t ls, const char *); 
    9499API_EXPORT(void) noit_log_stream_close(noit_log_stream_t ls); 
    95100API_EXPORT(size_t) noit_log_stream_size(noit_log_stream_t ls);