Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    pfSense not responding to network after ISP outage

    Scheduled Pinned Locked Moved General pfSense Questions
    11 Posts 3 Posters 522 Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • J
      jamie
      last edited by

      My ISP had an outage last night, one of their gateways stopped accepting PPPoE connections and it looks like I got impacted by it.

      This morning I have no internet, pfSense web UI not loading and not responding to pings on it's LAN interface. I plugged a serial cable in and the system was at least alive. It could ping itself on it's LAN IP, but couldn't ping anything with a static IP on my LAN, nor anything on the internet. Had a look through /var/log/system.log and there's a lot of PPPoE reconnection attempts through the night, which is my first clue to check my ISP status page and discovered about one of their gateways. But also during the night, PPPoE seems to come back up and according to the logs the system seems happy.

      What's odd though is why then I discover this morning it's not passing traffic. After not managing to get very far working out what went wrong I initiated a reboot over serial, it made the shutdown beep and logged a couple of messages to the console but then nothing more happened and it didn't reboot. Had to hard power cycle it.

      I'd like to work out what went wrong, but not entirely sure where to start, pointers would be much appreciated please.

      As a starting point, this is the last part of /var/log/system.log from when it looks like the PPPoE connection comes back up until I attempt to reboot and eventually power cycle it. IPs removed.

      Oct 23 02:52:48 fw ppp[16230]: [wan_link0] LCP: LayerUp
Oct 23 02:52:48 fw ppp[16230]: [wan_link0] CHAP: rec'd CHALLENGE #2 len: 29
Oct 23 02:52:48 fw ppp[16230]: [wan_link0]   Name: "AAA"
Oct 23 02:52:48 fw ppp[16230]: [wan_link0] CHAP: Using authname "AAA"
Oct 23 02:52:48 fw ppp[16230]: [wan_link0] CHAP: sending RESPONSE #2 len: 38
Oct 23 02:52:48 fw ppp[16230]: [wan_link0] CHAP: rec'd SUCCESS #2 len: 4
Oct 23 02:52:48 fw ppp[16230]: [wan_link0] LCP: authorization successful
Oct 23 02:52:48 fw ppp[16230]: [wan_link0] Link: Matched action 'bundle "wan" ""'
Oct 23 02:52:48 fw ppp[16230]: [wan_link0] Link: Join bundle "wan"
Oct 23 02:52:48 fw ppp[16230]: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: Open event
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: state change Initial --> Starting
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: LayerStart
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: Open event
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: state change Initial --> Starting
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: LayerStart
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: Up event
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: state change Starting --> Req-Sent
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: SendConfigReq #17
Oct 23 02:52:48 fw ppp[16230]: [wan]   IPADDR 0.0.0.0
Oct 23 02:52:48 fw ppp[16230]: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: Up event
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: state change Starting --> Req-Sent
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: SendConfigReq #9
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: rec'd Configure Request #1 (Req-Sent)
Oct 23 02:52:48 fw ppp[16230]: [wan]   IPADDR XGWIPX
Oct 23 02:52:48 fw ppp[16230]: [wan]     XGWIPX is OK
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: SendConfigAck #1
Oct 23 02:52:48 fw ppp[16230]: [wan]   IPADDR XGWIPX
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: state change Req-Sent --> Ack-Sent
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: rec'd Configure Request #1 (Req-Sent)
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: SendConfigAck #1
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: state change Req-Sent --> Ack-Sent
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: rec'd Configure Reject #17 (Ack-Sent)
Oct 23 02:52:48 fw ppp[16230]: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Oct 23 02:52:48 fw ppp[16230]: [wan] IPCP: SendConfigReq #18
Oct 23 02:52:48 fw ppp[16230]: [wan]   IPADDR 0.0.0.0
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: rec'd Configure Ack #9 (Ack-Sent)
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: state change Ack-Sent --> Opened
Oct 23 02:52:48 fw ppp[16230]: [wan] IPV6CP: LayerUp
Oct 23 02:52:48 fw ppp[16230]: [wan]   XV6X -> XV6X
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw kernel: ng_pppoe[14]: no matching session
Oct 23 02:52:49 fw php[53482]: /usr/local/sbin/ppp-ipv6: Accept router advertisements on interface pppoe0 
Oct 23 02:52:49 fw php[53482]: /usr/local/sbin/ppp-ipv6: Starting DHCP6 client for interfaces pppoe0 in DHCP6 without RA mode
Oct 23 02:52:49 fw php[53482]: /usr/local/sbin/ppp-ipv6: Starting rtsold process on wan(pppoe0)
Oct 23 02:52:51 fw check_reload_status[430]: rc.newwanipv6 starting pppoe0
Oct 23 02:52:51 fw ppp[16230]: [wan] IFACE: Up event
Oct 23 02:52:51 fw ppp[16230]: [wan] IFACE: Rename interface ng0 to pppoe0
Oct 23 02:52:51 fw ppp[16230]: [wan] IFACE: Add description "WAN"
Oct 23 02:52:51 fw ppp[16230]: [wan] IPCP: rec'd Configure Nak #18 (Ack-Sent)
Oct 23 02:52:51 fw ppp[16230]: [wan]   IPADDR XWANIPX
Oct 23 02:52:51 fw ppp[16230]: [wan]     XWANIPX is OK
Oct 23 02:52:51 fw ppp[16230]: [wan] IPCP: SendConfigReq #19
Oct 23 02:52:51 fw ppp[16230]: [wan]   IPADDR XWANIPX
Oct 23 02:52:51 fw ppp[16230]: [wan] IPCP: rec'd Configure Ack #19 (Ack-Sent)
Oct 23 02:52:51 fw ppp[16230]: [wan]   IPADDR XWANIPX
Oct 23 02:52:51 fw ppp[16230]: [wan] IPCP: state change Ack-Sent --> Opened
Oct 23 02:52:51 fw ppp[16230]: [wan] IPCP: LayerUp
Oct 23 02:52:51 fw ppp[16230]: [wan]   XWANIPX -> XGWIPX
Oct 23 02:52:51 fw check_reload_status[430]: rc.newwanip starting pppoe0
Oct 23 02:52:52 fw php-fpm[68321]: /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0.
Oct 23 02:52:52 fw php-fpm[68321]: /rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface WAN [wan].
Oct 23 02:52:52 fw php-fpm[68321]: /rc.newwanip: rc.newwanip: Info: starting on pppoe0.
Oct 23 02:52:52 fw php-fpm[68321]: /rc.newwanip: rc.newwanip: on (IP address: XWANIPX) (interface: WAN[wan]) (real interface: pppoe0).
Oct 23 02:52:59 fw php-fpm[68321]: /rc.newwanip: Default gateway setting Interface WAN_PPPOE Gateway as default.
Oct 23 02:53:00 fw sshguard[73849]: Exiting on signal.
Oct 23 02:53:00 fw sshguard[26899]: Now monitoring attacks.
Oct 23 02:53:00 fw rtsold[31644]: Received RA specifying route XV6X for interface wan(pppoe0)
Oct 23 02:53:00 fw rtsold[32795]: RTSOLD Lock in place - sending SIGHUP to dhcp6c
Oct 23 02:53:00 fw php-fpm[68321]: /rc.newwanip: Forcefully reloading IPsec
Oct 23 02:53:00 fw check_reload_status[430]: Reloading filter
Oct 23 02:53:01 fw php-fpm[398]: /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0.
Oct 23 02:53:01 fw php-fpm[398]: /rc.newwanipv6: rc.newwanipv6: on (IP address: XV6X) (interface: wan) (real interface: pppoe0).
Oct 23 02:53:01 fw php-fpm[68321]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Oct 23 02:53:02 fw php-fpm[68321]: OpenVPN terminate old pid: 68625
Oct 23 02:53:04 fw kernel: ovpns1: link state changed to DOWN
Oct 23 02:53:04 fw check_reload_status[430]: Reloading filter
Oct 23 02:53:05 fw check_reload_status[430]: Reloading filter
Oct 23 02:53:05 fw php-fpm[398]: /rc.newwanipv6: Ignoring IPsec reload since there are no tunnels on interface wan
Oct 23 02:53:05 fw php-fpm[398]: /rc.newwanipv6: Resyncing OpenVPN instances for interface WAN.
Oct 23 02:53:05 fw php-fpm[398]: /rc.newwanipv6: Creating rrd update script
Oct 23 02:53:05 fw php-fpm[68321]: OpenVPN PID written: 91961
Oct 23 02:53:05 fw php-fpm[398]: /rc.newwanipv6: pfSense package system has detected an IP change or dynamic WAN reconnection -  -> XV6X - Restarting packages.
Oct 23 02:53:05 fw kernel: ovpns1: link state changed to UP
Oct 23 02:53:05 fw check_reload_status[430]: Starting packages
Oct 23 02:53:05 fw php-fpm[68321]: /rc.newwanip: Creating rrd update script
Oct 23 02:53:05 fw check_reload_status[430]: rc.newwanip starting ovpns1
Oct 23 02:53:06 fw php-fpm[399]: /rc.start_packages: Restarting/Starting all packages.
Oct 23 02:53:06 fw php-fpm[92649]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1.
Oct 23 02:53:06 fw php-fpm[92649]: /rc.newwanip: rc.newwanip: on (IP address: 10.6.100.1) (interface: []) (real interface: ovpns1).
Oct 23 02:53:06 fw php-fpm[92649]: /rc.newwanip: rc.newwanip called with empty interface.
Oct 23 02:53:06 fw php-fpm[92649]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection -  ->  10.6.100.1 - Restarting packages.
Oct 23 02:53:06 fw check_reload_status[430]: Starting packages
Oct 23 02:53:07 fw php-fpm[68321]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - XWANIPX ->  XWANIPX - Restarting packages.
Oct 23 02:53:07 fw check_reload_status[430]: Starting packages
Oct 23 02:53:07 fw php-fpm[92649]: /rc.start_packages: Restarting/Starting all packages.
Oct 23 02:53:08 fw php-fpm[399]: /rc.start_packages: Restarting/Starting all packages.
Oct 23 02:59:00 fw sshguard[26899]: Exiting on signal.
Oct 23 02:59:00 fw sshguard[87972]: Now monitoring attacks.
Oct 23 03:28:00 fw sshguard[87972]: Exiting on signal.
Oct 23 03:28:00 fw sshguard[1055]: Now monitoring attacks.
Oct 23 03:35:00 fw sshguard[1055]: Exiting on signal.
Oct 23 03:35:00 fw sshguard[18095]: Now monitoring attacks.
Oct 23 03:56:00 fw sshguard[18095]: Exiting on signal.
Oct 23 03:56:00 fw sshguard[40983]: Now monitoring attacks.
Oct 23 04:09:00 fw sshguard[40983]: Exiting on signal.
Oct 23 04:09:00 fw sshguard[15970]: Now monitoring attacks.
Oct 23 04:21:00 fw sshguard[15970]: Exiting on signal.
Oct 23 04:21:00 fw sshguard[18277]: Now monitoring attacks.
Oct 23 04:25:00 fw sshguard[18277]: Exiting on signal.
Oct 23 04:25:00 fw sshguard[61886]: Now monitoring attacks.
Oct 23 04:54:00 fw sshguard[61886]: Exiting on signal.
Oct 23 04:54:00 fw sshguard[71579]: Now monitoring attacks.
Oct 23 05:07:00 fw sshguard[71579]: Exiting on signal.
Oct 23 05:07:00 fw sshguard[9209]: Now monitoring attacks.
Oct 23 05:23:00 fw sshguard[9209]: Exiting on signal.
Oct 23 05:23:00 fw sshguard[60578]: Now monitoring attacks.
Oct 23 05:52:00 fw sshguard[60578]: Exiting on signal.
Oct 23 05:52:00 fw sshguard[76264]: Now monitoring attacks.
Oct 23 05:53:00 fw sshguard[76264]: Exiting on signal.
Oct 23 05:53:00 fw sshguard[14063]: Now monitoring attacks.
Oct 23 06:21:00 fw sshguard[14063]: Exiting on signal.
Oct 23 06:21:00 fw sshguard[52376]: Now monitoring attacks.
Oct 23 06:39:00 fw sshguard[52376]: Exiting on signal.
Oct 23 06:39:00 fw sshguard[68754]: Now monitoring attacks.
Oct 23 06:51:00 fw sshguard[68754]: Exiting on signal.
Oct 23 06:51:00 fw sshguard[98477]: Now monitoring attacks.
Oct 23 07:25:00 fw sshguard[98477]: Exiting on signal.
Oct 23 07:25:00 fw sshguard[51561]: Now monitoring attacks.
Oct 23 08:01:00 fw sshguard[51561]: Exiting on signal.
Oct 23 08:01:00 fw sshguard[11229]: Now monitoring attacks.
Oct 23 08:08:00 fw sshguard[11229]: Exiting on signal.
Oct 23 08:08:00 fw sshguard[32945]: Now monitoring attacks.
Oct 23 08:11:00 fw sshguard[32945]: Exiting on signal.
Oct 23 08:11:00 fw sshguard[43107]: Now monitoring attacks.
Oct 23 08:21:39 fw login[97847]: login on ttyu0 as root
Oct 23 08:21:46 fw login[2606]: login on ttyu0 as root
Oct 23 08:21:55 fw login[3768]: login on ttyu0 as root
Oct 23 08:22:30 fw login[40698]: login on ttyu0 as root
Oct 23 08:25:00 fw sshguard[43107]: Exiting on signal.
Oct 23 08:25:00 fw sshguard[43462]: Now monitoring attacks.
Oct 23 08:34:03 fw php-cgi[75812]: rc.initial.reboot: Stopping all packages.
Oct 23 08:34:06 fw reboot[83072]: rebooted by root
Oct 23 08:34:06 fw syslogd: exiting on signal 15
Oct 23 08:37:34 fw syslogd: kernel boot file is /boot/kernel/kernel
Oct 23 08:37:34 fw kernel: ---<<BOOT>>---
      GertjanG 1 Reply Last reply Reply Quote 0
      • GertjanG
        Gertjan @jamie
        last edited by

        @jamie said in pfSense not responding to network after ISP outage:

        beep and logged a couple of messages to the console but then nothing more happened and it didn't reboot.

        That part, on the console access, from initial power up, going trough initial drive detection, and booting from a selected boot drive, and eventually booting pfSense, holds the info about what is happening.
        Can you show it ?

        No "help me" PM's please. Use the forum, the community will thank you.
        Edit : and where are the logs ??

        1 Reply Last reply Reply Quote 0
        • stephenw10S
          stephenw10 Netgate Administrator
          last edited by

          Did it come up with an IP or gateway that conflicted with any other locally defined subnet? You have obscured the IPs so we can't check.

          1 Reply Last reply Reply Quote 0
          • J
            jamie
            last edited by

            @Gertjan please correct me if I'm wrong but are you saying that the log of the next boot contains information on why the shutdown prior failed? I would think that is unlikely.

            @stephenw10 I've only obscured the WAN and upstream gateway IPs, both of which I've just done a find and replace on so anywhere you see XWANX, this is referencing a single IP address, same for XGWX. My WAN IP is static and was not one of my local subnets (which are all 10.x.x.x). Equally my gateway IP was correctly my ISP's gateway (another public address).

            stephenw10S GertjanG 2 Replies Last reply Reply Quote 0
            • stephenw10S
              stephenw10 Netgate Administrator @jamie
              last edited by

              @jamie said in pfSense not responding to network after ISP outage:

              Equally my gateway IP was correctly my ISP's gateway (another public address).

              Ok. I asked because ISPs using PPPoE commonly use a private IP address for the upstream gateway and that cannot conflict

              J 1 Reply Last reply Reply Quote 0
              • J
                jamie @stephenw10
                last edited by

                Ah ok. Mine is a public address, I looked it up and confirmed it's in a range owned by my ISP.

                1 Reply Last reply Reply Quote 0
                • stephenw10S
                  stephenw10 Netgate Administrator
                  last edited by

                  Hmm, what NICs are you using? On LAN especially? Hard to see anything that would prevent it pinging out from the LAN as long as LAN clients still had a valid IP address.

                  J 1 Reply Last reply Reply Quote 0
                  • J
                    jamie @stephenw10
                    last edited by

                    Here I'm using a PC Engines APU2 system with 3x onboard Intel I210 gigabit NICs. Some LAN clients still had their DHCP addresses, others were failing to DHCP as it wasn't getting served. Equally I tried pinging something with a known static IP and nothing.

                    1 Reply Last reply Reply Quote 0
                    • stephenw10S
                      stephenw10 Netgate Administrator
                      last edited by

                      Hmm, shouldn't be an issue with the NICs on that. Unless it's actually a hardware problem.

                      I'd try something low level. Start a continuous ping from the command line to something static on the LAN. Run a packet capture on the LAN interface to make sure it's actually sending packets.

                      1 Reply Last reply Reply Quote 0
                      • GertjanG
                        Gertjan @jamie
                        last edited by

                        @jamie said in pfSense not responding to network after ISP outage:

                        please correct me if I'm wrong but are you saying that the log of the next boot contains information on why the shutdown prior failed? I would think that is unlikely.

                        Correct.
                        But I was asking for this :

                        @jamie said in pfSense not responding to network after ISP outage:

                        nothing more happened and it didn't reboot.

                        For this

                        @jamie said in pfSense not responding to network after ISP outage:

                        ... contains information on why the shutdown prior failed?

                        For this the logs before the failed shutdown can show usefull info.

                        No "help me" PM's please. Use the forum, the community will thank you.
                        Edit : and where are the logs ??

                        J 1 Reply Last reply Reply Quote 0
                        • J
                          jamie @Gertjan
                          last edited by

                          @stephenw10 I had to force reboot at the time to get back online so unfortunately can't try now but if it happens again I'll run a capture and check that. Thanks!

                          @Gertjan I have provided the system.log covering the duration from when I initiated a reboot to the first two lines of the next boot after I had to pull power as the system appeared to have gotten stuck. Is there a different log file which you're interested to see?

                          1 Reply Last reply Reply Quote 0
                          • First post
                            Last post
                          Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.