[syslog-ng] Filtering duplicate messages
Balazs Scheidler
bazsi at balabit.hu
Thu May 29 22:13:28 CEST 2008
Hi Chris,
Thanks for your contribution. Please find my comments in-line.
Please note that in order to get this integrated into syslog-ng, you'll
need to sign a "Contributory License Agreement" which is available on
our website here:
http://www.balabit.com/network-security/syslog-ng/opensource-logging-system/contribution/
Thanks.
So after the legalese, let's see your notes and patch below.
On Thu, 2008-05-29 at 12:57 +1200, chris packham wrote:
> Here's a rough cut of my patch. It still needs a bit of cleanup and I
> have yet to implement the time-based behaviour. I just wanted to get
> some
> feedback.
>
> One particular thing I wanted to clarify is where in the log message
> pipeline would best to attach this behaviour to? I've currently
> attached it to the LogWriter. The disadvantage of that is that the new
> message I generate does not get passed through the filters or templates
> (and we've just done a bunch of wasted processing on a message that
> gets dropped)
There are basically three options:
1) sources
2) as a processing element between sources/destinations (for example
filters, LogProcess in syslog-ng 2.2)
3) in the LogWriter
All three has pros and cons:
1) suppress on input:
pros:
* drop messages as early as possible
* every destination would receive the same suppressions from the same
host
cons:
* would need a host-name indexed hashtable to store host specific
suppression info, this needs memory and CPU
2) suppress as a processing element:
pros:
* probably the most flexible, the user could choose which log pipes
have suppressions and which don't
cons:
* it requires the same amount of state as suppressing on input
* it is more complex than any other alternative and the flexibility
it provides is probably not needed
3) suppress in the LogWriter
pros:
* the easiest to implement
* no need for per-host state, it uses a per-destination state but
that's already available (every destination has a separate writer)
cons:
* different destinations will have a different set of suppressions
depending on the set of sources that feed the given destination
I'd say that doing it in LogWriter is a sane choice. We could do better
but that'd cost us memory and CPU for an added flexibility which is
probably not needed.
>
> The behaviour implemented is as follows.
>
> As a log message is output to a destination it is remembered
> as the last message seen.
>
> When a new message is to be output it is checked against the
> last message seen. If its contents (message text, including
> hostname and pid if present) are the same the message is dropped
> and a couter incremented. If the message is different to the
> last message seen a new log message indicating the value of the
> last message counter will be inserted into the queue and the new
> message will be processed.
>
> TODO: Implement a time based flush of last seen messages
>
> ---
> src/cfg-grammar.y | 3 +-
> src/cfg-lex.l | 3 +-
> src/logmsg.c | 26 +++++++++++++++++++++++
> src/logmsg.h | 2 +
> src/logwriter.c | 59
> ++++++++++++++++++++++++++++++++++++++++++++++++++++-
> src/logwriter.h | 9 ++++++++
> 6 files changed, 99 insertions(+), 3 deletions(-)
>
> diff --git a/src/cfg-grammar.y b/src/cfg-grammar.y
> index 39ff172..386c231 100644
> --- a/src/cfg-grammar.y
> +++ b/src/cfg-grammar.y
> @@ -62,7 +62,7 @@ gint last_addr_family = AF_INET;
> %token KW_USER KW_DOOR KW_SUN_STREAMS KW_PROGRAM
>
> /* option items */
> -%token KW_FSYNC KW_MARK_FREQ KW_STATS_FREQ KW_FLUSH_LINES
> KW_FLUSH_TIMEOUT KW_LOG_MSG_SIZE KW_FILE_TEMPLATE KW_PROTO_TEMPLATE
> +%token KW_FSYNC KW_MARK_FREQ KW_STATS_FREQ KW_FLUSH_LINES KW_SUPPRESS
> KW_FLUSH_TIMEOUT KW_LOG_MSG_SIZE KW_FILE_TEMPLATE KW_PROTO_TEMPLATE
>
> %token KW_CHAIN_HOSTNAMES KW_NORMALIZE_HOSTNAMES KW_KEEP_HOSTNAME
> KW_CHECK_HOSTNAME KW_BAD_HOSTNAME
> %token KW_KEEP_TIMESTAMP
> @@ -671,6 +671,7 @@ dest_writer_option
> : KW_FLAGS '(' dest_writer_options_flags ')' {
> last_writer_options->options = $3; }
> | KW_LOG_FIFO_SIZE '(' NUMBER ')' {
> last_writer_options->fifo_size = $3; }
> | KW_FLUSH_LINES '(' NUMBER ')' {
> last_writer_options->flush_lines = $3; }
> + | KW_SUPPRESS '(' yesno ')' {
> last_writer_options->suppress= $3; }
> | KW_FLUSH_TIMEOUT '(' NUMBER ')' {
> last_writer_options->flush_timeout = $3; }
> | KW_TEMPLATE '(' string ')' {
>
> last_writer_options->template = cfg_lookup_template(configuration, $3);
ok.
> diff --git a/src/cfg-lex.l b/src/cfg-lex.l
> index 5c5f54f..4eb0c63 100644
> --- a/src/cfg-lex.l
> +++ b/src/cfg-lex.l
> @@ -6,7 +6,7 @@
>
>
> /***************************************************************************
> *
> - * Copyright (c) 1999 Balzs Scheidler
> + * Copyright (c) 1999 Bal�zs Scheidler
> * Copyright (c) 1999-2007 BalaBit IT Ltd.
> *
> * This program is free software; you can redistribute it and/or modify
> @@ -86,6 +86,7 @@ static struct keyword keywords[] = {
> { "flush_timeout", KW_FLUSH_TIMEOUT },
> { "sync_freq", KW_FLUSH_LINES }, /* obsolete */
> { "sync", KW_FLUSH_LINES }, /* obsolete */
> + { "suppress", KW_SUPPRESS },
> { "fsync", KW_FSYNC },
> { "long_hostnames", KW_CHAIN_HOSTNAMES },
> { "chain_hostnames", KW_CHAIN_HOSTNAMES },
ok.
> diff --git a/src/logmsg.c b/src/logmsg.c
> index 05354b5..4da3af5 100644
> --- a/src/logmsg.c
> +++ b/src/logmsg.c
> @@ -766,3 +766,29 @@ log_msg_drop(LogMessage *m, guint path_flags)
> log_msg_ack(m);
> log_msg_unref(m);
> }
> +
> +/**
> + * log_msg_dup:
> + * @m: LogMessage instance
> + *
> + * This function duplicates an existing log message. The new message is
> not parsed.
> + */
> +LogMessage *
> +log_msg_dup(LogMessage *m)
> +{
> + LogMessage *nm = g_new0(LogMessage, 1);
> +
> + log_msg_init(nm, m->saddr);
> + nm->flags
> = m->flags;
> + nm->pri = m->pri;
> + g_string_assign_len(&nm->date, m->date.str, m->date.len);
> + g_string_assign_len(&nm->host, m->host.str, m->host.len);
> + g_string_assign_len(&nm->host_from, m->host_from.str,
> m->host_from.len);
> + g_string_assign_len(&nm->program, m->program.str, m->program.len);
> + g_string_assign_len(&nm->msg, m->msg.str, m->msg.len);
> + memcpy(&nm->stamp, &m->stamp, sizeof(LogStamp));
> + memcpy(&nm->recvd, &m->recvd, sizeof(LogStamp));
> +
> + return nm;
> +}
I don't think this is needed, but see below.
> +
> diff --git a/src/logmsg.h b/src/logmsg.h
> index 420a711..9dbb886 100644
> --- a/src/logmsg.h
> +++ b/src/logmsg.h
> @@ -107,6 +107,8 @@ void log_msg_ack_block_end(LogMessage *m);
> void log_msg_ack(LogMessage *msg);
> void log_msg_drop(LogMessage *msg, guint path_flags);
> void log_msg_clear_matches(LogMessage *self);
> +LogMessage *log_msg_dup(LogMessage *m);
> +
>
> gchar *log_msg_find_cr_or_lf(gchar *s, gsize n);
>
> diff --git a/src/logwriter.c b/src/logwriter.c
> index bb82b43..4843100 100644
> --- a/src/logwriter.c
> +++ b/src/logwriter.c
> @@ -178,11 +178,63 @@ log_writer_watch_new(LogWriter *writer, FDWrite
> *fd)
> return &self->super;
> }
>
> +static gboolean
> +log_writer_supress_duplicate(LogWriter *self, LogMessage *lm, gint
> path_flags)
> +{
> + if (!self->options->suppress)
> + return FALSE;
> +
> + if(self->suppress.hash)
> + {
> + guint hash = g_string_hash(&lm->msg);
> + if(self->suppress.hash == hash)
> + {
> + msg_debug("Dropping duplicate message",
> + NULL);
> + self->suppress.count ++;
> + log_msg_drop(lm, path_flags);
> + return TRUE;
> + }
I don't think g_string_hash buys us anything, in fact it might well be
slower than doing a direct string comparison (strcmp is performed in
chunks of sizeof(long) bytes, g_string_hash iterates over characters
individually).
You mentioned that you are also checking the hostname, which is not the
case, lm->msg contains the application name and pid only.
I think we should also check that.
> +
> + if (self->suppress.count)
> + {
> + gchar *buf;
> + LogMessage *m;
> + GString *line = g_string_sized_new(128);
> +
> + buf = g_strdup_printf("<%d> syslog-ng[%d]: Last message
> '%.20s' repeated %d times\n",
> + self->suppress.msg->pri,
> + getpid(),
> + self->suppress.msg->msg.str,
> + self->suppress.count);
we'd probably need a log_msg_new_internal() function, that would produce
the same message without having to parse it. This and the code in
messages.c would be a direct user of that function.
> + m = log_msg_new(buf, strlen(buf), self->suppress.msg->saddr,
> 0, NULL);
> + g_queue_push_tail(self->queue, m);
> + g_queue_push_tail(self->queue, GUINT_TO_POINTER(0x80000000));
> + g_free(buf);
> + }
> + log_msg_drop(self->suppress.msg, 0);
> + self->suppress.msg = log_msg_dup(lm);
As a LogMessage is read-only (well most of, and I'm directing syslog-ng
2.2 so that LogMessage is going to be read only), I think it is enough
to store a reference and no need to copy the complete message. This is
too expensive.
> + self->suppress.hash = g_string_hash(&lm->msg);
> + self->suppress.count = 0;
> + }
> + else
> + {
> + self->suppress.msg = log_msg_dup(lm);
> + self->suppress.hash = g_string_hash(&lm->msg);
> + self->suppress.count = 0;
> + }
> +
> + return FALSE;
> +}
> +
> static void
> log_writer_queue(LogPipe *s, LogMessage *lm, gint path_flags)
> {
> LogWriter *self = (LogWriter *) s;
> -
> +
> + if(log_writer_supress_duplicate(self, lm, path_flags))
> + return;
> +
> if ((self->queue->length / 2) == self->options->fifo_size)
> {
> /* drop incoming message, we must ack here, otherwise the sender
> might
> @@ -462,6 +514,9 @@ log_writer_new(guint32 flags, LogPipe *control,
> LogWriterOptions *options)
> self->queue = g_queue_new();
> self->flags = flags;
> self->control = control;
> + self->suppress.msg = NULL;
> + self->suppress.hash = 0;
> + self->suppress.count = 0;
> return &self->super;
> }
>
> @@ -476,6 +531,8 @@ log_writer_options_defaults(LogWriterOptions
> *options)
> options->ts_format = -1;
> options->zone_offset = -1;
> options->frac_digits = -1;
> + options->suppress = FALSE;
> +
> }
>
> void
> diff --git a/src/logwriter.h b/src/logwriter.h
> index 284899b..d3a136f 100644
> --- a/src/logwriter.h
> +++ b/src/logwriter.h
> @@ -41,6 +41,13 @@
> /* several writers use the same counter */
> #define LWOF_SHARE_STATS 0x0002
>
> +typedef struct _LogSuppress
> +{
> + LogMessage *msg;
> + guint hash;
> + guint32 count;
> +} LogSuppress;
As I've removed hash from the picture, I don't think we need a separate
structure for this. Just add two fields in LogWriter.
> +
> glong zone_offset;
> gshort frac_digits;
> + gboolean suppress;
> } LogWriterOptions;
>
> typedef struct _LogWriter
> @@
> -79,6 +87,7 @@ typedef struct _LogWriter
> gint partial_pos;
> LogPipe *control;
> LogWriterOptions *options;
> + LogSuppress suppress;
> } LogWriter;
>
> void log_writer_set_options(LogWriter *self, LogPipe *control,
> LogWriterOptions *options);
> --
> 1.5.4.5
>
> ______________________________________________________________________________
> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
> Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng
> FAQ: http://www.campin.net/syslog-ng/faq.html
>
--
Bazsi
More information about the syslog-ng
mailing list