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

1.1.1.4 ! misho       1: /* dnsmasq is Copyright (c) 2000-2021 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.
                    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:     {
1.1.1.4 ! misho     157:       /* The data in the payload is written with a terminating zero character 
1.1       misho     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;
1.1.1.4 ! misho     235:              safe_strncpy(logaddr.sun_path, _PATH_LOG, sizeof(logaddr.sun_path));
1.1       misho     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";
1.1.1.4 ! misho     291:   else if ((LOG_FACMASK & priority) == MS_SCRIPT)
        !           292:     func = "-script";
        !           293:            
1.1       misho     294: #ifdef LOG_PRI
                    295:   priority = LOG_PRI(priority);
                    296: #else
                    297:   /* Solaris doesn't have LOG_PRI */
                    298:   priority &= LOG_PRIMASK;
                    299: #endif
                    300: 
                    301:   if (echo_stderr) 
                    302:     {
                    303:       fprintf(stderr, "dnsmasq%s: ", func);
                    304:       va_start(ap, format);
                    305:       vfprintf(stderr, format, ap);
                    306:       va_end(ap);
                    307:       fputc('\n', stderr);
                    308:     }
                    309: 
                    310:   if (log_fd == -1)
                    311:     {
                    312: #ifdef __ANDROID__
                    313:       /* do android-specific logging. 
                    314:         log_fd is always -1 on Android except when logging to a file. */
                    315:       int alog_lvl;
                    316:       
                    317:       if (priority <= LOG_ERR)
                    318:        alog_lvl = ANDROID_LOG_ERROR;
                    319:       else if (priority == LOG_WARNING)
                    320:        alog_lvl = ANDROID_LOG_WARN;
                    321:       else if (priority <= LOG_INFO)
                    322:        alog_lvl = ANDROID_LOG_INFO;
                    323:       else
                    324:        alog_lvl = ANDROID_LOG_DEBUG;
                    325: 
                    326:       va_start(ap, format);
                    327:       __android_log_vprint(alog_lvl, "dnsmasq", format, ap);
                    328:       va_end(ap);
                    329: #else
                    330:       /* fall-back to syslog if we die during startup or 
                    331:         fail during running (always on Solaris). */
                    332:       static int isopen = 0;
                    333: 
                    334:       if (!isopen)
                    335:        {
                    336:          openlog("dnsmasq", LOG_PID, log_fac);
                    337:          isopen = 1;
                    338:        }
                    339:       va_start(ap, format);  
                    340:       vsyslog(priority, format, ap);
                    341:       va_end(ap);
                    342: #endif
                    343: 
                    344:       return;
                    345:     }
                    346:   
                    347:   if ((entry = free_entries))
                    348:     free_entries = entry->next;
                    349:   else if (entries_alloced < max_logs && (entry = malloc(sizeof(struct log_entry))))
                    350:     entries_alloced++;
                    351:   
                    352:   if (!entry)
                    353:     entries_lost++;
                    354:   else
                    355:     {
                    356:       /* add to end of list, consumed from the start */
                    357:       entry->next = NULL;
                    358:       if (!entries)
                    359:        entries = entry;
                    360:       else
                    361:        {
                    362:          struct log_entry *tmp;
                    363:          for (tmp = entries; tmp->next; tmp = tmp->next);
                    364:          tmp->next = entry;
                    365:        }
                    366:       
                    367:       time(&time_now);
                    368:       p = entry->payload;
                    369:       if (!log_to_file)
                    370:        p += sprintf(p, "<%d>", priority | log_fac);
                    371: 
                    372:       /* Omit timestamp for default daemontools situation */
                    373:       if (!log_stderr || !option_bool(OPT_NO_FORK)) 
                    374:        p += sprintf(p, "%.15s ", ctime(&time_now) + 4);
                    375:       
                    376:       p += sprintf(p, "dnsmasq%s[%d]: ", func, (int)pid);
                    377:         
                    378:       len = p - entry->payload;
                    379:       va_start(ap, format);  
                    380:       len += vsnprintf(p, MAX_MESSAGE - len, format, ap) + 1; /* include zero-terminator */
                    381:       va_end(ap);
                    382:       entry->length = len > MAX_MESSAGE ? MAX_MESSAGE : len;
                    383:       entry->offset = 0;
                    384:       entry->pid = pid;
                    385:     }
                    386:   
                    387:   /* almost always, logging won't block, so try and write this now,
                    388:      to save collecting too many log messages during a select loop. */
                    389:   log_write();
                    390:   
                    391:   /* Since we're doing things asynchronously, a cache-dump, for instance,
                    392:      can now generate log lines very fast. With a small buffer (desirable),
                    393:      that means it can overflow the log-buffer very quickly,
                    394:      so that the cache dump becomes mainly a count of how many lines 
                    395:      overflowed. To avoid this, we delay here, the delay is controlled 
                    396:      by queue-occupancy, and grows exponentially. The delay is limited to (2^8)ms.
                    397:      The scaling stuff ensures that when the queue is bigger than 8, the delay
                    398:      only occurs for the last 8 entries. Once the queue is full, we stop delaying
                    399:      to preserve performance.
                    400:   */
                    401: 
                    402:   if (entries && max_logs != 0)
                    403:     {
                    404:       int d;
                    405:       
                    406:       for (d = 0,entry = entries; entry; entry = entry->next, d++);
                    407:       
                    408:       if (d == max_logs)
                    409:        d = 0;
                    410:       else if (max_logs > 8)
                    411:        d -= max_logs - 8;
                    412: 
                    413:       if (d > 0)
                    414:        {
                    415:          struct timespec waiter;
                    416:          waiter.tv_sec = 0;
                    417:          waiter.tv_nsec = 1000000 << (d - 1); /* 1 ms */
                    418:          nanosleep(&waiter, NULL);
                    419:       
                    420:          /* Have another go now */
                    421:          log_write();
                    422:        }
                    423:     } 
                    424: }
                    425: 
1.1.1.3   misho     426: void set_log_writer(void)
1.1       misho     427: {
                    428:   if (entries && log_fd != -1 && connection_good)
1.1.1.3   misho     429:     poll_listen(log_fd, POLLOUT);
1.1       misho     430: }
                    431: 
1.1.1.3   misho     432: void check_log_writer(int force)
1.1       misho     433: {
1.1.1.3   misho     434:   if (log_fd != -1 && (force || poll_check(log_fd, POLLOUT)))
1.1       misho     435:     log_write();
                    436: }
                    437: 
                    438: void flush_log(void)
                    439: {
                    440:   /* write until queue empty, but don't loop forever if there's
1.1.1.4 ! misho     441:    no connection to the syslog in existence */
1.1       misho     442:   while (log_fd != -1)
                    443:     {
                    444:       struct timespec waiter;
                    445:       log_write();
                    446:       if (!entries || !connection_good)
                    447:        {
                    448:          close(log_fd);        
                    449:          break;
                    450:        }
                    451:       waiter.tv_sec = 0;
                    452:       waiter.tv_nsec = 1000000; /* 1 ms */
                    453:       nanosleep(&waiter, NULL);
                    454:     }
                    455: }
                    456: 
                    457: void die(char *message, char *arg1, int exit_code)
                    458: {
                    459:   char *errmess = strerror(errno);
                    460:   
                    461:   if (!arg1)
                    462:     arg1 = errmess;
                    463: 
                    464:   if (!log_stderr)
                    465:     {
                    466:       echo_stderr = 1; /* print as well as log when we die.... */
                    467:       fputc('\n', stderr); /* prettyfy  startup-script message */
                    468:     }
                    469:   my_syslog(LOG_CRIT, message, arg1, errmess);
                    470:   echo_stderr = 0;
                    471:   my_syslog(LOG_CRIT, _("FAILED to start up"));
                    472:   flush_log();
                    473:   
                    474:   exit(exit_code);
                    475: }

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