Annotation of embedaddon/dnsmasq/src/log.c, revision 1.1.1.5

1.1.1.5 ! misho       1: /* dnsmasq is Copyright (c) 2000-2022 Simon Kelley
1.1       misho       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.
1.1.1.5 ! misho     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:     }
1.1       misho     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)
1.1.1.5 ! misho     134:        log_fd = open(log_file, O_WRONLY|O_CREAT|O_APPEND, S_IRUSR|S_IWUSR|S_IRGRP);
1.1       misho     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:     {
1.1.1.4   misho     170:       /* The data in the payload is written with a terminating zero character 
1.1       misho     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;
1.1.1.4   misho     248:              safe_strncpy(logaddr.sun_path, _PATH_LOG, sizeof(logaddr.sun_path));
1.1       misho     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.
1.1.1.5 ! misho     289:    If OR'd with MS_DEBUG, the messages are suppressed unless --log-debug is set. */
1.1       misho     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";
1.1.1.4   misho     304:   else if ((LOG_FACMASK & priority) == MS_SCRIPT)
                    305:     func = "-script";
1.1.1.5 ! misho     306:   else if ((LOG_FACMASK & priority) == MS_DEBUG)
        !           307:     {
        !           308:       if (!option_bool(OPT_LOG_DEBUG))
        !           309:        return;
        !           310:       func = "-debug";
        !           311:     }
        !           312:   
1.1       misho     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: 
1.1.1.3   misho     445: void set_log_writer(void)
1.1       misho     446: {
                    447:   if (entries && log_fd != -1 && connection_good)
1.1.1.3   misho     448:     poll_listen(log_fd, POLLOUT);
1.1       misho     449: }
                    450: 
1.1.1.3   misho     451: void check_log_writer(int force)
1.1       misho     452: {
1.1.1.3   misho     453:   if (log_fd != -1 && (force || poll_check(log_fd, POLLOUT)))
1.1       misho     454:     log_write();
                    455: }
                    456: 
                    457: void flush_log(void)
                    458: {
                    459:   /* write until queue empty, but don't loop forever if there's
1.1.1.4   misho     460:    no connection to the syslog in existence */
1.1       misho     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>