[solved] PPPoE falling over under load

motific · May 8, 2020, 7:41 PM

I've had an issue for a few weeks now that when I max out my outbound connection for a while (for example firing off a big photo upload from my phone) then the WAN link dies and won't reconnect. Obviously during lockdown it's become quite an issue, kicking people out of conference calls etc.

When it happens I just get a repeated set of system log entries (below), each with a new process ID until I reboot. I don't need to reboot the bridge, just pfSense. Before I wipe & rebuild, is there anything specific I should look for?

May 8 16:22:23	ppp	65370	process 65370 started, version 5.8 (root@pfSense_master_amd64-pfSense_devel-job-07 19:39 18-Feb-2019)
May 8 16:22:23	ppp	65370	waiting for process 46068 to die...
May 8 16:22:23	ppp	46068	caught fatal signal TERM
May 8 16:22:23	ppp	46068	[wan] IFACE: Close event
May 8 16:22:23	ppp	46068	[wan] IPCP: Close event
May 8 16:22:23	ppp	46068	[wan] IPV6CP: Close event
May 8 16:22:23	php-fpm	9072	/rc.linkup: calling interface_dhcpv6_configure.
May 8 16:22:23	php-fpm	9072	/rc.linkup: Gateway, none 'available' for inet, use the first one configured. 'WAN_PPPOE'
May 8 16:22:23	php-fpm	9072	/rc.linkup: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
May 8 16:22:23	php-fpm	9072	/rc.linkup: Default gateway setting Interface WAN_DHCP6 Gateway as default.
May 8 16:22:23	check_reload_status	368	Restarting ipsec tunnels
May 8 16:22:24	ppp	65370	waiting for process 46068 to die...
May 8 16:22:25	ppp	46068	[wan] Bundle: Shutdown
May 8 16:22:25	ppp	65370	waiting for process 46068 to die...
May 8 16:22:25	ppp	46068	[wan_link0] Link: Shutdown
May 8 16:22:25	ppp	46068	process 46068 terminated
May 8 16:22:25	dhcpleases	61743	/etc/hosts changed size from original!
May 8 16:22:26	dhcpleases	80382	Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process.
May 8 16:22:26	dhcpleases	80382	kqueue error: unknown
May 8 16:22:26	ppp	65370	web: web is not running
May 8 16:22:26	ppp	65370	[wan] Bundle: Interface ng0 created
May 8 16:22:26	ppp	65370	[wan_link0] Link: OPEN event
May 8 16:22:26	kernel		ng0: changing name to 'pppoe0'
May 8 16:22:26	ppp	65370	[wan_link0] LCP: Open event
May 8 16:22:26	ppp	65370	[wan_link0] LCP: state change Initial --> Starting
May 8 16:22:26	ppp	65370	[wan_link0] LCP: LayerStart
May 8 16:22:26	ppp	65370	[wan_link0] PPPoE: Connecting to ''
May 8 16:22:28	check_reload_status	368	updating dyndns wan
May 8 16:22:28	check_reload_status	368	Reloading filter
May 8 16:22:35	ppp	65370	[wan_link0] PPPoE connection timeout after 9 seconds
May 8 16:22:35	ppp	65370	[wan_link0] Link: DOWN event
May 8 16:22:35	ppp	65370	[wan_link0] LCP: Down event
May 8 16:22:35	ppp	65370	[wan_link0] Link: reconnection attempt 1 in 1 seconds
May 8 16:22:36	ppp	65370	[wan_link0] Link: reconnection attempt 1
May 8 16:22:36	ppp	65370	[wan_link0] PPPoE: Connecting to ''
May 8 16:22:44	php-fpm	11315	/index.php: Successful login for user 'admin' from: 10.1.1.60 (Local Database)
May 8 16:22:44	nginx		2020/05/08 16:22:44 [error] 81975#100524: send() failed (54: Connection reset by peer)
May 8 16:22:45	ppp	65370	[wan_link0] PPPoE connection timeout after 9 seconds
May 8 16:22:45	ppp	65370	[wan_link0] Link: DOWN event
May 8 16:22:45	ppp	65370	[wan_link0] LCP: Down event
May 8 16:22:45	ppp	65370	[wan_link0] Link: reconnection attempt 2 in 4 seconds
May 8 16:22:47	kernel		re0: watchdog timeout
May 8 16:22:47	check_reload_status	368	Linkup starting $re0
May 8 16:22:47	kernel		re0: link state changed to DOWN
May 8 16:22:48	check_reload_status	368	Reloading filter
May 8 16:22:49	php-fpm	25188	/index.php: Successful login for user 'admin' from: 10.1.1.60 (Local Database)
May 8 16:22:49	ppp	65370	[wan_link0] Link: reconnection attempt 2
May 8 16:22:49	ppp	65370	[wan_link0] PPPoE: Connecting to ''
May 8 16:22:51	kernel		re0: link state changed to UP
May 8 16:22:51	check_reload_status	368	Linkup starting $re0
May 8 16:22:52	ppp	83933	Multi-link PPP daemon for FreeBSD
May 8 16:22:52	ppp	83933	process 83933 started, version 5.8 (root@pfSense_master_amd64-pfSense_devel-job-07 19:39 18-Feb-2019)

jimp · May 8, 2020, 5:03 PM

What snapshot are you on?

Can you try to force a reinstall of mpd? pkg upgrade -f mpd5

motific · May 8, 2020, 7:14 PM

I’m on 2.5.0.a.20200502.2108.

I’ll give that command a try and report back.

motific · May 8, 2020, 7:41 PM

@jimp - reinstalling MPD seems to have sorted it. Thanks!!!

jimp · May 8, 2020, 7:47 PM

OK, the problem may have been that the version of mpd5 you had was from a snapshot before the kernel moved to FreeBSD 12.1-STABLE. The base OS upgraded but the packages didn't get reinstalled if their version numbers didn't change. We're looking into a good solution for this already.

In the meantime, you might want to force a reinstall of everything: pkg upgrade -f, followed by a reboot.

w0w · May 9, 2020, 4:18 AM

@jimp
Accidentally executed pkg update -f

login-to-view

Is it ok?

motific · May 9, 2020, 2:18 PM

Looks like I spoke too soon. We pushed it extra-hard and it was fine yesterday but it's been flaky again today.

I'm just going for a complete wipe while I've got time today to do it properly.

w0w · May 9, 2020, 4:45 PM

It could be Realtek NIC. If it's possible, use other hardware, If not, you may need to compile realtek driver for your network card, not sure if it's still possible to with 2.5.0 but some people have compiled and using it
https://gist.github.com/jovimon/524e116471f249626fd2ccd141f3fe05 (pfSense user guide)
https://forums.freebsd.org/threads/replacing-realtek-re-driver.55861/page-2