PPPOE weird Issue
-
Hi Guys,
As stated, I have a very weird issue with my pfsense box (ver 2.4.5-RELEASE (amd64)
built on Tue Mar 24 15:25:50 EDT 2020 FreeBSD 11.3-STABLE)
pfSense HW is Shuttle XH61V with Intel(R) Core(TM) i5-3570TISP Cable -> pfSense box -> Cisco ASA 5505 (working as a switch, nothing else) -> PCsSo, for 2 months pfsense was working without any issues. I mean NONE.
Yesterday all of a sudden internet was down and I saw the PPPOE tries to reconnect unsuccessfuly.
extract from the logs:ppp [wan_link0] PPPoE: Connecting to '' ppp [wan_link0] PPPoE connection timeout after 9 seconds ppp [wan_link0] Link: DOWN event ppp [wan_link0] LCP: Down event ppp [wan_link0] Link: reconnection attempt 5 in 4 seconds ppp [wan_link0] Link: reconnection attempt 5 ppp [wan_link0] PPPoE: Connecting to '' ppp [wan_link0] PPPoE connection timeout after 9 seconds ppp [wan_link0] Link: DOWN event ppp [wan_link0] LCP: Down event ppp [wan_link0] Link: reconnection attempt 6 in 3 seconds ppp [wan_link0] Link: reconnection attempt 6 ppp [wan_link0] PPPoE: Connecting to '' ppp [wan_link0] PPPoE connection timeout after 9 seconds ppp [wan_link0] Link: DOWN event ppp [wan_link0] LCP: Down event ppp [wan_link0] Link: reconnection attempt 7 in 3 seconds ppp [wan] IPCP: Close event ppp [wan] IPV6CP: Close event ppp waiting for process 93148 to die... ppp [wan] Bundle: Shutdown ppp waiting for process 93148 to die... ppp [wan_link0] Link: Shutdown ppp process 93148 terminated ppp web: web is not running ppp [wan] Bundle: Interface ng0 created ppp [wan_link0] Link: OPEN event ppp [wan_link0] LCP: Open event ppp [wan_link0] LCP: state change Initial --> Starting ppp [wan_link0] LCP: LayerStart ppp [wan_link0] PPPoE: Connecting to '' ppp [wan_link0] PPPoE connection timeout after 9 secondsSo I rebooted the box - nothing, same thing.
I connected the cable from my ISP to Cisco ASA - instant connection
Connected the cable to another pfsense box I have (same config. backup/restore) - instant connection
Connected the cable to the 1st pfsense box - no go. Same loop
Factory reset, format/reinstall - same behavior.After that I found out if I do :
tcpdump -i re0 pppoedI get :
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode listening on re0, link-type EN10MB (Ethernet), capture size 262144 bytes 10:15:29.137696 PPPoE PADI [Host-Uniq 0x40B0900500F8FFFF] [Service-Name] 10:15:29.137853 PPPoE PADO [AC-Name "ISPName"] [Service-Name "ISPName\\"] [AC-Cookie 0xF73C16391229D19D7947B4D52239F03119060000] [Host-Uniq 0x40B0900500F8FFFF] 10:15:29.137864 PPPoE PADR [Host-Uniq 0x40B0900500F8FFFF] [AC-Cookie 0xF73C16391229D19D7947B4D52239F03119060000] [AC-Name "ISPName"] [Service-Name] 10:15:29.138239 PPPoE PADS [ses 0x555] [Service-Name "ISPName\\"] [Host-Uniq 0x40B0900500F8FFFF]and the internet is up instantly
pfSense kernel: re0: promiscuous mode enabled ppp: [wan_link0] PPPoE connection timeout after 9 seconds ppp: [wan_link0] Link: DOWN event ppp: [wan_link0] LCP: Down event ppp: [wan_link0] Link: reconnection attempt 10 in 4 seconds ppp: [wan_link0] Link: reconnection attempt 10 ppp: [wan_link0] PPPoE: Connecting to '' ppp: PPPoE: rec'd ACNAME "ISPName" ppp: [wan_link0] PPPoE: connection successful ppp: [wan_link0] Link: UP event ppp: [wan_link0] LCP: Up event ppp: [wan_link0] LCP: state change Starting --> Req-Sent ppp: [wan_link0] LCP: SendConfigReq #1 ppp: [wan_link0] PROTOCOMP ppp: [wan_link0] MRU 1492 ppp: [wan_link0] MAGICNUM 0xfb758008 ppp: [wan_link0] LCP: rec'd Configure Request #1 (Req-Sent) ppp: [wan_link0] MRU 1492 ppp: [wan_link0] AUTHPROTO PAP ppp: [wan_link0] MAGICNUM 0xf6fd6726 ppp: [wan_link0] LCP: SendConfigAck #1 ppp: [wan_link0] MRU 1492 ppp: [wan_link0] AUTHPROTO PAP ppp: [wan_link0] MAGICNUM 0xf6fd6726 ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent ppp: [wan_link0] LCP: SendConfigReq #2 ppp: [wan_link0] PROTOCOMP ppp: [wan_link0] MRU 1492 ppp: [wan_link0] MAGICNUM 0xfb758008 ppp: [wan_link0] LCP: rec'd Configure Reject #2 (Ack-Sent) ppp: [wan_link0] PROTOCOMP ppp: [wan_link0] LCP: SendConfigReq #3 ppp: [wan_link0] MRU 1492 ppp: [wan_link0] MAGICNUM 0xfb758008 ppp: [wan_link0] LCP: state change Ack-Sent --> Opened ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing ppp: [wan_link0] PAP: using authname "myusername" ppp: [wan_link0] PAP: sending REQUEST #1 len: 20 ppp: [wan_link0] LCP: LayerUp ppp: [wan_link0] PAP: rec'd ACK #1 len: 5 ppp: [wan_link0] LCP: authorization successful ppp: [wan_link0] Link: Matched action 'bundle "wan" ""' ppp: [wan_link0] Link: Join bundle "wan" ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps ppp: [wan] IPCP: Open event ppp: [wan] IPCP: state change Initial --> Starting ppp: [wan] IPV6CP: Open event ppp: [wan] IPV6CP: state change Initial --> Starting ppp: [wan] IPV6CP: LayerStart ppp: [wan] IPCP: Up event ppp: [wan] IPCP: state change Starting --> Req-Sent ppp: [wan] IPCP: SendConfigReq #1 ppp: [wan] IPADDR 0.0.0.0 ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid ppp: [wan] IPV6CP: Up event ppp: [wan] IPV6CP: state change Starting --> Req-Sent ppp: [wan] IPV6CP: SendConfigReq #1 ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent) ppp: [wan] IPADDR 85.11.xx ppp: [wan] 85.11.xx is OK ppp: [wan] IPCP: SendConfigAck #1 ppp: [wan] IPADDR 85.11.144.69 ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent) ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid ppp: [wan] IPCP: SendConfigReq #2 ppp: [wan] IPADDR 0.0.0.0 ppp: [wan_link0] LCP: rec'd Protocol Reject #2 (Opened) ppp: [wan_link0] LCP: protocol IPV6CP was rejected ppp: [wan] IPV6CP: protocol was rejected by peer ppp: [wan] IPV6CP: state change Req-Sent --> Stopped ppp: [wan] IPV6CP: LayerFinish ppp: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent) ppp: [wan] IPADDR ISP_GW ppp: [wan] MyIP is OK ppp: [wan] IPCP: SendConfigReq #3 ppp: [wan] IPADDR MyIP ppp: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent) ppp: [wan] IPADDR MyIP ppp: [wan] IPCP: state change Ack-Sent --> Opened ppp: [wan] IPCP: LayerUp ppp: [wan] MyIP -> ISP_GW check_reload_status: rc.newwanip starting pppoe0 ppp: [wan] IFACE: Up event ppp: [wan] IFACE: Rename interface ng0 to pppoe0 php-fpm[348]: /rc.newwanip: rc.newwanip: Info: starting on pppoe0. php-fpm[348]: /rc.newwanip: rc.newwanip: on (IP address: MyIP) (interface: WAN[wan]) (real interface: pppoe0). php-fpm[348]: /rc.newwanip: Default gateway setting Interface WAN_PPPOE Gateway as default. php-fpm[348]: /rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. '' php-fpm[348]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN. php-fpm[348]: /rc.newwanip: Creating rrd update script php-fpm[348]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - MyIP -> ISP_GW - Restarting packages. check_reload_status: Starting packages php-fpm[26760]: /rc.start_packages: Restarting/Starting all packages.So far, so good but this is while the tcpdump is running.
The second I break the command, the pfsense UI becomes unresponsive (even my network resources are unreachable) and the internet is down again.ppp [wan] IFACE: Up event ppp [wan] IFACE: Rename interface ng0 to pppoe0 ppp [wan_link0] LCP: no reply to 1 echo request(s) ppp [wan_link0] LCP: no reply to 2 echo request(s) ppp [wan_link0] LCP: no reply to 3 echo request(s) ppp [wan_link0] LCP: no reply to 4 echo request(s) ppp [wan_link0] LCP: no reply to 5 echo request(s) ppp [wan_link0] LCP: peer not responding to echo requests ppp [wan_link0] LCP: state change Opened --> Stopping ppp [wan_link0] Link: Leave bundle "wan" ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps ppp [wan] IPCP: Close event ppp [wan] IPCP: state change Opened --> Closing ppp [wan] IPCP: SendTerminateReq #4 ppp [wan] IPCP: LayerDown ppp [wan] IFACE: Down event ppp [wan] IFACE: Rename interface pppoe0 to pppoe0 ppp [wan] IPV6CP: Close event ppp [wan] IPV6CP: state change Stopped --> Closed ppp [wan] IPCP: Down event ppp [wan] IPCP: LayerFinish ppp [wan] Bundle: No NCPs left. Closing links... ppp [wan] IPCP: state change Closing --> Initial ppp [wan] IPV6CP: Down event ppp [wan] IPV6CP: state change Closed --> Initial ppp [wan_link0] LCP: SendTerminateReq #4 ppp [wan_link0] LCP: LayerDown ppp [wan_link0] LCP: SendTerminateReq #5 ppp [wan_link0] LCP: state change Stopping --> Stopped ppp [wan_link0] LCP: LayerFinish ppp [wan_link0] PPPoE: connection closed ppp [wan_link0] Link: DOWN event ppp [wan_link0] LCP: Down event ppp [wan_link0] LCP: state change Stopped --> Starting ppp [wan_link0] LCP: LayerStart ppp [wan_link0] Link: reconnection attempt 1 in 3 seconds ppp [wan_link0] Link: reconnection attempt 1 ppp [wan_link0] PPPoE: Connecting to '' ppp [wan_link0] PPPoE connection timeout after 9 secondsIn order to bring back the internet I have to reboot the box, run tcpdump and leave it running.
Any idea what might be causing this? -
So I created a script in /usr/local/etc/rc.d/ containing
/sbin/ifconfig re0 promiscwhich solves the problem. But why all of a sudden pfsense started behaving like this?