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>