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