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