]>
Commit | Line | Data |
---|---|---|
aff33962 | 1 | /* dnsmasq is Copyright (c) 2000-2015 Simon Kelley |
f2621c7f SK |
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 | |
824af85b SK |
5 | the Free Software Foundation; version 2 dated June, 1991, or |
6 | (at your option) version 3 dated 29 June, 2007. | |
7 | ||
f2621c7f SK |
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. | |
824af85b | 12 | |
73a08a24 SK |
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/>. | |
f2621c7f SK |
15 | */ |
16 | ||
17 | #include "dnsmasq.h" | |
18 | ||
572b41eb SK |
19 | #ifdef __ANDROID__ |
20 | # include <android/log.h> | |
21 | #endif | |
22 | ||
f2621c7f SK |
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; | |
8ef5ada2 SK |
37 | static int log_stderr = 0; |
38 | static int echo_stderr = 0; | |
f2621c7f SK |
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; | |
5aabfc78 | 45 | static int connection_type = SOCK_DGRAM; |
f2621c7f SK |
46 | |
47 | struct log_entry { | |
48 | int offset, length; | |
5aabfc78 | 49 | pid_t pid; /* to avoid duplicates over a fork */ |
f2621c7f SK |
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 | ||
1a6bca81 | 58 | int log_start(struct passwd *ent_pw, int errfd) |
f2621c7f | 59 | { |
1a6bca81 SK |
60 | int ret = 0; |
61 | ||
28866e95 | 62 | echo_stderr = option_bool(OPT_DEBUG); |
f2621c7f SK |
63 | |
64 | if (daemon->log_fac != -1) | |
65 | log_fac = daemon->log_fac; | |
66 | #ifdef LOG_LOCAL0 | |
28866e95 | 67 | else if (option_bool(OPT_DEBUG)) |
f2621c7f SK |
68 | log_fac = LOG_LOCAL0; |
69 | #endif | |
70 | ||
71 | if (daemon->log_file) | |
5aabfc78 | 72 | { |
f2621c7f SK |
73 | log_to_file = 1; |
74 | daemon->max_logs = 0; | |
8ef5ada2 SK |
75 | if (strcmp(daemon->log_file, "-") == 0) |
76 | { | |
77 | log_stderr = 1; | |
78 | echo_stderr = 0; | |
79 | log_fd = dup(STDERR_FILENO); | |
80 | } | |
f2621c7f | 81 | } |
f2621c7f | 82 | |
5aabfc78 SK |
83 | max_logs = daemon->max_logs; |
84 | ||
85 | if (!log_reopen(daemon->log_file)) | |
1a6bca81 | 86 | { |
c72daea8 | 87 | send_event(errfd, EVENT_LOG_ERR, errno, daemon->log_file ? daemon->log_file : ""); |
1a6bca81 SK |
88 | _exit(0); |
89 | } | |
90 | ||
f2621c7f SK |
91 | /* if queuing is inhibited, make sure we allocate |
92 | the one required buffer now. */ | |
5aabfc78 | 93 | if (max_logs == 0) |
f2621c7f SK |
94 | { |
95 | free_entries = safe_malloc(sizeof(struct log_entry)); | |
96 | free_entries->next = NULL; | |
97 | entries_alloced = 1; | |
98 | } | |
824af85b SK |
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) */ | |
8ef5ada2 | 104 | if (log_to_file && !log_stderr && ent_pw && ent_pw->pw_uid != 0 && |
1a6bca81 SK |
105 | fchown(log_fd, ent_pw->pw_uid, -1) != 0) |
106 | ret = errno; | |
107 | ||
108 | return ret; | |
5aabfc78 | 109 | } |
f2621c7f | 110 | |
5aabfc78 SK |
111 | int log_reopen(char *log_file) |
112 | { | |
8ef5ada2 SK |
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 | { | |
572b41eb | 124 | #if defined(HAVE_SOLARIS_NETWORK) || defined(__ANDROID__) |
8ef5ada2 SK |
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.... */ | |
824af85b | 127 | # define _PATH_LOG "" /* dummy */ |
8ef5ada2 | 128 | return 1; |
824af85b | 129 | #else |
8ef5ada2 SK |
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); | |
824af85b | 136 | #endif |
8ef5ada2 SK |
137 | } |
138 | } | |
139 | ||
140 | return log_fd != -1; | |
f2621c7f | 141 | } |
5aabfc78 SK |
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 | ||
f2621c7f SK |
151 | static void log_write(void) |
152 | { | |
153 | ssize_t rc; | |
5aabfc78 | 154 | |
f2621c7f SK |
155 | while (entries) |
156 | { | |
7de060b0 SK |
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 | ||
5aabfc78 SK |
170 | /* Avoid duplicates over a fork() */ |
171 | if (entries->pid != getpid()) | |
172 | { | |
173 | free_entry(); | |
174 | continue; | |
175 | } | |
176 | ||
f2621c7f SK |
177 | connection_good = 1; |
178 | ||
7de060b0 | 179 | if ((rc = write(log_fd, entries->payload + entries->offset, entries->length - len_adjust)) != -1) |
f2621c7f SK |
180 | { |
181 | entries->length -= rc; | |
182 | entries->offset += rc; | |
7de060b0 | 183 | if (entries->length == len_adjust) |
f2621c7f | 184 | { |
5aabfc78 | 185 | free_entry(); |
f2621c7f SK |
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 | ||
c72daea8 | 199 | if (errno == EAGAIN || errno == EWOULDBLOCK) |
f2621c7f SK |
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 | } | |
5aabfc78 SK |
207 | |
208 | /* errors handling after this assumes sockets */ | |
209 | if (!log_to_file) | |
f2621c7f | 210 | { |
5aabfc78 SK |
211 | /* Once a stream socket hits EPIPE, we have to close and re-open |
212 | (we ignore SIGPIPE) */ | |
213 | if (errno == EPIPE) | |
f2621c7f | 214 | { |
5aabfc78 SK |
215 | if (log_reopen(NULL)) |
216 | continue; | |
f2621c7f | 217 | } |
5aabfc78 SK |
218 | else if (errno == ECONNREFUSED || |
219 | errno == ENOTCONN || | |
220 | errno == EDESTADDRREQ || | |
221 | errno == ECONNRESET) | |
f2621c7f | 222 | { |
5aabfc78 SK |
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 | |
824af85b | 234 | logaddr.sun_family = AF_UNIX; |
5aabfc78 SK |
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 || | |
c72daea8 SK |
247 | errno == EAGAIN || |
248 | errno == EWOULDBLOCK) | |
5aabfc78 SK |
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) | |
f2621c7f | 257 | { |
5aabfc78 SK |
258 | connection_type = connection_type == SOCK_DGRAM ? SOCK_STREAM : SOCK_DGRAM; |
259 | if (log_reopen(NULL)) | |
260 | continue; | |
f2621c7f SK |
261 | } |
262 | } | |
263 | } | |
5aabfc78 | 264 | |
f2621c7f SK |
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 | ||
7622fc06 SK |
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 | */ | |
f2621c7f SK |
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; | |
5aabfc78 | 284 | pid_t pid = getpid(); |
7622fc06 | 285 | char *func = ""; |
5aabfc78 | 286 | |
7622fc06 SK |
287 | if ((LOG_FACMASK & priority) == MS_TFTP) |
288 | func = "-tftp"; | |
289 | else if ((LOG_FACMASK & priority) == MS_DHCP) | |
290 | func = "-dhcp"; | |
291 | ||
316e2730 | 292 | #ifdef LOG_PRI |
7622fc06 | 293 | priority = LOG_PRI(priority); |
316e2730 SK |
294 | #else |
295 | /* Solaris doesn't have LOG_PRI */ | |
296 | priority &= LOG_PRIMASK; | |
297 | #endif | |
298 | ||
8ef5ada2 | 299 | if (echo_stderr) |
f2621c7f | 300 | { |
7622fc06 | 301 | fprintf(stderr, "dnsmasq%s: ", func); |
824af85b | 302 | va_start(ap, format); |
f2621c7f | 303 | vfprintf(stderr, format, ap); |
824af85b | 304 | va_end(ap); |
f2621c7f SK |
305 | fputc('\n', stderr); |
306 | } | |
824af85b | 307 | |
f2621c7f SK |
308 | if (log_fd == -1) |
309 | { | |
572b41eb SK |
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). */ | |
f2621c7f | 330 | static int isopen = 0; |
572b41eb | 331 | |
f2621c7f SK |
332 | if (!isopen) |
333 | { | |
334 | openlog("dnsmasq", LOG_PID, log_fac); | |
335 | isopen = 1; | |
336 | } | |
824af85b | 337 | va_start(ap, format); |
f2621c7f SK |
338 | vsyslog(priority, format, ap); |
339 | va_end(ap); | |
572b41eb SK |
340 | #endif |
341 | ||
f2621c7f SK |
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); | |
7622fc06 | 369 | |
28866e95 SK |
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); | |
7622fc06 | 375 | |
f2621c7f | 376 | len = p - entry->payload; |
824af85b | 377 | va_start(ap, format); |
f2621c7f | 378 | len += vsnprintf(p, MAX_MESSAGE - len, format, ap) + 1; /* include zero-terminator */ |
824af85b | 379 | va_end(ap); |
f2621c7f SK |
380 | entry->length = len > MAX_MESSAGE ? MAX_MESSAGE : len; |
381 | entry->offset = 0; | |
5aabfc78 | 382 | entry->pid = pid; |
f2621c7f SK |
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 | } | |
f2621c7f SK |
422 | } |
423 | ||
b842bc97 | 424 | void set_log_writer(void) |
f2621c7f SK |
425 | { |
426 | if (entries && log_fd != -1 && connection_good) | |
b842bc97 | 427 | poll_listen(log_fd, POLLOUT); |
f2621c7f SK |
428 | } |
429 | ||
b842bc97 | 430 | void check_log_writer(int force) |
f2621c7f | 431 | { |
b842bc97 | 432 | if (log_fd != -1 && (force || poll_check(log_fd, POLLOUT))) |
f2621c7f SK |
433 | log_write(); |
434 | } | |
435 | ||
5aabfc78 SK |
436 | void flush_log(void) |
437 | { | |
28866e95 SK |
438 | /* write until queue empty, but don't loop forever if there's |
439 | no connection to the syslog in existance */ | |
8ef5ada2 | 440 | while (log_fd != -1) |
5aabfc78 | 441 | { |
8ef5ada2 | 442 | struct timespec waiter; |
5aabfc78 | 443 | log_write(); |
28866e95 | 444 | if (!entries || !connection_good) |
8ef5ada2 SK |
445 | { |
446 | close(log_fd); | |
447 | break; | |
448 | } | |
449 | waiter.tv_sec = 0; | |
450 | waiter.tv_nsec = 1000000; /* 1 ms */ | |
451 | nanosleep(&waiter, NULL); | |
5aabfc78 SK |
452 | } |
453 | } | |
454 | ||
455 | void die(char *message, char *arg1, int exit_code) | |
f2621c7f SK |
456 | { |
457 | char *errmess = strerror(errno); | |
458 | ||
459 | if (!arg1) | |
460 | arg1 = errmess; | |
461 | ||
8ef5ada2 SK |
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 | } | |
f2621c7f | 467 | my_syslog(LOG_CRIT, message, arg1, errmess); |
8ef5ada2 | 468 | echo_stderr = 0; |
f2621c7f | 469 | my_syslog(LOG_CRIT, _("FAILED to start up")); |
5aabfc78 | 470 | flush_log(); |
f2621c7f | 471 | |
5aabfc78 | 472 | exit(exit_code); |
f2621c7f | 473 | } |