File:  [ELWIX - Embedded LightWeight unIX -] / embedaddon / dnsmasq / src / log.c
Revision 1.1.1.5 (vendor branch): download - view: text, annotated - select for diffs - revision graph
Wed Sep 27 11:02:07 2023 UTC (9 months, 2 weeks ago) by misho
Branches: elwix, dnsmasq, MAIN
CVS tags: v8_2p1, HEAD
Version 8.2p1

    1: /* dnsmasq is Copyright (c) 2000-2022 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:      
  105:      If we've created a file with group-id root, we also make
  106:      the file group-writable. This gives processes in the root group
  107:      write access to the file and avoids the problem that on some systems,
  108:      once the file is owned by the dnsmasq user, it can't be written
  109:      whilst dnsmasq is running as root during startup.
  110:  */
  111:   if (log_to_file && !log_stderr && ent_pw && ent_pw->pw_uid != 0)
  112:     {
  113:       struct stat ls;
  114:       if (getgid() == 0 && fstat(log_fd, &ls) == 0 && ls.st_gid == 0 &&
  115: 	  (ls.st_mode & S_IWGRP) == 0)
  116: 	(void)fchmod(log_fd, S_IRUSR|S_IWUSR|S_IRGRP|S_IWGRP);
  117:       if (fchown(log_fd, ent_pw->pw_uid, -1) != 0)
  118: 	ret = errno;
  119:     }
  120: 
  121:   return ret;
  122: }
  123: 
  124: int log_reopen(char *log_file)
  125: {
  126:   if (!log_stderr)
  127:     {      
  128:       if (log_fd != -1)
  129: 	close(log_fd);
  130:       
  131:       /* NOTE: umask is set to 022 by the time this gets called */
  132:       
  133:       if (log_file)
  134: 	log_fd = open(log_file, O_WRONLY|O_CREAT|O_APPEND, S_IRUSR|S_IWUSR|S_IRGRP);
  135:       else
  136: 	{
  137: #if defined(HAVE_SOLARIS_NETWORK) || defined(__ANDROID__)
  138: 	  /* Solaris logging is "different", /dev/log is not unix-domain socket.
  139: 	     Just leave log_fd == -1 and use the vsyslog call for everything.... */
  140: #   define _PATH_LOG ""  /* dummy */
  141: 	  return 1;
  142: #else
  143: 	  int flags;
  144: 	  log_fd = socket(AF_UNIX, connection_type, 0);
  145: 	  
  146: 	  /* if max_logs is zero, leave the socket blocking */
  147: 	  if (log_fd != -1 && max_logs != 0 && (flags = fcntl(log_fd, F_GETFL)) != -1)
  148: 	    fcntl(log_fd, F_SETFL, flags | O_NONBLOCK);
  149: #endif
  150: 	}
  151:     }
  152:   
  153:   return log_fd != -1;
  154: }
  155: 
  156: static void free_entry(void)
  157: {
  158:   struct log_entry *tmp = entries;
  159:   entries = tmp->next;
  160:   tmp->next = free_entries;
  161:   free_entries = tmp;
  162: }      
  163: 
  164: static void log_write(void)
  165: {
  166:   ssize_t rc;
  167:    
  168:   while (entries)
  169:     {
  170:       /* The data in the payload is written with a terminating zero character 
  171: 	 and the length reflects this. For a stream connection we need to 
  172: 	 send the zero as a record terminator, but this isn't done for a 
  173: 	 datagram connection, so treat the length as one less than reality 
  174: 	 to elide the zero. If we're logging to a file, turn the zero into 
  175: 	 a newline, and leave the length alone. */
  176:       int len_adjust = 0;
  177: 
  178:       if (log_to_file)
  179: 	entries->payload[entries->offset + entries->length - 1] = '\n';
  180:       else if (connection_type == SOCK_DGRAM)
  181: 	len_adjust = 1;
  182: 
  183:       /* Avoid duplicates over a fork() */
  184:       if (entries->pid != getpid())
  185: 	{
  186: 	  free_entry();
  187: 	  continue;
  188: 	}
  189: 
  190:       connection_good = 1;
  191: 
  192:       if ((rc = write(log_fd, entries->payload + entries->offset, entries->length - len_adjust)) != -1)
  193: 	{
  194: 	  entries->length -= rc;
  195: 	  entries->offset += rc;
  196: 	  if (entries->length == len_adjust)
  197: 	    {
  198: 	      free_entry();
  199: 	      if (entries_lost != 0)
  200: 		{
  201: 		  int e = entries_lost;
  202: 		  entries_lost = 0; /* avoid wild recursion */
  203: 		  my_syslog(LOG_WARNING, _("overflow: %d log entries lost"), e);
  204: 		}	  
  205: 	    }
  206: 	  continue;
  207: 	}
  208:       
  209:       if (errno == EINTR)
  210: 	continue;
  211: 
  212:       if (errno == EAGAIN || errno == EWOULDBLOCK)
  213: 	return; /* syslogd busy, go again when select() or poll() says so */
  214:       
  215:       if (errno == ENOBUFS)
  216: 	{
  217: 	  connection_good = 0;
  218: 	  return;
  219: 	}
  220: 
  221:       /* errors handling after this assumes sockets */ 
  222:       if (!log_to_file)
  223: 	{
  224: 	  /* Once a stream socket hits EPIPE, we have to close and re-open
  225: 	     (we ignore SIGPIPE) */
  226: 	  if (errno == EPIPE)
  227: 	    {
  228: 	      if (log_reopen(NULL))
  229: 		continue;
  230: 	    }
  231: 	  else if (errno == ECONNREFUSED || 
  232: 		   errno == ENOTCONN || 
  233: 		   errno == EDESTADDRREQ || 
  234: 		   errno == ECONNRESET)
  235: 	    {
  236: 	      /* socket went (syslogd down?), try and reconnect. If we fail,
  237: 		 stop trying until the next call to my_syslog() 
  238: 		 ECONNREFUSED -> connection went down
  239: 		 ENOTCONN -> nobody listening
  240: 		 (ECONNRESET, EDESTADDRREQ are *BSD equivalents) */
  241: 	      
  242: 	      struct sockaddr_un logaddr;
  243: 	      
  244: #ifdef HAVE_SOCKADDR_SA_LEN
  245: 	      logaddr.sun_len = sizeof(logaddr) - sizeof(logaddr.sun_path) + strlen(_PATH_LOG) + 1; 
  246: #endif
  247: 	      logaddr.sun_family = AF_UNIX;
  248: 	      safe_strncpy(logaddr.sun_path, _PATH_LOG, sizeof(logaddr.sun_path));
  249: 	      
  250: 	      /* Got connection back? try again. */
  251: 	      if (connect(log_fd, (struct sockaddr *)&logaddr, sizeof(logaddr)) != -1)
  252: 		continue;
  253: 	      
  254: 	      /* errors from connect which mean we should keep trying */
  255: 	      if (errno == ENOENT || 
  256: 		  errno == EALREADY || 
  257: 		  errno == ECONNREFUSED ||
  258: 		  errno == EISCONN || 
  259: 		  errno == EINTR ||
  260: 		  errno == EAGAIN || 
  261: 		  errno == EWOULDBLOCK)
  262: 		{
  263: 		  /* try again on next syslog() call */
  264: 		  connection_good = 0;
  265: 		  return;
  266: 		}
  267: 	      
  268: 	      /* try the other sort of socket... */
  269: 	      if (errno == EPROTOTYPE)
  270: 		{
  271: 		  connection_type = connection_type == SOCK_DGRAM ? SOCK_STREAM : SOCK_DGRAM;
  272: 		  if (log_reopen(NULL))
  273: 		    continue;
  274: 		}
  275: 	    }
  276: 	}
  277: 
  278:       /* give up - fall back to syslog() - this handles out-of-space
  279: 	 when logging to a file, for instance. */
  280:       log_fd = -1;
  281:       my_syslog(LOG_CRIT, _("log failed: %s"), strerror(errno));
  282:       return;
  283:     }
  284: }
  285: 
  286: /* priority is one of LOG_DEBUG, LOG_INFO, LOG_NOTICE, etc. See sys/syslog.h.
  287:    OR'd to priority can be MS_TFTP, MS_DHCP, ... to be able to do log separation between
  288:    DNS, DHCP and TFTP services.
  289:    If OR'd with MS_DEBUG, the messages are suppressed unless --log-debug is set. */
  290: void my_syslog(int priority, const char *format, ...)
  291: {
  292:   va_list ap;
  293:   struct log_entry *entry;
  294:   time_t time_now;
  295:   char *p;
  296:   size_t len;
  297:   pid_t pid = getpid();
  298:   char *func = "";
  299: 
  300:   if ((LOG_FACMASK & priority) == MS_TFTP)
  301:     func = "-tftp";
  302:   else if ((LOG_FACMASK & priority) == MS_DHCP)
  303:     func = "-dhcp";
  304:   else if ((LOG_FACMASK & priority) == MS_SCRIPT)
  305:     func = "-script";
  306:   else if ((LOG_FACMASK & priority) == MS_DEBUG)
  307:     {
  308:       if (!option_bool(OPT_LOG_DEBUG))
  309: 	return;
  310:       func = "-debug";
  311:     }
  312:   
  313: #ifdef LOG_PRI
  314:   priority = LOG_PRI(priority);
  315: #else
  316:   /* Solaris doesn't have LOG_PRI */
  317:   priority &= LOG_PRIMASK;
  318: #endif
  319: 
  320:   if (echo_stderr) 
  321:     {
  322:       fprintf(stderr, "dnsmasq%s: ", func);
  323:       va_start(ap, format);
  324:       vfprintf(stderr, format, ap);
  325:       va_end(ap);
  326:       fputc('\n', stderr);
  327:     }
  328: 
  329:   if (log_fd == -1)
  330:     {
  331: #ifdef __ANDROID__
  332:       /* do android-specific logging. 
  333: 	 log_fd is always -1 on Android except when logging to a file. */
  334:       int alog_lvl;
  335:       
  336:       if (priority <= LOG_ERR)
  337: 	alog_lvl = ANDROID_LOG_ERROR;
  338:       else if (priority == LOG_WARNING)
  339: 	alog_lvl = ANDROID_LOG_WARN;
  340:       else if (priority <= LOG_INFO)
  341: 	alog_lvl = ANDROID_LOG_INFO;
  342:       else
  343: 	alog_lvl = ANDROID_LOG_DEBUG;
  344: 
  345:       va_start(ap, format);
  346:       __android_log_vprint(alog_lvl, "dnsmasq", format, ap);
  347:       va_end(ap);
  348: #else
  349:       /* fall-back to syslog if we die during startup or 
  350: 	 fail during running (always on Solaris). */
  351:       static int isopen = 0;
  352: 
  353:       if (!isopen)
  354: 	{
  355: 	  openlog("dnsmasq", LOG_PID, log_fac);
  356: 	  isopen = 1;
  357: 	}
  358:       va_start(ap, format);  
  359:       vsyslog(priority, format, ap);
  360:       va_end(ap);
  361: #endif
  362: 
  363:       return;
  364:     }
  365:   
  366:   if ((entry = free_entries))
  367:     free_entries = entry->next;
  368:   else if (entries_alloced < max_logs && (entry = malloc(sizeof(struct log_entry))))
  369:     entries_alloced++;
  370:   
  371:   if (!entry)
  372:     entries_lost++;
  373:   else
  374:     {
  375:       /* add to end of list, consumed from the start */
  376:       entry->next = NULL;
  377:       if (!entries)
  378: 	entries = entry;
  379:       else
  380: 	{
  381: 	  struct log_entry *tmp;
  382: 	  for (tmp = entries; tmp->next; tmp = tmp->next);
  383: 	  tmp->next = entry;
  384: 	}
  385:       
  386:       time(&time_now);
  387:       p = entry->payload;
  388:       if (!log_to_file)
  389: 	p += sprintf(p, "<%d>", priority | log_fac);
  390: 
  391:       /* Omit timestamp for default daemontools situation */
  392:       if (!log_stderr || !option_bool(OPT_NO_FORK)) 
  393: 	p += sprintf(p, "%.15s ", ctime(&time_now) + 4);
  394:       
  395:       p += sprintf(p, "dnsmasq%s[%d]: ", func, (int)pid);
  396:         
  397:       len = p - entry->payload;
  398:       va_start(ap, format);  
  399:       len += vsnprintf(p, MAX_MESSAGE - len, format, ap) + 1; /* include zero-terminator */
  400:       va_end(ap);
  401:       entry->length = len > MAX_MESSAGE ? MAX_MESSAGE : len;
  402:       entry->offset = 0;
  403:       entry->pid = pid;
  404:     }
  405:   
  406:   /* almost always, logging won't block, so try and write this now,
  407:      to save collecting too many log messages during a select loop. */
  408:   log_write();
  409:   
  410:   /* Since we're doing things asynchronously, a cache-dump, for instance,
  411:      can now generate log lines very fast. With a small buffer (desirable),
  412:      that means it can overflow the log-buffer very quickly,
  413:      so that the cache dump becomes mainly a count of how many lines 
  414:      overflowed. To avoid this, we delay here, the delay is controlled 
  415:      by queue-occupancy, and grows exponentially. The delay is limited to (2^8)ms.
  416:      The scaling stuff ensures that when the queue is bigger than 8, the delay
  417:      only occurs for the last 8 entries. Once the queue is full, we stop delaying
  418:      to preserve performance.
  419:   */
  420: 
  421:   if (entries && max_logs != 0)
  422:     {
  423:       int d;
  424:       
  425:       for (d = 0,entry = entries; entry; entry = entry->next, d++);
  426:       
  427:       if (d == max_logs)
  428: 	d = 0;
  429:       else if (max_logs > 8)
  430: 	d -= max_logs - 8;
  431: 
  432:       if (d > 0)
  433: 	{
  434: 	  struct timespec waiter;
  435: 	  waiter.tv_sec = 0;
  436: 	  waiter.tv_nsec = 1000000 << (d - 1); /* 1 ms */
  437: 	  nanosleep(&waiter, NULL);
  438:       
  439: 	  /* Have another go now */
  440: 	  log_write();
  441: 	}
  442:     } 
  443: }
  444: 
  445: void set_log_writer(void)
  446: {
  447:   if (entries && log_fd != -1 && connection_good)
  448:     poll_listen(log_fd, POLLOUT);
  449: }
  450: 
  451: void check_log_writer(int force)
  452: {
  453:   if (log_fd != -1 && (force || poll_check(log_fd, POLLOUT)))
  454:     log_write();
  455: }
  456: 
  457: void flush_log(void)
  458: {
  459:   /* write until queue empty, but don't loop forever if there's
  460:    no connection to the syslog in existence */
  461:   while (log_fd != -1)
  462:     {
  463:       struct timespec waiter;
  464:       log_write();
  465:       if (!entries || !connection_good)
  466: 	{
  467: 	  close(log_fd);	
  468: 	  break;
  469: 	}
  470:       waiter.tv_sec = 0;
  471:       waiter.tv_nsec = 1000000; /* 1 ms */
  472:       nanosleep(&waiter, NULL);
  473:     }
  474: }
  475: 
  476: void die(char *message, char *arg1, int exit_code)
  477: {
  478:   char *errmess = strerror(errno);
  479:   
  480:   if (!arg1)
  481:     arg1 = errmess;
  482: 
  483:   if (!log_stderr)
  484:     {
  485:       echo_stderr = 1; /* print as well as log when we die.... */
  486:       fputc('\n', stderr); /* prettyfy  startup-script message */
  487:     }
  488:   my_syslog(LOG_CRIT, message, arg1, errmess);
  489:   echo_stderr = 0;
  490:   my_syslog(LOG_CRIT, _("FAILED to start up"));
  491:   flush_log();
  492:   
  493:   exit(exit_code);
  494: }

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