Adding upstream version 3.8.1.upstream/3.8.1upstream

Signed-off-by: Daniel Baumann <daniel.baumann@progress-linux.org>

1 files changed, 510 insertions, 0 deletions

diff --git a/src/libserver/logger/logger_file.c b/src/libserver/logger/logger_file.c
new file mode 100644
index 0000000..20b04b8
--- /dev/null
+++ b/src/libserver/logger/logger_file.c
@@ -0,0 +1,510 @@
+/*
+ * 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
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include "config.h"
+#include "logger.h"
+#include "libserver/cfg_file.h"
+#include "libcryptobox/cryptobox.h"
+#include "unix-std.h"
+
+#include "logger_private.h"
+
+#define FILE_LOG_QUARK g_quark_from_static_string("file_logger")
+
+struct rspamd_file_logger_priv {
+	gint fd;
+	struct {
+		guint32 size;
+		guint32 used;
+		u_char *buf;
+	} io_buf;
+	gboolean throttling;
+	gchar *log_file;
+	gboolean is_buffered;
+	gboolean log_severity;
+	time_t throttling_time;
+	guint32 repeats;
+	guint64 last_line_cksum;
+	gchar *saved_message;
+	gsize saved_mlen;
+	gchar *saved_function;
+	gchar *saved_module;
+	gchar *saved_id;
+	guint saved_loglevel;
+};
+
+/**
+ * Calculate checksum for log line (used for repeating logic)
+ */
+static inline guint64
+rspamd_log_calculate_cksum(const gchar *message, size_t mlen)
+{
+	return rspamd_cryptobox_fast_hash(message, mlen, rspamd_hash_seed());
+}
+
+/*
+ * Write a line to log file (unbuffered)
+ */
+static bool
+direct_write_log_line(rspamd_logger_t *rspamd_log,
+					  struct rspamd_file_logger_priv *priv,
+					  void *data,
+					  gsize count,
+					  gboolean is_iov,
+					  gint level_flags)
+{
+	struct iovec *iov;
+	const gchar *line;
+	glong r;
+	gint fd;
+	gboolean locked = FALSE;
+
+	iov = (struct iovec *) data;
+	fd = priv->fd;
+
+	if (!rspamd_log->no_lock) {
+		gsize tlen;
+
+		if (is_iov) {
+			tlen = 0;
+
+			for (guint i = 0; i < count; i++) {
+				tlen += iov[i].iov_len;
+			}
+		}
+		else {
+			tlen = count;
+		}
+
+		if (tlen > PIPE_BUF) {
+			locked = TRUE;
+
+#ifndef DISABLE_PTHREAD_MUTEX
+			if (rspamd_log->mtx) {
+				rspamd_mempool_lock_mutex(rspamd_log->mtx);
+			}
+			else {
+				rspamd_file_lock(fd, FALSE);
+			}
+#else
+			rspamd_file_lock(fd, FALSE);
+#endif
+		}
+	}
+
+	if (is_iov) {
+		r = writev(fd, iov, count);
+	}
+	else {
+		line = (const gchar *) data;
+		r = write(fd, line, count);
+	}
+
+	if (locked) {
+#ifndef DISABLE_PTHREAD_MUTEX
+		if (rspamd_log->mtx) {
+			rspamd_mempool_unlock_mutex(rspamd_log->mtx);
+		}
+		else {
+			rspamd_file_unlock(fd, FALSE);
+		}
+#else
+		rspamd_file_unlock(fd, FALSE);
+#endif
+	}
+
+	if (r == -1) {
+		/* We cannot write message to file, so we need to detect error and make decision */
+		if (errno == EINTR) {
+			/* Try again */
+			return direct_write_log_line(rspamd_log, priv, data, count, is_iov, level_flags);
+		}
+
+		if (errno == EFAULT || errno == EINVAL || errno == EFBIG ||
+			errno == ENOSPC) {
+			/* Rare case */
+			priv->throttling = TRUE;
+			priv->throttling_time = time(NULL);
+		}
+		else if (errno == EPIPE || errno == EBADF) {
+			/* We write to some pipe and it disappears, disable logging or we has opened bad file descriptor */
+			rspamd_log->enabled = FALSE;
+		}
+
+		return false;
+	}
+	else if (priv->throttling) {
+		priv->throttling = FALSE;
+	}
+
+	return true;
+}
+
+/**
+ * Fill buffer with message (limits must be checked BEFORE this call)
+ */
+static void
+fill_buffer(rspamd_logger_t *rspamd_log,
+			struct rspamd_file_logger_priv *priv,
+			const struct iovec *iov, gint iovcnt)
+{
+	gint i;
+
+	for (i = 0; i < iovcnt; i++) {
+		memcpy(priv->io_buf.buf + priv->io_buf.used,
+			   iov[i].iov_base,
+			   iov[i].iov_len);
+		priv->io_buf.used += iov[i].iov_len;
+	}
+}
+
+static void
+rspamd_log_flush(rspamd_logger_t *rspamd_log, struct rspamd_file_logger_priv *priv)
+{
+	if (priv->is_buffered) {
+		direct_write_log_line(rspamd_log,
+							  priv,
+							  priv->io_buf.buf,
+							  priv->io_buf.used,
+							  FALSE,
+							  rspamd_log->log_level);
+		priv->io_buf.used = 0;
+	}
+}
+
+/*
+ * Write message to buffer or to file (using direct_write_log_line function)
+ */
+static bool
+file_log_helper(rspamd_logger_t *rspamd_log,
+				struct rspamd_file_logger_priv *priv,
+				const struct iovec *iov,
+				guint iovcnt,
+				gint level_flags)
+{
+	size_t len = 0;
+	guint i;
+
+	if (!priv->is_buffered) {
+		/* Write string directly */
+		return direct_write_log_line(rspamd_log, priv, (void *) iov, iovcnt,
+									 TRUE, level_flags);
+	}
+	else {
+		/* Calculate total length */
+		for (i = 0; i < iovcnt; i++) {
+			len += iov[i].iov_len;
+		}
+		/* Fill buffer */
+		if (priv->io_buf.size < len) {
+			/* Buffer is too small to hold this string, so write it directly */
+			rspamd_log_flush(rspamd_log, priv);
+			return direct_write_log_line(rspamd_log, priv, (void *) iov, iovcnt,
+										 TRUE, level_flags);
+		}
+		else if (priv->io_buf.used + len >= priv->io_buf.size) {
+			/* Buffer is full, try to write it directly */
+			rspamd_log_flush(rspamd_log, priv);
+			fill_buffer(rspamd_log, priv, iov, iovcnt);
+		}
+		else {
+			/* Copy incoming string to buffer */
+			fill_buffer(rspamd_log, priv, iov, iovcnt);
+		}
+	}
+
+	return true;
+}
+
+static void
+rspamd_log_reset_repeated(rspamd_logger_t *rspamd_log,
+						  struct rspamd_file_logger_priv *priv)
+{
+	gchar tmpbuf[256];
+	gssize r;
+
+	if (priv->repeats > REPEATS_MIN) {
+		r = rspamd_snprintf(tmpbuf,
+							sizeof(tmpbuf),
+							"Last message repeated %ud times",
+							priv->repeats - REPEATS_MIN);
+		priv->repeats = 0;
+
+		if (priv->saved_message) {
+			rspamd_log_file_log(priv->saved_module,
+								priv->saved_id,
+								priv->saved_function,
+								priv->saved_loglevel | RSPAMD_LOG_FORCED,
+								priv->saved_message,
+								priv->saved_mlen,
+								rspamd_log,
+								priv);
+
+			g_free(priv->saved_message);
+			g_free(priv->saved_function);
+			g_free(priv->saved_module);
+			g_free(priv->saved_id);
+			priv->saved_message = NULL;
+			priv->saved_function = NULL;
+			priv->saved_module = NULL;
+			priv->saved_id = NULL;
+		}
+
+		/* It is safe to use temporary buffer here as it is not static */
+		rspamd_log_file_log(NULL, NULL,
+							G_STRFUNC,
+							priv->saved_loglevel | RSPAMD_LOG_FORCED,
+							tmpbuf,
+							r,
+							rspamd_log,
+							priv);
+		rspamd_log_flush(rspamd_log, priv);
+	}
+}
+
+static gint
+rspamd_try_open_log_fd(rspamd_logger_t *rspamd_log,
+					   struct rspamd_file_logger_priv *priv,
+					   uid_t uid, gid_t gid,
+					   GError **err)
+{
+	gint fd;
+
+	fd = open(priv->log_file,
+			  O_CREAT | O_WRONLY | O_APPEND,
+			  S_IWUSR | S_IRUSR | S_IRGRP | S_IROTH);
+	if (fd == -1) {
+		g_set_error(err, FILE_LOG_QUARK, errno,
+					"open_log: cannot open desired log file: %s, %s\n",
+					priv->log_file, strerror(errno));
+		return -1;
+	}
+
+	if (uid != -1 || gid != -1) {
+		if (fchown(fd, uid, gid) == -1) {
+			g_set_error(err, FILE_LOG_QUARK, errno,
+						"open_log: cannot chown desired log file: %s, %s\n",
+						priv->log_file, strerror(errno));
+			close(fd);
+
+			return -1;
+		}
+	}
+
+	return fd;
+}
+
+void *
+rspamd_log_file_init(rspamd_logger_t *logger, struct rspamd_config *cfg,
+					 uid_t uid, gid_t gid, GError **err)
+{
+	struct rspamd_file_logger_priv *priv;
+
+	if (!cfg || !cfg->cfg_name) {
+		g_set_error(err, FILE_LOG_QUARK, EINVAL,
+					"no log file specified");
+		return NULL;
+	}
+
+	priv = g_malloc0(sizeof(*priv));
+
+	if (cfg->log_buffered) {
+		if (cfg->log_buf_size != 0) {
+			priv->io_buf.size = cfg->log_buf_size;
+		}
+		else {
+			priv->io_buf.size = LOGBUF_LEN;
+		}
+		priv->is_buffered = TRUE;
+		priv->io_buf.buf = g_malloc(priv->io_buf.size);
+	}
+
+	if (cfg->log_file) {
+		priv->log_file = g_strdup(cfg->log_file);
+	}
+
+	priv->log_severity = (logger->flags & RSPAMD_LOG_FLAG_SEVERITY);
+	priv->fd = rspamd_try_open_log_fd(logger, priv, uid, gid, err);
+
+	if (priv->fd == -1) {
+		rspamd_log_file_dtor(logger, priv);
+
+		return NULL;
+	}
+
+	return priv;
+}
+
+void rspamd_log_file_dtor(rspamd_logger_t *logger, gpointer arg)
+{
+	struct rspamd_file_logger_priv *priv = (struct rspamd_file_logger_priv *) arg;
+
+	rspamd_log_reset_repeated(logger, priv);
+	rspamd_log_flush(logger, priv);
+
+	if (priv->fd != -1) {
+		if (close(priv->fd) == -1) {
+			rspamd_fprintf(stderr, "cannot close log fd %d: %s; log file = %s\n",
+						   priv->fd, strerror(errno), priv->log_file);
+		}
+	}
+
+	g_free(priv->log_file);
+	g_free(priv);
+}
+
+bool rspamd_log_file_log(const gchar *module, const gchar *id,
+						 const gchar *function,
+						 gint level_flags,
+						 const gchar *message,
+						 gsize mlen,
+						 rspamd_logger_t *rspamd_log,
+						 gpointer arg)
+{
+	struct rspamd_file_logger_priv *priv = (struct rspamd_file_logger_priv *) arg;
+	gdouble now;
+	guint64 cksum;
+	gboolean got_time = FALSE;
+
+
+	if (!(level_flags & RSPAMD_LOG_FORCED) && !rspamd_log->enabled) {
+		return false;
+	}
+
+	/* Check throttling due to write errors */
+	if (!(level_flags & RSPAMD_LOG_FORCED) && priv->throttling) {
+		now = rspamd_get_calendar_ticks();
+
+		if (priv->throttling_time != now) {
+			priv->throttling_time = now;
+			got_time = TRUE;
+		}
+		else {
+			/* Do not try to write to file too often while throttling */
+			return false;
+		}
+	}
+
+	/* Check repeats */
+	cksum = rspamd_log_calculate_cksum(message, mlen);
+
+	if (cksum == priv->last_line_cksum) {
+		priv->repeats++;
+
+		if (priv->repeats > REPEATS_MIN && priv->repeats <
+											   REPEATS_MAX) {
+			/* Do not log anything but save message for future */
+			if (priv->saved_message == NULL) {
+				priv->saved_function = g_strdup(function);
+				priv->saved_mlen = mlen;
+				priv->saved_message = g_malloc(mlen);
+				memcpy(priv->saved_message, message, mlen);
+
+				if (module) {
+					priv->saved_module = g_strdup(module);
+				}
+
+				if (id) {
+					priv->saved_id = g_strdup(id);
+				}
+
+				priv->saved_loglevel = level_flags;
+			}
+
+			return true;
+		}
+		else if (priv->repeats > REPEATS_MAX) {
+			rspamd_log_reset_repeated(rspamd_log, priv);
+
+			bool ret = rspamd_log_file_log(module, id,
+										   function,
+										   level_flags,
+										   message,
+										   mlen,
+										   rspamd_log,
+										   priv);
+
+			/* Probably we have more repeats in future */
+			priv->repeats = REPEATS_MIN + 1;
+
+			return ret;
+		}
+	}
+	else {
+		/* Reset counter if new message differs from saved message */
+		priv->last_line_cksum = cksum;
+
+		if (priv->repeats > REPEATS_MIN) {
+			rspamd_log_reset_repeated(rspamd_log, priv);
+			return rspamd_log_file_log(module, id,
+									   function,
+									   level_flags,
+									   message,
+									   mlen,
+									   rspamd_log,
+									   arg);
+		}
+		else {
+			priv->repeats = 0;
+		}
+	}
+	if (!got_time) {
+		now = rspamd_get_calendar_ticks();
+	}
+
+	struct rspamd_logger_iov_ctx iov_ctx;
+	memset(&iov_ctx, 0, sizeof(iov_ctx));
+	rspamd_log_fill_iov(&iov_ctx, now, module, id, function, level_flags, message,
+						mlen, rspamd_log);
+
+	bool ret = file_log_helper(rspamd_log, priv, iov_ctx.iov, iov_ctx.niov, level_flags);
+	rspamd_log_iov_free(&iov_ctx);
+
+	return ret;
+}
+
+void *
+rspamd_log_file_reload(rspamd_logger_t *logger, struct rspamd_config *cfg,
+					   gpointer arg, uid_t uid, gid_t gid, GError **err)
+{
+	struct rspamd_file_logger_priv *npriv;
+
+	if (!cfg->cfg_name) {
+		g_set_error(err, FILE_LOG_QUARK, EINVAL,
+					"no log file specified");
+		return NULL;
+	}
+
+	npriv = rspamd_log_file_init(logger, cfg, uid, gid, err);
+
+	if (npriv) {
+		/* Close old */
+		rspamd_log_file_dtor(logger, arg);
+	}
+
+	return npriv;
+}
+
+bool rspamd_log_file_on_fork(rspamd_logger_t *logger, struct rspamd_config *cfg,
+							 gpointer arg, GError **err)
+{
+	struct rspamd_file_logger_priv *priv = (struct rspamd_file_logger_priv *) arg;
+
+	rspamd_log_reset_repeated(logger, priv);
+	rspamd_log_flush(logger, priv);
+
+	return true;
+}
\ No newline at end of file