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