spoof-source(yes) truncates forwarded UDP messages at 1024 bytes / Please make spoof_source_maxmsglen configurable

[xtaran]

syslog-ng

Version of syslog-ng

syslog-ng 3.8.1
Installer-Version: 3.8.1
Revision: 3.8.1-10
Module-Directory: /usr/lib/syslog-ng/3.8
Module-Path: /usr/lib/syslog-ng/3.8
Available-Modules: affile,date,afprog,basicfuncs,afsocket,csvparser,syslogformat,disk-buffer,linux-kmsg-format,cryptofuncs,sdjournal,confgen,kvformat,afmongodb,dbparser,cef,afuser,pseudofile,json-plugin,afsql,system-source
Enable-Debug: off
Enable-GProf: off
Enable-Memtrace: off
Enable-IPv6: on
Enable-Spoof-Source: on
Enable-TCP-Wrapper: on
Enable-Linux-Caps: off

According to git grep spoof_source_maxmsglen in the current git HEAD (as of 8f10d8f), this issue is still present in the current git HEAD.

Platform

Debian 9 Stretch, Raspbian 9 Stretch

Debug bundle

Create a debug bundle on your system with the syslog-ng-debun script which is included in the syslog-ng package.

There seems neither a syslog-ng-debun (nor a syslog-ng-debug in case that the n is a typo) file in the Debian package of syslog-ng (nor any other Debian package in Debian 9 Stretch).

Issue

With spoof-source(yes), messages over 1024 bytes are truncated when relaying. This seems to be related to #341. See my comment there.

Failure

Forwarding this over 1024 bytes long message UDP: 123456789a123456789a123456789b123456789b123456789c123456789c123456789d123456789d123456789e123456789e123456789f123456789f123456789g123456789g123456789h123456789h123456789i123456789i123456789j123456789j123456789k123456789k123456789l123456789l123456789m123456789m123456789n123456789n123456789o123456789o123456789p123456789p123456789q123456789q123456789r123456789r123456789s123456789s123456789t123456789t123456789u123456789u123456789v123456789v123456789w123456789w123456789x123456789x123456789y123456789y123456789z123456789z123456789A123456789A123456789B123456789B123456789C123456789C123456789D123456789D123456789E123456789E123456789F123456789F123456789G123456789G123456789H123456789H123456789I123456789I123456789J123456789J123456789K123456789K123456789L123456789L123456789M123456789M123456789N123456789N123456789O123456789O123456789P123456789P123456789Q123456789Q123456789R123456789R123456789S123456789S123456789T123456789T123456789U123456789U123456789V123456789V123456789W123456789W123456789X123456789X123456789Y123456789Y123456789Z123456789Z over UDP with and without spoof-source(yes) yields in different messages being forwarded to the receiving server:

• without spoof-source(yes) the following is received: 2019-02-04T16:15:30.951+00:00/2019-02-04T16:15:30.951+00:00 192.168.23.159/192.168.23.159/s_net_udp 1 2019-02-04T16:15:30+00:00 192.168.23.146 /usr/local/bin/generate-long-log-entry-network.pl - - - UDP: 123456789a123456789a123456789b123456789b123456789c123456789c123456789d123456789d123456789e123456789e123456789f123456789f123456789g123456789g123456789h123456789h123456789i123456789i123456789j123456789j123456789k123456789k123456789l123456789l123456789m123456789m123456789n123456789n123456789o123456789o123456789p123456789p123456789q123456789q123456789r123456789r123456789s123456789s123456789t123456789t123456789u123456789u123456789v123456789v123456789w123456789w123456789x123456789x123456789y123456789y123456789z123456789z123456789A123456789A123456789B123456789B123456789C123456789C123456789D123456789D123456789E123456789E123456789F123456789F123456789G123456789G123456789H123456789H123456789I123456789I123456789J123456789J123456789K123456789K123456789L123456789L123456789M123456789M123456789N123456789N123456789O123456789O123456789P123456789P123456789Q123456789Q123456789R123456789R123456789S123456789S123456789T123456789T123456789U123456789U123456789V123456789V123456789W123456789W123456789X123456789X123456789Y123456789Y123456789Z123456789Z
• with spoof-source(yes) the following is received: 2019-02-04T16:15:30.951+00:00/2019-02-04T16:15:30.951+00:00 192.168.23.146/192.168.23.146/s_net_udp 1 2019-02-04T16:15:30+00:00 192.168.23.146 /usr/local/bin/generate-long-log-entry-network.pl - - - UDP: 123456789a123456789a123456789b123456789b123456789c123456789c123456789d123456789d123456789e123456789e123456789f123456789f123456789g123456789g123456789h123456789h123456789i123456789i123456789j123456789j123456789k123456789k123456789l123456789l123456789m123456789m123456789n123456789n123456789o123456789o123456789p123456789p123456789q123456789q123456789r123456789r123456789s123456789s123456789t123456789t123456789u123456789u123456789v123456789v123456789w123456789w123456789x123456789x123456789y123456789y123456789z123456789z123456789A123456789A123456789B123456789B123456789C123456789C123456789D123456789D123456789E123456789E123456789F123456789F123456789G123456789G123456789H123456789H123456789I123456789I123456789J123456789J123456789K123456789K123456789L123456789L123456789M123456789M123456789N123456789N123456789O123456789O123456789P123456789P123456789Q123456789Q123456789R123456789R123456789S123456789S123456789T123456

Note that the latter message is not ending in 89Z.

Steps to reproduce

I used a setup with three Raspberry Pis to reproduce what we saw in large scale on our productive syslog relays:

nsg-lab-sender aka 192.168.23.146

Just forwards any syslog message to nsg-lab-relay.

Relevant configuration:

# cat /etc/syslog-ng/conf.d/sender.conf
destination d_relay {
    syslog(
        "nsg-lab-relay"
        transport("udp")
        port(514)
        flags(syslog-protocol)
    );
};

log {
    source(s_src);
    destination(d_relay);
};

This Perl script was used on the sender side to produce this log entry (and others):

#!/usr/bin/perl

use strict;
use warnings;
use Sys::Syslog qw(:standard :extended);

my $s = "";
foreach my $i ("a" .. "z", "A" .. "Z") {
    $s .= sprintf("123456789%s123456789%s", $i, $i);
}

# DEFAULT
openlog($0, 'perror', 'LOG_USER');
syslog('DEBUG', "DEFAULT: $s");
closelog();

sleep(1);

# TCP
openlog($0, 'perror', 'LOG_USER');
setlogsock({ type => "tcp", host => '192.168.23.159', port => 601 });
syslog('DEBUG', "TCP: $s");
closelog();

sleep(1);

# UDP
openlog($0, 'perror', 'LOG_USER');
setlogsock({ type => "udp", host => '192.168.23.159', port => 514 });
syslog('DEBUG', "UDP: $s");
closelog();

nsg-lab-relay aka 192.168.23.159

Listens on TCP and UDP, saves any received syslog message locally as well as forwards it in three different ways (udp without spoof_source, udp with spoof_source and tcp) to nsg-lab-receiver.

Relevant configuration:

# cat /etc/syslog-ng/conf.d/relay.conf 
source s_net_udp  {
    network(
        transport("udp")
        ip("0.0.0.0")
        ip-protocol(4)
        port(514)
        tags("udp")
    );
};
source s_net_udp6 {
    network(
        transport("udp")
        ip("::")
        ip-protocol(6)
        port(514)
        tags("udp6")
    );
};
source s_net_tcp {
    network(
        transport("tcp")
        ip-protocol(6)
        port(601)
        tags("tcp")
    );
};
source s_net_tls {
    network(
        transport("tls")
        ip-protocol(6)
        port(6514)
        tags("tls")
        tls(peer-verify(optional-trusted))
    );
};

destination d_receiver_udp_spoof {
    syslog(
        "nsg-lab-receiver"
        transport("udp")
        port(514)
        flags(syslog-protocol)
        spoof-source(yes)
        persist-name("fwd_udp_spoof")
    );
};

destination d_receiver_udp {
    syslog(
        "nsg-lab-receiver"
        transport("udp")
        port(514)
        flags(syslog-protocol)
        persist-name("fwd_udp")
    );
};

destination d_receiver_tcp {
    syslog(
        "nsg-lab-receiver"
        transport("tcp")
        port(601)
        flags(syslog-protocol)
        persist-name("fwd_tcp")
    );
};

destination d_test {
    file(
        "/var/log/test.${R_YEAR}-${R_MONTH}-${R_DAY}.log"
        ts-format(iso)
        frac-digits(3)
        dir-perm(0750)
        perm(0640)
        template("${R_ISODATE}/${S_ISODATE} ${HOST}/${SOURCEIP}/${SOURCE} ${MSGHDR} $(indent-multi-line ${MSG})\n")
    );
};

log {
    source(s_src);
    source(s_net_udp);
    source(s_net_udp6);
    source(s_net_tcp);
    source(s_net_tls);
    destination(d_receiver_udp_spoof);
    destination(d_receiver_udp);
    destination(d_receiver_tcp);
    destination(d_test);
};

nsg-lab-receiver aka 192.168.23.164

Listens on TCP and UDP and saves any receivedsyslog message to a dedicated log file.

Relevant configuration:

# cat /etc/syslog-ng/conf.d/receiver.conf
source s_net_udp  {
    network(
        transport("udp")
        ip("0.0.0.0")
        ip-protocol(4)
        port(514)
        tags("udp")
    );
};
source s_net_udp6 {
    network(
        transport("udp")
        ip("::")
        ip-protocol(6)
        port(514)
        tags("udp6")
    );
};
source s_net_tcp {
    network(
        transport("tcp")
        ip-protocol(6)
        port(601)
        tags("tcp")
    );
};
source s_net_tls {
    network(
        transport("tls")
        ip-protocol(6)
        port(6514)
        tags("tls")
        tls(peer-verify(optional-trusted))
    );
};

destination d_test {
    file(
        "/var/log/test.${R_YEAR}-${R_MONTH}-${R_DAY}.log"
        ts-format(iso)
        frac-digits(3)
        dir-group("xlog")
        group("xlog")
        dir-perm(0750)
        perm(0640)
        template("${R_ISODATE}/${S_ISODATE} ${HOST}/${SOURCEIP}/${SOURCE} ${MSGHDR} $(indent-multi-line ${MSG})\n")
    );
};

log {
    source(s_net_udp);
    source(s_net_udp6);
    source(s_net_tcp);
    source(s_net_tls);
    destination(d_test);
};

Configuration

See above. Any other configuration is just the default from the Debian package of syslog-ng.

Input and output logs (if possible)

See above.

Suggestion / Wishlist

Please make spoof_source_maxmsglen (see #341) configurable.

[xtaran]

Both, RFC 5424 as well as RFC 5426 recommend that Syslog receivers SHOULD support syslog messages which are 2048 octet long.

So I assume in this case the motivation behind truncating is that the message is not discarded after being forwarded due to its size. But then again, the chances seem high to me, that, if that long UDP packet could be received, the forwarding inside the same perimeter works with the same MTU sizes and that truncating is likely not needed. IMHO yet another reason to not hardcode this value.

[szemere]

Hello @xtaran,
thank you for reporting this issue (and also thank you for all the details you provided, very nice description).

I have started to investigate the problem, maybe there are other options beside "just" making this variable public in the configuration. I will be back with my findings.

Br,
Laci

[bazsi]

please see #2535 for a potential solution.

[xtaran]

Woah, that was quick, thanks!

Will have a closer look tomorrow (by compiling syslog-ng on my lab relay from git HEAD). Will post comments to the pull request.

[xtaran]

Will have a closer look tomorrow (by compiling syslog-ng on my lab relay from git HEAD). Will post comments to the pull request.

I think it's probably better to wait for a patch for #2535 (comment) before testing. Or should I still try the first suggested fix?

[gaborznagy]

#2535 is merged, I am closing this ticket if you agree.