Page MenuHomeVyOS Platform

syslog: ensure rsyslog is registered as default systemd syslog service
Closed, ResolvedPublicBUG

Description

Accel-ppp PPPoE server does not log subscriber sessions

set interfaces ethernet eth2 vif 23
set service pppoe-server access-concentrator 'vyos-vpp'
set service pppoe-server authentication any-login
set service pppoe-server authentication local-users username one password 'one'
set service pppoe-server authentication mode 'local'
set service pppoe-server client-ip-pool FIRST range '100.64.0.0/18'
set service pppoe-server client-ipv6-pool IPv6-POOL delegate 2001:db8:8003::/48 delegation-prefix '56'
set service pppoe-server client-ipv6-pool IPv6-POOL prefix 2001:db8:8002::/48 mask '64'
set service pppoe-server default-ipv6-pool 'IPv6-POOL'
set service pppoe-server default-pool 'FIRST'
set service pppoe-server gateway-address '100.64.0.1'
set service pppoe-server interface eth2 combined
set service pppoe-server interface eth2.23
set service pppoe-server log level '5'
set service pppoe-server name-server '1.1.1.1'
set service pppoe-server name-server '1.0.0.1'
set service pppoe-server ppp-options disable-ccp
set service pppoe-server ppp-options ipv6 'allow'

We do not see any logs for PPPoE sessions:

vyos@vpp:~$ sudo journalctl -f
Apr 16 06:54:53 vpp systemd[1]: Starting user@1002.service - User Manager for UID 1002...
Apr 16 06:54:54 vpp systemd[2959]: Queued start job for default target default.target.
Apr 16 06:54:54 vpp systemd[2959]: Reached target paths.target - Paths.
Apr 16 06:54:54 vpp systemd[2959]: Reached target sockets.target - Sockets.
Apr 16 06:54:54 vpp systemd[2959]: Reached target timers.target - Timers.
Apr 16 06:54:54 vpp systemd[2959]: Reached target basic.target - Basic System.
Apr 16 06:54:54 vpp systemd[2959]: Reached target default.target - Main User Target.
Apr 16 06:54:54 vpp systemd[2959]: Startup finished in 169ms.
Apr 16 06:54:54 vpp systemd[1]: Started user@1002.service - User Manager for UID 1002.
Apr 16 06:54:54 vpp systemd[1]: Started session-1.scope - Session 1 of User vyos.


Apr 16 06:55:37 vpp (udev-worker)[3131]: Network interface NamePolicy= disabled on kernel command line.

journalctl by target accel-ppp:

vyos@vpp:~$ journalctl -t accel-pppoe
-- No entries --
vyos@vpp:~$

In VyOS 1.4.1 all work fine:

vyos@vyos# sudo journalctl -f
Apr 16 07:00:53 vyos systemd[1]: Stopping accel-ppp@pppoe.service - Accel-PPP - High performance VPN server application for Linux...
Apr 16 07:00:53 vyos accel-pppoe[3191]: terminate, sig = 15
Apr 16 07:00:54 vyos systemd[1]: accel-ppp@pppoe.service: Deactivated successfully.
Apr 16 07:00:54 vyos systemd[1]: Stopped accel-ppp@pppoe.service - Accel-PPP - High performance VPN server application for Linux.
Apr 16 07:00:54 vyos systemd[1]: Starting accel-ppp@pppoe.service - Accel-PPP - High performance VPN server application for Linux...
Apr 16 07:00:54 vyos systemd[1]: accel-ppp@pppoe.service: Can't open PID file /run/accel-pppd/pppoe.pid (yet?) after start: No such file or directory
Apr 16 07:00:54 vyos systemd[1]: Started accel-ppp@pppoe.service - Accel-PPP - High performance VPN server application for Linux.
Apr 16 07:00:54 vyos sudo[3288]: pam_unix(sudo:session): session closed for user root
Apr 16 07:00:58 vyos sudo[3298]:     vyos : TTY=ttyS0 ; PWD=/home/vyos ; USER=root ; COMMAND=/usr/bin/journalctl -f
Apr 16 07:00:58 vyos sudo[3298]: pam_unix(sudo:session): session opened for user root(uid=0) by vyos(uid=1002)



Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23: recv [PPPoE PADI 0c:74:47:92:00:00 => ff:ff:ff:ff:ff:ff sid=0000 <Service-Name > <Host-Uniq ff0f0000>]
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23: send [PPPoE PADO 0c:9b:fd:58:00:00 => 0c:74:47:92:00:00 sid=0000 <AC-Name vyos-ac> <Service-Name > <AC-Cookie 293db7ac3fd144630e06f9a04bf33c57b613e1e0363d7c29> <Host-Uniq ff0f0000>]
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23: recv [PPPoE PADR 0c:74:47:92:00:00 => 0c:9b:fd:58:00:00 sid=0000 <Service-Name > <Host-Uniq ff0f0000> <AC-Cookie 293db7ac3fd144630e06f9a04bf33c57b613e1e0363d7c29>]
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23: send [PPPoE PADS 0c:9b:fd:58:00:00 => 0c:74:47:92:00:00 sid=0001 <AC-Name vyos-ac> <Service-Name > <Host-Uniq ff0f0000>]
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: lcp_layer_init
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: auth_layer_init
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: ccp_layer_init
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: ipcp_layer_init
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: ipv6cp_layer_init
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: ppp establishing
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: lcp_layer_start
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: send [LCP ConfReq id=c0 <auth PAP> <mru 1492> <magic 3daadde9>]
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: recv [LCP ConfReq id=1 <mru 1492> <magic fd1b26e2>]
Apr 16 07:01:18 vyos accel-pppoe[3293]: eth0.23:: send [LCP ConfAck id=1]
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: fsm timeout 9
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: send [LCP ConfReq id=c0 <auth PAP> <mru 1492> <magic 3daadde9>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: recv [LCP ConfAck id=c0 <auth PAP> <mru 1492> <magic 3daadde9>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: lcp_layer_started
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: auth_layer_start
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: recv [LCP EchoReq id=0 <magic fd1b26e2>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: send [LCP EchoRep id=0 <magic 3daadde9>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: eth0.23:: recv [PAP AuthReq id=1]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: connect: ppp0 <--> pppoe(0c:74:47:92:00:00)
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: ppp connected
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: send [PAP AuthAck id=1 "Authentication succeeded"]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: three: authentication succeeded
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: auth_layer_started
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: ccp_layer_start
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: ipcp_layer_start
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: ipv6cp_layer_start
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: recv [IPCP ConfReq id=1 <addr 0.0.0.0> <dns1 0.0.0.0> <dns2 0.0.0.0>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: send [IPCP ConfReq id=7 <addr 100.64.0.1>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: send [IPCP ConfNak id=1 <addr 100.64.0.0> <dns1 1.1.1.1> <dns2 1.0.0.1>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: recv [IPCP ConfAck id=7 <addr 100.64.0.1>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: recv [IPCP ConfReq id=2 <addr 100.64.0.0> <dns1 1.1.1.1> <dns2 1.0.0.1>]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: send [IPCP ConfAck id=2]
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: ipcp_layer_started
Apr 16 07:01:21 vyos accel-pppoe[3293]: ppp0:three: pppoe: ppp started
Apr 16 07:01:21 vyos (udev-worker)[3304]: Network interface NamePolicy= disabled on kernel command line.
^C
[edit]
vyos@vyos#

The accel-ppp configuration looks good and similar between rolling/1.4.1
rolling:

vyos@vpp# cat /run/accel-pppd/pppoe.conf | grep "^\[log" -A 4
[log]
syslog=accel-pppoe,daemon
copy=1
level=5

1.4.1:

vyos@vyos# cat /run/accel-pppd/pppoe.conf | grep "^\[log" -A 4
[log]
syslog=accel-pppoe,daemon
copy=1
level=5

Details

Version
VyOS 2025.04.08-0813-rolling
Is it a breaking change?
Unspecified (possibly destroys the router)
Issue type
Bug (incorrect behavior)

Event Timeline

Viacheslav triaged this task as Normal priority.

The simple way to reproduce:

logger -t accel-pppoe "hello journal"

And check logs, expected entry:

Apr 16 08:33:39 vyos accel-pppoe[8427]: hello journal

But we get no entries:

vyos@vpp# logger -t accel-pppoe "hello journal"
[edit]
vyos@vpp# logger -t accel-pppoe "hello journal"
[edit]
vyos@vpp# logger -t accel-pppoe "hello journal"
[edit]
vyos@vpp# journalctl -t accel-pppoe
-- No entries --
[edit]
vyos@vpp#
c-po renamed this task from Accel-ppp PPPoE server does not log subscriber sessions to syslog: ensure rsyslog is registered as default systemd syslog service.Apr 18 2025, 5:55 PM
c-po moved this task from Open to Finished on the VyOS 1.5 Circinus board.