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