February 2021 - syslog-ng - lists.balabit.hu

UDP drops with syslog-ng 3.24.1-1
by brian hoffman 05 Oct '22

05 Oct '22

We've been centrally logging with syslog-ng for about 5 years now. Over that time, the number of sources has grown significantly, and at some point we crossed a line where drops were happening (a quick survey of 3 million syslog packets yielded 420 unique currently sending hosts). After much research and experimentation, we've been able to get to the point where throughout the day there are 0 drops for the most part. This was achieved by installing the latest syslog-ng (not the RedHat packaged one) and creating a source for each CPU. Occasionally, though, we still have periods of drops so I'm trying to eliminate these last few. Here are some relevant configuration items:2 RedHat 7.8 VMs (load balanced via an F5) with 16GB memory and 4 CPUs each running syslog-ng-3.24.1-1.el7.x86_64.net.core.rmem_default = 212992net.core.rmem_max = 268435456 log_fifo_size(268435456); source s_network {network(ip("0.0.0.0") port(514) transport("udp") so_rcvbuf(441326592) so-reuseport(1) persist-name("udp1"));network(ip("0.0.0.0") port(514) transport("udp") so_rcvbuf(441326592) so-reuseport(1) persist-name("udp2"));network(ip("0.0.0.0") port(514) transport("udp") so_rcvbuf(441326592) so-reuseport(1) persist-name("udp3"));network(ip("0.0.0.0") port(514) transport("udp") so_rcvbuf(441326592) so-reuseport(1) persist-name("udp4"));network(ip("0.0.0.0") port(514) transport("tcp") max_connections(200) keep_alive(yes) so_rcvbuf(67108864));}; We are limited to UDP, unfortunately, because we do not have control over the devices/networks/etc. that are sending to us, but we have changed as many of the internal senders and destinations to TCP as we can. With a script I created to view the packets, including drops, as well as the individual RECVQs, the issue can be illustrated. Here's what things look like normally:Thu May 7 10:48:15 EDT 2020, 27003 IP pkts rcvd,26980 IP pkts sent,24951 UDP pkts rcvd, 28075 UDP pkts sent,0 UDP pkt rcv err RECVQ-1=2176RECVQ-2=0RECVQ-3=0RECVQ-4=0Thu May 7 10:48:16 EDT 2020, 28453 IP pkts rcvd,28426 IP pkts sent,26185 UDP pkts rcvd, 29180 UDP pkts sent,0 UDP pkt rcv errRECVQ-1=0RECVQ-2=0RECVQ-3=4352RECVQ-4=0Thu May 7 10:48:17 EDT 2020, 28294 IP pkts rcvd,28276 IP pkts sent,26277 UDP pkts rcvd, 28709 UDP pkts sent,0 UDP pkt rcv errRECVQ-1=2176RECVQ-2=0RECVQ-3=0RECVQ-4=0 The RECVQs are sparsely used, and there are no errors. Around 9pm every night, the packet counts go up significantly (probably due to backup related logs):Wed May 6 21:00:08 EDT 2020, 66382 IP pkts rcvd,66366 IP pkts sent,39405 UDP pkts rcvd, 67592 UDP pkts sent,0 UDP pkt rcv errRECVQ-1=1595008RECVQ-2=106217088RECVQ-3=53694976RECVQ-4=31858816Wed May 6 21:00:09 EDT 2020, 69317 IP pkts rcvd,69338 IP pkts sent,44446 UDP pkts rcvd, 75958 UDP pkts sent,0 UDP pkt rcv errRECVQ-1=13056RECVQ-2=126397312RECVQ-3=75568128RECVQ-4=41626880Wed May 6 21:00:10 EDT 2020, 71205 IP pkts rcvd,71227 IP pkts sent,43657 UDP pkts rcvd, 74603 UDP pkts sent,0 UDP pkt rcv errRECVQ-1=920448RECVQ-2=146122752RECVQ-3=100951168RECVQ-4=52622208Wed May 6 21:00:12 EDT 2020, 69578 IP pkts rcvd,69454 IP pkts sent,124465 UDP pkts rcvd, 163367 UDP pkts sent,0 UDP pkt rcv errRECVQ-1=13140864RECVQ-2=44494848RECVQ-3=125579136RECVQ-4=0 Still, though, it's handling it with no errors. But then at some point a threshold is reached and errors start piling up:Wed May 6 21:00:20 EDT 2020, 63177 IP pkts rcvd,63291 IP pkts sent,0 UDP pkts rcvd, 0 UDP pkts sent,38011 UDP pkt rcv errRECVQ-1=536871424RECVQ-2=200357376RECVQ-3=292948352RECVQ-4=28890752Wed May 6 21:00:21 EDT 2020, 69501 IP pkts rcvd,69464 IP pkts sent,0 UDP pkts rcvd, 1 UDP pkts sent,42158 UDP pkt rcv errRECVQ-1=536871424RECVQ-2=223551360RECVQ-3=314995584RECVQ-4=41735680Wed May 6 21:00:23 EDT 2020, 69962 IP pkts rcvd,69978 IP pkts sent,0 UDP pkts rcvd, 2 UDP pkts sent,43775 UDP pkt rcv errRECVQ-1=536871424RECVQ-2=244732544RECVQ-3=338239616RECVQ-4=53858176Wed May 6 21:00:24 EDT 2020, 68266 IP pkts rcvd,68216 IP pkts sent,0 UDP pkts rcvd, 0 UDP pkts sent,43118 UDP pkt rcv errRECVQ-1=536871424RECVQ-2=265258752RECVQ-3=360643712RECVQ-4=65362688 The common denominator I've found is that one of the RECVQs hits 536,871,424. This number seems to be almost exactly double (512 difference) the rmem.max/log_fifo_size (268,435,456). Even though there seems to be capacity in the other RECVQs, just one of those hitting that magic number seems to be enough to throw things out of whack. During this time, the CPU usage for syslog-ng also drops: top - 21:00:11 up 2 days, 8:40, 2 users, load average: 1.09, 1.41, 1.32 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 7214 root 20 0 2111388 1.7g 5392 S 123.6 10.9 3080:46 syslog-ng top - 21:00:14 up 2 days, 8:40, 2 users, load average: 1.00, 1.39, 1.31 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 7214 root 20 0 2111388 1.7g 5392 S 24.6 10.9 3080:46 syslog-ng top - 21:00:17 up 2 days, 8:40, 2 users, load average: 1.00, 1.39, 1.31 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 7214 root 20 0 2111388 1.7g 5392 S 7.6 10.9 3080:47 syslog-ng As best I can tell, based on the reading I've done, the message counts we're getting should be doable, but it's still not clear exactly how to size some of these options as they relate to UDP (like log_fetch_limit, which we do not have set). Anything else I should try?

2 4

Syslog-ng 3.4.5 support question
by mukesh kumar 05 Mar '21

05 Mar '21

Hi, We are using syslog-ng 3.4.5 version and we are using it to utilize patterndb. We are not looking for bug fix but using it for just all the different ways we can use the patterndb xml. Please provide me the info on such as the IF and ELSE statements, For loops in the xml file. Thanks, Mukesh Kumar

4 5

Console logging stops after some time.
by Alexandre Santos 24 Feb '21

24 Feb '21

Hi All, I am using a Debian10 with syslog-ng 3.19. I have a simple configuration formed by a log to a file and a log to the console "usertty(*)". Please check the attached file. *After some time the logging to the console stops, but the logging to the file keeps working.* I used strace to debug this. (strace -p <syslog-ng-pid> -yy -f -s 256 -e trace=write) *root@localhost:~# w root 12:50:41 up 3:16, 5 users, load average: 0.21, 0.35, 0.37USER TTY FROM LOGIN@ IDLE JCPU PCPU WHATroot ttyS0 - 09:36 45:18 0.02s 0.02s -bashroot pts/1 10.0.2.2 09:40 1.00s 0.26s 0.00s w rootroot pts/4 10.0.2.2 09:56 24:08 3.03s 2.84s strace -p 23429 -yy -f -s 256 -e trace=writeroot pts/5 10.0.2.2 10:26 22:01 0.01s 0.01s tail -f /var/log/apps.logroot pts/0 10.0.2.2 12:31 19:25 21.77s 0.00s sleep 60root@localhost:~# strace -p 23429 -yy -f -s 256 -e trace=write[pid 24379] write(26</dev/ttyS0<char 4:64>>, "2021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 107) = 107[pid 24379] write(26</dev/pts/1<char 136:1>>, "2021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 107) = 107[pid 24379] write(26</dev/pts/4<char 136:4>>, "2021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 1072021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398[pid 24379] write(26</dev/pts/4<char 136:4>>, "2021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 1072021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398[pid 24379] write(26</dev/pts/5<char 136:5>>, "2021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 107) = 107[pid 24379] write(26</dev/pts/0<char 136:0>>, "2021 Feb 19 12:31:16 localhost 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 107) = 107[pid 24379] write(23<pipe:[1957563]>, "<190>1 2021-02-19T12:31:16.855+00:00 localhost usm 6802 - - 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 136) = 136[pid 24379] write(23<pipe:[1957563]>, "<190>1 2021-02-19T12:31:16.885+00:00 localhost usm 6802 - - 8395:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 136) = 136[pid 23703] write(1</var/log/apps.log>, "<190>1 2021-02-19T12:31:16.855+00:00 localhost usm 6802 - - 8389:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 136) = 136[pid 23703] write(1</var/log/apps.log>, "<190>1 2021-02-19T12:31:16.885+00:00 localhost usm 6802 - - 8395:Usm INFO {Orchestrator.cpp:1329} attr_id=10931 moid=8398\n", 136) = 136* After some time I stop seeing writes to the console's, and only see writes to the apps.log file. *[pid 24379] write(23<pipe:[1957563]>, "<190>1 2021-02-19T12:31:21.334+00:00 localhost dbf 7884 - - 8159:Dbf INFO {transaction_context.cpp:20} dtor of TransCtxt, tid: 120\n", 145) = 145[pid 23703] write(1</var/log/apps.log>, "<190>1 2021-02-19T12:31:21.334+00:00 localhost dbf 7884 - - 8159:Dbf INFO {transaction_context.cpp:20} dtor of TransCtxt, tid: 120\n", 145) = 145* It seems that due to the high amount of messages the logging to the console is discarded. Can you help me to solve this, Thanks in advance, Alex

2 5

query on using throttle in syslog-ng.conf file
by SIMON BABY 20 Feb '21

20 Feb '21

Hello Team, I am new to this group and I have a query on adding the throttle attribute in syslog-ng.conf file. My target is little slow to process all the messages sent by the sender and sometimes the link connected to the target device is broken. I am thinking of slowing down the sender by adding the throttle attribute. I have the below queries: 1) What exactly the throttle confoguration does? 2) What does throttle(500) mean ? will it send 500 Bytes per second or 500 messages per second? What does the message here mean ? Can it be the entire message sent by the application ? Is there an upper limit and lower limit ? 3) Any side effect of my system if I am going to use throttle(). 4) Any other method in syslog-ng to delay the logs sending at the sender? 5) My destination configuration is below. Is it a valid configuration ? destination logFiler { file("/var/log/wq.log" template("${FULLDATE}${TZ} ${HOST} ${PROGRAM} [$LEVEL] ${MSG}\n") template_escape(yes) throttle(500));}; Thank you for your time. Regards Simon

2 9

tty10 on Debian under LXC
by John Kristoff 16 Feb '21

16 Feb '21

I ran into the exact problem succinctly and completely written up here: <https://www.claudiokuenzler.com/blog/988/syslog-ng-lxc-container-no-space-l…> It doesn't appear this was brought to the attention of the devs nor an issue even filed in github. I'd like to make sure I didn't miss something, so posting here for comment before I submit a github issue. In summary, LXC sets up a small number of tty devices by default. However, syslog-ng in Debian has this config statement: destination d_console_all { file(`tty10`); }; This results in syslog-ng writing the a new /dev/tty10 file instead of to a device, which will pretty quickly fill up an LXC /dev partition, causing syslog-ng to soon start failing when it sees the device associated with tty10 file handle full. I have modified my syslog-ng.conf directly to use tty2 as the blog post suggested, but it would be nice if there was a "cleaner" work-around in the future. John

2 2

Insider 2021-02: proxy protocol; sudo JSON; Kafka;
by Peter Czanik (pczanik) 11 Feb '21

11 Feb '21

Dear syslog-ng users, This is the 88th issue of syslog-ng Insider, a monthly newsletter that brings you syslog-ng-related news. NEWS Finding the real source IP: using the PROXY protocol ---------------------------------------------------- Until now collecting logs behind proxies or load balancers needed some compromises. You either trusted the host information included in the log messages or you could only see the proxy as the sender host. Starting with syslog-ng 3.30 there is a third option available: using the PROXY protocol. While not an official Internet standard, it is supported by a number of popular software, like HAProxy. Other software can be extended to use it, like F5 load balancers using iRules. This way crucial information about the original network connection is not lost, but it is forwarded to the server by the proxy. https://www.syslog-ng.com/community/b/blog/posts/finding-the-real-source-ip… Parsing sudo JSON logs: building a syslog-ng configuration ---------------------------------------------------------- The latest version of sudo, version 1.9.4 includes support for JSON formatted logging. Compared to traditional sudo logs, it has the advantage of containing more information in a structured way. While traditional sudo logs are also parsed automatically by syslog-ng, it is worth taking a look at the new JSON formatted logs. >From this blog, you can learn how the new logs look like and also a configuration working with these logs. Instead of just posting a complex configuration, I try to show you how my configuration was built. Creating a new configuration in smaller iterations makes the resulting configurations easier to debug. https://www.syslog-ng.com/community/b/blog/posts/parsing-sudo-json-logs-bui… Kafka destination improved with template support ------------------------------------------------ The C implementation of the Kafka destination in syslog-ng has been improved in version 3.30. Support for templates in topic names was added as a result of a Google Summer of Code (GSoC) project. The advantage of the new template support feature is that you no longer have to use a static topic name. For example, you can include the name of your host or the application sending the log in the topic name. From this blog you can learn about a minimal Kafka setup, configuring syslog-ng and testing syslog-ng with Kafka. https://www.syslog-ng.com/community/b/blog/posts/kafka-destination-improved… Syslog-ng PE 7.0.23 released ---------------------------- Version 7.0.23 of syslog-ng PE was released with clustering support for Windows Event Collector (WEC). You can learn more about it from the documentation or from this short video: https://www.youtube.com/watch?v=bYdIJaM24Z8 WEBINARS * You can browse recordings of past webinars at https://www.syslog-ng.com/events/ Your feedback and news, or tips about the next issue are welcome. To read this newsletter online, visit: https://syslog-ng.com/blog/ Peter Czanik (CzP) <peter.czanik(a)oneidentity.com> Balabit (a OneIdentity company) / syslog-ng upstream https://syslog-ng.com/community/ https://twitter.com/PCzanik

1 0

flags(final) - Question
by Matthias Gruber 09 Feb '21

09 Feb '21

Hi! After searching why a log-message doesnt got the right destination path, I propably got a bit crossed up with the flag(final) statement, perhaps someone can enlight me :-) Following scenario (no valid syntax, only for description) filter(f_a) { match("something");}; destination(d_a) { file("/destination_a"); }: destination(d_b) { file("/destination_b"); }: destination(d_c) { file("/destination_c"); }: log { source(s_remote_default_syslog_udp); if filter(f_a) { destination(d_a); flag(final); } else { destination(d_b); flag(final); }; destination(d_c); }; What I expect is if filter->f_a hits the message is written in destination->d_a (what he do), then hits the final, and ends the log-statement What I discovered he also write destination->d_c Is that the expected behaviour? And if so, how to accomplish, that e.g. if the if or the else part hit, no destination -> d_c is written. Yeah I know, why the destination->d_c :-), correct I stumbled over this, normally after such a if/elif/else-Block I dunno have this destination->d_c line in my syslog-ng environments. Only a bit courious about it and seeking for an explanation. cheers Matthias ------------------------------------------------------------------------------------ METZLER Informationstechnologie Matthias Gruber IT-Infrastruktur & -Betrieb B. Metzler seel. Sohn & Co. Kommanditgesellschaft auf Aktien Untermainanlage 1 60329 Frankfurt am Main Telefon (0 69) 21 04 - 43 30 Telefax (0 69) 21 04 - 40 40 MGruber(a)metzler.com www.metzler.com Persönlich haftende Gesellschafter: Harald Illy, Friedrich von Metzler, Emmerich Müller, Gerhard Wiesheu Vorsitzender des Aufsichtsrats: Dr. Christoph Schücking Sitz der Gesellschaft: Frankfurt am Main, Handelsregister-Nr. HRB 27 515 Diese Nachricht ist vertraulich. Sollten Sie nicht der vorgesehene Empfänger sein, so bitten wir Sie höflich, dies unverzüglich dem Absender mitzuteilen und die Nachricht zu löschen. Es ist unzulässig, die Nachricht unbefugt weiterzuleiten oder zu kopieren. Da wir nicht die Echtheit oder Vollständigkeit der in dieser Nachricht enthaltenen Informationen garantieren oder zusichern können, sind die vorstehenden Ausführungen rechtlich nicht bindend. Eine Haftung hierfür wird ausgeschlossen. This message is confidential. If you are not the intended recipient, we kindly ask you to inform the sender and delete the information. Any unauthorised dissemination or copying hereof is prohibited. As we cannot guarantee or assure the genuineness or completeness of the information contained in this message, the statements set forth above are not legally binding. Accordingly we cannot accept any liability for their contents.

2 2

filtering based on text?
by Dan Egli 08 Feb '21

08 Feb '21

Hey folks, I've looked for a way to do this, and I guess my google-foo is weak today. I've got a situation where on one of my machines, an automated process FREQUENTLY calls sudo so it can gain the permissions it needs to do certain tasks. But that means my /var/log/messages is getting FILLED with sudo messages. I was hoping I could insert some kind of text filter that would allow me to shunt messages where one user (the automated process) calls sudo into another log file. It would basically need to be a nested filter, i.e.: If message_source = sudo then if user = X then log to auto_sudo.log If someone knows how this can be done, I'd appreciate it. Thanks! --- Dan

3 3

PostgreSQL destination - connection refused
by victorsugo 06 Feb '21

06 Feb '21

Hi, I'd like to store incoming log messages in a postgres db. Both db server and syslog-ng run in a docker container. I'm using docker-compose to manage containers. The syslog-ng is depending on the pg container, but... every time I start containers with docker-compose up -d, the syslog-ng starts, but can't connect to database. I found this in the /var/log/messages on the syslog-ng's container: err syslog-ng[1]: Error establishing SQL connection; type='pgsql', host='pgsrv.infra-net', port='', username='syslog', database='postgres', error='could not connect to server: Connection refused ... Is there any way to reconnect automatically or abort syslog-ng if it can't connect to the db? It is important if I don't want to lose some logs... (or do I need to forget the SQL backend if I want to operate a log server without loss of data??) Regards, Sent with [ProtonMail](https://protonmail.com) Secure Email.

1 1

problems with multiline log messages on ubuntu18
by Jerry Scharf 06 Feb '21

06 Feb '21

Hi, We have been struggling with problems with multiple log messages being broken apart. Our apps can send random things to the logger including entire stack traces. We have a classifier that sends unknown lines to their own log file, so this makes a complete mess. This was with the distro apt package. So I went to building 3.25.1 by hand. If I build it with nothing on the configure line, it processes the multiline log messages just fine but if I build it with the ubuntu18 debian rules, it breaks the same way. I narrowed it down to if --eneable-systemd is set it breaks. Here are some relevant things. DISTRIB_DESCRIPTION="Ubuntu 18.04.5 LTS" config cmd ../configure --prefix=/usr/local --sysconfdir=/etc/syslog-ng --enable-dynamic-linking --enable-json --enable-manpages --enable-python --enable-java=no --enable-mongodb=no --enable-legacy-mongodb-options=no SOURCE_REVISION=3.25.1-ir1 --enable-systemd=no attaching the conf and the file classifier (60...) thanks, jerry

2 1