Bug#1064385: rsyslog: New default log format is different for local and remote log

[Ralf Schlatterbeck]

Package: rsyslog
Version: 8.2302.0-1
Severity: important

Dear Maintainer,

I'm using rsyslog to log local events and remote events to the same log.
For this I've enabled UDP receiving.
The main machine is the host, while the other machines logging via UDP are
virtual machines running on that host. The network carrying the syslog traffic
is not visible outside the host machine.

The version of rsyslog in Debian stable now uses the new international
timestamp format by default. Unfortunately this format differs for local and
remote logs.

The local machine by default logs in the following format:
2024-02-16T22:05:52.315463+01:00 tux [...]

while a machine logging via UDP appears like this:
2024-02-16T22:06:02+01:00 tux1 [...]

Please observe that the sub-seconds part of the timestamp is not included in
the remote logs.

Unfortunately this causes logcheck to completely ignore all the remote logs
because it matches on a 32-byte timestamp (and the timestamp of the remote
machine only has 25 byte).

I had to revert to the old 'traditional' log format (which was the default in
previous versions of syslog shipped by Debian) with the following config line:

$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

You will have to remove that line from the appended config file for reproducing
the issue.

Fortunately the old 'traditional' format is still supported by logcheck.

Expected behavior:
The timestamp format logcheck produces with the default configuration should be
made the same for local and remote logs.


-- System Information:
Debian Release: 12.5
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable-security'), (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 6.1.0-18-amd64 (SMP w/8 CPU threads; PREEMPT)
Locale: LANG=C, LC_CTYPE=C (charmap=UTF-8) (ignored: LC_ALL set to en_US.UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages rsyslog depends on:
ii libc6 2.36-9+deb12u4
ii libestr0 0.1.11-1
ii libfastjson4 1.2304.0-1
ii liblognorm5 2.0.6-4
ii libsystemd0 252.22-1~deb12u1
ii libuuid1 2.38.1-5+b1
ii libzstd1 1.5.4+dfsg2-5
ii zlib1g 1:1.2.13.dfsg-1

Versions of packages rsyslog recommends:
ii logrotate 3.21.0-1

Versions of packages rsyslog suggests:
pn rsyslog-doc <none>
pn rsyslog-gssapi <none>
pn rsyslog-mongodb <none>
pn rsyslog-mysql | rsyslog-pgsql <none>
pn rsyslog-openssl | rsyslog-gnutls <none>
pn rsyslog-relp <none>

-- Configuration Files:
/etc/rsyslog.conf changed:
module(load="imuxsock") # provides support for local system logging
module(load="imklog") # provides kernel logging support
module(load="imudp")
input(type="imudp" port="514")
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$FileOwner root
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022
$WorkDirectory /var/spool/rsyslog
$IncludeConfig /etc/rsyslog.d/*.conf
*.*;auth,authpriv.none -/var/log/syslog
auth,authpriv.* /var/log/auth.log
cron.* -/var/log/cron.log
kern.* -/var/log/kern.log
mail.* -/var/log/mail.log
user.* -/var/log/user.log


-- no debconf information

[Ralf Schlatterbeck]

Hi Michael,
Thanks for the quick answers!

On Wed, Feb 21, 2024 at 01:30:50PM +0100, Michael Biebl wrote:

> The Debian package does not ship any patches in that regard.
> It's thus best if you raise this issue directly upstream at
> https://github.com/rsyslog/rsyslog/issues

I've made an upstream bug-report on the issue at
https://github.com/rsyslog/rsyslog/issues/5332

On Wed, Feb 21, 2024 at 01:40:21PM +0100, Michael Biebl wrote:
> Am 21.02.24 um 12:09 schrieb Ralf Schlatterbeck:

> > Unfortunately this causes logcheck to completely ignore all the remote logs
> > because it matches on a 32-byte timestamp (and the timestamp of the remote
> > machine only has 25 byte).
>

> This is a bug in the logcheck rules, I'd say. It should deal with timestamps
> having no subseconds resolution.
>
> https://www.rsyslog.com/doc/configuration/properties.html
> I suppose that for remote messages it uses "timereported", which typically
> uses a resolution in seconds

I still think that rsyslog should not mix two different timestamp
formats in the same logfile with the same template configuration. And
yes, maybe logcheck should recognize both formats with/without
subseconds part.

Thanks
Ralf
--
Dr. Ralf Schlatterbeck Tel: +43/2243/26465-16
Open Source Consulting www: www.runtux.com
Reichergasse 131, A-3411 Weidling email: off...@runtux.com

[Ralf Schlatterbeck]

Upstream has decided that it is not a bug and that the RFC 3339
timestamps can in fact freely mix timestamps with or without the
sub-seconds part (I've checked, the RFC explicitly has the subseconds
part defined as optional in the grammar).

For people coming here to look: I've successfully modified my remote
client rsyslog configuration to send *long* timestamps to the remote
syslog. The default configuration seems to use
RSYSLOG_TraditionalForwardFormat (I didn't find much info about which
template formats are built into rsyslog and what they do, I've used
'strings' and 'grep' to find out). The RSYSLOG_ForwardFormat formats
forwarded messages *with* sub-seconds part.

So instead of, e.g.,
*.*;auth,authpriv.none @syslog:514
you specify a format:
auth,authpriv.* @syslog:514;RSYSLOG_ForwardFormat

which transmits the sub-seconds part to the receiving rsyslog.

So I think we can close this.

Thanks,

[Ralf Schlatterbeck]

On Thu, Feb 22, 2024 at 12:17:58PM +0100, Michael Biebl wrote:
>
> Reading through the upstream bug report, they basically agree that this is a
> logcheck issue which should handle RFC 3339 timestamps more robustly.
> Do you plan to raise this issue with the logcheck maintainers?
> As I'm not a logcheck user, I don't plan to do that myself.

Yes, see
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1064395

Thanks