Annotation of embedaddon/dnsmasq/src/log.c, revision 1.1.1.3
1.1.1.3 ! misho 1: /* dnsmasq is Copyright (c) 2000-2016 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: {
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: */
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:
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:
1.1.1.3 ! misho 424: void set_log_writer(void)
1.1 misho 425: {
426: if (entries && log_fd != -1 && connection_good)
1.1.1.3 ! misho 427: poll_listen(log_fd, POLLOUT);
1.1 misho 428: }
429:
1.1.1.3 ! misho 430: void check_log_writer(int force)
1.1 misho 431: {
1.1.1.3 ! misho 432: if (log_fd != -1 && (force || poll_check(log_fd, POLLOUT)))
1.1 misho 433: log_write();
434: }
435:
436: void 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:
455: void 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: }
FreeBSD-CVSweb <freebsd-cvsweb@FreeBSD.org>