Coverage Report

Created: 2023-03-26 06:08

/src/unbound/util/log.c
Line
Count
Source (jump to first uncovered line)
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
8.88k
{
88
8.88k
  FILE *f;
89
8.88k
  if(!key_created) {
90
2
    key_created = 1;
91
2
    ub_thread_key_create(&logkey, NULL);
92
2
    lock_basic_init(&log_lock);
93
2
  }
94
8.88k
  lock_basic_lock(&log_lock);
95
8.88k
  if(logfile 
96
8.88k
#if defined(HAVE_SYSLOG_H) || defined(UB_ON_WINDOWS)
97
8.88k
  || logging_to_syslog
98
8.88k
#endif
99
8.88k
  ) {
100
8.88k
    lock_basic_unlock(&log_lock); /* verbose() needs the lock */
101
8.88k
    verbose(VERB_QUERY, "switching log to %s", 
102
8.88k
      use_syslog?"syslog":(filename&&filename[0]?filename:"stderr"));
103
8.88k
    lock_basic_lock(&log_lock);
104
8.88k
  }
105
8.88k
  if(logfile && logfile != stderr) {
106
8.88k
    FILE* cl = logfile;
107
8.88k
    logfile = NULL; /* set to NULL before it is closed, so that
108
      other threads have a valid logfile or NULL */
109
8.88k
    fclose(cl);
110
8.88k
  }
111
8.88k
#ifdef HAVE_SYSLOG_H
112
8.88k
  if(logging_to_syslog) {
113
0
    closelog();
114
0
    logging_to_syslog = 0;
115
0
  }
116
8.88k
  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
0
    openlog(ident, LOG_NDELAY, UB_SYSLOG_FACILITY);
122
0
    logging_to_syslog = 1;
123
0
    lock_basic_unlock(&log_lock);
124
0
    return;
125
0
  }
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
8.88k
  if(!filename || !filename[0]) {
137
0
    logfile = stderr;
138
0
    lock_basic_unlock(&log_lock);
139
0
    return;
140
0
  }
141
  /* open the file for logging */
142
8.88k
  if(chrootdir && chrootdir[0] && strncmp(filename, chrootdir,
143
0
    strlen(chrootdir)) == 0) 
144
0
    filename += strlen(chrootdir);
145
8.88k
  f = fopen(filename, "a");
146
8.88k
  if(!f) {
147
0
    lock_basic_unlock(&log_lock);
148
0
    log_err("Could not open logfile %s: %s", filename, 
149
0
      strerror(errno));
150
0
    return;
151
0
  }
152
8.88k
#ifndef UB_ON_WINDOWS
153
  /* line buffering does not work on windows */
154
8.88k
  setvbuf(f, NULL, (int)_IOLBF, 0);
155
8.88k
#endif
156
8.88k
  logfile = f;
157
8.88k
  lock_basic_unlock(&log_lock);
158
8.88k
}
159
160
void log_file(FILE *f)
161
0
{
162
0
  lock_basic_lock(&log_lock);
163
0
  logfile = f;
164
0
  lock_basic_unlock(&log_lock);
165
0
}
166
167
void log_thread_set(int* num)
168
0
{
169
0
  ub_thread_key_set(logkey, num);
170
0
}
171
172
int log_thread_get(void)
173
0
{
174
0
  unsigned int* tid;
175
0
  if(!key_created) return 0;
176
0
  tid = (unsigned int*)ub_thread_key_get(logkey);
177
0
  return (int)(tid?*tid:0);
178
0
}
179
180
void log_ident_set(const char* id)
181
0
{
182
0
  ident = id;
183
0
}
184
185
void log_ident_set_default(const char* id)
186
0
{
187
0
  default_ident = id;
188
0
}
189
190
void log_ident_revert_to_default()
191
0
{
192
0
  ident = default_ident;
193
0
}
194
195
void log_ident_set_or_default(const char* identity)
196
0
{
197
0
  if(identity == NULL || identity[0] == 0)
198
0
    log_ident_set(default_ident);
199
0
  else
200
0
    log_ident_set(identity);
201
0
}
202
203
void log_set_time_asc(int use_asc)
204
0
{
205
0
  log_time_asc = use_asc;
206
0
}
207
208
void* log_get_lock(void)
209
0
{
210
0
  if(!key_created)
211
0
    return NULL;
212
0
#ifndef THREADS_DISABLED
213
0
  return (void*)&log_lock;
214
#else
215
  return NULL;
216
#endif
217
0
}
218
219
void
220
log_vmsg(int pri, const char* type,
221
  const char *format, va_list args)
222
0
{
223
0
  char message[MAXSYSLOGMSGLEN];
224
0
  unsigned int* tid = (unsigned int*)ub_thread_key_get(logkey);
225
0
  time_t now;
226
0
#if defined(HAVE_STRFTIME) && defined(HAVE_LOCALTIME_R) 
227
0
  char tmbuf[32];
228
0
  struct tm tm;
229
#elif defined(UB_ON_WINDOWS)
230
  char tmbuf[128], dtbuf[128];
231
#endif
232
0
  (void)pri;
233
0
  vsnprintf(message, sizeof(message), format, args);
234
0
#ifdef HAVE_SYSLOG_H
235
0
  if(logging_to_syslog) {
236
0
    syslog(pri, "[%d:%x] %s: %s", 
237
0
      (int)getpid(), tid?*tid:0, type, message);
238
0
    return;
239
0
  }
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
0
  lock_basic_lock(&log_lock);
268
0
  if(!logfile) {
269
0
    lock_basic_unlock(&log_lock);
270
0
    return;
271
0
  }
272
0
  now = (time_t)time(NULL);
273
0
#if defined(HAVE_STRFTIME) && defined(HAVE_LOCALTIME_R) 
274
0
  if(log_time_asc && strftime(tmbuf, sizeof(tmbuf), "%b %d %H:%M:%S",
275
0
    localtime_r(&now, &tm))%(sizeof(tmbuf)) != 0) {
276
    /* %sizeof buf!=0 because old strftime returned max on error */
277
0
    fprintf(logfile, "%s %s[%d:%x] %s: %s\n", tmbuf, 
278
0
      ident, (int)getpid(), tid?*tid:0, type, message);
279
0
  } 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
0
  fprintf(logfile, "[" ARG_LL "d] %s[%d:%x] %s: %s\n", (long long)now, 
289
0
    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
0
  lock_basic_unlock(&log_lock);
295
0
}
296
297
/**
298
 * implementation of log_info
299
 * @param format: format string printf-style.
300
 */
301
void
302
log_info(const char *format, ...)
303
0
{
304
0
        va_list args;
305
0
  va_start(args, format);
306
0
  log_vmsg(LOG_INFO, "info", format, args);
307
0
  va_end(args);
308
0
}
309
310
/**
311
 * implementation of log_err
312
 * @param format: format string printf-style.
313
 */
314
void
315
log_err(const char *format, ...)
316
0
{
317
0
        va_list args;
318
0
  va_start(args, format);
319
0
  log_vmsg(LOG_ERR, "error", format, args);
320
0
  va_end(args);
321
0
}
322
323
/**
324
 * implementation of log_warn
325
 * @param format: format string printf-style.
326
 */
327
void
328
log_warn(const char *format, ...)
329
0
{
330
0
        va_list args;
331
0
  va_start(args, format);
332
0
  log_vmsg(LOG_WARNING, "warning", format, args);
333
0
  va_end(args);
334
0
}
335
336
/**
337
 * implementation of fatal_exit
338
 * @param format: format string printf-style.
339
 */
340
void
341
fatal_exit(const char *format, ...)
342
0
{
343
0
        va_list args;
344
0
  va_start(args, format);
345
0
  log_vmsg(LOG_CRIT, "fatal error", format, args);
346
0
  va_end(args);
347
0
  exit(1);
348
0
}
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
13.8k
{
358
13.8k
        va_list args;
359
13.8k
  va_start(args, format);
360
13.8k
  if(verbosity >= level) {
361
0
    if(level == VERB_OPS)
362
0
      log_vmsg(LOG_NOTICE, "notice", format, args);
363
0
    else if(level == VERB_DETAIL)
364
0
      log_vmsg(LOG_INFO, "info", format, args);
365
0
    else  log_vmsg(LOG_DEBUG, "debug", format, args);
366
0
  }
367
13.8k
  va_end(args);
368
13.8k
}
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
0
{
374
0
  size_t i, j;
375
0
  uint8_t* data8 = (uint8_t*)data;
376
0
  const char* hexchar = "0123456789ABCDEF";
377
0
  char buf[1024+1]; /* alloc blocksize hex chars + \0 */
378
0
  const size_t blocksize = 512;
379
0
  size_t len;
380
381
0
  if(length == 0) {
382
0
    verbose(v, "%s[%u]", msg, (unsigned)length);
383
0
    return;
384
0
  }
385
386
0
  for(i=0; i<length; i+=blocksize/2) {
387
0
    len = blocksize/2;
388
0
    if(length - i < blocksize/2)
389
0
      len = length - i;
390
0
    for(j=0; j<len; j++) {
391
0
      buf[j*2] = hexchar[ data8[i+j] >> 4 ];
392
0
      buf[j*2 + 1] = hexchar[ data8[i+j] & 0xF ];
393
0
    }
394
0
    buf[len*2] = 0;
395
0
    verbose(v, "%s[%u:%u] %.*s", msg, (unsigned)length, 
396
0
      (unsigned)i, (int)len*2, buf);
397
0
  }
398
0
}
399
400
void 
401
log_hex(const char* msg, void* data, size_t length)
402
0
{
403
0
  log_hex_f(verbosity, msg, data, length);
404
0
}
405
406
void
407
log_query(const char *format, ...)
408
0
{
409
0
  va_list args;
410
0
  va_start(args, format);
411
0
  log_vmsg(LOG_INFO, "query", format, args);
412
0
  va_end(args);
413
0
}
414
415
void
416
log_reply(const char *format, ...)
417
0
{
418
0
  va_list args;
419
0
  va_start(args, format);
420
0
  log_vmsg(LOG_INFO, "reply", format, args);
421
0
  va_end(args);
422
0
}
423
424
void log_buf(enum verbosity_value level, const char* msg, sldns_buffer* buf)
425
0
{
426
0
  if(verbosity < level)
427
0
    return;
428
0
  log_hex_f(level, msg, sldns_buffer_begin(buf), sldns_buffer_limit(buf));
429
0
}
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 */