log.c 12.1 KB
Newer Older
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16
/*  Copyright (C) 2011 CZ.NIC, z.s.p.o. <knot-dns@labs.nic.cz>

    This program is free software: you can redistribute it and/or modify
    it under the terms of the GNU General Public License as published by
    the Free Software Foundation, either version 3 of the License, or
    (at your option) any later version.

    This program is distributed in the hope that it will be useful,
    but WITHOUT ANY WARRANTY; without even the implied warranty of
    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
    GNU General Public License for more details.

    You should have received a copy of the GNU General Public License
    along with this program.  If not, see <http://www.gnu.org/licenses/>.
 */

17 18
#include <stdarg.h>
#include <stdio.h>
19 20
#include <string.h>
#include <stdlib.h>
21 22
#include <unistd.h>
#include <sys/time.h>
23
#include <time.h>
24
#include <urcu.h>
25

Jan Včelák's avatar
Jan Včelák committed
26 27 28
#ifdef ENABLE_SYSTEMD
#define SD_JOURNAL_SUPPRESS_LOCATION 1
#include <systemd/sd-journal.h>
29
#include <systemd/sd-daemon.h>
Jan Včelák's avatar
Jan Včelák committed
30 31
#endif

32
#include "knot/common/log.h"
33
#include "libknot/libknot.h"
34
#include "contrib/macros.h"
35
#include "contrib/openbsd/strlcpy.h"
36
#include "contrib/ucw/lists.h"
37

38 39 40
/* Single log message buffer length (one line). */
#define LOG_BUFLEN 512

41 42
#define LOG_NULL_ZONE_STRING "?"

43
/*! Log source table. */
44 45 46 47
struct log_sink
{
	uint8_t *facility;     /* Log sinks. */
	size_t facility_count; /* Sink count. */
Daniel Salzman's avatar
Daniel Salzman committed
48
	FILE **file;           /* Open files. */
49
	ssize_t file_count;    /* Nr of open files. */
Daniel Salzman's avatar
Daniel Salzman committed
50
	logflag_t flags;       /* Formatting flags. */
51
};
52

53 54
/*! Log sink singleton. */
struct log_sink *s_log = NULL;
55

56 57 58 59
#ifdef ENABLE_SYSTEMD
int use_journal = 0;
#endif

60
#define facility_at(s, i) (s->facility + ((i) << LOG_SRC_BITS))
61 62 63
#define facility_next(f) (f) += (1 << LOG_SRC_BITS)
#define facility_levels(f, i) *((f) + (i))

64 65
/*! \brief Close open files and free given sink. */
static void sink_free(struct log_sink *log)
66
{
67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90
	if (log == NULL) {
		return;
	}

	/* Close open logfiles. */
	for (int i = 0; i < log->file_count; ++i) {
		fclose(log->file[i]);
	}
	free(log->facility);
	free(log->file);
	free(log);
}

/*!
 * \brief Create logging facilities respecting their
 *        canonical order.
 *
 * Facilities ordering: Syslog, Stderr, Stdout, File0...
 */
static struct log_sink *sink_setup(unsigned logfiles)
{
	struct log_sink *log = malloc(sizeof(struct log_sink));
	if (log == NULL) {
		return NULL;
91 92
	}

93 94 95
	/* Ensure minimum facilities count. */
	int facilities = LOGT_FILE + logfiles;

96
	/* Reserve space for facilities. */
97 98 99 100 101 102
	memset(log, 0, sizeof(struct log_sink));
	log->facility_count = facilities << LOG_SRC_BITS;
	log->facility = malloc(log->facility_count);
	if (!log->facility) {
		free(log);
		return NULL;
103
	}
104
	memset(log->facility, 0, log->facility_count);
105 106

	/* Reserve space for logfiles. */
107
	if (logfiles > 0) {
108 109 110 111 112
		log->file = malloc(sizeof(FILE*) * logfiles);
		if (!log->file) {
			free(log->facility);
			free(log);
			return NULL;
113
		}
114
		memset(log->file, 0, sizeof(FILE*) * logfiles);
115 116
	}

117
	return log;
118 119
}

120 121 122
/*! \brief Publish new log sink and free the replaced. */
static void sink_publish(struct log_sink *log)
{
123 124
	struct log_sink **current_log = &s_log;
	struct log_sink *old_log = rcu_xchg_pointer(current_log, log);
125 126 127
	synchronize_rcu();
	sink_free(old_log);
}
128

129 130 131
static uint8_t sink_levels(struct log_sink *log, int facility, logsrc_t src)
{
	assert(log);
132

133
	// Check facility
134
	if (unlikely(log->facility_count == 0 || facility >= log->facility_count)) {
135 136 137 138 139 140 141
		return 0;
	}

	return *(log->facility + (facility << LOG_SRC_BITS) + src);
}

static int sink_levels_set(struct log_sink *log, int facility, logsrc_t src, uint8_t levels)
142
{
143
	// Check facility
144
	if (unlikely(log->facility_count == 0 || facility >= log->facility_count)) {
145 146
		return KNOT_EINVAL;
	}
147

148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164
	// Get facility pointer from offset
	uint8_t *lp = log->facility + (facility << LOG_SRC_BITS);

	// Assign level if not multimask
	if (src != LOG_ANY) {
		*(lp + src) = levels;
	} else {
		// Any == set to all sources
		for (int i = 0; i <= LOG_ANY; ++i) {
			*(lp + i) = levels;
		}
	}

	return KNOT_EOK;
}

static int sink_levels_add(struct log_sink *log, int facility, logsrc_t src, uint8_t levels)
165
{
166 167 168
	uint8_t new_levels = sink_levels(log, facility, src) | levels;
	return sink_levels_set(log, facility, src, new_levels);
}
169

170 171
int log_init()
{
172
	/* Setup initial state. */
Marek Vavrusa's avatar
Marek Vavrusa committed
173
	int ret = KNOT_EOK;
174 175
	int emask = LOG_MASK(LOG_CRIT) | LOG_MASK(LOG_ERR) | LOG_MASK(LOG_WARNING);
	int imask = LOG_MASK(LOG_NOTICE) | LOG_MASK(LOG_INFO) | LOG_MASK(LOG_DEBUG);
176

177 178 179 180 181 182
	/* Publish base log sink. */
	struct log_sink *log = sink_setup(0);
	if (log == NULL) {
		return KNOT_EINVAL;
	}

183 184 185 186
#ifdef ENABLE_SYSTEMD
	/* Should only use the journal if system was booted with systemd */
	use_journal = sd_booted();
#endif
187 188 189 190
	sink_levels_set(log, LOGT_SYSLOG, LOG_ANY, emask);
	sink_levels_set(log, LOGT_STDERR, LOG_ANY, emask);
	sink_levels_set(log, LOGT_STDOUT, LOG_ANY, imask);
	sink_publish(log);
191

192
	setlogmask(LOG_UPTO(LOG_DEBUG));
193
	openlog(PACKAGE_NAME, LOG_PID, LOG_DAEMON);
194
	return ret;
195 196
}

197
void log_close()
198
{
199
	sink_publish(NULL);
200 201 202 203

	fflush(stdout);
	fflush(stderr);

204
	closelog();
205 206
}

207
bool log_isopen()
208
{
209
	return s_log != NULL;
210 211
}

Daniel Salzman's avatar
Daniel Salzman committed
212 213 214 215 216
void log_flag_set(logflag_t flag)
{
	s_log->flags |= flag;
}

217 218
/*! \brief Open file as a logging facility. */
static int log_open_file(struct log_sink *log, const char* filename)
219 220
{
	// Check facility
221
	if (unlikely(log->facility_count  == 0 ||
Marek Vavruša's avatar
Marek Vavruša committed
222
	                  LOGT_FILE + log->file_count >= log->facility_count)) {
Marek Vavrusa's avatar
Marek Vavrusa committed
223
		return KNOT_ERROR;
224 225 226
	}

	// Open file
227 228
	log->file[log->file_count] = fopen(filename, "a");
	if (!log->file[log->file_count]) {
Marek Vavrusa's avatar
Marek Vavrusa committed
229
		return KNOT_EINVAL;
230 231
	}

232
	// Disable buffering
233
	setvbuf(log->file[log->file_count], (char *)0, _IONBF, 0);
234

235
	return LOGT_FILE + log->file_count++;
236 237 238 239
}

uint8_t log_levels(int facility, logsrc_t src)
{
240
	return sink_levels(s_log, facility, src);
241 242 243 244
}

int log_levels_set(int facility, logsrc_t src, uint8_t levels)
{
245
	return sink_levels_set(s_log, facility, src, levels);
246 247 248 249
}

int log_levels_add(int facility, logsrc_t src, uint8_t levels)
{
250
	return sink_levels_add(s_log, facility, src, levels);
251 252
}

Jan Včelák's avatar
Jan Včelák committed
253
static int emit_log_msg(int level, const char *zone, size_t zone_len, const char *msg)
254
{
255 256
	rcu_read_lock();
	struct log_sink *log = s_log;
257
	if(!log_isopen()) {
258
		rcu_read_unlock();
Marek Vavrusa's avatar
Marek Vavrusa committed
259
		return KNOT_ERROR;
260 261 262
	}

	int ret = 0;
263
	uint8_t *f = facility_at(log, LOGT_SYSLOG);
Jan Včelák's avatar
Jan Včelák committed
264
	logsrc_t src = zone ? LOG_ZONE : LOG_SERVER;
265 266

	// Syslog
267
	if (facility_levels(f, src) & LOG_MASK(level)) {
Jan Včelák's avatar
Jan Včelák committed
268
#ifdef ENABLE_SYSTEMD
269 270 271 272 273 274 275
		if (use_journal) {
			char *zone_fmt = zone ? "ZONE=%.*s" : NULL;
			sd_journal_send("PRIORITY=%d", level,
			                "MESSAGE=%s", msg,
			                zone_fmt, zone_len, zone,
			                NULL);
		} else
Jan Včelák's avatar
Jan Včelák committed
276
#endif
277 278 279
		{
			syslog(level, "%s", msg);
		}
280
		ret = 1; // To prevent considering the message as ignored.
281 282
	}

283 284
	// Convert level to mask
	level = LOG_MASK(level);
285

286
	/* Prefix date and time. */
Daniel Salzman's avatar
Daniel Salzman committed
287 288 289 290 291 292 293 294 295
	char tstr[LOG_BUFLEN] = { 0 };
	if (!log_isopen() || !(s_log->flags & LOG_FNO_TIMESTAMP)) {
		struct tm lt;
		struct timeval tv;
		gettimeofday(&tv, NULL);
		time_t sec = tv.tv_sec;
		if (localtime_r(&sec, &lt) != NULL) {
			strftime(tstr, sizeof(tstr), KNOT_LOG_TIME_FORMAT " ", &lt);
		}
296
	}
297

298
	// Log streams
299
	for (int i = LOGT_STDERR; i < LOGT_FILE + log->file_count; ++i) {
300

301
		// Check facility levels mask
302
		f = facility_at(log, i);
303 304 305
		if (facility_levels(f, src) & level) {

			// Select stream
306
			FILE *stream;
307 308 309
			switch(i) {
			case LOGT_STDERR: stream = stderr; break;
			case LOGT_STDOUT: stream = stdout; break;
310
			default: stream = log->file[i - LOGT_FILE]; break;
311 312 313
			}

			// Print
314
			ret = fprintf(stream, "%s%s\n", tstr, msg);
315 316 317
			if (stream == stdout) {
				fflush(stream);
			}
318 319 320
		}
	}

321 322
	rcu_read_unlock();

323
	if (ret < 0) {
Marek Vavrusa's avatar
Marek Vavrusa committed
324
		return KNOT_EINVAL;
325 326
	}

327
	return ret;
328
}
329

330
static const char *level_prefix(int level)
331
{
332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354
	switch (level) {
	case LOG_DEBUG:   return "debug";
	case LOG_INFO:    return "info";
	case LOG_NOTICE:  return "notice";
	case LOG_WARNING: return "warning";
	case LOG_ERR:     return "error";
	case LOG_CRIT:    return "critical";
	default:
		return NULL;
	};
}

static int log_msg_add(char **write, size_t *capacity, const char *fmt, ...)
{
	assert(*write);
	assert(capacity);
	assert(fmt);

	va_list args;
	va_start(args, fmt);
	int written = vsnprintf(*write, *capacity, fmt, args);
	va_end(args);

355
	if (written < 0 || written >= *capacity) {
356 357 358 359 360 361 362 363 364 365 366 367 368
		return KNOT_ESPACE;
	}

	*write += written;
	*capacity -= written;

	return KNOT_EOK;
}

static int log_msg_text(int level, const char *zone, const char *fmt, va_list args)
{
	int ret;

369
	/* Buffer for log message. */
370
	char sbuf[LOG_BUFLEN];
371 372
	char *write = sbuf;
	size_t capacity = sizeof(sbuf) - 1;
373

374
	/* Prefix error level. */
Daniel Salzman's avatar
Daniel Salzman committed
375 376 377 378 379 380
	if (level != LOG_INFO || !log_isopen() || !(s_log->flags & LOG_FNO_INFO)) {
		const char *prefix = level_prefix(level);
		ret = log_msg_add(&write, &capacity, "%s: ", prefix);
		if (ret != KNOT_EOK) {
			return ret;
		}
381
	}
382

383
	/* Prefix zone name. */
Jan Včelák's avatar
Jan Včelák committed
384
	size_t zone_len = 0;
385
	if (zone) {
386
		/* Strip terminating dot (unless root zone). */
Jan Včelák's avatar
Jan Včelák committed
387 388 389
		zone_len = strlen(zone);
		if (zone_len > 1 && zone[zone_len - 1] == '.') {
			zone_len -= 1;
390 391
		}

Jan Včelák's avatar
Jan Včelák committed
392
		ret = log_msg_add(&write, &capacity, "[%.*s] ", zone_len, zone);
393 394 395
		if (ret != KNOT_EOK) {
			return ret;
		}
Marek Vavrusa's avatar
Marek Vavrusa committed
396
	}
397

398
	/* Compile log message. */
399
	ret = vsnprintf(write, capacity, fmt, args);
400

401
	/* Send to logging facilities. */
402
	if (ret >= 0) {
Jan Včelák's avatar
Jan Včelák committed
403
		ret = emit_log_msg(level, zone, zone_len, sbuf);
404 405 406 407 408
	}

	return ret;
}

409
int log_msg(int priority, const char *fmt, ...)
410
{
411 412 413 414 415 416 417 418 419 420 421
	if (!fmt) {
		return KNOT_EINVAL;
	}

	va_list args;
	va_start(args, fmt);
	int result = log_msg_text(priority, NULL, fmt, args);
	va_end(args);

	return result;
}
422

423 424 425 426
int log_msg_zone(int priority, const knot_dname_t *zone, const char *fmt, ...)
{
	va_list args;
	va_start(args, fmt);
427
	char *zone_str = knot_dname_to_str_alloc(zone);
428 429 430
	int result = log_msg_text(priority,
				  zone_str ? zone_str : LOG_NULL_ZONE_STRING,
				  fmt, args);
431
	free(zone_str);
432
	va_end(args);
433 434 435 436 437 438 439 440

	return result;
}

int log_msg_zone_str(int priority, const char *zone, const char *fmt, ...)
{
	va_list args;
	va_start(args, fmt);
441 442 443
	int result = log_msg_text(priority,
				  zone ? zone : LOG_NULL_ZONE_STRING,
				  fmt, args);
444 445 446
	va_end(args);

	return result;
447
}
Lubos Slovak's avatar
Lubos Slovak committed
448

449 450
int log_update_privileges(int uid, int gid)
{
451 452
	for (unsigned i = 0; i < s_log->file_count; ++i) {
		if (fchown(fileno(s_log->file[i]), uid, gid) < 0) {
453 454
			return KNOT_ERROR;
		}
455

456 457 458
	}
	return KNOT_EOK;
}
459

460 461 462 463 464 465 466 467 468 469 470 471 472 473 474 475
static logtype_t get_logtype(const char *logname)
{
	assert(logname);

	if (strcasecmp(logname, "syslog") == 0) {
		return LOGT_SYSLOG;
	} else if (strcasecmp(logname, "stderr") == 0) {
		return LOGT_STDERR;
	} else if (strcasecmp(logname, "stdout") == 0) {
		return LOGT_STDOUT;
	} else {
		return LOGT_FILE;
	}
}

int log_reconfigure(conf_t *conf, void *data)
476 477
{
	// Data not used
478
	UNUSED(data);
479 480

	// Use defaults if no 'log' section is configured.
481
	if (conf_id_count(conf, C_LOG) == 0) {
482 483 484 485 486 487 488
		log_close();
		log_init();
		return KNOT_EOK;
	}

	// Find maximum log facility id
	unsigned files = 0;
489 490
	for (conf_iter_t iter = conf_iter(conf, C_LOG); iter.code == KNOT_EOK;
	     conf_iter_next(conf, &iter)) {
491 492
		conf_val_t id = conf_iter_id(conf, &iter);
		if (get_logtype(conf_str(&id)) == LOGT_FILE) {
493 494 495 496 497 498 499 500 501 502 503
			++files;
		}
	}

	// Initialize logsystem
	struct log_sink *log = sink_setup(files);
	if (log == NULL) {
		return KNOT_ENOMEM;
	}

	// Setup logs
504 505
	for (conf_iter_t iter = conf_iter(conf, C_LOG); iter.code == KNOT_EOK;
	     conf_iter_next(conf, &iter)) {
506 507
		conf_val_t id = conf_iter_id(conf, &iter);
		const char *logname = conf_str(&id);
508

509 510
		// Get facility.
		int facility = get_logtype(logname);
511
		if (facility == LOGT_FILE) {
512
			facility = log_open_file(log, logname);
513
			if (facility < 0) {
Jan Včelák's avatar
Jan Včelák committed
514
				log_error("failed to open log, file '%s'",
515
				          logname);
516 517 518 519
				continue;
			}
		}

520 521
		conf_val_t level_val;
		unsigned level;
522

523 524 525 526
		// Set SERVER logging.
		level_val = conf_id_get(conf, C_LOG, C_SERVER, &id);
		level = conf_opt(&level_val);
		sink_levels_add(log, facility, LOG_SERVER, level);
527

528 529 530 531
		// Set ZONE logging.
		level_val = conf_id_get(conf, C_LOG, C_ZONE, &id);
		level = conf_opt(&level_val);
		sink_levels_add(log, facility, LOG_ZONE, level);
532

533 534 535 536
		// Set ANY logging.
		level_val = conf_id_get(conf, C_LOG, C_ANY, &id);
		level = conf_opt(&level_val);
		sink_levels_add(log, facility, LOG_ANY, level);
537 538
	}

539
	sink_publish(log);
540

541
	return KNOT_EOK;
542
}