release/src/router/dnsmasq/src/log.c

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