VILLASnode/common/lib/log.cpp

/** Logging and debugging routines
 *
 * @author Steffen Vogel <post@steffenvogel.de>
 * @copyright 2014-2022, Institute for Automation of Complex Power Systems, EONERC
 * @license Apache License 2.0
 *********************************************************************************/

#include <list>
#include <algorithm>
#include <map>

#include <fnmatch.h>

#include <spdlog/sinks/syslog_sink.h>
#include <spdlog/sinks/basic_file_sink.h>

#include <villas/log.hpp>
#include <villas/terminal.hpp>
#include <villas/exceptions.hpp>

using namespace villas;

/** The global log instance */
Log villas::logging;

static std::map<spdlog::level::level_enum, std::string> levelNames = {
		{ spdlog::level::trace,		"trc" },
		{ spdlog::level::debug,		"dbg" },
		{ spdlog::level::info,		"info"  },
		{ spdlog::level::warn,		"warn"  },
		{ spdlog::level::err,		"err" },
		{ spdlog::level::critical,	"crit"  },
		{ spdlog::level::off,		"off"   }
	};

class CustomLevelFlag : public spdlog::custom_flag_formatter {

public:
	void format(const spdlog::details::log_msg &msg, const std::tm &, spdlog::memory_buf_t &dest) override
	{
		auto lvl = levelNames[msg.level];
		auto lvlpad = std::string(padinfo_.width_ - lvl.size(), ' ') + lvl;
		dest.append(lvlpad.data(), lvlpad.data() + lvlpad.size());
	}

	spdlog::details::padding_info get_padding_info()
	{
		return padinfo_;
	}

	std::unique_ptr<custom_flag_formatter> clone() const override
	{
		return spdlog::details::make_unique<CustomLevelFlag>();
	}
};

Log::Log(Level lvl) :
	level(lvl),
	pattern("%H:%M:%S %^%-4t%$ %-16n %v")
{
	char *p = getenv("VILLAS_LOG_PREFIX");

	sinks = std::make_shared<DistSink::element_type>();

	setLevel(level);
	setFormatter(pattern, p ? p : "");

	// Default sink
	sink = std::make_shared<spdlog::sinks::stderr_color_sink_mt>();

	sinks->add_sink(sink);
}

int Log::getWidth()
{
	int width = Terminal::getCols() - 50;

	if (!prefix.empty())
		width -= prefix.length();

	return width;
}

Logger Log::get(const std::string &name)
{
	Logger logger = spdlog::get(name);

	if (not logger) {
		logger = std::make_shared<Logger::element_type>(name, sink);

		logger->set_level(level);
		logger->set_formatter(formatter->clone());

		for (auto &expr : expressions) {
			int flags = 0;
#ifdef FNM_EXTMATCH
			// musl-libc doesnt support this flag yet
			flags |= FNM_EXTMATCH;
#endif
			if (!fnmatch(expr.name.c_str(), name.c_str(), flags))
				logger->set_level(expr.level);
		}

		spdlog::register_logger(logger);
	}

	return logger;
}

void Log::parse(json_t *json)
{
	const char *level = nullptr;
	const char *path = nullptr;
	const char *pattern = nullptr;

	int ret, syslog = 0;

	json_error_t err;
	json_t *json_expressions = nullptr;

	ret = json_unpack_ex(json, &err, JSON_STRICT, "{ s?: s, s?: s, s?: o, s?: b, s?: s }",
		"level", &level,
		"file", &path,
		"expressions", &json_expressions,
		"syslog", &syslog,
		"pattern", &pattern
	);
	if (ret)
		throw ConfigError(json, err, "node-config-logging");

	if (level)
		setLevel(level);

	if (path) {
		auto sink = std::make_shared<spdlog::sinks::basic_file_sink_mt>(path);

		sinks->add_sink(sink);
	}

	if (syslog) {
#if SPDLOG_VERSION >= 10400
		auto sink = std::make_shared<spdlog::sinks::syslog_sink_mt>("villas", LOG_PID, LOG_DAEMON, true);
#else
		auto sink = std::make_shared<spdlog::sinks::syslog_sink_mt>("villas", LOG_PID, LOG_DAEMON);
#endif
		sinks->add_sink(sink);
	}

	if (json_expressions) {
		if (!json_is_array(json_expressions))
			throw ConfigError(json_expressions, "node-config-logging-expressions", "The 'expressions' setting must be a list of objects.");

		size_t i;
		json_t *json_expression;

		// cppcheck-suppress unknownMacro
		json_array_foreach(json_expressions, i, json_expression)
			expressions.emplace_back(json_expression);
	}
}

void Log::setFormatter(const std::string &pat, const std::string &pfx)
{
	pattern = pat;
	prefix = pfx;

	formatter = std::make_shared<spdlog::pattern_formatter>(spdlog::pattern_time_type::utc);
	formatter->add_flag<CustomLevelFlag>('t');
	formatter->set_pattern(prefix + pattern);

	spdlog::set_formatter(formatter->clone());
	sinks->set_formatter(formatter->clone());
}

void Log::setLevel(Level lvl)
{
	level = lvl;

	spdlog::set_level(lvl);
	sinks->set_level(lvl);
}

void Log::setLevel(const std::string &lvl)
{
	auto l = SPDLOG_LEVEL_NAMES;

	auto it = std::find(l.begin(), l.end(), lvl);
	if (it == l.end())
		throw RuntimeError("Invalid log level {}", lvl);

	setLevel(spdlog::level::from_str(lvl));
}

Log::Level Log::getLevel() const
{
	return level;
}

std::string Log::getLevelName() const
{
	auto sv = spdlog::level::to_string_view(level);

	return std::string(sv.data());
}

Log::Expression::Expression(json_t *json)
{
	int ret;

	const char *nme;
	const char *lvl;

	json_error_t err;

	ret = json_unpack_ex(json, &err, JSON_STRICT, "{ s: s, s: s }",
		"name", &nme,
		"level", &lvl
	);
	if (ret)
		throw ConfigError(json, err, "node-config-logging-expressions");

	level = spdlog::level::from_str(lvl);
	name = nme;
}