xref: /spdk/lib/log/log.c (revision 0ce363bebe8ca422f8a9e2bd103dc1eaee71fb2e)

/*   SPDX-License-Identifier: BSD-3-Clause
 *   Copyright (C) 2016 Intel Corporation.
 *   All rights reserved.
 */

#include "spdk/stdinc.h"
#include "spdk/util.h"

#include "spdk/log.h"

static const char *const spdk_level_names[] = {
	[SPDK_LOG_ERROR]	= "ERROR",
	[SPDK_LOG_WARN]		= "WARNING",
	[SPDK_LOG_NOTICE]	= "NOTICE",
	[SPDK_LOG_INFO]		= "INFO",
	[SPDK_LOG_DEBUG]	= "DEBUG",
};

#define MAX_TMPBUF 1024

static struct spdk_log_opts g_log_opts = {
	.log = NULL,
	.open = NULL,
	.close = NULL,
	.user_ctx = NULL,
};
static bool g_log_timestamps = true;

enum spdk_log_level g_spdk_log_level;
enum spdk_log_level g_spdk_log_print_level;

void
spdk_log_set_level(enum spdk_log_level level)
{
	assert(level >= SPDK_LOG_DISABLED);
	assert(level <= SPDK_LOG_DEBUG);
	g_spdk_log_level = level;
}

enum spdk_log_level
spdk_log_get_level(void) {
	return g_spdk_log_level;
}

void
spdk_log_set_print_level(enum spdk_log_level level)
{
	assert(level >= SPDK_LOG_DISABLED);
	assert(level <= SPDK_LOG_DEBUG);
	g_spdk_log_print_level = level;
}

enum spdk_log_level
spdk_log_get_print_level(void) {
	return g_spdk_log_print_level;
}

static void
log_open(void *ctx)
{
	openlog("spdk", LOG_PID, LOG_LOCAL7);
}

static void
log_close(void *ctx)
{
	closelog();
}

void
spdk_log_open(spdk_log_cb *log)
{
	if (log) {
		struct spdk_log_opts opts = {.log = log};
		opts.size = SPDK_SIZEOF(&opts, log);
		spdk_log_open_ext(&opts);
	} else {
		spdk_log_open_ext(NULL);
	}
}

void
spdk_log_open_ext(struct spdk_log_opts *opts)
{
	if (!opts) {
		g_log_opts.open = log_open;
		g_log_opts.close = log_close;
		goto out;
	}

	g_log_opts.log = SPDK_GET_FIELD(opts, log, NULL);
	g_log_opts.open = SPDK_GET_FIELD(opts, open, NULL);
	g_log_opts.close = SPDK_GET_FIELD(opts, close, NULL);
	g_log_opts.user_ctx = SPDK_GET_FIELD(opts, user_ctx, NULL);

out:
	if (g_log_opts.open) {
		g_log_opts.open(g_log_opts.user_ctx);
	}
}

void
spdk_log_close(void)
{
	if (g_log_opts.close) {
		g_log_opts.close(g_log_opts.user_ctx);
	}
	memset(&g_log_opts, 0, sizeof(g_log_opts));
}

void
spdk_log_enable_timestamps(bool value)
{
	g_log_timestamps = value;
}

static void
get_timestamp_prefix(char *buf, int buf_size)
{
	struct tm *info;
	char date[24];
	struct timespec ts;
	long usec;

	if (!g_log_timestamps) {
		buf[0] = '\0';
		return;
	}

	clock_gettime(CLOCK_REALTIME, &ts);
	info = localtime(&ts.tv_sec);
	usec = ts.tv_nsec / 1000;
	if (info == NULL) {
		snprintf(buf, buf_size, "[%s.%06ld] ", "unknown date", usec);
		return;
	}

	strftime(date, sizeof(date), "%Y-%m-%d %H:%M:%S", info);
	snprintf(buf, buf_size, "[%s.%06ld] ", date, usec);
}

void
spdk_log(enum spdk_log_level level, const char *file, const int line, const char *func,
	 const char *format, ...)
{
	va_list ap;

	va_start(ap, format);
	spdk_vlog(level, file, line, func, format, ap);
	va_end(ap);
}

int
spdk_log_to_syslog_level(enum spdk_log_level level)
{
	switch (level) {
	case SPDK_LOG_DEBUG:
	case SPDK_LOG_INFO:
		return LOG_INFO;
	case SPDK_LOG_NOTICE:
		return LOG_NOTICE;
	case SPDK_LOG_WARN:
		return LOG_WARNING;
	case SPDK_LOG_ERROR:
		return LOG_ERR;
	case SPDK_LOG_DISABLED:
		return -1;
	default:
		break;
	}

	return LOG_INFO;
}

void
spdk_vlog(enum spdk_log_level level, const char *file, const int line, const char *func,
	  const char *format, va_list ap)
{
	int severity = LOG_INFO;
	char *buf, _buf[MAX_TMPBUF], *ext_buf = NULL;
	char timestamp[64];
	va_list ap_copy;
	int rc;

	if (g_log_opts.log) {
		g_log_opts.log(level, file, line, func, format, ap);
		return;
	}

	if (level > g_spdk_log_print_level && level > g_spdk_log_level) {
		return;
	}

	severity = spdk_log_to_syslog_level(level);
	if (severity < 0) {
		return;
	}

	buf = _buf;

	va_copy(ap_copy, ap);
	rc = vsnprintf(_buf, sizeof(_buf), format, ap);
	if (rc > MAX_TMPBUF) {
		/* The output including the terminating was more than MAX_TMPBUF bytes.
		 * Try allocating memory large enough to hold the output.
		 */
		rc = vasprintf(&ext_buf, format, ap_copy);
		if (rc < 0) {
			/* Failed to allocate memory. Allow output to be truncated. */
		} else {
			buf = ext_buf;
		}
	}
	va_end(ap_copy);

	if (level <= g_spdk_log_print_level) {
		get_timestamp_prefix(timestamp, sizeof(timestamp));
		if (file) {
			fprintf(stderr, "%s%s:%4d:%s: *%s*: %s", timestamp, file, line, func, spdk_level_names[level], buf);
		} else {
			fprintf(stderr, "%s%s", timestamp, buf);
		}
	}

	if (level <= g_spdk_log_level) {
		if (file) {
			syslog(severity, "%s:%4d:%s: *%s*: %s", file, line, func, spdk_level_names[level], buf);
		} else {
			syslog(severity, "%s", buf);
		}
	}

	free(ext_buf);
}

void
spdk_vflog(FILE *fp, const char *file, const int line, const char *func,
	   const char *format, va_list ap)
{
	char buf[MAX_TMPBUF];
	char timestamp[64];

	vsnprintf(buf, sizeof(buf), format, ap);

	get_timestamp_prefix(timestamp, sizeof(timestamp));

	if (file) {
		fprintf(fp, "%s%s:%4d:%s: %s", timestamp, file, line, func, buf);
	} else {
		fprintf(fp, "%s%s", timestamp, buf);
	}

	fflush(fp);
}

void
spdk_flog(FILE *fp, const char *file, const int line, const char *func,
	  const char *format, ...)
{
	va_list ap;

	va_start(ap, format);
	spdk_vflog(fp, file, line, func, format, ap);
	va_end(ap);
}

static void
fdump(FILE *fp, const char *label, const uint8_t *buf, size_t len)
{
	char tmpbuf[MAX_TMPBUF];
	char buf16[16 + 1];
	size_t total;
	unsigned int idx;

	fprintf(fp, "%s\n", label);

	memset(buf16, 0, sizeof buf16);
	total = 0;
	for (idx = 0; idx < len; idx++) {
		if (idx != 0 && idx % 16 == 0) {
			snprintf(tmpbuf + total, sizeof tmpbuf - total,
				 " %s", buf16);
			memset(buf16, 0, sizeof buf16);
			fprintf(fp, "%s\n", tmpbuf);
			total = 0;
		}
		if (idx % 16 == 0) {
			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
					  "%08x ", idx);
		}
		if (idx % 8 == 0) {
			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
					  "%s", " ");
		}
		total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
				  "%2.2x ", buf[idx] & 0xff);
		buf16[idx % 16] = isprint(buf[idx]) ? buf[idx] : '.';
	}
	for (; idx % 16 != 0; idx++) {
		if (idx == 8) {
			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
					  " ");
		}

		total += snprintf(tmpbuf + total, sizeof tmpbuf - total, "   ");
	}
	snprintf(tmpbuf + total, sizeof tmpbuf - total, "  %s", buf16);
	fprintf(fp, "%s\n", tmpbuf);
	fflush(fp);
}

void
spdk_log_dump(FILE *fp, const char *label, const void *buf, size_t len)
{
	fdump(fp, label, buf, len);
}