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