Browse Source

[Minor] Refactor logging function to join console and file

tags/3.7.1
Vsevolod Stakhov 8 months ago
parent
commit
b59249576f
No account linked to committer's email address

+ 197
- 3
src/libserver/logger/logger.c View File

@@ -1,11 +1,11 @@
/*-
* Copyright 2016 Vsevolod Stakhov
/*
* Copyright 2023 Vsevolod Stakhov
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
@@ -27,6 +27,8 @@ static rspamd_logger_t *default_logger = NULL;
static rspamd_logger_t *emergency_logger = NULL;
static struct rspamd_log_modules *log_modules = NULL;

static const gchar lf_chr = '\n';

guint rspamd_task_log_id = (guint) -1;
RSPAMD_CONSTRUCTOR(rspamd_task_log_init)
{
@@ -1003,4 +1005,196 @@ rspamd_get_log_severity_string(gint level_flags)
bitnum = ffs(level_flags) - 1;
#endif
return level_strs[bitnum];
}

static inline void
log_time(gdouble now, rspamd_logger_t *rspamd_log, gchar *timebuf,
size_t len)
{
time_t sec = (time_t) now;
gsize r;
struct tm tms;

rspamd_localtime(sec, &tms);
r = strftime(timebuf, len, "%F %H:%M:%S", &tms);

if (rspamd_log->flags & RSPAMD_LOG_FLAG_USEC) {
gchar usec_buf[16];

rspamd_snprintf(usec_buf, sizeof(usec_buf), "%.5f",
now - (gdouble) sec);
rspamd_snprintf(timebuf + r, len - r,
"%s", usec_buf + 1);
}
}

gsize rspamd_log_fill_iov(struct iovec *iov,
double ts,
const gchar *module,
const gchar *id,
const gchar *function,
gint level_flags,
const gchar *message,
gsize mlen,
rspamd_logger_t *logger)
{
bool log_color = (logger->flags & RSPAMD_LOG_FLAG_COLOR);
bool log_severity = (logger->flags & RSPAMD_LOG_FLAG_SEVERITY);
bool log_rspamadm = (logger->flags & RSPAMD_LOG_FLAG_RSPAMADM);
bool log_systemd = (logger->flags & RSPAMD_LOG_FLAG_SYSTEMD);

gint r;

if (iov == NULL) {
if (log_rspamadm) {
if (logger->log_level == G_LOG_LEVEL_DEBUG) {
return 4;
}
else {
return 3; /* No time component */
}
}
else if (log_systemd) {
return 3;
}
else {
if (log_color) {
return 5;
}
else {
return 4;
}
}
}
else {
static gchar timebuf[64], modulebuf[64];
static gchar tmpbuf[256];

if (!log_systemd) {
log_time(ts, logger, timebuf, sizeof(timebuf));
}

if (!log_rspamadm) {
if (!log_systemd) {
if (log_color) {
if (level_flags & (G_LOG_LEVEL_INFO | G_LOG_LEVEL_MESSAGE)) {
/* White */
r = rspamd_snprintf(tmpbuf, sizeof(tmpbuf), "\033[0;37m");
}
else if (level_flags & G_LOG_LEVEL_WARNING) {
/* Magenta */
r = rspamd_snprintf(tmpbuf, sizeof(tmpbuf), "\033[0;32m");
}
else if (level_flags & G_LOG_LEVEL_CRITICAL) {
/* Red */
r = rspamd_snprintf(tmpbuf, sizeof(tmpbuf), "\033[1;31m");
}
else {
r = 0;
}
}
else {
r = 0;
}

if (log_severity) {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"%s [%s] #%P(%s) ",
timebuf,
rspamd_get_log_severity_string(level_flags),
logger->pid,
logger->process_type);
}
else {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"%s #%P(%s) ",
timebuf,
logger->pid,
logger->process_type);
}
}
else {
r = 0;
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"(%s) ",
logger->process_type);
}

int mremain, mr;
char *m;

modulebuf[0] = '\0';
mremain = sizeof(modulebuf);
m = modulebuf;

if (id != NULL) {
guint slen = strlen(id);
slen = MIN(RSPAMD_LOG_ID_LEN, slen);
mr = rspamd_snprintf(m, mremain, "<%*.s>; ", slen,
id);
m += mr;
mremain -= mr;
}
if (module != NULL) {
mr = rspamd_snprintf(m, mremain, "%s; ", module);
m += mr;
mremain -= mr;
}
if (function != NULL) {
mr = rspamd_snprintf(m, mremain, "%s: ", function);
m += mr;
mremain -= mr;
}
else {
mr = rspamd_snprintf(m, mremain, ": ");
m += mr;
mremain -= mr;
}

/* Ensure that we have a space at the end */
if (m > modulebuf && *(m - 1) != ' ') {
*(m - 1) = ' ';
}

/* Construct IOV for log line */
iov[0].iov_base = tmpbuf;
iov[0].iov_len = r;
iov[1].iov_base = modulebuf;
iov[1].iov_len = m - modulebuf;
iov[2].iov_base = (void *) message;
iov[2].iov_len = mlen;
iov[3].iov_base = (void *) &lf_chr;
iov[3].iov_len = 1;

if (log_color) {
iov[4].iov_base = "\033[0m";
iov[4].iov_len = sizeof("\033[0m") - 1;

return 5;
}

return 4;
}
else {
/* Rspamadm case */
int niov = 0;

if (logger->log_level == G_LOG_LEVEL_DEBUG) {
iov[niov].iov_base = (void *) timebuf;
iov[niov++].iov_len = strlen(timebuf);
iov[niov].iov_base = (void *) " ";
iov[niov++].iov_len = 1;
}

iov[niov].iov_base = (void *) message;
iov[niov++].iov_len = mlen;
iov[niov].iov_base = (void *) &lf_chr;
iov[niov++].iov_len = 1;

return niov;
}
}
}

+ 12
- 123
src/libserver/logger/logger_console.c View File

@@ -1,11 +1,11 @@
/*-
* Copyright 2020 Vsevolod Stakhov
/*
* Copyright 2023 Vsevolod Stakhov
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
@@ -153,13 +153,8 @@ bool rspamd_log_console_log(const gchar *module, const gchar *id,
gpointer arg)
{
struct rspamd_console_logger_priv *priv = (struct rspamd_console_logger_priv *) arg;
static gchar timebuf[64], modulebuf[64];
gchar tmpbuf[256];
gchar *m;
struct iovec iov[6];
gulong r = 0, mr = 0;
size_t mremain;
gint fd, niov = 0;
gint fd, r;
double now;

if (level_flags & G_LOG_LEVEL_CRITICAL) {
fd = priv->crit_fd;
@@ -184,119 +179,13 @@ bool rspamd_log_console_log(const gchar *module, const gchar *id,
rspamd_file_lock(fd, FALSE);
#endif

if (!(rspamd_log->flags & RSPAMD_LOG_FLAG_SYSTEMD)) {
log_time(rspamd_get_calendar_ticks(),
rspamd_log, timebuf, sizeof(timebuf));
}

if (priv->log_color) {
if (level_flags & (G_LOG_LEVEL_INFO | G_LOG_LEVEL_MESSAGE)) {
/* White */
r = rspamd_snprintf(tmpbuf, sizeof(tmpbuf), "\033[0;37m");
}
else if (level_flags & G_LOG_LEVEL_WARNING) {
/* Magenta */
r = rspamd_snprintf(tmpbuf, sizeof(tmpbuf), "\033[0;32m");
}
else if (level_flags & G_LOG_LEVEL_CRITICAL) {
/* Red */
r = rspamd_snprintf(tmpbuf, sizeof(tmpbuf), "\033[1;31m");
}
}
else {
r = 0;
}

if (priv->log_rspamadm) {
if (rspamd_log->log_level == G_LOG_LEVEL_DEBUG) {
log_time(rspamd_get_calendar_ticks(),
rspamd_log, timebuf, sizeof(timebuf));
iov[niov].iov_base = (void *) timebuf;
iov[niov++].iov_len = strlen(timebuf);
iov[niov].iov_base = (void *) " ";
iov[niov++].iov_len = 1;
}

iov[niov].iov_base = (void *) message;
iov[niov++].iov_len = mlen;
iov[niov].iov_base = (void *) &lf_chr;
iov[niov++].iov_len = 1;
}
else {
if (!(rspamd_log->flags & RSPAMD_LOG_FLAG_SYSTEMD)) {
if (priv->log_severity) {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"%s [%s] #%P(%s) ",
timebuf,
rspamd_get_log_severity_string(level_flags),
rspamd_log->pid,
rspamd_log->process_type);
}
else {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"%s #%P(%s) ",
timebuf,
rspamd_log->pid,
rspamd_log->process_type);
}
}
else {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"#%P(%s) ",
rspamd_log->pid,
rspamd_log->process_type);
}

modulebuf[0] = '\0';
mremain = sizeof(modulebuf);
m = modulebuf;

if (id != NULL) {
guint slen = strlen(id);
slen = MIN(RSPAMD_LOG_ID_LEN, slen);
mr = rspamd_snprintf(m, mremain, "<%*.s>; ", slen,
id);
m += mr;
mremain -= mr;
}
if (module != NULL) {
mr = rspamd_snprintf(m, mremain, "%s; ", module);
m += mr;
mremain -= mr;
}
if (function != NULL) {
mr = rspamd_snprintf(m, mremain, "%s: ", function);
m += mr;
mremain -= mr;
}
else {
mr = rspamd_snprintf(m, mremain, ": ");
m += mr;
mremain -= mr;
}

/* Ensure that we have a space at the end */
if (m > modulebuf && *(m - 1) != ' ') {
*(m - 1) = ' ';
}

iov[niov].iov_base = tmpbuf;
iov[niov++].iov_len = r;
iov[niov].iov_base = modulebuf;
iov[niov++].iov_len = m - modulebuf;
iov[niov].iov_base = (void *) message;
iov[niov++].iov_len = mlen;
iov[niov].iov_base = (void *) &lf_chr;
iov[niov++].iov_len = 1;
}

if (priv->log_color) {
iov[niov].iov_base = "\033[0m";
iov[niov++].iov_len = sizeof("\033[0m") - 1;
}
now = rspamd_get_calendar_ticks();
gsize niov = rspamd_log_fill_iov(NULL, now, module, id,
function, level_flags, message,
mlen, rspamd_log);
struct iovec *iov = g_alloca(sizeof(struct iovec) * niov);
rspamd_log_fill_iov(iov, now, module, id, function, level_flags, message,
mlen, rspamd_log);

again:
r = writev(fd, iov, niov);

+ 9
- 111
src/libserver/logger/logger_file.c View File

@@ -1,11 +1,11 @@
/*-
* Copyright 2020 Vsevolod Stakhov
/*
* Copyright 2023 Vsevolod Stakhov
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
@@ -24,8 +24,6 @@

#define FILE_LOG_QUARK g_quark_from_static_string("file_logger")

static const gchar lf_chr = '\n';

struct rspamd_file_logger_priv {
gint fd;
struct {
@@ -57,28 +55,6 @@ rspamd_log_calculate_cksum(const gchar *message, size_t mlen)
return rspamd_cryptobox_fast_hash(message, mlen, rspamd_hash_seed());
}

static inline void
log_time(gdouble now, rspamd_logger_t *rspamd_log, gchar *timebuf,
size_t len)
{
time_t sec = (time_t) now;
gsize r;
struct tm tms;

rspamd_localtime(sec, &tms);
r = strftime(timebuf, len, "%F %H:%M:%S", &tms);

if (rspamd_log->flags & RSPAMD_LOG_FLAG_USEC) {
gchar usec_buf[16];

rspamd_snprintf(usec_buf, sizeof(usec_buf), "%.5f",
now - (gdouble) sec);
rspamd_snprintf(timebuf + r, len - r,
"%s", usec_buf + 1);
}
}


/*
* Write a line to log file (unbuffered)
*/
@@ -399,15 +375,8 @@ bool rspamd_log_file_log(const gchar *module, const gchar *id,
gpointer arg)
{
struct rspamd_file_logger_priv *priv = (struct rspamd_file_logger_priv *) arg;
static gchar timebuf[64], modulebuf[64];
gchar tmpbuf[256];
gchar *m;
gdouble now;
struct iovec iov[6];
gulong r = 0, mr = 0;
guint64 cksum;
size_t mremain;
const gchar *cptype = NULL;
gboolean got_time = FALSE;


@@ -496,84 +465,13 @@ bool rspamd_log_file_log(const gchar *module, const gchar *id,
now = rspamd_get_calendar_ticks();
}

/* Format time */
if (!(rspamd_log->flags & RSPAMD_LOG_FLAG_SYSTEMD)) {
log_time(now, rspamd_log, timebuf, sizeof(timebuf));
}

cptype = rspamd_log->process_type;
r = 0;

if (!(rspamd_log->flags & RSPAMD_LOG_FLAG_SYSTEMD)) {
if (priv->log_severity) {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"%s [%s] #%P(%s) ",
timebuf,
rspamd_get_log_severity_string(level_flags),
rspamd_log->pid,
cptype);
}
else {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"%s #%P(%s) ",
timebuf,
rspamd_log->pid,
cptype);
}
}
else {
r += rspamd_snprintf(tmpbuf + r,
sizeof(tmpbuf) - r,
"(%s) ",
cptype);
}

modulebuf[0] = '\0';
mremain = sizeof(modulebuf);
m = modulebuf;

if (id != NULL) {
guint slen = strlen(id);
slen = MIN(RSPAMD_LOG_ID_LEN, slen);
mr = rspamd_snprintf(m, mremain, "<%*.s>; ", slen,
id);
m += mr;
mremain -= mr;
}
if (module != NULL) {
mr = rspamd_snprintf(m, mremain, "%s; ", module);
m += mr;
mremain -= mr;
}
if (function != NULL) {
mr = rspamd_snprintf(m, mremain, "%s: ", function);
m += mr;
mremain -= mr;
}
else {
mr = rspamd_snprintf(m, mremain, ": ");
m += mr;
mremain -= mr;
}

/* Ensure that we have a space at the end */
if (m > modulebuf && *(m - 1) != ' ') {
*(m - 1) = ' ';
}
gsize niov = rspamd_log_fill_iov(NULL, now, module, id, function, level_flags, message,
mlen, rspamd_log);
struct iovec *iov = g_alloca(sizeof(struct iovec) * niov);
rspamd_log_fill_iov(iov, now, module, id, function, level_flags, message,
mlen, rspamd_log);

/* Construct IOV for log line */
iov[0].iov_base = tmpbuf;
iov[0].iov_len = r;
iov[1].iov_base = modulebuf;
iov[1].iov_len = m - modulebuf;
iov[2].iov_base = (void *) message;
iov[2].iov_len = mlen;
iov[3].iov_base = (void *) &lf_chr;
iov[3].iov_len = 1;

return file_log_helper(rspamd_log, priv, iov, 4, level_flags);
return file_log_helper(rspamd_log, priv, iov, niov, level_flags);
}

void *

+ 25
- 3
src/libserver/logger/logger_private.h View File

@@ -1,11 +1,11 @@
/*-
* Copyright 2020 Vsevolod Stakhov
/*
* Copyright 2023 Vsevolod Stakhov
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
@@ -102,6 +102,28 @@ bool rspamd_log_file_log(const gchar *module, const gchar *id,
gpointer arg);
bool rspamd_log_file_on_fork(rspamd_logger_t *logger, struct rspamd_config *cfg,
gpointer arg, GError **err);

/**
* Fills IOV of logger (usable for file/console logging)
* Warning: this function is NOT reentrant, do not call it twice from a single moment of execution
* @param iov if NULL just returns the number of elements required in IOV array
* @param module
* @param id
* @param function
* @param level_flags
* @param message
* @param mlen
* @param rspamd_log
* @return number of iov elements being filled
*/
gsize rspamd_log_fill_iov(struct iovec *iov,
double ts,
const gchar *module, const gchar *id,
const gchar *function,
gint level_flags,
const gchar *message,
gsize mlen,
rspamd_logger_t *rspamd_log);
/**
* Escape log line by replacing unprintable characters to hex escapes like \xNN
* @param src

Loading…
Cancel
Save