WAN periodically Rebooting

diyhouse

@stephenw10 said in WAN periodically Rebooting:
Looking into logs around 13:15 today,.. things look like this,
where there are many things happening,.. none of which look good, WAN failing up down layerup etc etc.. even to my untrained eye,.. but I hope will mean something to a 'trained eye of pfsense,..
..Back to November,.. do you have a fixed IP,.. and are you maybe with another provider ( Not BT),.. as my last reboot, was intentional some 110days ago,.. any other 'house failures' as long as there less than 10hrs do not cause an issue... ( as Big battery on UPS )
I seek your advice,.. etc ,.. should I just buy an MT992? and replace modem?
Many Tx

Aug 1 15:32:55	ppp	90375	[wan_link0] LCP: no reply to 2 echo request(s)
Aug 1 15:32:45	ppp	90375	[wan_link0] LCP: no reply to 1 echo request(s)
Aug 1 13:15:46	ppp	90375	[wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 1 13:15:44	ppp	90375	[wan] IFACE: Add description "1_WAN"
Aug 1 13:15:44	ppp	90375	[wan] IFACE: Rename interface ng0 to pppoe0
Aug 1 13:15:44	ppp	90375	[wan] IFACE: Up event
Aug 1 13:15:43	ppp	90375	[wan] 109.151.224.138 -> 172.16.12.102
Aug 1 13:15:43	ppp	90375	[wan] IPCP: LayerUp
Aug 1 13:15:43	ppp	90375	[wan] IPCP: state change Ack-Sent --> Opened
Aug 1 13:15:43	ppp	90375	[wan] SECDNS 81.139.57.100
Aug 1 13:15:43	ppp	90375	[wan] PRIDNS 81.139.56.100
Aug 1 13:15:43	ppp	90375	[wan] IPADDR 109.151.224.138
Aug 1 13:15:43	ppp	90375	[wan] IPCP: rec'd Configure Ack #52 (Ack-Sent)
Aug 1 13:15:43	ppp	90375	[wan] SECDNS 81.139.57.100
Aug 1 13:15:43	ppp	90375	[wan] PRIDNS 81.139.56.100
Aug 1 13:15:43	ppp	90375	[wan] IPADDR 109.151.224.138
Aug 1 13:15:43	ppp	90375	[wan] IPCP: SendConfigReq #52
Aug 1 13:15:43	ppp	90375	[wan] SECDNS 81.139.57.100
Aug 1 13:15:43	ppp	90375	[wan] PRIDNS 81.139.56.100
Aug 1 13:15:43	ppp	90375	[wan] 109.151.224.138 is OK
Aug 1 13:15:43	ppp	90375	[wan] IPADDR 109.151.224.138
Aug 1 13:15:43	ppp	90375	[wan] IPCP: rec'd Configure Nak #51 (Ack-Sent)
Aug 1 13:15:43	ppp	90375	[wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 1 13:15:43	ppp	90375	[wan] SECDNS 0.0.0.0
Aug 1 13:15:43	ppp	90375	[wan] PRIDNS 0.0.0.0
Aug 1 13:15:43	ppp	90375	[wan] IPADDR 0.0.0.0
Aug 1 13:15:43	ppp	90375	[wan] IPCP: SendConfigReq #51
Aug 1 13:15:43	ppp	90375	[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Aug 1 13:15:43	ppp	90375	[wan] IPCP: rec'd Configure Reject #50 (Ack-Sent)
Aug 1 13:15:43	ppp	90375	[wan] IPCP: state change Req-Sent --> Ack-Sent
Aug 1 13:15:43	ppp	90375	[wan] IPADDR 172.16.12.102
Aug 1 13:15:43	ppp	90375	[wan] IPCP: SendConfigAck #185
Aug 1 13:15:43	ppp	90375	[wan] 172.16.12.102 is OK
Aug 1 13:15:43	ppp	90375	[wan] IPADDR 172.16.12.102
Aug 1 13:15:43	ppp	90375	[wan] IPCP: rec'd Configure Request #185 (Req-Sent)
Aug 1 13:15:43	ppp	90375	[wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 1 13:15:43	ppp	90375	[wan] SECDNS 0.0.0.0
Aug 1 13:15:43	ppp	90375	[wan] PRIDNS 0.0.0.0
Aug 1 13:15:43	ppp	90375	[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Aug 1 13:15:43	ppp	90375	[wan] IPADDR 0.0.0.0
Aug 1 13:15:43	ppp	90375	[wan] IPCP: SendConfigReq #50
Aug 1 13:15:43	ppp	90375	[wan] IPCP: state change Starting --> Req-Sent
Aug 1 13:15:43	ppp	90375	[wan] IPCP: Up event
Aug 1 13:15:43	ppp	90375	[wan] IPCP: LayerStart
Aug 1 13:15:43	ppp	90375	[wan] IPCP: state change Initial --> Starting
Aug 1 13:15:43	ppp	90375	[wan] IPCP: Open event
Aug 1 13:15:43	ppp	90375	[wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Aug 1 13:15:43	ppp	90375	[wan_link0] Link: Join bundle "wan"
Aug 1 13:15:43	ppp	90375	[wan_link0] Link: Matched action 'bundle "wan" ""'
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: authorization successful
Aug 1 13:15:43	ppp	90375	[wan_link0] MESG: CHAP authentication success
Aug 1 13:15:43	ppp	90375	[wan_link0] CHAP: rec'd SUCCESS #1 len: 31
Aug 1 13:15:43	ppp	90375	[wan_link0] CHAP: sending RESPONSE #1 len: 52
Aug 1 13:15:43	ppp	90375	[wan_link0] CHAP: Using authname "green-light@service.btclick.com"
Aug 1 13:15:43	ppp	90375	[wan_link0] Name: "acc-aln2.tbs"
Aug 1 13:15:43	ppp	90375	[wan_link0] CHAP: rec'd CHALLENGE #1 len: 51
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: LayerUp
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: auth: peer wants CHAP, I want nothing
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: state change Ack-Sent --> Opened
Aug 1 13:15:43	ppp	90375	[wan_link0] MAGICNUM 0xc47d9da9
Aug 1 13:15:43	ppp	90375	[wan_link0] MRU 1492
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: rec'd Configure Ack #36 (Ack-Sent)
Aug 1 13:15:43	ppp	90375	[wan_link0] MAGICNUM 0xc47d9da9
Aug 1 13:15:43	ppp	90375	[wan_link0] MRU 1492
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: SendConfigReq #36
Aug 1 13:15:43	ppp	90375	[wan_link0] PROTOCOMP
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: rec'd Configure Reject #35 (Ack-Sent)
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: state change Req-Sent --> Ack-Sent
Aug 1 13:15:43	ppp	90375	[wan_link0] MAGICNUM 0x7c14f295
Aug 1 13:15:43	ppp	90375	[wan_link0] AUTHPROTO CHAP MD5
Aug 1 13:15:43	ppp	90375	[wan_link0] MRU 1492
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: SendConfigAck #75
Aug 1 13:15:43	ppp	90375	[wan_link0] MAGICNUM 0x7c14f295
Aug 1 13:15:43	ppp	90375	[wan_link0] AUTHPROTO CHAP MD5
Aug 1 13:15:43	ppp	90375	[wan_link0] MRU 1492
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: rec'd Configure Request #75 (Req-Sent)
Aug 1 13:15:43	ppp	90375	[wan_link0] MAGICNUM 0xc47d9da9
Aug 1 13:15:43	ppp	90375	[wan_link0] MRU 1492
Aug 1 13:15:43	ppp	90375	[wan_link0] PROTOCOMP
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: SendConfigReq #35
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: state change Starting --> Req-Sent
Aug 1 13:15:43	ppp	90375	[wan_link0] LCP: Up event
Aug 1 13:15:43	ppp	90375	[wan_link0] Link: UP event
Aug 1 13:15:43	ppp	90375	[wan_link0] PPPoE: connection successful
Aug 1 13:15:43	ppp	90375	PPPoE: rec'd ACNAME "acc-aln2.tbs"
Aug 1 13:15:43	ppp	90375	[wan_link0] PPPoE: Connecting to ''
Aug 1 13:15:43	ppp	90375	[wan_link0] Link: reconnection attempt 3
Aug 1 13:15:39	ppp	90375	[wan_link0] Link: reconnection attempt 3 in 4 seconds
Aug 1 13:15:39	ppp	90375	[wan_link0] LCP: Down event
Aug 1 13:15:39	ppp	90375	[wan_link0] Link: DOWN event
Aug 1 13:15:39	ppp	90375	[wan_link0] PPPoE connection timeout after 9 seconds
Aug 1 13:15:30	ppp	90375	[wan_link0] PPPoE: Connecting to ''
Aug 1 13:15:30	ppp	90375	[wan_link0] Link: reconnection attempt 2
Aug 1 13:15:28	ppp	90375	[wan_link0] Link: reconnection attempt 2 in 2 seconds
Aug 1 13:15:28	ppp	90375	[wan_link0] LCP: Down event
Aug 1 13:15:28	ppp	90375	[wan_link0] Link: DOWN event
Aug 1 13:15:28	ppp	90375	[wan_link0] PPPoE connection timeout after 9 seconds
Aug 1 13:15:19	ppp	90375	[wan_link0] PPPoE: Connecting to ''
Aug 1 13:15:19	ppp	90375	[wan_link0] Link: reconnection attempt 1
Aug 1 13:15:18	ppp	90375	[wan_link0] Link: reconnection attempt 1 in 1 seconds
Aug 1 13:15:18	ppp	90375	[wan_link0] LCP: LayerDown
Aug 1 13:15:18	ppp	90375	[wan] Bundle: Last link has gone, no links for bw-manage defined
Aug 1 13:15:18	ppp	90375	[wan] IPCP: state change Closing --> Initial
Aug 1 13:15:18	ppp	90375	[wan] Bundle: No NCPs left. Closing links...
Aug 1 13:15:18	ppp	90375	[wan] IPCP: LayerFinish
Aug 1 13:15:18	ppp	90375	[wan] IPCP: Down event
Aug 1 13:15:18	ppp	90375	[wan] IFACE: Set description "1_WAN"
Aug 1 13:15:18	ppp	90375	[wan] IFACE: Rename interface pppoe0 to pppoe0
Aug 1 13:15:18	ppp	90375	[wan] IFACE: Down event
Aug 1 13:15:18	ppp	90375	[wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
Aug 1 13:15:17	ppp	90375	[wan] IPCP: LayerDown
Aug 1 13:15:17	ppp	90375	[wan] IPCP: SendTerminateReq #49
Aug 1 13:15:17	ppp	90375	[wan] IPCP: state change Opened --> Closing
Aug 1 13:15:17	ppp	90375	[wan] IPCP: Close event
Aug 1 13:15:17	ppp	90375	[wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Aug 1 13:15:17	ppp	90375	[wan_link0] Link: Leave bundle "wan"
Aug 1 13:15:17	ppp	90375	[wan_link0] LCP: state change Opened --> Starting
Aug 1 13:15:17	ppp	90375	[wan_link0] LCP: Down event
Aug 1 13:15:17	ppp	90375	[wan_link0] Link: DOWN event
Aug 1 13:15:17	ppp	90375	[wan_link0] PPPoE: connection closed
Aug 1 13:15:17	ppp	90375	[wan_link0] LCP: no reply to 3 echo request(s)
Aug 1 13:15:07	ppp	90375	[wan_link0] LCP: no reply to 2 echo request(s)
Aug 1 13:14:57	ppp	90375	[wan_link0] LCP: no reply to 1 echo request(s)

stephenw10

Well the modem is not losing link to pfSense so it's not rebooting.

Those logs show it stops seeing responses from upstream but not the count of 5 missed replies that would trigger a reconnect. However the connection is them promptly closed which implies something was sent from upstream. If so a different modem might not make any difference.

However given the age of the HG612 I would probably try replacing it. An MT992 is likely to be better at using the available line conditions anyway.
What sort of connections speeds do you get?

diyhouse

@stephenw10
Well using webtool 'speedtest',.. I get 40Mbps download, ( I am surprised ) and 15Mps up,.. with a ping of 15ms. No other traffic as far as I can see,.. but who knows what is up stream. at 9PM at night

Now many moons ago when I 1st setup pfsense I seem to recall getting 56Mbps,.. and prob 20Mbps Up,..

compared to 72Mbps the the offical BT, Modem,.. but I was happy with '56',.. as the 72 was only BT reporting on itself,...

Having 'lost' 16Mbps download,.. something would seem to be Off,...
.... off to order MT992....

diyhouse

@diyhouse MT992 order,.. brand new one!!,.. just no power block,..
But have spare for old one if required,.. and I supply it from a UPS anyway...
So should be good for a few years,.. of 24/7 running.
Thinking about it the HG612 must have been running for 3 or 4 yrs,.. solid,.. and it does sometimes run warm, especially during hot summers,.. like ATM in the UK.. 40C ambient in loft, (must find invoice to see how long),.. Hummm

stephenw10

Could also be your line conditions have deteriorated. The unlocked HG612 gives nice stats for that:

Screenshot from 2024-08-02 21-40-50.png

It really is a shame the MT992 is locked down. I'm sure all that data is in there.

diyhouse

@stephenw10
Hi Steve,.. My new MT992 has just arrived,... minus power supply as stated before,,,.
Just covering the 'idiot guide question',.. supply requirements 12v @1amp,... I ASSUME,... centre pin is plus,.. and barrel outer is -Ve... as per normal convention,.. as it does not state on MT992...
Many Tx

stephenw10

Yup I assume so. I used the same battery backup unit I was using with the HG612. (So, yes, it must be!)

diyhouse

@stephenw10 Hi Stephen,.. well MT992 installed... and although speed test seems to have some improvements ( but this could just be time of day etc ), ..'uptime' on the other hand does not seem to be much better,... as my 1st disconnect occurred 50mins after 1st boot and connect of modem,.. logs as follows

I see at 13:59:51 connection is lost,.. but how do I see what caused the the event...?
Many Tx

Aug 12 14:15:17	php	31129	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Aug 12 14:15:00	php	31129	[pfBlockerNG] Starting cron process.
Aug 12 14:15:00	sshguard	32443	Now monitoring attacks.
Aug 12 14:15:00	sshguard	54598	Exiting on signal.
Aug 12 14:06:00	sshguard	54598	Now monitoring attacks.
Aug 12 14:06:00	sshguard	28085	Exiting on signal.
Aug 12 14:04:00	sshguard	28085	Now monitoring attacks.
Aug 12 14:04:00	sshguard	94791	Exiting on signal.
Aug 12 14:01:00	sshguard	94791	Now monitoring attacks.
Aug 12 14:01:00	sshguard	18557	Exiting on signal.
Aug 12 14:00:56	ppp	19091	[wan_link0] LCP: no reply to 2 echo request(s)
Aug 12 14:00:46	ppp	19091	[wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 14:00:30	php_pfb	85217	[pfBlockerNG] filterlog daemon started
Aug 12 14:00:30	php	84813	[pfBlockerNG] DNSBL parser daemon started
Aug 12 14:00:29	vnstatd	85867	Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Aug 12 14:00:29	vnstatd	81408	Monitoring (11): pppoe0 (1000 Mbit) pfsync0 (1000 Mbit) pflog0 (1000 Mbit) igb3.30 (1000 Mbit) igb3.20 (1000 Mbit) igb3.10 (1000 Mbit) igb3 (1000 Mbit) igb2 (10 Mbit) igb1 (1000 Mbit) igb0 (1000 Mbit) enc0 (1000 Mbit)
Aug 12 14:00:29	vnstatd	81408	Data retention: 48 5MinuteHours, 4 HourlyDays, 62 DailyDays, 25 MonthlyMonths, -1 YearlyYears, 20 TopDayEntries
Aug 12 14:00:29	vnstatd	81408	vnStat daemon 2.11 (pid:81408 uid:0 gid:0, SQLite 3.43.1)
Aug 12 14:00:29	tail_pfb	84427	[pfBlockerNG] Firewall Filter Service started
Aug 12 14:00:29	lighttpd_pfb	81906	[pfBlockerNG] DNSBL Webserver started
Aug 12 14:00:29	php_pfb	80281	[pfBlockerNG] filterlog daemon stopped
Aug 12 14:00:29	tail_pfb	78860	[pfBlockerNG] Firewall Filter Service stopped
Aug 12 14:00:29	lighttpd_pfb	77070	[pfBlockerNG] DNSBL Webserver stopped
Aug 12 14:00:29	vnstatd	22588	SIGTERM received, exiting.
Aug 12 14:00:19	vnstatd	49205	Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Aug 12 14:00:19	bandwidthd	49002	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	48834	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	49002	Opening igb1
Aug 12 14:00:19	bandwidthd	48764	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	48834	Opening igb1
Aug 12 14:00:19	bandwidthd	49176	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	49176	Opening igb1
Aug 12 14:00:19	bandwidthd	48764	Opening igb1
Aug 12 14:00:19	bandwidthd	48227	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	48227	Opening igb1
Aug 12 14:00:19	bandwidthd	48477	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	47880	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	48649	Packet Encoding: Ethernet
Aug 12 14:00:19	bandwidthd	48477	Opening igb1
Aug 12 14:00:19	bandwidthd	48649	Opening igb1
Aug 12 14:00:19	bandwidthd	47880	Opening igb1
Aug 12 14:00:19	bandwidthd	46528	Monitoring subnet 192.168.3.0 with netmask 255.255.255.0
Aug 12 14:00:19	bandwidthd	46381	Monitoring subnet 192.168.3.0 with netmask 255.255.255.0
Aug 12 14:00:19	php-fpm	18605	/rc.start_packages: The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'killall: warning: kill -TERM 63951: No such process killall: warning: kill -TERM 65017: No such process'
Aug 12 14:00:18	php-fpm	18605	/rc.start_packages: Restarting/Starting all packages.
Aug 12 14:00:17	check_reload_status	430	Reloading filter
Aug 12 14:00:17	check_reload_status	430	Starting packages
Aug 12 14:00:17	php-fpm	88053	/rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 86.146.217.76 -> 86.168.50.162 - Restarting packages.
Aug 12 14:00:16	php-fpm	62823	/rc.openvpn: Gateway, none 'available' for inet6, use the first one configured. 'LAN1_DHCP6'
Aug 12 14:00:16	php-fpm	62823	/rc.openvpn: Gateway, none 'available' for inet, use the first one configured. '1_WAN_PPPOE'
Aug 12 14:00:14	php-fpm	88053	/rc.newwanip: Creating rrd update script
Aug 12 14:00:14	php-fpm	88053	/rc.newwanip: Resyncing OpenVPN instances for interface 1_WAN.
Aug 12 14:00:14	php-fpm	88053	/rc.newwanip: IP Address has changed, killing states on former IP Address 86.146.217.76.
Aug 12 14:00:14	php-fpm	88053	/rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. 'LAN1_DHCP6'
Aug 12 14:00:14	check_reload_status	430	Reloading filter
Aug 12 14:00:14	check_reload_status	430	Restarting OpenVPN tunnels/interfaces
Aug 12 14:00:14	check_reload_status	430	Restarting IPsec tunnels
Aug 12 14:00:14	check_reload_status	430	updating dyndns 1_WAN_PPPOE
Aug 12 14:00:14	php-fpm	88053	/rc.newwanip: Default gateway setting Interface 1_WAN_PPPOE Gateway as default.
Aug 12 14:00:14	rc.gateway_alarm	42980	>>> Gateway alarm: 1_WAN_PPPOE (Addr:172.16.12.102 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%)
Aug 12 14:00:14	php-fpm	88053	/rc.newwanip: Gateway, none 'available' for inet, use the first one configured. '1_WAN_PPPOE'
Aug 12 14:00:09	ppp	19091	[wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 12 14:00:08	php-fpm	88053	/rc.newwanip: rc.newwanip: on (IP address: 86.168.50.162) (interface: 1_WAN[wan]) (real interface: pppoe0).
Aug 12 14:00:08	php-fpm	88053	/rc.newwanip: rc.newwanip: Info: starting on pppoe0.
Aug 12 14:00:07	ppp	19091	[wan] IFACE: Add description "1_WAN"
Aug 12 14:00:07	ppp	19091	[wan] IFACE: Rename interface ng0 to pppoe0
Aug 12 14:00:07	ppp	19091	[wan] IFACE: Up event
Aug 12 14:00:07	check_reload_status	430	rc.newwanip starting pppoe0
Aug 12 14:00:06	check_reload_status	430	Rewriting resolv.conf
Aug 12 14:00:06	ppp	19091	[wan] 86.168.50.162 -> 172.16.12.102
Aug 12 14:00:06	ppp	19091	[wan] IPCP: LayerUp
Aug 12 14:00:06	ppp	19091	[wan] IPCP: state change Ack-Sent --> Opened
Aug 12 14:00:06	ppp	19091	[wan] SECDNS 81.139.57.100
Aug 12 14:00:06	ppp	19091	[wan] PRIDNS 81.139.56.100
Aug 12 14:00:06	ppp	19091	[wan] IPADDR 86.168.50.162
Aug 12 14:00:06	ppp	19091	[wan] IPCP: rec'd Configure Ack #7 (Ack-Sent)
Aug 12 14:00:06	ppp	19091	[wan] SECDNS 81.139.57.100
Aug 12 14:00:06	ppp	19091	[wan] PRIDNS 81.139.56.100
Aug 12 14:00:06	ppp	19091	[wan] IPADDR 86.168.50.162
Aug 12 14:00:06	ppp	19091	[wan] IPCP: SendConfigReq #7
Aug 12 14:00:06	ppp	19091	[wan] SECDNS 81.139.57.100
Aug 12 14:00:06	ppp	19091	[wan] PRIDNS 81.139.56.100
Aug 12 14:00:06	ppp	19091	[wan] 86.168.50.162 is OK
Aug 12 14:00:06	ppp	19091	[wan] IPADDR 86.168.50.162
Aug 12 14:00:06	ppp	19091	[wan] IPCP: rec'd Configure Nak #6 (Ack-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 12 14:00:06	ppp	19091	[wan] SECDNS 0.0.0.0
Aug 12 14:00:06	ppp	19091	[wan] PRIDNS 0.0.0.0
Aug 12 14:00:06	ppp	19091	[wan] IPADDR 0.0.0.0
Aug 12 14:00:06	ppp	19091	[wan] IPCP: SendConfigReq #6
Aug 12 14:00:06	ppp	19091	[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Aug 12 14:00:06	ppp	19091	[wan] IPCP: rec'd Configure Reject #5 (Ack-Sent)
Aug 12 14:00:06	ppp	19091	[wan] IPCP: state change Req-Sent --> Ack-Sent
Aug 12 14:00:06	ppp	19091	[wan] IPADDR 172.16.12.102
Aug 12 14:00:06	ppp	19091	[wan] IPCP: SendConfigAck #187
Aug 12 14:00:06	ppp	19091	[wan] 172.16.12.102 is OK
Aug 12 14:00:06	ppp	19091	[wan] IPADDR 172.16.12.102
Aug 12 14:00:06	ppp	19091	[wan] IPCP: rec'd Configure Request #187 (Req-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 12 14:00:06	ppp	19091	[wan] SECDNS 0.0.0.0
Aug 12 14:00:06	ppp	19091	[wan] PRIDNS 0.0.0.0
Aug 12 14:00:06	ppp	19091	[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Aug 12 14:00:06	ppp	19091	[wan] IPADDR 0.0.0.0
Aug 12 14:00:06	ppp	19091	[wan] IPCP: SendConfigReq #5
Aug 12 14:00:06	ppp	19091	[wan] IPCP: state change Starting --> Req-Sent
Aug 12 14:00:06	ppp	19091	[wan] IPCP: Up event
Aug 12 14:00:06	ppp	19091	[wan] IPCP: LayerStart
Aug 12 14:00:06	ppp	19091	[wan] IPCP: state change Initial --> Starting
Aug 12 14:00:06	ppp	19091	[wan] IPCP: Open event
Aug 12 14:00:06	ppp	19091	[wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Aug 12 14:00:06	ppp	19091	[wan_link0] Link: Join bundle "wan"
Aug 12 14:00:06	ppp	19091	[wan_link0] Link: Matched action 'bundle "wan" ""'
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: authorization successful
Aug 12 14:00:06	ppp	19091	[wan_link0] MESG: CHAP authentication success
Aug 12 14:00:06	ppp	19091	[wan_link0] CHAP: rec'd SUCCESS #1 len: 31
Aug 12 14:00:06	ppp	19091	[wan_link0] CHAP: sending RESPONSE #1 len: 52
Aug 12 14:00:06	ppp	19091	[wan_link0] CHAP: Using authname "green-light@service.btclick.com"
Aug 12 14:00:06	ppp	19091	[wan_link0] Name: "acc-aln2.tbs"
Aug 12 14:00:06	ppp	19091	[wan_link0] CHAP: rec'd CHALLENGE #1 len: 59
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: LayerUp
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: auth: peer wants CHAP, I want nothing
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: state change Ack-Sent --> Opened
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x53da0584
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: rec'd Configure Ack #4 (Ack-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x53da0584
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: SendConfigReq #4
Aug 12 14:00:06	ppp	19091	[wan_link0] PROTOCOMP
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: rec'd Configure Reject #3 (Ack-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: state change Req-Sent --> Ack-Sent
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x4fd3fb4b
Aug 12 14:00:06	ppp	19091	[wan_link0] AUTHPROTO CHAP MD5
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: SendConfigAck #58
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x4fd3fb4b
Aug 12 14:00:06	ppp	19091	[wan_link0] AUTHPROTO CHAP MD5
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: rec'd Configure Request #58 (Req-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x53da0584
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] PROTOCOMP
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: SendConfigReq #3
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: state change Starting --> Req-Sent
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: Up event
Aug 12 14:00:06	ppp	19091	[wan_link0] Link: UP event
Aug 12 14:00:06	ppp	19091	[wan_link0] PPPoE: connection successful
Aug 12 14:00:06	ppp	19091	PPPoE: rec'd ACNAME "acc-aln2.tbs"
Aug 12 14:00:06	ppp	19091	[wan_link0] PPPoE: Connecting to ''
Aug 12 14:00:06	ppp	19091	[wan_link0] Link: reconnection attempt 2
Aug 12 14:00:05	ppp	19091	[wan_link0] Link: reconnection attempt 2 in 1 seconds
Aug 12 14:00:05	ppp	19091	[wan_link0] LCP: Down event
Aug 12 14:00:05	ppp	19091	[wan_link0] Link: DOWN event
Aug 12 14:00:05	ppp	19091	[wan_link0] PPPoE connection timeout after 9 seconds
Aug 12 13:59:56	ppp	19091	[wan_link0] PPPoE: Connecting to ''
Aug 12 13:59:56	ppp	19091	[wan_link0] Link: reconnection attempt 1
Aug 12 13:59:52	ppp	19091	[wan_link0] Link: reconnection attempt 1 in 4 seconds
Aug 12 13:59:52	ppp	19091	[wan_link0] LCP: LayerDown
Aug 12 13:59:52	ppp	19091	[wan] Bundle: Last link has gone, no links for bw-manage defined
Aug 12 13:59:52	ppp	19091	[wan] IPCP: state change Closing --> Initial
Aug 12 13:59:52	ppp	19091	[wan] Bundle: No NCPs left. Closing links...
Aug 12 13:59:52	ppp	19091	[wan] IPCP: LayerFinish
Aug 12 13:59:52	ppp	19091	[wan] IPCP: Down event
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Set description "1_WAN"
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Rename interface pppoe0 to pppoe0
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Down event
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
Aug 12 13:59:52	check_reload_status	430	Rewriting resolv.conf
Aug 12 13:59:51	ppp	19091	[wan] IPCP: LayerDown
Aug 12 13:59:51	ppp	19091	[wan] IPCP: SendTerminateReq #4
Aug 12 13:59:51	ppp	19091	[wan] IPCP: state change Opened --> Closing
Aug 12 13:59:51	ppp	19091	[wan] IPCP: Close event
Aug 12 13:59:51	ppp	19091	[wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Aug 12 13:59:51	ppp	19091	[wan_link0] Link: Leave bundle "wan"
Aug 12 13:59:51	ppp	19091	[wan_link0] LCP: state change Opened --> Starting
Aug 12 13:59:51	ppp	19091	[wan_link0] LCP: Down event
Aug 12 13:59:51	ppp	19091	[wan_link0] Link: DOWN event
Aug 12 13:59:51	ppp	19091	[wan_link0] PPPoE: connection closed
Aug 12 13:59:33	ppp	19091	[wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:53:00	sshguard	18557	Now monitoring attacks.

stephenw10

Anything different/additonal in the ppp log?

diyhouse

@diyhouse Stephen,.. just a thought,.. do I need / require to tweak any settings in the advanced page of the WAN PPPoE connection,.. currently everything is blank ( none checked ) in the advanced page

diyhouse

@diyhouseThis is the prelude to the reboot,...

Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: LayerUp
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: auth: peer wants CHAP, I want nothing
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: state change Ack-Sent --> Opened
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x53da0584
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: rec'd Configure Ack #4 (Ack-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x53da0584
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: SendConfigReq #4
Aug 12 14:00:06	ppp	19091	[wan_link0] PROTOCOMP
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: rec'd Configure Reject #3 (Ack-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: state change Req-Sent --> Ack-Sent
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x4fd3fb4b
Aug 12 14:00:06	ppp	19091	[wan_link0] AUTHPROTO CHAP MD5
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: SendConfigAck #58
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x4fd3fb4b
Aug 12 14:00:06	ppp	19091	[wan_link0] AUTHPROTO CHAP MD5
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: rec'd Configure Request #58 (Req-Sent)
Aug 12 14:00:06	ppp	19091	[wan_link0] MAGICNUM 0x53da0584
Aug 12 14:00:06	ppp	19091	[wan_link0] MRU 1492
Aug 12 14:00:06	ppp	19091	[wan_link0] PROTOCOMP
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: SendConfigReq #3
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: state change Starting --> Req-Sent
Aug 12 14:00:06	ppp	19091	[wan_link0] LCP: Up event
Aug 12 14:00:06	ppp	19091	[wan_link0] Link: UP event
Aug 12 14:00:06	ppp	19091	[wan_link0] PPPoE: connection successful
Aug 12 14:00:06	ppp	19091	PPPoE: rec'd ACNAME "acc-aln2.tbs"
Aug 12 14:00:06	ppp	19091	[wan_link0] PPPoE: Connecting to ''
Aug 12 14:00:06	ppp	19091	[wan_link0] Link: reconnection attempt 2
Aug 12 14:00:05	ppp	19091	[wan_link0] Link: reconnection attempt 2 in 1 seconds
Aug 12 14:00:05	ppp	19091	[wan_link0] LCP: Down event
Aug 12 14:00:05	ppp	19091	[wan_link0] Link: DOWN event
Aug 12 14:00:05	ppp	19091	[wan_link0] PPPoE connection timeout after 9 seconds
Aug 12 13:59:56	ppp	19091	[wan_link0] PPPoE: Connecting to ''
Aug 12 13:59:56	ppp	19091	[wan_link0] Link: reconnection attempt 1
Aug 12 13:59:52	ppp	19091	[wan_link0] Link: reconnection attempt 1 in 4 seconds
Aug 12 13:59:52	ppp	19091	[wan_link0] LCP: LayerDown
Aug 12 13:59:52	ppp	19091	[wan] Bundle: Last link has gone, no links for bw-manage defined
Aug 12 13:59:52	ppp	19091	[wan] IPCP: state change Closing --> Initial
Aug 12 13:59:52	ppp	19091	[wan] Bundle: No NCPs left. Closing links...
Aug 12 13:59:52	ppp	19091	[wan] IPCP: LayerFinish
Aug 12 13:59:52	ppp	19091	[wan] IPCP: Down event
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Set description "1_WAN"
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Rename interface pppoe0 to pppoe0
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Down event
Aug 12 13:59:52	ppp	19091	[wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
Aug 12 13:59:51	ppp	19091	[wan] IPCP: LayerDown
Aug 12 13:59:51	ppp	19091	[wan] IPCP: SendTerminateReq #4
Aug 12 13:59:51	ppp	19091	[wan] IPCP: state change Opened --> Closing
Aug 12 13:59:51	ppp	19091	[wan] IPCP: Close event
Aug 12 13:59:51	ppp	19091	[wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Aug 12 13:59:51	ppp	19091	[wan_link0] Link: Leave bundle "wan"
Aug 12 13:59:51	ppp	19091	[wan_link0] LCP: state change Opened --> Starting
Aug 12 13:59:51	ppp	19091	[wan_link0] LCP: Down event
Aug 12 13:59:51	ppp	19091	[wan_link0] Link: DOWN event
Aug 12 13:59:51	ppp	19091	[wan_link0] PPPoE: connection closed
Aug 12 13:59:33	ppp	19091	[wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:49:22	ppp	19091	[wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:28:00	ppp	19091	[wan_link0] LCP: no reply to 2 echo request(s)
Aug 12 13:27:50	ppp	19091	[wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:27:10	ppp	19091	[wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:09:02	ppp	19091	[wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 12 13:09:00	ppp	19091	[wan] IFACE: Add description "1_WAN"
Aug 12 13:09:00	ppp	19091	[wan] IFACE: Rename interface ng0 to pppoe0
Aug 12 13:09:00	ppp	19091	[wan] IFACE: Up event
Aug 12 13:08:59	ppp	19091	[wan] 86.146.217.76 -> 172.16.12.102

stephenw10

@diyhouse said in WAN periodically Rebooting:

Aug 12 13:59:51 ppp 19091 [wan_link0] Link: DOWN event
Aug 12 13:59:51 ppp 19091 [wan_link0] PPPoE: connection closed
Aug 12 13:59:33 ppp 19091 [wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:49:22 ppp 19091 [wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:28:00 ppp 19091 [wan_link0] LCP: no reply to 2 echo request(s)
Aug 12 13:27:50 ppp 19091 [wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:27:10 ppp 19091 [wan_link0] LCP: no reply to 1 echo request(s)
Aug 12 13:09:02 ppp 19091 [wan_link0] rec'd unexpected protocol IPV6CP, rejecting
Aug 12 13:09:00 ppp 19091 [wan] IFACE: Add description "1_WAN"
Aug 12 13:09:00 ppp 19091 [wan] IFACE: Rename interface ng0 to pppoe0
Aug 12 13:09:00 ppp 19091 [wan] IFACE: Up event

Huh that's interesting. I wonder if it's counting those 5 alerts as enough to reconnect even though they are not consecutive.

Though it doesn't show the LCP: peer not responding to echo requests message that would normally indicate it being triggered. And the value there should be a max time of 60s which would never be reached.

No you should not need any settings in the advanced options.

If you look in /var/etc/mpd_wan.conf you will see the generated conf file used to connect. It's possible to make a custom conf file by copying that to /conf and then editing it there. The mpd daemon will use a file there in preference.

diyhouse

@stephenw10 this is my 'mpd_wan.conf' file.. credentials removed,..
what do you suggest I modify,..
If I update this file how do I force it to be used,.. ie how do I force a 'reload'

I see these two values,.. set link keep-alive 10 60,.. what do you suggest,. 100 300,
ie 5 mins....
Can I not just edit the primary file,.. or does this get overwritten..

2.7.2-RELEASE][mark@pfSense.mylocal]/var/etc: cat mpd_wan.conf 
startup:
	# configure the console
	set console close
	# configure the web server
	set web close

default:
pppoeclient:
	create bundle static wan
	set bundle period 6
	set bundle lowat 0
	set bundle hiwat 0
	set bundle min-con 3
	set bundle min-dis 6
	set bundle enable bw-manage
	
	set iface name pppoe0
	set iface description "1_WAN"
	set iface disable on-demand
	set iface idle 0
	set iface enable tcpmssfix
	set iface up-script /usr/local/sbin/ppp-linkup
	set iface down-script /usr/local/sbin/ppp-linkdown
	set ipcp ranges 0.0.0.0/0 0.0.0.0/0
	set ipcp enable req-pri-dns
	set ipcp enable req-sec-dns
	#log -bund -ccp -chat -iface -ipcp -lcp -link

	create link static wan_link0 pppoe
	set link action bundle wan
	set link disable multilink
	set link keep-alive 10 60
	set link max-redial 0
	set link disable chap pap
	set link accept chap pap eap
	set link disable incoming
	set link mtu 1492
	set auth authname "account"
	set auth password passwd
	set pppoe service ""
	set pppoe iface igb0
	open

stephenw10

Indeed the file in /var/etc gets overwritten at boot or whenever the config is rebuilt so you have to copy it to /conf to make permanent changes to it.

I would start by setting link keep-alive to something just larger to see if that has any effect so maybe: 20 120

diyhouse

@stephenw10
Tx,..
Ok,.. just trying to copy file over to /conf... but insufficient privs,.. sudo does not work...
and from what I can read I have to use the shell window offered from the console,.. with a direct login at the h/w,.. or have I missed something..?

stephenw10

You can do it from the gui Diag > Command Prompt.

Then edit it from Diag > Edit File

diyhouse

@diyhouse well bit the bullet,.. suffered in 40C loft ambient
File copied ,. and edited with a bit of vi... followed by a reboot..
Now I wait for next event..
Thanks

stephenw10

Ha, hottest day of the year, clearly the best day for it.

For reference though you can do it from the GUI or by logging in as admin.

diyhouse

@stephenw10 Yep it was hot,.. But file edited,.. I did try ssh'ing into pfsense as 'admin',..
but this did not work,.
also how do I reload setting and force the new setting into play...?
( all good so far 20 mins in,.. no errors on PPP,.. )
Tx

stephenw10

Re-saving the WAN interface should do it.