Page MenuHomeVyOS Platform
Create Task
Maniphest T7311

syslog: duplicate kernel log entries
Closed, ResolvedPublic
Actions

Description

Syslog messages from the kernel are being duplicated, both to local storage (/var/log/messages) and to remote syslog destinations.

Steps to replicate / reproduce this issue:

  • Create a new instance of Vyos nightly (noticed on versions from 1.5-rolling-202503030030 through 2025.04.01-0021-rolling)
  • Create a default deny firewall rule
  • tail -f /var/log/messages
  • Create traffic that hits the default deny firewall rule from a remote host (e.g. wget https://vyos-ip/)
  • Notice duplicate kernel log messages for denied traffic in /var/log/messages:
Apr  2 09:08:45 vyos kernel: [ 1986.329864] [ipv4-NAM-WAN-LOCAL-4-default-D]IN=eth0 OUT= MAC=52:54:00:07:c0:f7:52:54:00:e4:f6:1c:08:00 SRC=192.168.122.1 DST=192.168.122.230 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=29171 DF PROTO=TCP SPT=58756 DPT=443 WINDOW=64240 RES=0x00 SYN URGP=0
Apr  2 09:08:45 vyos kernel: [ipv4-NAM-WAN-LOCAL-4-default-D]IN=eth0 OUT= MAC=52:54:00:07:c0:f7:52:54:00:e4:f6:1c:08:00 SRC=192.168.122.1 DST=192.168.122.230 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=29171 DF PROTO=TCP SPT=58756 DPT=443 WINDOW=64240 RES=0x00 SYN URGP=0
Apr  2 09:08:46 vyos kernel: [ 1987.344107] [ipv4-NAM-WAN-LOCAL-4-default-D]IN=eth0 OUT= MAC=52:54:00:07:c0:f7:52:54:00:e4:f6:1c:08:00 SRC=192.168.122.1 DST=192.168.122.230 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=29172 DF PROTO=TCP SPT=58756 DPT=443 WINDOW=64240 RES=0x00 SYN URGP=0
Apr  2 09:08:46 vyos kernel: [ipv4-NAM-WAN-LOCAL-4-default-D]IN=eth0 OUT= MAC=52:54:00:07:c0:f7:52:54:00:e4:f6:1c:08:00 SRC=192.168.122.1 DST=192.168.122.230 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=29172 DF PROTO=TCP SPT=58756 DPT=443 WINDOW=64240 RES=0x00 SYN URGP=0
Apr  2 09:08:47 vyos kernel: [ 1988.357517] [ipv4-NAM-WAN-LOCAL-4-default-D]IN=eth0 OUT= MAC=52:54:00:07:c0:f7:52:54:00:e4:f6:1c:08:00 SRC=192.168.122.1 DST=192.168.122.230 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=29173 DF PROTO=TCP SPT=58756 DPT=443 WINDOW=64240 RES=0x00 SYN URGP=0
Apr  2 09:08:47 vyos kernel: [ipv4-NAM-WAN-LOCAL-4-default-D]IN=eth0 OUT= MAC=52:54:00:07:c0:f7:52:54:00:e4:f6:1c:08:00 SRC=192.168.122.1 DST=192.168.122.230 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=29173 DF PROTO=TCP SPT=58756 DPT=443 WINDOW=64240 RES=0x00 SYN URGP=0

There should be 3 entries in the above /var/log/messages (one per second) - but instead there are 6 (each message is duplicated). The "ID=" field should be unique - but each ID can be seen in 2 messages.

Note that the duplicate messages are malformed - including what looks like part of the time stamp at the beginning of the message entry.

Details

Version
-
Is it a breaking change?
Perfectly compatible
Issue type
Bug (incorrect behavior)

Related Objects

Event Timeline

woodsb02 created this task.Apr 2 2025, 9:13 AM
woodsb02 triaged this task as Normal priority.
woodsb02 created this object in space S1 VyOS Public.
woodsb02 updated the task description. (Show Details)
woodsb02 added a comment.Apr 2 2025, 9:16 AM

I believe this is caused by the /run/rsyslog/rsyslog.conf file including these 2 entries:

  • module(load="imklog") # provides kernel logging support
  • module(load="imjournal"...

journald already collects the kernel messages (as can be seen with the journalctl -xek command), so by also collecting them from the rsyslog imklog module they are duplicated.

pasik subscribed.Apr 2 2025, 11:04 AM
woodsb02 added a comment.Apr 2 2025, 10:59 PM

Note that the duplicate messages are malformed - including what looks like part of the time stamp at the beginning of the message entry.

This is the kernel timestamp being shown in the message. The rsyslog imklog module has a KeepKernelTimestamp parameter which defaults to off - so this shouldn’t be included in the message.
https://www.rsyslog.com/doc/configuration/modules/imklog.html#keepkerneltimestamp

I believe this is because of this bug fix from October 2023 which isn’t included in version of rsyslog in vyos (8.2302.0 aka 2023.02):
https://github.com/rsyslog/rsyslog/commit/8e1388f65c629ae5066ef20a838db9dcde8fd746

woodsb02 added a comment.Apr 3 2025, 1:20 AM

Pull request created to fix this issue:
https://github.com/vyos/vyos-1x/pull/4433

c-po assigned this task to woodsb02.Apr 6 2025, 11:46 AM
c-po added a project: VyOS 1.5 Circinus.
Restricted Repository Identity mentioned this in rVYOSONEX91d428f1084d: T7311: syslog: Fix duplicate kernel log entries.Apr 10 2025, 4:43 AM
Restricted Repository Identity mentioned this in rVYOSONEX8eb5915b7630: Merge pull request #4433 from woodsb02/patch-3.
Viacheslav closed this task as Resolved.Apr 12 2025, 11:13 AM
Viacheslav moved this task from Need Triage to Completed on the VyOS Rolling board.
Viacheslav moved this task from Open to Finished on the VyOS 1.5 Circinus board.
dmbaturin edited projects, added VyOS 1.5 Circinus (1.5-stream-2025-Q2); removed VyOS 1.5 Circinus.Jul 9 2025, 12:15 PM