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, *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