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
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() */
36static int log_fac = LOG_DAEMON;
37static int log_stderr = 0;
38static int log_fd = -1;
39static int log_to_file = 0;
40static int entries_alloced = 0;
41static int entries_lost = 0;
42static int connection_good = 1;
43static int max_logs = 0;
44static int connection_type = SOCK_DGRAM;
45
46struct 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
53static struct log_entry *entries = NULL;
54static struct log_entry *free_entries = NULL;
55
56
57int 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
104int 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
117#if defined(HAVE_SOLARIS_NETWORK) || defined(__ANDROID__)
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
139static 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
147static 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*/
259void 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 = "";
268#ifdef __ANDROID__
269  int alog_lvl;
270#endif
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
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
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	}
393    }
394#endif
395}
396
397void 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
406void check_log_writer(fd_set *set)
407{
408  if (log_fd != -1 && (!set || FD_ISSET(log_fd, set)))
409    log_write();
410}
411
412void 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
425void 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}
442