Most log messages fit on a single line. However, Windows and some developer tools and services, like Tomcat, write multi-line log messages. These can come in various formats. For example, new log messages start with a date in a specific format. You use the multi-line-prefix() of the syslog-ng file() source to send multi-line messages as single messages instead of line by line.
I must admit that I have never seen multi-line logs in production. I am not a developer, do not run Tomcat or Windows. However, recently I tested a software on Windows, which produced multi-line log messages.
Before you begin
In this blog I use syslog-ng Windows Agent, a commercial product to collect multi-line log messages. However, multi-line log messages have been supported by syslog-ng for ages. You should be able to write a similar configuration for syslog-ng running on your Linux box too.
On the server side any version available in Linux distributions should work.
The sample logs
As the application I tested is not yet publicly available, I modified the logs a bit, and removed any sensitive and easy to recognize information. Here are the sample logs I used:
2024-02-13 09:13:38.028 +01:00 [DBG] Hosting starting 2024-02-13 09:13:38.088 +01:00 [DBG] Environment is Dev 2024-02-13 09:13:38.092 +01:00 [DBG] aaaaaaaaaaaaaaaa bbbbbbbbbbbbbb ccccccccccccccccc dddddddddddddddd eeeeeeeeeeeee fffffffffffffffff gggggggggggggggg 2024-02-13 09:13:38.109 +01:00 [DBG] Starting service... 2024-02-13 09:13:38.110 +01:00 [DBG] Initializing agent state 2024-02-13 09:13:38.114 +01:00 [DBG] Waiting for agent update events
Initial configuration and testing
When I first configured the syslog-ng Windows Agent to collect logs from the log file, I did not care that the logs had multi-line log messages. I simply added a file source and chose the file to follow in the configuration interface.
Here is the configuration on the server side (a slightly modified version from last week’s configuration):
source s_net {
syslog(port(601));
};
parser p_winxml {
windows-eventlog-xml-parser(prefix('winxml.'));
};
destination d_fromnet_p {
file("/var/log/fromnet_p");
};
destination d_fromnet_w {
file("/var/log/fromnet_w.json" template("$(format-json --scope rfc5424 --scope dot-nv-pairs
--rekey .* --shift 1 --scope nv-pairs)\n") );
};
log {source(s_net); parser(p_plainxml); destination(d_fromnet_p);};
log {
source(s_net);
if (not match("PROGRAM" value("syslog-ng-agent"))) {
parser(p_winxml);
};
destination(d_fromnet_w);
};
However, the results looked useless both in the plain text logs and in the JSON formatted version. As you can see, each line of the multi-line message is forwarded and saved separately:
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"4"},"file@18372.4":{"size":"469","position":"55","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: 2024-02-13 09:13:38.028 +01:00 [DBG] Hosting starting","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"5"},"file@18372.4":{"size":"469","position":"112","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: 2024-02-13 09:13:38.088 +01:00 [DBG] Environment is Dev","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"6"},"file@18372.4":{"size":"469","position":"167","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: 2024-02-13 09:13:38.092 +01:00 [DBG] aaaaaaaaaaaaaaaa","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"7"},"file@18372.4":{"size":"469","position":"183","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: bbbbbbbbbbbbbb","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"8"},"file@18372.4":{"size":"469","position":"205","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: ccccccccccccccccc","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"9"},"file@18372.4":{"size":"469","position":"226","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: dddddddddddddddd","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"10"},"file@18372.4":{"size":"469","position":"241","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: eeeeeeeeeeeee","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"11"},"file@18372.4":{"size":"469","position":"260","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: fffffffffffffffff","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"12"},"file@18372.4":{"size":"469","position":"278","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: gggggggggggggggg","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"13"},"file@18372.4":{"size":"469","position":"336","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: 2024-02-13 09:13:38.109 +01:00 [DBG] Starting service...","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"14"},"file@18372.4":{"size":"469","position":"399","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: 2024-02-13 09:13:38.110 +01:00 [DBG] Initializing agent state","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"13","sequenceId":"15"},"file@18372.4":{"size":"469","position":"469","name":"c:\\temp\\log.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13284","MESSAGE":"c:\\temp\\log.txt: 2024-02-13 09:13:38.114 +01:00 [DBG] Waiting for agent update events","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:10:25"}
And the simple version:
Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: 2024-02-13 09:13:38.028 +01:00 [DBG] Hosting starting Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: 2024-02-13 09:13:38.088 +01:00 [DBG] Environment is Dev Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: 2024-02-13 09:13:38.092 +01:00 [DBG] aaaaaaaaaaaaaaaa Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: bbbbbbbbbbbbbb Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: ccccccccccccccccc Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: dddddddddddddddd Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: eeeeeeeeeeeee Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: fffffffffffffffff Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: gggggggggggggggg Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: 2024-02-13 09:13:38.109 +01:00 [DBG] Starting service... Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: 2024-02-13 09:13:38.110 +01:00 [DBG] Initializing agent state Feb 23 10:10:25 czp-win11vm syslog-ng-agent[13284]: c:\temp\log.txt: 2024-02-13 09:13:38.114 +01:00 [DBG] Waiting for agent update events
Developing a regexp for multi-line-prefix()
Using the multi-line-prefix() requires you to write regular expressions. I know a few people, who can write one off the top of their head just by looking at a sample. Mere mortals, like me, can use tools to write regexp. There are also freely available online resources. I used https://regexr.com/ to develop a regexp. If you take a look at the sample log you will see that all log messages start with a similar part, a date and a log level enclosed in square brackets:
2024-02-13 09:13:38.028 +01:00 [DBG]
Replace the sample text on the website with this and start creating a regexp. There is a cheat sheet, and as you extend the expression, you can see how much of the date and log level are covered by it. Once you are ready, you should have an expression similar to this:
[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]{3} .[0-9]{2}:[0-9]{2} \[.{3}\]
In the Windows Agent GUI navigate to the previously created file source and edit it. At the bottom of the tab there are settings for multi-line. Set “application” to “custom” and copy the regexp from above into the “prefix” field.
Once you restart the Windows Agent, it should treat multi-line messages as single line messages. But when you check the results, you will see that something is off by a bit. The JSON formatted log is OK:
{"TRANSPORT":"rfc6587","SOURCE":"s_net","SDATA":{"meta":{"sysUpTime":"16","sequenceId":"6"},"file@18372.4":{"size":"469","position":"278","name":"c:\\temp\\log2.txt"}},"PROGRAM":"syslog-ng-agent","PRIORITY":"info","PID":"13036","MESSAGE":"c:\\temp\\log2.txt: 2024-02-13 09:13:38.092 +01:00 [DBG] aaaaaaaaaaaaaaaa\r\nbbbbbbbbbbbbbb\r\n ccccccccccccccccc\r\n dddddddddddddddd\r\neeeeeeeeeeeee\r\nfffffffffffffffff\r\ngggggggggggggggg","HOST_FROM":"172.16.167.128","HOST":"czp-win11vm","FACILITY":"local0","DATE":"Feb 23 10:18:42"}
All lines arrived in a single message. However, the plain text logs are not OK:
Feb 23 10:18:42 czp-win11vm syslog-ng-agent[13036]: c:\temp\log2.txt: 2024-02-13 09:13:38.028 +01:00 [DBG] Hosting starting Feb 23 10:18:42 czp-win11vm syslog-ng-agent[13036]: c:\temp\log2.txt: 2024-02-13 09:13:38.088 +01:00 [DBG] Environment is Dev Feb 23 10:18:42 czp-win11vm syslog-ng-agent[13036]: c:\temp\log2.txt: 2024-02-13 09:13:38.092 +01:00 [DBG] aaaaaaaaaaaaaaaa Feb 23 10:18:42 czp-win11vm syslog-ng-agent[13036]: c:\temp\log2.txt: 2024-02-13 09:13:38.109 +01:00 [DBG] Starting service... Feb 23 10:18:42 czp-win11vm syslog-ng-agent[13036]: c:\temp\log2.txt: 2024-02-13 09:13:38.110 +01:00 [DBG] Initializing agent state
Only the first line of the multi-line log message shows up in the logs.
Fixing the syslog-ng configuration
There is a fix for this in the file destination. You only have to change a single line, so I did not copy & paste here the complete configuration:
file("/var/log/fromnet_p" flags(no-multi-line));
The flag “no-multi-line” makes sure that all lines of the original message are printed on a single line:
Feb 23 11:15:26 czp-win11vm syslog-ng-agent[7548]: c:\temp\log4.txt: 2024-02-13 09:13:38.092 +01:00 [DBG] aaaaaaaaaaaaaaaa bbbbbbbbbbbbbb ccccccccccccccccc dddddddddddddddd eeeeeeeeeeeee fffffffffffffffff gggggggggggggggg
What is next?
As I mentioned in the introduction, this is just one of many ways how multi-line messages are formatted and can be handled by syslog-ng. For more information about multi line message formats supported by syslog-ng, see the online documentation about the file() source.
-
If you have questions or comments related to syslog-ng, do not hesitate to contact us. You can reach us by email or even chat with us. For a list of possibilities, check our GitHub page under the “Community” section at https://github.com/syslog-ng/syslog-ng. On Twitter, I am available as @PCzanik, on Mastodon as @Pczanik@fosstodon.org.