0

Please don't bother reading this question. syslog-ng is already set up to send RFC5424 messages with octet-counting framing by default. I was confused by the behaviour of another component. This question is invalid.

I have a syslog-ng OSE config (v3.31.2):

@version: 3.29
@include "scl.conf"
    
source s_network {
    udp(ip(0.0.0.0) port(514));
};
    
destination d_network_telegraf {
    syslog("telegraf" port(601) transport(tcp));
};
    
log {
    source(s_network);
    destination(d_network_telegraf);
};

The intention is to forward RFC3164 formatted syslog messages received on UDP port 514, and forward them as RFC5424 formatted messages to telegraf on TCP port 601.

With this configuration, syslog-ng appears to be emitting the forwarded messages as RFC5424 with non-transparent (octet-stuffed) framing (message starts with an ASCII < character). Unfortunately telegraf expects to receive messages with octet-counting framing (message starts with a digit). RFC6587 covers these.

Although it is possible to configure telegraf to expect non-transparent framing, this doesn't seem to be working correctly. Before I dig into that, I'd like to try the alternative, which is to configure syslog-ng to output RFC5424 messages with octet-counting framing. This is apparently the recommended framing type anyway.

However I am not able to find anything in the syslog-ng docs about this. In almost all cases, the documentation discusses the use of the syslog driver for input, not output, and there's almost no mention of octet-counting at all.

Is it possible to configure syslog-ng in this manner?

EDIT

This is the exact config I am using:

@version: 3.29
@include "scl.conf"

options {
    create-dirs(yes);
    flush-lines(1);
    time-reopen(60);
};

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

source s_network {
    udp(ip(0.0.0.0) port(514));
};

destination d_local {
    file("/data/syslog-ng/var/log/messages");
    file("/data/syslog-ng/var/log/messages-kv.log" template("$ISODATE $HOST $(format-welf --scope all-nv-pairs)\n") frac-digits(3));
};

destination d_network_files {
    file("/data/syslog-ng/var/log/messages-network");
    file("/data/syslog-ng/var/log/messages-network-kv.log" template("$ISODATE $HOST $(format-welf --scope all-nv-pairs)\n") frac-digits(3));
};

destination d_network_telegraf {
    syslog("telegraf" port(601) transport(tcp));
};

log {
    source(s_network);
    destination(d_network_telegraf);
    destination(d_network_files);
};

Here is a message sent by logger -i -d --server localhost this is a test to syslog-ng via UDP port 514:

0000   02 42 ac 15 00 09 02 42 69 3a f6 78 08 00 45 00   .B.....Bi:.x..E.
0010   00 a6 79 e7 40 00 40 11 68 2b ac 15 00 01 ac 15   ..y.@.@.h+......
0020   00 09 b4 bd 02 02 00 92 58 d8 3c 31 33 3e 31 20   ........X.<13>1 
0030   32 30 32 31 2d 31 31 2d 31 38 54 31 32 3a 34 31   2021-11-18T12:41
0040   3a 35 39 2e 39 34 33 39 36 35 2b 31 33 3a 30 30   :59.943965+13:00
0050   20 6b 6f 72 69 6d 61 6b 6f 20 64 61 76 69 64 20    korimako david 
0060   36 38 38 31 34 30 20 2d 20 5b 74 69 6d 65 51 75   688140 - [timeQu
0070   61 6c 69 74 79 20 74 7a 4b 6e 6f 77 6e 3d 22 31   ality tzKnown="1
0080   22 20 69 73 53 79 6e 63 65 64 3d 22 31 22 20 73   " isSynced="1" s
0090   79 6e 63 41 63 63 75 72 61 63 79 3d 22 37 39 37   yncAccuracy="797
00a0   30 30 30 22 5d 20 74 68 69 73 20 69 73 20 61 20   000"] this is a 
00b0   74 65 73 74                                       test

And here is a captured message between syslog-ng and telegraf (TCP port 601):

0000   02 42 ac 15 00 07 02 42 ac 15 00 09 08 00 45 00   .B.....B......E.
0010   00 ec ba 61 40 00 40 06 27 70 ac 15 00 09 ac 15   ...a@.@.'p......
0020   00 07 a7 ab 02 59 be 1c 32 98 d1 f9 90 93 80 18   .....Y..2.......
0030   01 f6 59 19 00 00 01 01 08 0a 0c 3e 2a 2d 7a e2   ..Y........>*-z.
0040   58 de 3c 31 33 3e 31 20 32 30 32 31 2d 31 31 2d   X.<13>1 2021-11-
0050   31 37 54 32 33 3a 34 31 3a 35 39 2b 30 30 3a 30   17T23:41:59+00:0
0060   30 20 31 37 32 2e 32 31 2e 30 2e 31 20 31 20 2d   0 172.21.0.1 1 -
0070   20 2d 20 2d 20 32 30 32 31 2d 31 31 2d 31 38 54    - - 2021-11-18T
0080   31 32 3a 34 31 3a 35 39 2e 39 34 33 39 36 35 2b   12:41:59.943965+
0090   31 33 3a 30 30 20 6b 6f 72 69 6d 61 6b 6f 20 64   13:00 korimako d
00a0   61 76 69 64 20 36 38 38 31 34 30 20 2d 20 5b 74   avid 688140 - [t
00b0   69 6d 65 51 75 61 6c 69 74 79 20 74 7a 4b 6e 6f   imeQuality tzKno
00c0   77 6e 3d 22 31 22 20 69 73 53 79 6e 63 65 64 3d   wn="1" isSynced=
00d0   22 31 22 20 73 79 6e 63 41 63 63 75 72 61 63 79   "1" syncAccuracy
00e0   3d 22 37 39 37 30 30 30 22 5d 20 74 68 69 73 20   ="797000"] this 
00f0   69 73 20 61 20 74 65 73 74 0a                     is a test.

You can see that the message, which starts at byte 66 (0x42), begins with a < character (<13>1 2021...). According to RFC6587, this is interpreted not as octet-counting framing but as the alternative: non-transparent framing.

syslog-ng's full log for this event is:

[2021-11-17T23:41:59.944928] Incoming log entry; line='<13>1 2021-11-18T12:41:59.943965+13:00 korimako david 688140 - [timeQuality tzKnown="1" isSynced="1" syncAccuracy="797000"] this is a test'
[2021-11-17T23:41:59.987236] Outgoing message; message='2021-11-17T23:41:59.944+00:00 172.21.0.1 HOST=172.21.0.1 HOST_FROM=172.21.0.1 LEGACY_MSGHDR="1 " MESSAGE="2021-11-18T12:41:59.943965+13:00 korimako david 688140 - [timeQuality tzKnown=\"1\" isSynced=\"1\" syncAccuracy=\"797000\"] this is a test" PROGRAM=1 SOURCE=s_network\x0a'
[2021-11-17T23:41:59.987403] Outgoing message; message='Nov 17 23:41:59 172.21.0.1 1 2021-11-18T12:41:59.943965+13:00 korimako david 688140 - [timeQuality tzKnown="1" isSynced="1" syncAccuracy="797000"] this is a test\x0a'
[2021-11-17T23:42:31.994550] Syslog connection established; fd='12', server='AF_INET(172.21.0.7:601)', local='AF_INET(0.0.0.0:0)'
[2021-11-17T23:42:31.994946] Outgoing message; message='<13>1 2021-11-17T23:41:59+00:00 172.21.0.1 1 - - - 2021-11-18T12:41:59.943965+13:00 korimako david 688140 - [timeQuality tzKnown="1" isSynced="1" syncAccuracy="797000"] this is a test\x0a'
[2021-11-17T23:42:36.996059] EOF occurred while idle; fd='12'
[2021-11-17T23:42:36.996187] Syslog connection closed; fd='12', server='AF_INET(172.21.0.7:601)', time_reopen='60'
[2021-11-17T23:43:36.996635] Syslog connection established; fd='12', server='AF_INET(172.21.0.7:601)', local='AF_INET(0.0.0.0:0)'

UPDATE 1: I've found the missing octet-counting value at the start of the message - it's in a preceding TCP frame. I think this means that the output from syslog-ng is using octet-counting framing after all. I'm now actively debugging the telegraf source because I think it's receiving the message but erroneously closing the connection afterwards. I'll update this as I discover more.

UPDATE 2: I've determined that the telegraf syslog plugin has either a bug or a mistake in its documentation, and is disconnecting any incoming TCP connections that are idle for more than 5 seconds. It is not a parsing issue merely a timeout.

Therefore there is no issue with syslog-ng and this entire question is null and void.

davidA
  • 353
  • 2
  • 11

1 Answers1

0

syslog-ng can be configured to support all combinations: RFC3164 or RFC5424 formats, with or without the framing technique defined in RFC6587.

syslog() uses RFC6587 framing (octet counting) and prefers RFC5424 as message format, but falls back to RFC3164 on the source side, when RFC5424 parsing fails.

network() operates without frames (without octet-counting - this is called "Non-Transparent-Framing" in the RFC) and its default is RFC3164, but this can be changed (to RFC5424) with the flags(syslog-protocol) flag.

MrAnno
  • 211
  • 1
  • 5
  • When using `syslog()` or `network(... flags(syslog-protocol))` how do you switch between octet-counting and non-transparent (octet stuffing) modes? I'm currently using `syslog()` and it seems to be non-transparent only. Both those modes are covered by RFC6587. Perhaps there's a special option to switch it over to octet-counting? I can't find anything in the docs about this though. – davidA Nov 17 '21 at 20:32
  • syslog() should use octet-counting, while network() uses the old "non-transparent-framing" method (separates messages with \n). – MrAnno Nov 17 '21 at 21:01
  • If that's not the case, you may have found a bug. Are you using the exact same config you shared? – MrAnno Nov 17 '21 at 21:02
  • I've updated the text of my question to include the full config I'm using, along with some wireshark captures and corresponding syslog-ng console logs. Let me know if anything else might be useful to see. – davidA Nov 17 '21 at 23:55
  • Another update - I've found the 'missing' octet-counting "[digits] " prefix in a preceding TCP frame, so it is there in the stream. I missed this. So this means that syslog-ng *is* outputting octet-counting framing, as expected. I think there's definitely an issue with how telegraf is handling these messages though, as it is actively closing the connection after each message due to a timeout. I am debugging this now. Anyway, @MrAnno, thank you for your time responding to this and my apologies for wasting it. – davidA Nov 18 '21 at 00:55
  • 1
    My pleasure. Hmm, interesting. There is something that might be interesting for you: In case telegraf sends anything back to syslog-ng, the default behavior is to close the connection, because the network(), syslog() drivers do not expect answers from the server. If that is the case, you can try the following undocumented option: `close-on-input(no)`. – MrAnno Nov 18 '21 at 11:07