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