Provide a unique sequential message ID

[amdrsantos]

I am trying to provide a unique sequential message ID for each log message.

I am using use-rcptid(yes); in the global options and then rewrite r_sequence_id { set("${RCPTID}" value(".SDATA.meta.sequenceId")); }; in each destination.

This works fine, even in restarts and reloads, the sequence is not interrupted, but the indication of suppressed messages comes with a different sequence:

<190>1 2023-03-09T16:25:26.174+00:00 machine pal 6619 - [meta sequenceId="10720"] 8100:CC              INFO   [1-1]: sending attribute change notificationAid { Eqpt { SerialConsoleState { value: ControlState_ENABLE } AutoSensState { value: CnslAutoSens_LOCKED } CurrSerialConsoleXrate { } } }
<187>1 2023-03-09T16:25:26.548+00:00 machine fdrcollector 6484 - [meta sequenceId="10721"] 6484:fdrcollector    ERROR  {FdrDataCollector.cpp:147} Error Failed to connect to Redis: No route to host
<187>1 2023-03-09T16:25:30.215+00:00 machine fdrcollector 8473 - [meta sequenceId="2"] Last message '6484:fdrcollector   ' repeated 1 times, suppressed by syslog-ng on machine
<188>1 2023-03-09T16:25:30.014+00:00 machine SdaServerInterCc 6315 - [meta sequenceId="10740"] serf: Intent queue depth: 307
<187>1 2023-03-09T16:25:32.737+00:00 machine fdrcollector 6484 - [meta sequenceId="10767"] 6484:fdrcollector    ERROR  {FdrDataCollector.cpp:147} Error Failed to connect to Redis: No route to host
<187>1 2023-03-09T16:25:39.287+00:00 machine fdrcollector 8473 - [meta sequenceId="3"] Last message '6484:fdrcollector   ' repeated 1 times, suppressed by syslog-ng on machine
<187>1 2023-03-09T16:25:38.865+00:00 machine fdrcollector 6484 - [meta sequenceId="10823"] 6484:fdrcollector    ERROR  {FdrDataCollector.cpp:147} Error Failed to connect to Redis: No route to host

Is there any way that this could be avoided?

[bazsi]

the suppression message does not traverse the same path as the messages where you apply the rewrite rule, rather they are generated right within the destination itself, but this means that your rewrite rule does not apply.

Also, it is considered a local message and as such syslog-ng generates its own sequenceId. That's why it is different. sequenceId is defined by the RFC as an originator defined sequence https://www.rfc-editor.org/rfc/rfc5424#page-24

So a relay overriding this value may not be completely RFC conformant, which is probably not much relevant to you, but I wanted to point out and explain the current syslog-ng behaviour, that is:

• we forward sequenceId if we received it (or if you set it via rewrite rule)
• we generate a sequenceId at the destination for local messages (but only those).

The behaviour you experience stems from the fact that the formatting of the suppression message is hard-coded into the destination logic in syslog-ng, so it does not traverse your rewrite rule.

The good news is that all messages have an RCPTID, even the suppression one, so the trick is to inject that value to the message somehow.

[amdrsantos]

What do mean by somehow? Via message template? Or some other thing?
Thanks

[bazsi]

Yes, a template would be possible. I was looking at how I could make the suppression message customizable, but all the alternatives were pretty complicated.

But suppress() could be extracted from the destination and provided as a parser () component. With that you could customize its contents. Would that be interesting to you?

This is probably even doable today with grouping-by () which would probably use a lot more memory than suppress() but could still deliver the functionality. If that works for you, I'd be willing to implement something that would not be as flexible as grouping-by but would use a lot less resources.

Here's a sample that would be similar to suppress, but with grouping-by:

I am on a phone so I can't try what I type here. I'll come back from my desktop as I get there.

[amdrsantos]

Thanks, Bazsi, I think that would work for us, please post an example when you can.

[amdrsantos]

Here's a sample that would be similar to suppress, but with grouping-by:

I never got the example :). Post it when you can
Thanks

[bazsi]

This does the job, however I can see some deficiencies with this:

• it adds a delay of 10 seconds
• it can potentially consume a lot of memory (as all different messages that happen in a 10second timespan are kept in memory)

@version: 4.0

log {
	source { tcp(port(2000) flags(no-parse)); };

	parser {
		grouping-by(
			timeout(10)
			key("$MSG")
			aggregate(
				value("MSG", "$MSG (duplicates $(- $(context-length) 1))")
			)
			inject-mode(aggregate-only)
		);
	};

	destination { file("deduplicated.log"); };
};

[bazsi]

I tried to improve this a bit, by using $HOST as key (not as high in cardinality)

@version: 4.0

log {
        source { tcp(port(2000) flags(no-parse)); };

        parser {
                grouping-by(
                        timeout(10)
                        key("$HOST")
                        aggregate(
                                value("MSG", "$MSG (duplicates $(- $(context-length) 1))")
                        )
                        trigger("$(context-length)" > 1 and "${MSG}" != "${MSG}@1")
                        inject-mode(aggregate-only)
                );
        };

        destination { file("deduplicated.log"); };
};

The issue here is that trigger() is evaluated by the time the new message is already consumed into a context, so at the time we generate the aggregate we would be aggregating the duplicates and the first non-matching message.

We also have where() option but that does not see the context.

[bazsi]

I was testing with this input:

$ cat duplicates 
foo
foo
foo
foo
bar
foo
foo
foo
foo
bar

The output of the 1st:

Apr 17 16:30:20 localhost foo (suppressed 8)
Apr 17 16:30:20 localhost bar (suppressed 2)

The output of the 2nd (incorrect):

Apr 17 16:37:50 localhost bar (duplicates 5)
Apr 17 16:37:50 localhost bar (duplicates 5)

[amdrsantos]

Thanks, we encountered another issue.
We were trying to use ${RCPTID} as sequenceId of RFC 5424.

The "sequenceId" parameter tracks the sequence in which the
originator submits messages to the syslog transport for sending. It
is an integer that MUST be set to 1 when the syslog function is
started and MUST be increased with every message up to a maximum
value of 2147483647. If that value is reached, the next message MUST
be sent with a sequenceId of 1.

The RCPTID is 64 bit according to the code, 48 bit according to the documentation.
sequenceId is 32 bit

Do you know if when setting rewrite r_sequence_id { set("${RCPTID}" value(".SDATA.meta.sequenceId")); }; will be truncated to 32 bit?
Also, the hiding of zero needs to be done.

In relation to your comment in #3036 (comment), are there going to be any changes?

[amdrsantos]

Can the RCPTID be changed to 32bit ?
Can we have an internal log with a notification that the id has rotated?
Thanks, Alex

[bazsi]

you could get to the same results using template functions to $(% $RCPTID 2147483648) would give you a 32 bit counter. to also get the non-zero capability, use 1 smaller number to modulo with and add one using something like $(+ $(% $RCPTID 2147483647))

…

On Tue, May 9, 2023 at 11:49 AM Alexandre Santos ***@***.***> wrote: Can the RCPTID be changed to 32bit ? Can we have an internal log with a notification that the id has rotated? Thanks, Alex — Reply to this email directly, view it on GitHub <#4363 (reply in thread)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAFOK5R4D4X2QW7V3LHXLBTXFIHK5ANCNFSM6AAAAAAVVK3DTM> . You are receiving this because you commented.Message ID: ***@***.***>

-- Bazsi

[bazsi]

FYI, I've just opened a PR which allows you to change the $SEQNUM behaviour using this configuration sample:

$ cat etc/syslog-ng-syslog.conf
@version: current

log {
	source { tcp(port(2000)); };
	destination { syslog("0" port(2001) flags(seqnum-all)); };
};

Note the "seqnum-all" flag, this will cause the syslog driver to always send meta.sequenceId as an incrementing number, not just for local messages.

I felt the original RFC5424 prescribed behaviour did not make much sense, so you can basically disable it with this flag. I think this is pretty close to what you'd like to accomplish.