This KB addresses a situation where messages in different /var/log files (messages, interactive-commands, etc.) are delayed. This behavior could be experienced in an EVPN-VXLAN based environment with VTEP interfaces present in the devices. Every packet traversing through VTEP results into a particular message that overwhelms logging infrastructure resulting in this delay.
The impact of this problem will be that an event (such as interface down) will take place at a certain time, but it will not be present in logs until several minutes later.
Although the offending message is printed in the log files at the lowest syslog priority level “debug”, but some delay is still seen even when priority level is higher. This is due to the fact that the problem message is still generated by the code at higher priority levels, just that it doesn’t get saved in the files.
Cause
This problem is due to a software bug introduced in following releases:
EVO: 23.2R1-EVO, 22.4R2-EVO 23.2R1, 23.1R1-EVO,Junos: 23.1R1, 22.4R2
WorkaroundDisabling of syslog kernel debug will stop above vtep_ifl_l2hdr_compute messages getting saved in the file. However, the CPU will still be higher than usual and some logs delay will still be there depending upon number of packets going through VTEP tunnels.
user@switch# set system syslog file kernel_logs kernel debug ?
Possible completions:
<[Enter]> Execute this command
| Pipe through a command
[edit]
user@switch# set system syslog file kernel_logs kernel debug
Following message at the syslog level of debug will be seen in files at debug priority level causing this problem.
Jun 11 15:47:39.622 switch kernel: vtep_ifl_l2hdr_compute 671 host gbp src tag 0 vxlan flags 0x8
Jun 11 17:15:00.038 switch eventd[10253]: EVENTD_KERNEL_LOGS_DROPPED: Due to excessive logging, (1) kernel events dropped by eventd
Jun 11 15:47:39.632 switch kernel: vtep_ifl_l2hdr_compute 671 host gbp src tag 0 vxlan flags 0x8
Jun 11 17:15:00.040 switch eventd[10253]: EVENTD_KERNEL_LOGS_DROPPED: Due to excessive logging, (2) kernel events dropped by eventd
Jun 11 15:47:39.660 switch kernel: vtep_ifl_l2hdr_compute 671 host gbp src tag 0 vxlan flags 0x8
Jun 11 17:15:00.059 switch eventd[10253]: EVENTD_KERNEL_LOGS_DROPPED: Due to excessive logging, (1) kernel events dropped by eventd
Jun 11 15:47:39.687 switch kernel: vtep_ifl_l2hdr_compute 671 host gbp src tag 0 vxlan flags 0x8
Jun 11 17:15:00.087 switch eventd[10253]: EVENTD_KERNEL_LOGS_DROPPED: Due to excessive logging, (1) kernel events dropped by eventd
Below is one such example where logs are delayed for more than 90 minutes.
Following “show log interactive-commands” command is issued at 13:51:38. However in the file “interactive-commands”, this command is not present. The last present command is at 12:05:25, which is an hour and 45 minutes before 13:51:38.
user@switch> show log interactive-commands | last 10
Jun 05 13:51:38 >>> Current Time
Jun 5 11:43:19.065 switch mgd[73179]: %INTERACT-6-UI_CMDLINE_READ_LINE: User 'user', command 'show bfd session address 163.162.179.38 '
Jun 5 11:43:23.016 switch mgd[73179]: %INTERACT-6-UI_CMDLINE_READ_LINE: User 'user', command 'show bfd session address 163.162.179.38 extensive '
…
Jun 5 12:05:21.063 switch mgd[74596]: %INTERACT-6-UI_CMDLINE_READ_LINE: User 'user', command 'show configuration | display set '
Jun 5 12:05:25.353 switch mgd[74596]: %INTERACT-6-UI_CMDLINE_READ_LINE: User 'user', command 'exit '
Jun 5 12:05:25.357 switch mgd[74596]: %INTERACT-6-UI_LOGOUT_EVENT: User 'user' logout <==== The last log message is at 12:05:25, almost an hour and 45 minutes prior to the last issued command
This issue has been fixed in following releases. Please upgrade to any of these are their subsequent versions.
EVO: 25.2R2-EVO, 25.3R1-EVO, 25.4R1-EVO
Junos: 22.4R3-S8, 23.2R2-S5, 23.4R2-S6, 24.2R2-S3, 25.2R1-S1, 25.2R2, 25.3R, 25.4R1