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