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