Page MenuHomeVyOS Platform

protocol logs not sent to remote syslog
Closed, ResolvedPublicBUG

Description

I see /var/log/frr/frr.log contains some ospf and few bgp events. And with this configuration, I expected logs to be delivered to remote syslog host. However, only messages from /var/log/messages are seen on remote syslog host.

set host 172.18.42.12:1514 facility all level 'debug'
set host 172.18.42.12:1514 facility all protocol 'tcp'

Not sure if this is a bug of new feature. Also, how can I control protocol event logging? ospf has log-adjacency-changes, but I dont know if there is something similiar for bgp?

Details

Difficulty level
Unknown (require assessment)
Version
1.2.3
Why the issue appeared?
Will be filled on close
Is it a breaking change?
Unspecified (possibly destroys the router)

Event Timeline

syncer triaged this task as Low priority.
syncer edited projects, added VyOS 1.3 Equuleus; removed VyOS 1.2 Crux.

The main reason is frr code for placing log files in a separate file.
https://github.com/FRRouting/frr/blob/master/tools/etc/rsyslog.d/45-frr.conf

We can move it to /var/log/messages
I don't see any reason to separate it from "messages"

Another bug that the following configuration doesn't configure vtysh level debug

set system syslog global facility all level 'all'
set system syslog global facility protocols level 'all'

For example bgp keepalives

vyos@r5:~$ monitor protocol bgp enable keepalives 
BGP keepalives debugging is on

As we see the level "informational" only

vyos@r5:~$ vtysh -c "show run" | match log
log syslog informational
vyos@r5:~$

There are not keepalive messages

vyos@r5:~$ sudo tail -f /var/log/frr/frr.log | match bgp
Nov 24 16:03:44 r5 bgpd[838]: bgp_update_receive: rcvd End-of-RIB for IPv4 Unicast from 100.64.0.2 in vrf default

To fix it we should declare to vtysh, level "debug" what mean "log syslog" without other options

vyos@r5:~$ vtysh -c "conf t" -c "log syslog debug"
vyos@r5:~$ 
vyos@r5:~$ vtysh -c "show run" | match log
log syslog
vyos@r5:~$

Now we see debug messages

vyos@r5:~$ sudo tail -f /var/log/frr/frr.log | match bgp
Nov 24 16:03:44 r5 bgpd[838]: bgp_update_receive: rcvd End-of-RIB for IPv4 Unicast from 100.64.0.2 in vrf default
Nov 24 16:32:13 r5 bgpd[838]: 100.64.0.2 sending KEEPALIVE
Nov 24 16:32:13 r5 bgpd[838]: 100.64.0.2 KEEPALIVE rcvd
Nov 24 16:32:23 r5 bgpd[838]: 100.64.0.2 sending KEEPALIVE
Nov 24 16:32:23 r5 bgpd[838]: 100.64.0.2 KEEPALIVE rcvd
Nov 24 16:32:33 r5 bgpd[838]: 100.64.0.2 sending KEEPALIVE
Nov 24 16:32:33 r5 bgpd[838]: 100.64.0.2 KEEPALIVE rcvd

PR https://github.com/vyos/vyos-build/pull/133

With that pr, logs will be placed in the file /var/log/messages
It allow to send them to a remote Syslog server.
Also, it fixes debug mode for protocols. So before we see only "informational" level.

monitor protocol ospf enable event 
monitor protocol ospf enable lsa 
monitor protocol ospf enable nsm
monitor protocol ospf enable packet all 
monitor protocol ospf enable rib

Monitor logs

vyos@r1:~$ monitor protocol ospf
tail:   OSPF: unrecognized file system type 0x794c7630 for ‘/var/log/messages’. please report this to bug-coreutils@gnu.org. reverting to polling
Hello sent to [224.0.0.5] via [vtun5:10.0.0.1]. 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): start 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): next index 82 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): refresh index 81 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): end 
  OSPF: make_hello: options: 2, int: vtun5:10.0.0.1 
  OSPF: ospf_write to 224.0.0.5, id 14724, off 0, len 64, interface vtun5, mtu 1500: 
  OSPF: Hello sent to [224.0.0.5] via [vtun5:10.0.0.1]. 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): start 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): next index 83 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): refresh index 82 
  OSPF: LSA[Refresh]: ospf_lsa_refresh_walker(): end 
  OSPF: make_hello: options: 2, int: vtun5:10.0.0.1 
  OSPF: ospf_write to 224.0.0.5, id 14725, off 0, len 64, interface vtun5, mtu 1500: 
  OSPF: Hello sent to [224.0.0.5] via [vtun5:10.0.0.1].

@olofl Can you check the latest rolling release? Are all logs sent correctly?

monitor protocol bgp enable keepalives 
monitor protocol bgp enable rib 

vyos@r5:~$ monitor protocol bgp 
  BGP: 100.64.0.2 sending KEEPALIVE 
  BGP: 100.64.0.2 KEEPALIVE rcvd 
  BGP: 100.64.0.2 sending KEEPALIVE 
  BGP: 100.64.0.2 KEEPALIVE rcvd 
  BGP: 100.64.0.2 sending KEEPALIVE 
  BGP: 100.64.0.2 KEEPALIVE rcvd 

vyos@r5:~$ show log | match bgp
Nov 26 18:11:59 debian watchfrr[868]: [EC 268435457] bgpd state -> down : initial connection attempt failed
Nov 26 18:11:59 debian watchfrr.sh[889]: Cannot stop bgpd: pid file not found
Nov 26 18:12:01 debian zebra[909]: client 26 says hello and bids fair to announce only bgp routes vrf=0
Nov 26 18:12:03 debian watchfrr[868]: bgpd state -> up : connect succeeded
Nov 26 18:12:11 r5 bgpd[914]: bgp_update_receive: rcvd End-of-RIB for IPv4 Unicast from 100.64.0.2 in vrf default
Nov 26 18:13:30 r5 bgpd[914]: 100.64.0.2 sending KEEPALIVE
Nov 26 18:13:30 r5 bgpd[914]: 100.64.0.2 KEEPALIVE rcvd
Nov 26 18:13:40 r5 bgpd[914]: 100.64.0.2 sending KEEPALIVE