Multi-line-timeout: making sure your last multi-line message is not lost

When your application has a problem that it cannot handle, then Java, PHP and other environments often write multi-line error messages. These long messages include many information useful for developers but it might be difficult to handle for logging systems. A multi-line log message is usually saved when the beginning of the next message is detected, which made handling the last message problematic.

This is where multi-line-timeout can help. After a pre-configured timeout, the last message is saved by syslog-ng. Losing a message when there are thousands of them is probably not a big deal. But if you are lucky, the error messages are rare. Maybe just a single message in a file. In either case, you can lose most or all of the messages. If you do not want to lose these messages, configure multi-line-timeout.

Note: this problem does not affect some less common multi-line modes, like multi-line-garbage or multi-line-suffix.

In this blog, you will find a simple configuration and a test to see how multi-line-timeout works. You can use it as a basis for your own use case.

Preparations for testing multi-line-timeout

It is hard to predict when your Java application writes a stack trace, so instead of that I prepared you an easy way to test multi-line-timeout using synthetic log messages. All you need for testing:

• syslog-ng 3.26 (or later) installed

• two open terminal windows

• a browser window, from where you can copy & paste commands

If your operating system does not have syslog-ng 3.26 (or later) available, check our third party repositories page. On most Linux distributions, you can create configuration snippets under /etc/syslog-ng/conf.d with a .conf extension. Otherwise append the following to syslog-ng.conf:

source s_multi {
    file("/var/log/events"
        multi-line-mode("prefix-garbage")
        multi-line-prefix('^EVENT: ')
        multi-line-timeout(10)
        flags("no-parse")
    );
};

destination d_multi {
    file("/var/log/multi");
};

log {source(s_multi); destination(d_multi); };

The above configuration expects multi-line messages to arrive into a file called /var/log/events and writes the results to /var/log/multi. These files do not exist by default, so you should create them:

touch /var/log/multi /var/log/events

This way you can follow log output right from the beginning. Once you restarted / reloaded syslog-ng and the configuration took effect, you are ready for testing.

Testing

For testing you will need two terminal windows and a browser window. From the browser, you will need to copy & paste commands into one of the terminal windows. You will use the second terminal window to follow the content of /var/log/multi, the file where syslog-ng saves multi-line logs when using the above configuration. In the first terminal, enter the following command, which you can then follow in the second terminal window:

tail -f /var/log/multi

Use the commands below in the first terminal one after the other as follows. First, copy and paste the first three lines from the commands below to the first terminal and hit enter. You will see, that the first two lines are displayed immediately. This is because there syslog-ng knows for sure that the log messages arrived successfully as the beginning pattern of the third message is also already there. The third message only arrives after the 10 seconds time-out, as there is no next message there (yet), which could indicate that the previous message is over.

Finally, copy & paste the last command to the first terminal and hit enter. After ten seconds, you should see the log message on the second terminal.

echo EVENT: bla1 >> /var/log/events ; echo bla 1 >> /var/log/events ; echo blabla 1 >> /var/log/events
echo EVENT: bla2 >> /var/log/events ; echo bla 2 >> /var/log/events ; echo blabla 2 >> /var/log/events
echo EVENT: bla3 >> /var/log/events ; echo bla 3 >> /var/log/events ; echo blabla 3 >> /var/log/events
echo EVENT: bla4 >> /var/log/events ; echo bla 4 >> /var/log/events ; echo blabla 4 >> /var/log/events

What is next?

As you could see from the above using multi-line-timeout resolves problems around reading multi-line log messages from files. Now it is time to custom tailor the above configuration example to your environment.

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.