file-logger: Add option to log messages as JSON objects

Closes strongswan/strongswan#2222
This commit is contained in:
Tobias Brunner 2024-04-25 17:09:48 +02:00
parent c87aae300a
commit a2fba6db4a
5 changed files with 110 additions and 53 deletions

View File

@ -26,8 +26,18 @@ charon.filelog.<name>.flush_line = no
Enabling this option disables block buffering and enables line buffering.
charon.filelog.<name>.ike_name = no
Prefix each log entry with the connection name and a unique numerical
identifier for each IKE_SA.
Add the connection name and a unique numerical identifier for the current
IKE_SA to each log entry if available.
charon.filelog.<name>.json = no
If enabled, each log entry is written to the file as a JSON object.
Enables writing each log entry as a JSON object to the file. The properties
are "time" (if `time_format` is set), "thread", "group", "level" and "msg".
Newlines, double quotes and backslashes are escaped in the latter. If
`ike_name` is enabled, "ikesa-uniqueid" and "ikesa-name" are added to the
object if available. The `log_level` option does not apply if this is
enabled.
charon.filelog.<name>.log_level = no
Add the log level of each message after the subsystem (e.g. [IKE2]).

View File

@ -383,7 +383,7 @@ static void load_log_levels(file_logger_t *logger, char *section)
static void load_logger_options(file_logger_t *logger, char *section)
{
char *time_format;
bool add_ms, ike_name, log_level;
bool add_ms, ike_name, log_level, json;
time_format = conftest->test->get_str(conftest->test,
"log.%s.time_format", NULL, section);
@ -393,8 +393,10 @@ static void load_logger_options(file_logger_t *logger, char *section)
"log.%s.ike_name", FALSE, section);
log_level = conftest->test->get_bool(conftest->test,
"log.%s.log_level", FALSE, section);
json = conftest->test->get_bool(conftest->test,
"log.%s.json", FALSE, section);
logger->set_options(logger, time_format, add_ms, ike_name, log_level);
logger->set_options(logger, time_format, add_ms, ike_name, log_level, json);
}
/**
@ -460,7 +462,7 @@ int main(int argc, char *argv[])
lib->credmgr->add_set(lib->credmgr, &conftest->creds->set);
logger = file_logger_create("stdout");
logger->set_options(logger, NULL, FALSE, FALSE, FALSE);
logger->set_options(logger, NULL, FALSE, FALSE, FALSE, FALSE);
logger->open(logger, FALSE, FALSE);
logger->set_level(logger, DBG_ANY, LEVEL_CTRL);
charon->bus->add_logger(charon->bus, &logger->logger);

View File

@ -1,5 +1,5 @@
/*
* Copyright (C) 2012-2020 Tobias Brunner
* Copyright (C) 2012-2024 Tobias Brunner
* Copyright (C) 2006 Martin Willi
*
* Copyright (C) secunet Security Networks AG
@ -80,6 +80,11 @@ struct private_file_logger_t {
*/
bool log_level;
/**
* Print log messages as JSON objects
*/
bool json;
/**
* Mutex to ensure multi-line log messages are not torn apart
*/
@ -95,11 +100,13 @@ METHOD(logger_t, log_, void,
private_file_logger_t *this, debug_t group, level_t level, int thread,
ike_sa_t* ike_sa, const char *message)
{
char groupstr[5], timestr[128], namestr[128] = "";
const char *current = message, *next;
char groupstr[5], timestr[128];
char idstr[11] = "", namestr[128] = "", nameidstr[142];
const char *current = message, *next = NULL;
struct tm tm;
timeval_t tv;
time_t s;
size_t time_len;
u_int ms = 0;
this->lock->read_lock(this->lock);
@ -115,67 +122,101 @@ METHOD(logger_t, log_, void,
s = tv.tv_sec;
ms = tv.tv_usec / 1000;
localtime_r(&s, &tm);
strftime(timestr, sizeof(timestr), this->time_format, &tm);
}
time_len = strftime(timestr, sizeof(timestr), this->time_format, &tm);
if (this->log_level)
{
snprintf(groupstr, sizeof(groupstr), "%N%d", debug_names, group,
level);
}
else
{
snprintf(groupstr, sizeof(groupstr), "%N", debug_names, group);
if (this->add_ms && sizeof(timestr) - time_len > 4)
{
snprintf(&timestr[time_len], sizeof(timestr)-time_len, ".%03u", ms);
}
}
if (this->ike_name && ike_sa)
{
snprintf(idstr, sizeof(idstr), "%u", ike_sa->get_unique_id(ike_sa));
if (ike_sa->get_peer_cfg(ike_sa))
{
snprintf(namestr, sizeof(namestr), " <%s|%d>",
ike_sa->get_name(ike_sa), ike_sa->get_unique_id(ike_sa));
snprintf(namestr, sizeof(namestr), "%s", ike_sa->get_name(ike_sa));
}
else
}
this->mutex->lock(this->mutex);
if (this->json)
{
fprintf(this->out, "{");
if (this->time_format)
{
snprintf(namestr, sizeof(namestr), " <%d>",
ike_sa->get_unique_id(ike_sa));
fprintf(this->out, "\"time\":\"%s\",", timestr);
}
fprintf(this->out, "\"thread\":%u,\"group\":\"%N\",\"level\":%u,",
thread, debug_names, group, level);
if (idstr[0])
{
fprintf(this->out, "\"ikesa-uniqueid\":\"%s\",", idstr);
}
if (namestr[0])
{
fprintf(this->out, "\"ikesa-name\":\"%s\",", namestr);
}
fprintf(this->out, "\"msg\":\"");
/* replace some characters incompatible with JSON strings */
for (next = current; *next; next++)
{
const char *esc;
switch (*next)
{
case '\n':
esc = "\\n";
break;
case '\\':
esc = "\\\\";
break;
case '"':
esc = "\\\"";
break;
default:
continue;
}
fprintf(this->out, "%.*s%s", (int)(next - current), current, esc);
current = next + 1;
}
fprintf(this->out, "%s\"}\n", current);
}
else
{
namestr[0] = '\0';
}
/* prepend a prefix in front of every line */
this->mutex->lock(this->mutex);
while (TRUE)
{
next = strchr(current, '\n');
if (this->time_format)
if (this->log_level)
{
if (this->add_ms)
{
fprintf(this->out, "%s.%03u %.2d[%s]%s ",
timestr, ms, thread, groupstr, namestr);
}
else
{
fprintf(this->out, "%s %.2d[%s]%s ",
timestr, thread, groupstr, namestr);
}
snprintf(groupstr, sizeof(groupstr), "%N%d", debug_names, group,
level);
}
else
{
fprintf(this->out, "%.2d[%s]%s ",
thread, groupstr, namestr);
snprintf(groupstr, sizeof(groupstr), "%N", debug_names, group);
}
if (next == NULL)
snprintf(nameidstr, sizeof(nameidstr), " <%s%s%s>", namestr,
namestr[0] ? "|" : "", idstr);
/* prepend the prefix in front of every line */
while (TRUE)
{
fprintf(this->out, "%s\n", current);
break;
next = strchr(current, '\n');
if (this->time_format)
{
fprintf(this->out, "%s %.2d[%s]%s ",
timestr, thread, groupstr, nameidstr);
}
else
{
fprintf(this->out, "%.2d[%s]%s ",
thread, groupstr, nameidstr);
}
if (!next)
{
fprintf(this->out, "%s\n", current);
break;
}
fprintf(this->out, "%.*s\n", (int)(next - current), current);
current = next + 1;
}
fprintf(this->out, "%.*s\n", (int)(next - current), current);
current = next + 1;
}
#ifndef HAVE_SETLINEBUF
if (this->flush_line)
@ -218,7 +259,7 @@ METHOD(file_logger_t, set_level, void,
METHOD(file_logger_t, set_options, void,
private_file_logger_t *this, char *time_format, bool add_ms, bool ike_name,
bool log_level)
bool log_level, bool json)
{
this->lock->write_lock(this->lock);
free(this->time_format);
@ -226,6 +267,7 @@ METHOD(file_logger_t, set_options, void,
this->add_ms = add_ms;
this->ike_name = ike_name;
this->log_level = log_level;
this->json = json;
this->lock->unlock(this->lock);
}

View File

@ -53,9 +53,10 @@ struct file_logger_t {
* current second after the timestamp
* @param ike_name TRUE to prefix the name of the IKE_SA
* @param log_level TRUE to include the log level in the message
* @param json TRUE to log as JSON objects
*/
void (*set_options) (file_logger_t *this, char *time_format, bool add_ms,
bool ike_name, bool log_level);
bool ike_name, bool log_level, bool json);
/**
* Open (or reopen) the log file according to the given parameters

View File

@ -493,7 +493,7 @@ static void load_file_logger(private_daemon_t *this, char *section,
file_logger_t *file_logger;
debug_t group;
level_t def;
bool add_ms, ike_name, log_level, flush_line, append;
bool add_ms, ike_name, log_level, json, flush_line, append;
char *time_format, *filename;
time_format = lib->settings->get_str(lib->settings,
@ -504,6 +504,8 @@ static void load_file_logger(private_daemon_t *this, char *section,
"%s.filelog.%s.ike_name", FALSE, lib->ns, section);
log_level = lib->settings->get_bool(lib->settings,
"%s.filelog.%s.log_level", FALSE, lib->ns, section);
json = lib->settings->get_bool(lib->settings,
"%s.filelog.%s.json", FALSE, lib->ns, section);
flush_line = lib->settings->get_bool(lib->settings,
"%s.filelog.%s.flush_line", FALSE, lib->ns, section);
append = lib->settings->get_bool(lib->settings,
@ -518,7 +520,7 @@ static void load_file_logger(private_daemon_t *this, char *section,
}
file_logger->set_options(file_logger, time_format, add_ms, ike_name,
log_level);
log_level, json);
file_logger->open(file_logger, flush_line, append);
def = lib->settings->get_int(lib->settings, "%s.filelog.%s.default", 1,