contrib/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 #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
  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
 160 void log_file(FILE *f)
 161 {
 162         lock_basic_lock(&log_lock);
 163         logfile = f;
 164         lock_basic_unlock(&log_lock);
 165 }
 166
 167 void log_thread_set(int* num)
 168 {
 169         ub_thread_key_set(logkey, num);
 170 }
 171
 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
 180 void log_ident_set(const char* id)
 181 {
 182         ident = id;
 183 }
 184
 185 void log_ident_set_default(const char* id)
 186 {
 187         default_ident = id;
 188 }
 189
 190 void log_ident_revert_to_default()
 191 {
 192         ident = default_ident;
 193 }
 194
 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
 203 void log_set_time_asc(int use_asc)
 204 {
 205         log_time_asc = use_asc;
 206 }
 207
 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
 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
 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
 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
 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
 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
 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
 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
 401 log_hex(const char* msg, void* data, size_t length)
 402 {
 403         log_hex_f(verbosity, msg, data, length);
 404 }
 405
 406 void
 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
 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
 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
 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 */