Home | History | Annotate | Download | only in src
      1 /* dnsmasq is Copyright (c) 2000-2009 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 log_fd = -1;
     39 static int log_to_file = 0;
     40 static int entries_alloced = 0;
     41 static int entries_lost = 0;
     42 static int connection_good = 1;
     43 static int max_logs = 0;
     44 static int connection_type = SOCK_DGRAM;
     45 
     46 struct log_entry {
     47   int offset, length;
     48   pid_t pid; /* to avoid duplicates over a fork */
     49   struct log_entry *next;
     50   char payload[MAX_MESSAGE];
     51 };
     52 
     53 static struct log_entry *entries = NULL;
     54 static struct log_entry *free_entries = NULL;
     55 
     56 
     57 int log_start(struct passwd *ent_pw, int errfd)
     58 {
     59   int ret = 0;
     60 
     61   log_stderr = !!(daemon->options & OPT_DEBUG);
     62 
     63   if (daemon->log_fac != -1)
     64     log_fac = daemon->log_fac;
     65 #ifdef LOG_LOCAL0
     66   else if (daemon->options & OPT_DEBUG)
     67     log_fac = LOG_LOCAL0;
     68 #endif
     69 
     70   if (daemon->log_file)
     71     {
     72       log_to_file = 1;
     73       daemon->max_logs = 0;
     74     }
     75 
     76   max_logs = daemon->max_logs;
     77 
     78   if (!log_reopen(daemon->log_file))
     79     {
     80       send_event(errfd, EVENT_LOG_ERR, errno);
     81       _exit(0);
     82     }
     83 
     84   /* if queuing is inhibited, make sure we allocate
     85      the one required buffer now. */
     86   if (max_logs == 0)
     87     {
     88       free_entries = safe_malloc(sizeof(struct log_entry));
     89       free_entries->next = NULL;
     90       entries_alloced = 1;
     91     }
     92 
     93   /* If we're running as root and going to change uid later,
     94      change the ownership here so that the file is always owned by
     95      the dnsmasq user. Then logrotate can just copy the owner.
     96      Failure of the chown call is OK, (for instance when started as non-root) */
     97   if (log_to_file && ent_pw && ent_pw->pw_uid != 0 &&
     98       fchown(log_fd, ent_pw->pw_uid, -1) != 0)
     99     ret = errno;
    100 
    101   return ret;
    102 }
    103 
    104 int log_reopen(char *log_file)
    105 {
    106   if (log_fd != -1)
    107     close(log_fd);
    108 
    109   /* NOTE: umask is set to 022 by the time this gets called */
    110 
    111   if (log_file)
    112     {
    113       log_fd = open(log_file, O_WRONLY|O_CREAT|O_APPEND, S_IRUSR|S_IWUSR|S_IRGRP);
    114       return log_fd != -1;
    115     }
    116   else
    117 #if defined(__ANDROID__)
    118 #   define _PATH_LOG ""  /* dummy */
    119     log_fd = -1;
    120 #else
    121     {
    122        int flags;
    123        log_fd = socket(AF_UNIX, connection_type, 0);
    124 
    125       if (log_fd == -1)
    126 	return 0;
    127 
    128       /* if max_logs is zero, leave the socket blocking */
    129       if (max_logs != 0 && (flags = fcntl(log_fd, F_GETFL)) != -1)
    130 	fcntl(log_fd, F_SETFL, flags | O_NONBLOCK);
    131     }
    132 #endif
    133 
    134   return 1;
    135 }
    136 
    137 static void free_entry(void)
    138 {
    139   struct log_entry *tmp = entries;
    140   entries = tmp->next;
    141   tmp->next = free_entries;
    142   free_entries = tmp;
    143 }
    144 
    145 static void log_write(void)
    146 {
    147   ssize_t rc;
    148 
    149   while (entries)
    150     {
    151       /* Avoid duplicates over a fork() */
    152       if (entries->pid != getpid())
    153 	{
    154 	  free_entry();
    155 	  continue;
    156 	}
    157 
    158       connection_good = 1;
    159 
    160       if ((rc = write(log_fd, entries->payload + entries->offset, entries->length)) != -1)
    161 	{
    162 	  entries->length -= rc;
    163 	  entries->offset += rc;
    164 	  if (entries->length == 0)
    165 	    {
    166 	      free_entry();
    167 	      if (entries_lost != 0)
    168 		{
    169 		  int e = entries_lost;
    170 		  entries_lost = 0; /* avoid wild recursion */
    171 		  my_syslog(LOG_WARNING, _("overflow: %d log entries lost"), e);
    172 		}
    173 	    }
    174 	  continue;
    175 	}
    176 
    177       if (errno == EINTR)
    178 	continue;
    179 
    180       if (errno == EAGAIN)
    181 	return; /* syslogd busy, go again when select() or poll() says so */
    182 
    183       if (errno == ENOBUFS)
    184 	{
    185 	  connection_good = 0;
    186 	  return;
    187 	}
    188 
    189       /* errors handling after this assumes sockets */
    190       if (!log_to_file)
    191 	{
    192 	  /* Once a stream socket hits EPIPE, we have to close and re-open
    193 	     (we ignore SIGPIPE) */
    194 	  if (errno == EPIPE)
    195 	    {
    196 	      if (log_reopen(NULL))
    197 		continue;
    198 	    }
    199 	  else if (errno == ECONNREFUSED ||
    200 		   errno == ENOTCONN ||
    201 		   errno == EDESTADDRREQ ||
    202 		   errno == ECONNRESET)
    203 	    {
    204 	      /* socket went (syslogd down?), try and reconnect. If we fail,
    205 		 stop trying until the next call to my_syslog()
    206 		 ECONNREFUSED -> connection went down
    207 		 ENOTCONN -> nobody listening
    208 		 (ECONNRESET, EDESTADDRREQ are *BSD equivalents) */
    209 
    210 	      struct sockaddr_un logaddr;
    211 
    212 #ifdef HAVE_SOCKADDR_SA_LEN
    213 	      logaddr.sun_len = sizeof(logaddr) - sizeof(logaddr.sun_path) + strlen(_PATH_LOG) + 1;
    214 #endif
    215 	      logaddr.sun_family = AF_UNIX;
    216 	      strncpy(logaddr.sun_path, _PATH_LOG, sizeof(logaddr.sun_path));
    217 
    218 	      /* Got connection back? try again. */
    219 	      if (connect(log_fd, (struct sockaddr *)&logaddr, sizeof(logaddr)) != -1)
    220 		continue;
    221 
    222 	      /* errors from connect which mean we should keep trying */
    223 	      if (errno == ENOENT ||
    224 		  errno == EALREADY ||
    225 		  errno == ECONNREFUSED ||
    226 		  errno == EISCONN ||
    227 		  errno == EINTR ||
    228 		  errno == EAGAIN)
    229 		{
    230 		  /* try again on next syslog() call */
    231 		  connection_good = 0;
    232 		  return;
    233 		}
    234 
    235 	      /* try the other sort of socket... */
    236 	      if (errno == EPROTOTYPE)
    237 		{
    238 		  connection_type = connection_type == SOCK_DGRAM ? SOCK_STREAM : SOCK_DGRAM;
    239 		  if (log_reopen(NULL))
    240 		    continue;
    241 		}
    242 	    }
    243 	}
    244 
    245       /* give up - fall back to syslog() - this handles out-of-space
    246 	 when logging to a file, for instance. */
    247       log_fd = -1;
    248       my_syslog(LOG_CRIT, _("log failed: %s"), strerror(errno));
    249       return;
    250     }
    251 }
    252 
    253 /* priority is one of LOG_DEBUG, LOG_INFO, LOG_NOTICE, etc. See sys/syslog.h.
    254    OR'd to priority can be MS_TFTP, MS_DHCP, ... to be able to do log separation between
    255    DNS, DHCP and TFTP services.
    256 */
    257 void my_syslog(int priority, const char *format, ...)
    258 {
    259   va_list ap;
    260   struct log_entry *entry;
    261   time_t time_now;
    262   char *p;
    263   size_t len;
    264   pid_t pid = getpid();
    265   char *func = "";
    266 #ifdef __ANDROID__
    267   int alog_lvl;
    268 #endif
    269 
    270   if ((LOG_FACMASK & priority) == MS_TFTP)
    271     func = "-tftp";
    272   else if ((LOG_FACMASK & priority) == MS_DHCP)
    273     func = "-dhcp";
    274 
    275   priority = LOG_PRI(priority);
    276 
    277   if (log_stderr)
    278     {
    279       fprintf(stderr, "dnsmasq%s: ", func);
    280       va_start(ap, format);
    281       vfprintf(stderr, format, ap);
    282       va_end(ap);
    283       fputc('\n', stderr);
    284     }
    285 
    286 #ifdef __ANDROID__
    287     if (priority <= LOG_ERR)
    288       alog_lvl = ANDROID_LOG_ERROR;
    289     else if (priority == LOG_WARNING)
    290       alog_lvl = ANDROID_LOG_WARN;
    291     else if (priority <= LOG_INFO)
    292       alog_lvl = ANDROID_LOG_INFO;
    293     else
    294       alog_lvl = ANDROID_LOG_DEBUG;
    295     va_start(ap, format);
    296     __android_log_vprint(alog_lvl, "dnsmasq", format, ap);
    297     va_end(ap);
    298 #else
    299 
    300   if (log_fd == -1)
    301     {
    302       /* fall-back to syslog if we die during startup or fail during running. */
    303       static int isopen = 0;
    304       if (!isopen)
    305 	{
    306 	  openlog("dnsmasq", LOG_PID, log_fac);
    307 	  isopen = 1;
    308 	}
    309       va_start(ap, format);
    310       vsyslog(priority, format, ap);
    311       va_end(ap);
    312       return;
    313     }
    314 
    315   if ((entry = free_entries))
    316     free_entries = entry->next;
    317   else if (entries_alloced < max_logs && (entry = malloc(sizeof(struct log_entry))))
    318     entries_alloced++;
    319 
    320   if (!entry)
    321     entries_lost++;
    322   else
    323     {
    324       /* add to end of list, consumed from the start */
    325       entry->next = NULL;
    326       if (!entries)
    327 	entries = entry;
    328       else
    329 	{
    330 	  struct log_entry *tmp;
    331 	  for (tmp = entries; tmp->next; tmp = tmp->next);
    332 	  tmp->next = entry;
    333 	}
    334 
    335       time(&time_now);
    336       p = entry->payload;
    337       if (!log_to_file)
    338 	p += sprintf(p, "<%d>", priority | log_fac);
    339 
    340       p += sprintf(p, "%.15s dnsmasq%s[%d]: ", ctime(&time_now) + 4, func, (int)pid);
    341 
    342       len = p - entry->payload;
    343       va_start(ap, format);
    344       len += vsnprintf(p, MAX_MESSAGE - len, format, ap) + 1; /* include zero-terminator */
    345       va_end(ap);
    346       entry->length = len > MAX_MESSAGE ? MAX_MESSAGE : len;
    347       entry->offset = 0;
    348       entry->pid = pid;
    349 
    350       /* replace terminator with \n */
    351       if (log_to_file)
    352 	entry->payload[entry->length - 1] = '\n';
    353     }
    354 
    355   /* almost always, logging won't block, so try and write this now,
    356      to save collecting too many log messages during a select loop. */
    357   log_write();
    358 
    359   /* Since we're doing things asynchronously, a cache-dump, for instance,
    360      can now generate log lines very fast. With a small buffer (desirable),
    361      that means it can overflow the log-buffer very quickly,
    362      so that the cache dump becomes mainly a count of how many lines
    363      overflowed. To avoid this, we delay here, the delay is controlled
    364      by queue-occupancy, and grows exponentially. The delay is limited to (2^8)ms.
    365      The scaling stuff ensures that when the queue is bigger than 8, the delay
    366      only occurs for the last 8 entries. Once the queue is full, we stop delaying
    367      to preserve performance.
    368   */
    369 
    370   if (entries && max_logs != 0)
    371     {
    372       int d;
    373 
    374       for (d = 0,entry = entries; entry; entry = entry->next, d++);
    375 
    376       if (d == max_logs)
    377 	d = 0;
    378       else if (max_logs > 8)
    379 	d -= max_logs - 8;
    380 
    381       if (d > 0)
    382 	{
    383 	  struct timespec waiter;
    384 	  waiter.tv_sec = 0;
    385 	  waiter.tv_nsec = 1000000 << (d - 1); /* 1 ms */
    386 	  nanosleep(&waiter, NULL);
    387 
    388 	  /* Have another go now */
    389 	  log_write();
    390 	}
    391     }
    392 #endif
    393 }
    394 
    395 void set_log_writer(fd_set *set, int *maxfdp)
    396 {
    397   if (entries && log_fd != -1 && connection_good)
    398     {
    399       FD_SET(log_fd, set);
    400       bump_maxfd(log_fd, maxfdp);
    401     }
    402 }
    403 
    404 void check_log_writer(fd_set *set)
    405 {
    406   if (log_fd != -1 && (!set || FD_ISSET(log_fd, set)))
    407     log_write();
    408 }
    409 
    410 void flush_log(void)
    411 {
    412   /* block until queue empty */
    413   if (log_fd != -1)
    414     {
    415       int flags;
    416       if ((flags = fcntl(log_fd, F_GETFL)) != -1)
    417 	fcntl(log_fd, F_SETFL, flags & ~O_NONBLOCK);
    418       log_write();
    419       close(log_fd);
    420     }
    421 }
    422 
    423 void die(char *message, char *arg1, int exit_code)
    424 {
    425   char *errmess = strerror(errno);
    426 
    427   if (!arg1)
    428     arg1 = errmess;
    429 
    430   log_stderr = 1; /* print as well as log when we die.... */
    431   fputc('\n', stderr); /* prettyfy  startup-script message */
    432   my_syslog(LOG_CRIT, message, arg1, errmess);
    433 
    434   log_stderr = 0;
    435   my_syslog(LOG_CRIT, _("FAILED to start up"));
    436   flush_log();
    437 
    438   exit(exit_code);
    439 }
    440