RCPTID skipping numbers when suppression is enabled

[amdrsantos]

syslog-ng

Version of syslog-ng

syslog-ng 4 (4.1.0)
Config version: 4.0
Installer-Version: 4.1.0
Revision: 4.1.0-1
Compile-Date: Feb 28 2023 15:33:51
Module-Directory: /usr/lib/syslog-ng/4.1
Module-Path: /usr/lib/syslog-ng/4.1
Include-Path: /usr/share/syslog-ng/include
Available-Modules: afmongodb,timestamp,csvparser,appmodel,regexp-parser,rate-limit-filter,correlation,afsocket,syslogformat,linux-kmsg-format,hook-commands,affile,tags-parser,metrics-probe,cryptofuncs,disk-buffer,afuser,confgen,afprog,cef,basicfuncs,afsql,system-source,kvformat,pseudofile,json-plugin,sdjournal,pacctformat
Enable-Debug: off
Enable-GProf: off
Enable-Memtrace: off
Enable-IPv6: on
Enable-Spoof-Source: on
Enable-TCP-Wrapper: on
Enable-Linux-Caps: on
Enable-Systemd: on

Platform

PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"

Debug bundle

Not available

Issue

Failure

In the following log excerpt:

<190>1 2023-08-24T09:26:48.261+00:00 machine pmManager 6588 - [meta sequenceId="1332902"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 7585
<190>1 2023-08-24T09:26:48.261+00:00 machine pmManager 6588 - [meta sequenceId="1332903"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 10497
<190>1 2023-08-24T09:26:48.261+00:00 machine pmManager 6588 - [meta sequenceId="1332904"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 10628
<190>1 2023-08-24T09:26:48.261+00:00 machine pmManager 6588 - [meta sequenceId="1332905"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 15383
<190>1 2023-08-24T09:26:48.261+00:00 machine pmManager 6588 - [meta sequenceId="1332906"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 17143
<190>1 2023-08-24T09:26:48.448+00:00 machine pmManager 67637 - [meta sequenceId="3"] Last message '22744:Pm            ' repeated 11 times, suppressed by syslog-ng on machine
<190>1 2023-08-24T09:26:48.263+00:00 machine pmManager 6588 - [meta sequenceId="1332918"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 21096
<190>1 2023-08-24T09:26:48.263+00:00 machine pmManager 6588 - [meta sequenceId="1332920"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 1440
<190>1 2023-08-24T09:26:48.453+00:00 machine pmManager 67637 - [meta sequenceId="4"] Last message '22744:Pm            ' repeated 17 times, suppressed by syslog-ng on machine
<190>1 2023-08-24T09:26:48.266+00:00 machine pmManager 6588 - [meta sequenceId="1332938"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 2160
<190>1 2023-08-24T09:26:48.453+00:00 machine pmManager 67637 - [meta sequenceId="5"] Last message '22744:Pm            ' repeated 1 times, suppressed by syslog-ng on machine
<190>1 2023-08-24T09:26:48.267+00:00 machine pmManager 6588 - [meta sequenceId="1332941"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 44903
<190>1 2023-08-24T09:26:48.267+00:00 machine pmManager 6588 - [meta sequenceId="1332943"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 8622
<190>1 2023-08-24T09:26:48.267+00:00 machine pmManager 6588 - [meta sequenceId="1332944"] 22744:Pm             INFO   {Orchestrator.cpp:1612} No registered CBT_EXE calback for moid 17682
<190>1 2023-08-24T09:26:48.457+00:00 machine pmManager 67637 - [meta sequenceId="6"] Last message '22744:Pm            ' repeated 38 times, suppressed by syslog-ng on machine
<190>1 2023-08-24T09:26:48.279+00:00 machine pmManager 6588 - [meta sequenceId="1332983"] 22744:Pm             INFO   {Orchestrator.cpp:1578} In_work CBT_EXE Start key=MO: ioa-pm__pm-resource [DB Key(Hex): ed558b2f5c07ed550f0001299d395f4101290300312d3400000000  key_len: 27]
<190>1 2023-08-24T09:26:48.280+00:00 machine pmManager 6588 - [meta sequenceId="1332985"] 22744:Pm             INFO   {DbfHandler.cpp:216} process command: e_CommandEnum_addPmp DBF request=94
<190>1 2023-08-24T09:26:48.280+00:00 machine pmManager 6588 - [meta sequenceId="1332986"] 22828:Pm             INFO   {RequestDispatcher.cpp:321} Agent 1-4 requests for DBF request 94:
<190>1 2023-08-24T09:26:48.281+00:00 machine pmManager 6588 - [meta sequenceId="1332987"] 22828:Pm             INFO   {RequestDispatcher.cpp:327} request 1: [Command=e_CommandEnum_addPmp PmpKey=01299D395F4101290300312D340000 ResyncPmpKeys= PmpType=gx:CHM6 Aid=1-4 Period= Parameter= ParameterType=e_ParameterTypeEnum_counter Direction=e_ParameterDirectionEnum_all Location=e_ParameterLocationEnum_all Shelf=1 Slot=4 EnableSwitch=0 SupervisionSwitch=0 HistorySwitch=0 ThresholdingSwitch=0 LowThresholdEnable=0 HighThresholdEnable=0 LowThreshold=0 HighThreshold=0 SignalType= Rate= ClientMode= PortType= SupportedFacilities= NumberOfRecords=0 SkipRecords=0 StartBin=0 EndBin=0 StartTime= EndTime=]

It is missing IDs 1332919, 1332942, 1332985.
It is like after the suppression message RCPTID jumped one number.
We are using rewrite r_sequence_id {set("${RCPTID}" value(".SDATA.meta.sequenceId"));}; to set the sequence ID

Steps to reproduce

Force syslog-ng to suppress some messages

Configuration

@version: 4.1

# First, set some global options.
options {
    chain_hostnames(off);
    flush_lines(0);
    use_dns(no);
    dns-cache(no);
    use_fqdn(no);
    owner("root");
    group("root");
    perm(0644);
    stats(freq(0));
    bad_hostname("^gconfd$");
    ts-format("iso");
    time_zone("UTC");
    mark-freq(0);
    frac-digits(3);
    keep-hostname(yes);
    use-rcptid(yes);
};

# common block end


source s_src {
    system();
    internal();
};

rewrite r_sequence_id {set("${RCPTID}" value(".SDATA.meta.sequenceId"));};

# localFile: default-audit
destination d_localfile_default-audit {
    file("/var/log/default-audit.log"
        flags(syslog-protocol)
        suppress(5)
        disk-buffer(
            mem-buf-size(2097152)
            disk-buf-size(4194304)
            reliable(yes)
            dir("/tmp")
        )
    );
};
log {
    source(s_src);
    rewrite(r_sequence_id);
    destination(d_localfile_default-audit);
    flags(flow-control);
};
# end of localFile: default-audit

Input and output logs (if possible)

[MrAnno]

RCPTID is a global counter in syslog-ng, each new message increments it by one.
When suppression is enabled, repeated N times, suppressed by syslog-ng messages are produced, and they also increment this counter.

[amdrsantos]

Yes, but suppression messages go through a different path otherwise they would have the RCPTID, Instead they have their own counter.
How can I change this behavior?

[MrAnno]

What exactly would you like to achieve?

Based on the discussion in #4363, you are seeking a way to uniquely identify each message in syslog-ng.
If you require a system-wide unique ID, there may be gaps between those IDs on the destination side, because your configuration contains multiple paths/destinations.

RCPTID can be used for precisely this purpose. RCPTID is assigned to a message when it enters the system, so you will see gaps in the sequenceId values on the destination side when new messages are received/produced in other log paths.

The suppression message is no exception: it is new message created by syslog-ng dynamically, so it increments the RCPTID.

It is missing IDs 1332919, 1332942, 1332985.

These IDs were assigned to the suppression summary messages, but you can't see them because the sequenceId field of those suppression messages is filled with a different counter: the given destination's local sequence number.

Unfortunately, rewriting the sequenceId field of the suppression message is not possible currently, but I can try implementing such a feature if that's what you want to achieve.

[bazsi]

This PR should add the capability to send a monotonic sequence ID:

#4745

Let me know if that helps.