unbound/util/log.c

1 /*
2 * util/log.c - implementation of the log code
3 *
4 * Copyright (c) 2007, NLnet Labs. All rights reserved.
5 *
6 * This software is open source.
7 *
8 * Redistribution and use in source and binary forms, with or without
9 * modification, are permitted provided that the following conditions
10 * are met:
11 *
12 * Redistributions of source code must retain the above copyright notice,
13 * this list of conditions and the following disclaimer.
14 *
15 * Redistributions in binary form must reproduce the above copyright notice,
16 * this list of conditions and the following disclaimer in the documentation
17 * and/or other materials provided with the distribution.
18 *
19 * Neither the name of the NLNET LABS nor the names of its contributors may
20 * be used to endorse or promote products derived from this software without
21 * specific prior written permission.
22 *
23 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
24 * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
25 * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
26 * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
27 * HOLDER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
28 * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED
29 * TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
30 * PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
31 * LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
32 * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
33 * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
34 */
35 /**
36 * \file
37 * Implementation of log.h.
38 */
39
40#include "config.h"
41#include "util/log.h"
42#include "util/locks.h"
43#include "sldns/sbuffer.h"
44#include <stdarg.h>
45#ifdef HAVE_TIME_H
46#include <time.h>
47#endif
48#include <sys/time.h>
49#ifdef HAVE_SYSLOG_H
50# include <syslog.h>
51#else
52 /**define LOG_ constants */
53# define LOG_CRIT 2
54# define LOG_ERR 3
55# define LOG_WARNING 4
56# define LOG_NOTICE 5
57# define LOG_INFO 6
58# define LOG_DEBUG 7
59#endif
60#ifdef UB_ON_WINDOWS
61# include "winrc/win_svc.h"
62#endif
63
64 /* default verbosity */
65 enum verbosity_value verbosity = NO_VERBOSE;
66 /** the file logged to. */
67 static FILE* logfile = 0;
68 /** if key has been created */
69 static int key_created = 0;
70 /** pthread key for thread ids in logfile */
71 static ub_thread_key_type logkey;
72#ifndef THREADS_DISABLED
73 /** pthread mutex to protect FILE* */
74 static lock_basic_type log_lock;
75#endif
76 /** the identity of this executable/process */
77 static const char* ident="unbound";
78 static const char* default_ident="unbound";
79#if defined(HAVE_SYSLOG_H) || defined(UB_ON_WINDOWS)
80 /** are we using syslog(3) to log to */
81 static int logging_to_syslog = 0;
82#endif /* HAVE_SYSLOG_H */
83 /** print time in UTC or in secondsfrom1970 */
84 static int log_time_asc = 0;
85 /** print time in iso format */
86 static int log_time_iso = 0;
87
88 void
89 log_init(const char* filename, int use_syslog, const char* chrootdir)
90{
91 FILE *f;
92 if(!key_created) {
93 key_created = 1;
94 ub_thread_key_create(&logkey, NULL);
95 lock_basic_init(&log_lock);
96 }
97 lock_basic_lock(&log_lock);
98 if(logfile
99#if defined(HAVE_SYSLOG_H) || defined(UB_ON_WINDOWS)
100 || logging_to_syslog
101#endif
102 ) {
103 lock_basic_unlock(&log_lock); /* verbose() needs the lock */
104 verbose(VERB_QUERY, "switching log to %s",
105 use_syslog?"syslog":(filename&&filename[0]?filename:"stderr"));
106 lock_basic_lock(&log_lock);
107 }
108 if(logfile && logfile != stderr) {
109 FILE* cl = logfile;
110 logfile = NULL; /* set to NULL before it is closed, so that
111 other threads have a valid logfile or NULL */
112 fclose(cl);
113 }
114#ifdef HAVE_SYSLOG_H
115 if(logging_to_syslog) {
116 closelog();
117 logging_to_syslog = 0;
118 }
119 if(use_syslog) {
120 /* do not delay opening until first write, because we may
121 * chroot and no longer be able to access dev/log and so on */
122 /* the facility is LOG_DAEMON by default, but
123 * --with-syslog-facility=LOCAL[0-7] can override it */
124 openlog(ident, LOG_NDELAY, UB_SYSLOG_FACILITY);
125 logging_to_syslog = 1;
126 lock_basic_unlock(&log_lock);
127 return;
128 }
129#elif defined(UB_ON_WINDOWS)
130 if(logging_to_syslog) {
131 logging_to_syslog = 0;
132 }
133 if(use_syslog) {
134 logging_to_syslog = 1;
135 lock_basic_unlock(&log_lock);
136 return;
137 }
138#endif /* HAVE_SYSLOG_H */
139 if(!filename || !filename[0]) {
140 logfile = stderr;
141 lock_basic_unlock(&log_lock);
142 return;
143 }
144 /* open the file for logging */
145 if(chrootdir && chrootdir[0] && strncmp(filename, chrootdir,
146 strlen(chrootdir)) == 0)
147 filename += strlen(chrootdir);
148 f = fopen(filename, "a");
149 if(!f) {
150 lock_basic_unlock(&log_lock);
151 log_err("Could not open logfile %s: %s", filename,
152 strerror(errno));
153 return;
154 }
155#ifndef UB_ON_WINDOWS
156 /* line buffering does not work on windows */
157 setvbuf(f, NULL, (int)_IOLBF, 0);
158#endif
159 logfile = f;
160 lock_basic_unlock(&log_lock);
161}
162
163 void log_file(FILE *f)
164{
165 lock_basic_lock(&log_lock);
166 logfile = f;
167 lock_basic_unlock(&log_lock);
168}
169
170 void log_thread_set(int* num)
171{
172 ub_thread_key_set(logkey, num);
173}
174
175 int log_thread_get(void)
176{
177 unsigned int* tid;
178 if(!key_created) return 0;
179 tid = (unsigned int*)ub_thread_key_get(logkey);
180 return (int)(tid?*tid:0);
181}
182
183 void log_ident_set(const char* id)
184{
185 ident = id;
186}
187
188 void log_ident_set_default(const char* id)
189{
190 default_ident = id;
191}
192
193 void log_ident_revert_to_default(void)
194{
195 ident = default_ident;
196}
197
198 void log_ident_set_or_default(const char* identity)
199{
200 if(identity == NULL || identity[0] == 0)
201 log_ident_set(default_ident);
202 else
203 log_ident_set(identity);
204}
205
206 void log_set_time_asc(int use_asc)
207{
208 log_time_asc = use_asc;
209}
210
211 void log_set_time_iso(int use_iso)
212{
213 log_time_iso = use_iso;
214}
215
216 void* log_get_lock(void)
217{
218 if(!key_created)
219 return NULL;
220#ifndef THREADS_DISABLED
221 return (void*)&log_lock;
222#else
223 return NULL;
224#endif
225}
226
227 void
228 log_vmsg(int pri, const char* type,
229 const char *format, va_list args)
230{
231 char message[MAXSYSLOGMSGLEN];
232 unsigned int* tid = (unsigned int*)ub_thread_key_get(logkey);
233 time_t now;
234#if defined(HAVE_STRFTIME) && defined(HAVE_LOCALTIME_R)
235 char tmbuf[32];
236 struct tm tm;
237#elif defined(UB_ON_WINDOWS)
238 char tmbuf[128], dtbuf[128];
239#endif
240 (void)pri;
241 vsnprintf(message, sizeof(message), format, args);
242#ifdef HAVE_SYSLOG_H
243 if(logging_to_syslog) {
244 syslog(pri, "[%d:%x] %s: %s",
245 (int)getpid(), tid?*tid:0, type, message);
246 return;
247 }
248#elif defined(UB_ON_WINDOWS)
249 if(logging_to_syslog) {
250 char m[32768];
251 HANDLE* s;
252 LPCTSTR str = m;
253 DWORD tp = MSG_GENERIC_ERR;
254 WORD wt = EVENTLOG_ERROR_TYPE;
255 if(strcmp(type, "info") == 0) {
256 tp=MSG_GENERIC_INFO;
257 wt=EVENTLOG_INFORMATION_TYPE;
258 } else if(strcmp(type, "warning") == 0) {
259 tp=MSG_GENERIC_WARN;
260 wt=EVENTLOG_WARNING_TYPE;
261 } else if(strcmp(type, "notice") == 0
262 || strcmp(type, "debug") == 0) {
263 tp=MSG_GENERIC_SUCCESS;
264 wt=EVENTLOG_SUCCESS;
265 }
266 snprintf(m, sizeof(m), "[%s:%x] %s: %s",
267 ident, tid?*tid:0, type, message);
268 s = RegisterEventSource(NULL, SERVICE_NAME);
269 if(!s) return;
270 ReportEvent(s, wt, 0, tp, NULL, 1, 0, &str, NULL);
271 DeregisterEventSource(s);
272 return;
273 }
274#endif /* HAVE_SYSLOG_H */
275 lock_basic_lock(&log_lock);
276 if(!logfile) {
277 lock_basic_unlock(&log_lock);
278 return;
279 }
280#if defined(HAVE_STRFTIME) && defined(HAVE_LOCALTIME_R)
281 if(log_time_iso && log_time_asc) {
282 char tzbuf[16];
283 struct timeval tv;
284 struct tm *tm_p;
285 if(gettimeofday(&tv, NULL) < 0)
286 memset(&tv, 0, sizeof(tv));
287 now = (time_t)tv.tv_sec;
288 tm_p = localtime_r(&now, &tm);
289 strftime(tmbuf, sizeof(tmbuf), "%Y-%m-%dT%H:%M:%S", tm_p);
290 if(strftime(tzbuf, sizeof(tzbuf), "%z", tm_p) == 5) {
291 /* put ':' in "+hh:mm" */
292 tzbuf[5] = tzbuf[4];
293 tzbuf[4] = tzbuf[3];
294 tzbuf[3] = ':';
295 tzbuf[6] = 0;
296 }
297 fprintf(logfile, "%s.%3.3d%s %s[%d:%x] %s: %s\n",
298 tmbuf, (int)tv.tv_usec/1000, tzbuf,
299 ident, (int)getpid(), tid?*tid:0, type, message);
300#ifdef UB_ON_WINDOWS
301 /* line buffering does not work on windows */
302 fflush(logfile);
303#endif
304 lock_basic_unlock(&log_lock);
305 return;
306 }
307#endif /* HAVE_STRFTIME && HAVE_LOCALTIME_R */
308 now = (time_t)time(NULL);
309#if defined(HAVE_STRFTIME) && defined(HAVE_LOCALTIME_R)
310 if(log_time_asc && strftime(tmbuf, sizeof(tmbuf), "%b %d %H:%M:%S",
311 localtime_r(&now, &tm))%(sizeof(tmbuf)) != 0) {
312 /* %sizeof buf!=0 because old strftime returned max on error */
313 fprintf(logfile, "%s %s[%d:%x] %s: %s\n", tmbuf,
314 ident, (int)getpid(), tid?*tid:0, type, message);
315 } else
316#elif defined(UB_ON_WINDOWS)
317 if(log_time_asc && GetTimeFormat(LOCALE_USER_DEFAULT, 0, NULL, NULL,
318 tmbuf, sizeof(tmbuf)) && GetDateFormat(LOCALE_USER_DEFAULT, 0,
319 NULL, NULL, dtbuf, sizeof(dtbuf))) {
320 fprintf(logfile, "%s %s %s[%d:%x] %s: %s\n", dtbuf, tmbuf,
321 ident, (int)getpid(), tid?*tid:0, type, message);
322 } else
323#endif
324 fprintf(logfile, "[" ARG_LL "d] %s[%d:%x] %s: %s\n", (long long)now,
325 ident, (int)getpid(), tid?*tid:0, type, message);
326#ifdef UB_ON_WINDOWS
327 /* line buffering does not work on windows */
328 fflush(logfile);
329#endif
330 lock_basic_unlock(&log_lock);
331}
332
333 /**
334 * implementation of log_info
335 * @param format: format string printf-style.
336 */
337 void
338 log_info(const char *format, ...)
339{
340 va_list args;
341 va_start(args, format);
342 log_vmsg(LOG_INFO, "info", format, args);
343 va_end(args);
344}
345
346 /**
347 * implementation of log_err
348 * @param format: format string printf-style.
349 */
350 void
351 log_err(const char *format, ...)
352{
353 va_list args;
354 va_start(args, format);
355 log_vmsg(LOG_ERR, "error", format, args);
356 va_end(args);
357}
358
359 /**
360 * implementation of log_warn
361 * @param format: format string printf-style.
362 */
363 void
364 log_warn(const char *format, ...)
365{
366 va_list args;
367 va_start(args, format);
368 log_vmsg(LOG_WARNING, "warning", format, args);
369 va_end(args);
370}
371
372 /**
373 * implementation of fatal_exit
374 * @param format: format string printf-style.
375 */
376 void
377 fatal_exit(const char *format, ...)
378{
379 va_list args;
380 va_start(args, format);
381 log_vmsg(LOG_CRIT, "fatal error", format, args);
382 va_end(args);
383 exit(1);
384}
385
386 /**
387 * implementation of verbose
388 * @param level: verbose level for the message.
389 * @param format: format string printf-style.
390 */
391 void
392 verbose(enum verbosity_value level, const char* format, ...)
393{
394 va_list args;
395 va_start(args, format);
396 if(verbosity >= level) {
397 if(level == VERB_OPS)
398 log_vmsg(LOG_NOTICE, "notice", format, args);
399 else if(level == VERB_DETAIL)
400 log_vmsg(LOG_INFO, "info", format, args);
401 else log_vmsg(LOG_DEBUG, "debug", format, args);
402 }
403 va_end(args);
404}
405
406 /** log hex data */
407 static void
408 log_hex_f(enum verbosity_value v, const char* msg, void* data, size_t length)
409{
410 size_t i, j;
411 uint8_t* data8 = (uint8_t*)data;
412 const char* hexchar = "0123456789ABCDEF";
413 char buf[1024+1]; /* alloc blocksize hex chars + 0円 */
414 const size_t blocksize = 512;
415 size_t len;
416
417 if(length == 0) {
418 verbose(v, "%s[%u]", msg, (unsigned)length);
419 return;
420 }
421
422 for(i=0; i<length; i+=blocksize/2) {
423 len = blocksize/2;
424 if(length - i < blocksize/2)
425 len = length - i;
426 for(j=0; j<len; j++) {
427 buf[j*2] = hexchar[ data8[i+j] >> 4 ];
428 buf[j*2 + 1] = hexchar[ data8[i+j] & 0xF ];
429 }
430 buf[len*2] = 0;
431 verbose(v, "%s[%u:%u] %.*s", msg, (unsigned)length,
432 (unsigned)i, (int)len*2, buf);
433 }
434}
435
436 void
437 log_hex(const char* msg, void* data, size_t length)
438{
439 log_hex_f(verbosity, msg, data, length);
440}
441
442 void
443 log_query(const char *format, ...)
444{
445 va_list args;
446 va_start(args, format);
447 log_vmsg(LOG_INFO, "query", format, args);
448 va_end(args);
449}
450
451 void
452 log_reply(const char *format, ...)
453{
454 va_list args;
455 va_start(args, format);
456 log_vmsg(LOG_INFO, "reply", format, args);
457 va_end(args);
458}
459
460 void log_buf(enum verbosity_value level, const char* msg, sldns_buffer* buf)
461{
462 if(verbosity < level)
463 return;
464 log_hex_f(level, msg, sldns_buffer_begin(buf), sldns_buffer_limit(buf));
465}
466
467#ifdef USE_WINSOCK
468 char* wsa_strerror(DWORD err)
469{
470 static char unknown[32];
471
472 switch(err) {
473 case WSA_INVALID_HANDLE: return "Specified event object handle is invalid.";
474 case WSA_NOT_ENOUGH_MEMORY: return "Insufficient memory available.";
475 case WSA_INVALID_PARAMETER: return "One or more parameters are invalid.";
476 case WSA_OPERATION_ABORTED: return "Overlapped operation aborted.";
477 case WSA_IO_INCOMPLETE: return "Overlapped I/O event object not in signaled state.";
478 case WSA_IO_PENDING: return "Overlapped operations will complete later.";
479 case WSAEINTR: return "Interrupted function call.";
480 case WSAEBADF: return "File handle is not valid.";
481 case WSAEACCES: return "Permission denied.";
482 case WSAEFAULT: return "Bad address.";
483 case WSAEINVAL: return "Invalid argument.";
484 case WSAEMFILE: return "Too many open files.";
485 case WSAEWOULDBLOCK: return "Resource temporarily unavailable.";
486 case WSAEINPROGRESS: return "Operation now in progress.";
487 case WSAEALREADY: return "Operation already in progress.";
488 case WSAENOTSOCK: return "Socket operation on nonsocket.";
489 case WSAEDESTADDRREQ: return "Destination address required.";
490 case WSAEMSGSIZE: return "Message too long.";
491 case WSAEPROTOTYPE: return "Protocol wrong type for socket.";
492 case WSAENOPROTOOPT: return "Bad protocol option.";
493 case WSAEPROTONOSUPPORT: return "Protocol not supported.";
494 case WSAESOCKTNOSUPPORT: return "Socket type not supported.";
495 case WSAEOPNOTSUPP: return "Operation not supported.";
496 case WSAEPFNOSUPPORT: return "Protocol family not supported.";
497 case WSAEAFNOSUPPORT: return "Address family not supported by protocol family.";
498 case WSAEADDRINUSE: return "Address already in use.";
499 case WSAEADDRNOTAVAIL: return "Cannot assign requested address.";
500 case WSAENETDOWN: return "Network is down.";
501 case WSAENETUNREACH: return "Network is unreachable.";
502 case WSAENETRESET: return "Network dropped connection on reset.";
503 case WSAECONNABORTED: return "Software caused connection abort.";
504 case WSAECONNRESET: return "Connection reset by peer.";
505 case WSAENOBUFS: return "No buffer space available.";
506 case WSAEISCONN: return "Socket is already connected.";
507 case WSAENOTCONN: return "Socket is not connected.";
508 case WSAESHUTDOWN: return "Cannot send after socket shutdown.";
509 case WSAETOOMANYREFS: return "Too many references.";
510 case WSAETIMEDOUT: return "Connection timed out.";
511 case WSAECONNREFUSED: return "Connection refused.";
512 case WSAELOOP: return "Cannot translate name.";
513 case WSAENAMETOOLONG: return "Name too long.";
514 case WSAEHOSTDOWN: return "Host is down.";
515 case WSAEHOSTUNREACH: return "No route to host.";
516 case WSAENOTEMPTY: return "Directory not empty.";
517 case WSAEPROCLIM: return "Too many processes.";
518 case WSAEUSERS: return "User quota exceeded.";
519 case WSAEDQUOT: return "Disk quota exceeded.";
520 case WSAESTALE: return "Stale file handle reference.";
521 case WSAEREMOTE: return "Item is remote.";
522 case WSASYSNOTREADY: return "Network subsystem is unavailable.";
523 case WSAVERNOTSUPPORTED: return "Winsock.dll version out of range.";
524 case WSANOTINITIALISED: return "Successful WSAStartup not yet performed.";
525 case WSAEDISCON: return "Graceful shutdown in progress.";
526 case WSAENOMORE: return "No more results.";
527 case WSAECANCELLED: return "Call has been canceled.";
528 case WSAEINVALIDPROCTABLE: return "Procedure call table is invalid.";
529 case WSAEINVALIDPROVIDER: return "Service provider is invalid.";
530 case WSAEPROVIDERFAILEDINIT: return "Service provider failed to initialize.";
531 case WSASYSCALLFAILURE: return "System call failure.";
532 case WSASERVICE_NOT_FOUND: return "Service not found.";
533 case WSATYPE_NOT_FOUND: return "Class type not found.";
534 case WSA_E_NO_MORE: return "No more results.";
535 case WSA_E_CANCELLED: return "Call was canceled.";
536 case WSAEREFUSED: return "Database query was refused.";
537 case WSAHOST_NOT_FOUND: return "Host not found.";
538 case WSATRY_AGAIN: return "Nonauthoritative host not found.";
539 case WSANO_RECOVERY: return "This is a nonrecoverable error.";
540 case WSANO_DATA: return "Valid name, no data record of requested type.";
541 case WSA_QOS_RECEIVERS: return "QOS receivers.";
542 case WSA_QOS_SENDERS: return "QOS senders.";
543 case WSA_QOS_NO_SENDERS: return "No QOS senders.";
544 case WSA_QOS_NO_RECEIVERS: return "QOS no receivers.";
545 case WSA_QOS_REQUEST_CONFIRMED: return "QOS request confirmed.";
546 case WSA_QOS_ADMISSION_FAILURE: return "QOS admission error.";
547 case WSA_QOS_POLICY_FAILURE: return "QOS policy failure.";
548 case WSA_QOS_BAD_STYLE: return "QOS bad style.";
549 case WSA_QOS_BAD_OBJECT: return "QOS bad object.";
550 case WSA_QOS_TRAFFIC_CTRL_ERROR: return "QOS traffic control error.";
551 case WSA_QOS_GENERIC_ERROR: return "QOS generic error.";
552 case WSA_QOS_ESERVICETYPE: return "QOS service type error.";
553 case WSA_QOS_EFLOWSPEC: return "QOS flowspec error.";
554 case WSA_QOS_EPROVSPECBUF: return "Invalid QOS provider buffer.";
555 case WSA_QOS_EFILTERSTYLE: return "Invalid QOS filter style.";
556 case WSA_QOS_EFILTERTYPE: return "Invalid QOS filter type.";
557 case WSA_QOS_EFILTERCOUNT: return "Incorrect QOS filter count.";
558 case WSA_QOS_EOBJLENGTH: return "Invalid QOS object length.";
559 case WSA_QOS_EFLOWCOUNT: return "Incorrect QOS flow count.";
560 /*case WSA_QOS_EUNKOWNPSOBJ: return "Unrecognized QOS object.";*/
561 case WSA_QOS_EPOLICYOBJ: return "Invalid QOS policy object.";
562 case WSA_QOS_EFLOWDESC: return "Invalid QOS flow descriptor.";
563 case WSA_QOS_EPSFLOWSPEC: return "Invalid QOS provider-specific flowspec.";
564 case WSA_QOS_EPSFILTERSPEC: return "Invalid QOS provider-specific filterspec.";
565 case WSA_QOS_ESDMODEOBJ: return "Invalid QOS shape discard mode object.";
566 case WSA_QOS_ESHAPERATEOBJ: return "Invalid QOS shaping rate object.";
567 case WSA_QOS_RESERVED_PETYPE: return "Reserved policy QOS element type.";
568 default:
569 snprintf(unknown, sizeof(unknown),
570 "unknown WSA error code %d", (int)err);
571 return unknown;
572 }
573}
574#endif /* USE_WINSOCK */
575