File:  [ELWIX - Embedded LightWeight unIX -] / embedaddon / dnsmasq / src / log.c
Revision 1.1.1.1 (vendor branch): download - view: text, annotated - select for diffs - revision graph
Mon Jul 29 19:37:40 2013 UTC (10 years, 11 months ago) by misho
Branches: elwix, dnsmasq, MAIN
CVS tags: v2_66p0, v2_66, HEAD
dnsmasq

    1: /* dnsmasq is Copyright (c) 2000-2013 Simon Kelley
    2: 
    3:    This program is free software; you can redistribute it and/or modify
    4:    it under the terms of the GNU General Public License as published by
    5:    the Free Software Foundation; version 2 dated June, 1991, or
    6:    (at your option) version 3 dated 29 June, 2007.
    7:  
    8:    This program is distributed in the hope that it will be useful,
    9:    but WITHOUT ANY WARRANTY; without even the implied warranty of
   10:    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
   11:    GNU General Public License for more details.
   12:      
   13:    You should have received a copy of the GNU General Public License
   14:    along with this program.  If not, see <http://www.gnu.org/licenses/>.
   15: */
   16: 
   17: #include "dnsmasq.h"
   18: 
   19: #ifdef __ANDROID__
   20: #  include <android/log.h>
   21: #endif
   22: 
   23: /* Implement logging to /dev/log asynchronously. If syslogd is 
   24:    making DNS lookups through dnsmasq, and dnsmasq blocks awaiting
   25:    syslogd, then the two daemons can deadlock. We get around this
   26:    by not blocking when talking to syslog, instead we queue up to 
   27:    MAX_LOGS messages. If more are queued, they will be dropped,
   28:    and the drop event itself logged. */
   29: 
   30: /* The "wire" protocol for logging is defined in RFC 3164 */
   31: 
   32: /* From RFC 3164 */
   33: #define MAX_MESSAGE 1024
   34: 
   35: /* defaults in case we die() before we log_start() */
   36: static int log_fac = LOG_DAEMON;
   37: static int log_stderr = 0;
   38: static int echo_stderr = 0;
   39: static int log_fd = -1;
   40: static int log_to_file = 0;
   41: static int entries_alloced = 0;
   42: static int entries_lost = 0;
   43: static int connection_good = 1;
   44: static int max_logs = 0;
   45: static int connection_type = SOCK_DGRAM;
   46: 
   47: struct log_entry {
   48:   int offset, length;
   49:   pid_t pid; /* to avoid duplicates over a fork */
   50:   struct log_entry *next;
   51:   char payload[MAX_MESSAGE];
   52: };
   53: 
   54: static struct log_entry *entries = NULL;
   55: static struct log_entry *free_entries = NULL;
   56: 
   57: 
   58: int log_start(struct passwd *ent_pw, int errfd)
   59: {
   60:   int ret = 0;
   61: 
   62:   echo_stderr = option_bool(OPT_DEBUG);
   63: 
   64:   if (daemon->log_fac != -1)
   65:     log_fac = daemon->log_fac;
   66: #ifdef LOG_LOCAL0
   67:   else if (option_bool(OPT_DEBUG))
   68:     log_fac = LOG_LOCAL0;
   69: #endif
   70: 
   71:   if (daemon->log_file)
   72:     { 
   73:       log_to_file = 1;
   74:       daemon->max_logs = 0;
   75:       if (strcmp(daemon->log_file, "-") == 0)
   76: 	{
   77: 	  log_stderr = 1;
   78: 	  echo_stderr = 0;
   79: 	  log_fd = dup(STDERR_FILENO);
   80: 	}
   81:     }
   82:   
   83:   max_logs = daemon->max_logs;
   84: 
   85:   if (!log_reopen(daemon->log_file))
   86:     {
   87:       send_event(errfd, EVENT_LOG_ERR, errno, daemon->log_file ? daemon->log_file : "");
   88:       _exit(0);
   89:     }
   90: 
   91:   /* if queuing is inhibited, make sure we allocate
   92:      the one required buffer now. */
   93:   if (max_logs == 0)
   94:     {  
   95:       free_entries = safe_malloc(sizeof(struct log_entry));
   96:       free_entries->next = NULL;
   97:       entries_alloced = 1;
   98:     }
   99: 
  100:   /* If we're running as root and going to change uid later,
  101:      change the ownership here so that the file is always owned by
  102:      the dnsmasq user. Then logrotate can just copy the owner.
  103:      Failure of the chown call is OK, (for instance when started as non-root) */
  104:   if (log_to_file && !log_stderr && ent_pw && ent_pw->pw_uid != 0 && 
  105:       fchown(log_fd, ent_pw->pw_uid, -1) != 0)
  106:     ret = errno;
  107: 
  108:   return ret;
  109: }
  110: 
  111: int log_reopen(char *log_file)
  112: {
  113:   if (!log_stderr)
  114:     {      
  115:       if (log_fd != -1)
  116: 	close(log_fd);
  117:       
  118:       /* NOTE: umask is set to 022 by the time this gets called */
  119:       
  120:       if (log_file)
  121: 	log_fd = open(log_file, O_WRONLY|O_CREAT|O_APPEND, S_IRUSR|S_IWUSR|S_IRGRP);      
  122:       else
  123: 	{
  124: #if defined(HAVE_SOLARIS_NETWORK) || defined(__ANDROID__)
  125: 	  /* Solaris logging is "different", /dev/log is not unix-domain socket.
  126: 	     Just leave log_fd == -1 and use the vsyslog call for everything.... */
  127: #   define _PATH_LOG ""  /* dummy */
  128: 	  return 1;
  129: #else
  130: 	  int flags;
  131: 	  log_fd = socket(AF_UNIX, connection_type, 0);
  132: 	  
  133: 	  /* if max_logs is zero, leave the socket blocking */
  134: 	  if (log_fd != -1 && max_logs != 0 && (flags = fcntl(log_fd, F_GETFL)) != -1)
  135: 	    fcntl(log_fd, F_SETFL, flags | O_NONBLOCK);
  136: #endif
  137: 	}
  138:     }
  139:   
  140:   return log_fd != -1;
  141: }
  142: 
  143: static void free_entry(void)
  144: {
  145:   struct log_entry *tmp = entries;
  146:   entries = tmp->next;
  147:   tmp->next = free_entries;
  148:   free_entries = tmp;
  149: }      
  150: 
  151: static void log_write(void)
  152: {
  153:   ssize_t rc;
  154:    
  155:   while (entries)
  156:     {
  157:       /* The data in the payoad is written with a terminating zero character 
  158: 	 and the length reflects this. For a stream connection we need to 
  159: 	 send the zero as a record terminator, but this isn't done for a 
  160: 	 datagram connection, so treat the length as one less than reality 
  161: 	 to elide the zero. If we're logging to a file, turn the zero into 
  162: 	 a newline, and leave the length alone. */
  163:       int len_adjust = 0;
  164: 
  165:       if (log_to_file)
  166: 	entries->payload[entries->offset + entries->length - 1] = '\n';
  167:       else if (connection_type == SOCK_DGRAM)
  168: 	len_adjust = 1;
  169: 
  170:       /* Avoid duplicates over a fork() */
  171:       if (entries->pid != getpid())
  172: 	{
  173: 	  free_entry();
  174: 	  continue;
  175: 	}
  176: 
  177:       connection_good = 1;
  178: 
  179:       if ((rc = write(log_fd, entries->payload + entries->offset, entries->length - len_adjust)) != -1)
  180: 	{
  181: 	  entries->length -= rc;
  182: 	  entries->offset += rc;
  183: 	  if (entries->length == len_adjust)
  184: 	    {
  185: 	      free_entry();
  186: 	      if (entries_lost != 0)
  187: 		{
  188: 		  int e = entries_lost;
  189: 		  entries_lost = 0; /* avoid wild recursion */
  190: 		  my_syslog(LOG_WARNING, _("overflow: %d log entries lost"), e);
  191: 		}	  
  192: 	    }
  193: 	  continue;
  194: 	}
  195:       
  196:       if (errno == EINTR)
  197: 	continue;
  198: 
  199:       if (errno == EAGAIN || errno == EWOULDBLOCK)
  200: 	return; /* syslogd busy, go again when select() or poll() says so */
  201:       
  202:       if (errno == ENOBUFS)
  203: 	{
  204: 	  connection_good = 0;
  205: 	  return;
  206: 	}
  207: 
  208:       /* errors handling after this assumes sockets */ 
  209:       if (!log_to_file)
  210: 	{
  211: 	  /* Once a stream socket hits EPIPE, we have to close and re-open
  212: 	     (we ignore SIGPIPE) */
  213: 	  if (errno == EPIPE)
  214: 	    {
  215: 	      if (log_reopen(NULL))
  216: 		continue;
  217: 	    }
  218: 	  else if (errno == ECONNREFUSED || 
  219: 		   errno == ENOTCONN || 
  220: 		   errno == EDESTADDRREQ || 
  221: 		   errno == ECONNRESET)
  222: 	    {
  223: 	      /* socket went (syslogd down?), try and reconnect. If we fail,
  224: 		 stop trying until the next call to my_syslog() 
  225: 		 ECONNREFUSED -> connection went down
  226: 		 ENOTCONN -> nobody listening
  227: 		 (ECONNRESET, EDESTADDRREQ are *BSD equivalents) */
  228: 	      
  229: 	      struct sockaddr_un logaddr;
  230: 	      
  231: #ifdef HAVE_SOCKADDR_SA_LEN
  232: 	      logaddr.sun_len = sizeof(logaddr) - sizeof(logaddr.sun_path) + strlen(_PATH_LOG) + 1; 
  233: #endif
  234: 	      logaddr.sun_family = AF_UNIX;
  235: 	      strncpy(logaddr.sun_path, _PATH_LOG, sizeof(logaddr.sun_path));
  236: 	      
  237: 	      /* Got connection back? try again. */
  238: 	      if (connect(log_fd, (struct sockaddr *)&logaddr, sizeof(logaddr)) != -1)
  239: 		continue;
  240: 	      
  241: 	      /* errors from connect which mean we should keep trying */
  242: 	      if (errno == ENOENT || 
  243: 		  errno == EALREADY || 
  244: 		  errno == ECONNREFUSED ||
  245: 		  errno == EISCONN || 
  246: 		  errno == EINTR ||
  247: 		  errno == EAGAIN || 
  248: 		  errno == EWOULDBLOCK)
  249: 		{
  250: 		  /* try again on next syslog() call */
  251: 		  connection_good = 0;
  252: 		  return;
  253: 		}
  254: 	      
  255: 	      /* try the other sort of socket... */
  256: 	      if (errno == EPROTOTYPE)
  257: 		{
  258: 		  connection_type = connection_type == SOCK_DGRAM ? SOCK_STREAM : SOCK_DGRAM;
  259: 		  if (log_reopen(NULL))
  260: 		    continue;
  261: 		}
  262: 	    }
  263: 	}
  264: 
  265:       /* give up - fall back to syslog() - this handles out-of-space
  266: 	 when logging to a file, for instance. */
  267:       log_fd = -1;
  268:       my_syslog(LOG_CRIT, _("log failed: %s"), strerror(errno));
  269:       return;
  270:     }
  271: }
  272: 
  273: /* priority is one of LOG_DEBUG, LOG_INFO, LOG_NOTICE, etc. See sys/syslog.h.
  274:    OR'd to priority can be MS_TFTP, MS_DHCP, ... to be able to do log separation between
  275:    DNS, DHCP and TFTP services.
  276: */
  277: void my_syslog(int priority, const char *format, ...)
  278: {
  279:   va_list ap;
  280:   struct log_entry *entry;
  281:   time_t time_now;
  282:   char *p;
  283:   size_t len;
  284:   pid_t pid = getpid();
  285:   char *func = "";
  286: 
  287:   if ((LOG_FACMASK & priority) == MS_TFTP)
  288:     func = "-tftp";
  289:   else if ((LOG_FACMASK & priority) == MS_DHCP)
  290:     func = "-dhcp";
  291:       
  292: #ifdef LOG_PRI
  293:   priority = LOG_PRI(priority);
  294: #else
  295:   /* Solaris doesn't have LOG_PRI */
  296:   priority &= LOG_PRIMASK;
  297: #endif
  298: 
  299:   if (echo_stderr) 
  300:     {
  301:       fprintf(stderr, "dnsmasq%s: ", func);
  302:       va_start(ap, format);
  303:       vfprintf(stderr, format, ap);
  304:       va_end(ap);
  305:       fputc('\n', stderr);
  306:     }
  307: 
  308:   if (log_fd == -1)
  309:     {
  310: #ifdef __ANDROID__
  311:       /* do android-specific logging. 
  312: 	 log_fd is always -1 on Android except when logging to a file. */
  313:       int alog_lvl;
  314:       
  315:       if (priority <= LOG_ERR)
  316: 	alog_lvl = ANDROID_LOG_ERROR;
  317:       else if (priority == LOG_WARNING)
  318: 	alog_lvl = ANDROID_LOG_WARN;
  319:       else if (priority <= LOG_INFO)
  320: 	alog_lvl = ANDROID_LOG_INFO;
  321:       else
  322: 	alog_lvl = ANDROID_LOG_DEBUG;
  323: 
  324:       va_start(ap, format);
  325:       __android_log_vprint(alog_lvl, "dnsmasq", format, ap);
  326:       va_end(ap);
  327: #else
  328:       /* fall-back to syslog if we die during startup or 
  329: 	 fail during running (always on Solaris). */
  330:       static int isopen = 0;
  331: 
  332:       if (!isopen)
  333: 	{
  334: 	  openlog("dnsmasq", LOG_PID, log_fac);
  335: 	  isopen = 1;
  336: 	}
  337:       va_start(ap, format);  
  338:       vsyslog(priority, format, ap);
  339:       va_end(ap);
  340: #endif
  341: 
  342:       return;
  343:     }
  344:   
  345:   if ((entry = free_entries))
  346:     free_entries = entry->next;
  347:   else if (entries_alloced < max_logs && (entry = malloc(sizeof(struct log_entry))))
  348:     entries_alloced++;
  349:   
  350:   if (!entry)
  351:     entries_lost++;
  352:   else
  353:     {
  354:       /* add to end of list, consumed from the start */
  355:       entry->next = NULL;
  356:       if (!entries)
  357: 	entries = entry;
  358:       else
  359: 	{
  360: 	  struct log_entry *tmp;
  361: 	  for (tmp = entries; tmp->next; tmp = tmp->next);
  362: 	  tmp->next = entry;
  363: 	}
  364:       
  365:       time(&time_now);
  366:       p = entry->payload;
  367:       if (!log_to_file)
  368: 	p += sprintf(p, "<%d>", priority | log_fac);
  369: 
  370:       /* Omit timestamp for default daemontools situation */
  371:       if (!log_stderr || !option_bool(OPT_NO_FORK)) 
  372: 	p += sprintf(p, "%.15s ", ctime(&time_now) + 4);
  373:       
  374:       p += sprintf(p, "dnsmasq%s[%d]: ", func, (int)pid);
  375:         
  376:       len = p - entry->payload;
  377:       va_start(ap, format);  
  378:       len += vsnprintf(p, MAX_MESSAGE - len, format, ap) + 1; /* include zero-terminator */
  379:       va_end(ap);
  380:       entry->length = len > MAX_MESSAGE ? MAX_MESSAGE : len;
  381:       entry->offset = 0;
  382:       entry->pid = pid;
  383:     }
  384:   
  385:   /* almost always, logging won't block, so try and write this now,
  386:      to save collecting too many log messages during a select loop. */
  387:   log_write();
  388:   
  389:   /* Since we're doing things asynchronously, a cache-dump, for instance,
  390:      can now generate log lines very fast. With a small buffer (desirable),
  391:      that means it can overflow the log-buffer very quickly,
  392:      so that the cache dump becomes mainly a count of how many lines 
  393:      overflowed. To avoid this, we delay here, the delay is controlled 
  394:      by queue-occupancy, and grows exponentially. The delay is limited to (2^8)ms.
  395:      The scaling stuff ensures that when the queue is bigger than 8, the delay
  396:      only occurs for the last 8 entries. Once the queue is full, we stop delaying
  397:      to preserve performance.
  398:   */
  399: 
  400:   if (entries && max_logs != 0)
  401:     {
  402:       int d;
  403:       
  404:       for (d = 0,entry = entries; entry; entry = entry->next, d++);
  405:       
  406:       if (d == max_logs)
  407: 	d = 0;
  408:       else if (max_logs > 8)
  409: 	d -= max_logs - 8;
  410: 
  411:       if (d > 0)
  412: 	{
  413: 	  struct timespec waiter;
  414: 	  waiter.tv_sec = 0;
  415: 	  waiter.tv_nsec = 1000000 << (d - 1); /* 1 ms */
  416: 	  nanosleep(&waiter, NULL);
  417:       
  418: 	  /* Have another go now */
  419: 	  log_write();
  420: 	}
  421:     } 
  422: }
  423: 
  424: void set_log_writer(fd_set *set, int *maxfdp)
  425: {
  426:   if (entries && log_fd != -1 && connection_good)
  427:     {
  428:       FD_SET(log_fd, set);
  429:       bump_maxfd(log_fd, maxfdp);
  430:     }
  431: }
  432: 
  433: void check_log_writer(fd_set *set)
  434: {
  435:   if (log_fd != -1 && (!set || FD_ISSET(log_fd, set)))
  436:     log_write();
  437: }
  438: 
  439: void flush_log(void)
  440: {
  441:   /* write until queue empty, but don't loop forever if there's
  442:    no connection to the syslog in existance */
  443:   while (log_fd != -1)
  444:     {
  445:       struct timespec waiter;
  446:       log_write();
  447:       if (!entries || !connection_good)
  448: 	{
  449: 	  close(log_fd);	
  450: 	  break;
  451: 	}
  452:       waiter.tv_sec = 0;
  453:       waiter.tv_nsec = 1000000; /* 1 ms */
  454:       nanosleep(&waiter, NULL);
  455:     }
  456: }
  457: 
  458: void die(char *message, char *arg1, int exit_code)
  459: {
  460:   char *errmess = strerror(errno);
  461:   
  462:   if (!arg1)
  463:     arg1 = errmess;
  464: 
  465:   if (!log_stderr)
  466:     {
  467:       echo_stderr = 1; /* print as well as log when we die.... */
  468:       fputc('\n', stderr); /* prettyfy  startup-script message */
  469:     }
  470:   my_syslog(LOG_CRIT, message, arg1, errmess);
  471:   echo_stderr = 0;
  472:   my_syslog(LOG_CRIT, _("FAILED to start up"));
  473:   flush_log();
  474:   
  475:   exit(exit_code);
  476: }

FreeBSD-CVSweb <freebsd-cvsweb@FreeBSD.org>