Need help to find out the crash cause! "Address family for hostname not supported"
-
Hi,
It was an ordinary day and there was nothing wrong with my firewall.
But all of a sudden, all my network clients lost connection with the firewall. They were not getting any local ip, gateway was down and firewall was unreachable.I tried to check the firewall console by means of IPMI and this was the prompt I saw. I could not get a screenshot but I think this was coming from syslogd.
"Address family for hostname not supported"
This prompt was being spammed and I could not interact with the console at all. Ctrl + C, Enter were not registering. I had to forcibly restart the firewall.When I checked later, the system log was full of below messages during that down time.
Aug 5 20:27:54 pfSense ppp[46169]: [wan_link0] LCP: SendTerminateReq #16 Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: state change Stopping --> Stopped Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: LayerFinish Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] PPPoE: connection closed Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: state change Stopped --> Starting Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: LayerStart Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 1 in 1 seconds Aug 5 20:27:57 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 1 Aug 5 20:27:57 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to '' Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] PPPoE connection timeout after 9 seconds Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 2 in 4 seconds Aug 5 20:28:10 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 2 Aug 5 20:28:10 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to '' Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] PPPoE connection timeout after 9 seconds Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 3 in 3 seconds Aug 5 20:28:22 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 3 Aug 5 20:28:22 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to '' Aug 5 20:28:31 pfSense ppp[46169]: [wan_link0] PPPoE connection timeout after 9 seconds Aug 5 20:28:31 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:28:31 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:28:31 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 4 in 1 seconds Aug 5 20:28:32 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 4 Aug 5 20:28:32 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to '' Aug 5 20:28:41 pfSense ppp[46169]: [wan_link0] PPPoE connection timeout after 9 seconds Aug 5 20:28:41 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:28:41 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:28:41 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 5 in 2 seconds Aug 5 20:28:43 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 5 Aug 5 20:28:43 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to '' Aug 5 20:28:52 pfSense ppp[46169]: [wan_link0] PPPoE connection timeout after 9 seconds
Any help determining the cause of this issue?
-
Looks like your PPPoE connection went down and is failing to reconnect.
Did you reboot? Did it come back up? Do you see the address family error in the logs?
What pfSense version is that?
Steve
-
@stephenw10
It is pfsense plus 24.03.
After force restarting, everything is back to normal.
I did not see the address family error in the system logs.
Even if my WAN pppoe went down, it should not take my whole network with it.And the pfsense console was unresponsive so I believe something crashed.
-
I agree it should not. Something should have been logged though. Unless the logging process itself stopped.
-
@stephenw10 Any other useful logs that I can find?
-
Well what was logged just before it stopped responding?
-
@stephenw10
Nothing alarming.Aug 5 20:24:26 pfSense php-fpm[35753]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:24:26 pfSense php-fpm[35753]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use OVPN_S2S_VPNV4. Aug 5 20:25:00 pfSense sshguard[2009]: Exiting on signal. Aug 5 20:25:00 pfSense sshguard[34682]: Now monitoring attacks. Aug 5 20:26:00 pfSense sshguard[34682]: Exiting on signal. Aug 5 20:26:00 pfSense sshguard[39502]: Now monitoring attacks. Aug 5 20:26:29 pfSense rc.gateway_alarm[59809]: >>> Gateway alarm: OVPN_S2S_VPNV4 (Addr:10.25.25.2 Alarm:0 RTT:432.143ms RTTsd:266.441ms Loss:0%) Aug 5 20:26:29 pfSense check_reload_status[635]: updating dyndns OVPN_S2S_VPNV4 Aug 5 20:26:29 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:26:29 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:26:29 pfSense check_reload_status[635]: Reloading filter Aug 5 20:26:30 pfSense php-fpm[35753]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:26:30 pfSense php-fpm[35753]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use OVPN_S2S_VPNV4. Aug 5 20:26:52 pfSense rc.gateway_alarm[70947]: >>> Gateway alarm: WAN_PPPOE (Addr:10.98.238.224 Alarm:1 RTT:20.071ms RTTsd:120.021ms Loss:22%) Aug 5 20:26:52 pfSense check_reload_status[635]: updating dyndns WAN_PPPOE Aug 5 20:26:52 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:26:52 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:26:52 pfSense check_reload_status[635]: Reloading filter Aug 5 20:26:52 pfSense rc.gateway_alarm[73517]: >>> Gateway alarm: OVPN_S2S_VPNV4 (Addr:10.25.25.2 Alarm:1 RTT:375.366ms RTTsd:253.213ms Loss:22%) Aug 5 20:26:52 pfSense check_reload_status[635]: updating dyndns OVPN_S2S_VPNV4 Aug 5 20:26:52 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:26:52 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:26:52 pfSense check_reload_status[635]: Reloading filter Aug 5 20:26:53 pfSense php-fpm[23123]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:26:53 pfSense php-fpm[23123]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use WAN_PPPOE. Aug 5 20:26:53 pfSense php-fpm[47625]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:26:53 pfSense php-fpm[47625]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use OVPN_S2S_VPNV4. Aug 5 20:27:04 pfSense ppp[46169]: [wan_link0] LCP: no reply to 1 echo request(s) Aug 5 20:27:14 pfSense ppp[46169]: [wan_link0] LCP: no reply to 2 echo request(s) Aug 5 20:27:20 pfSense rc.gateway_alarm[28745]: >>> Gateway alarm: MODEM_DHCP (Addr:192.168.0.1 Alarm:1 RTT:11.614ms RTTsd:102.030ms Loss:21%) Aug 5 20:27:20 pfSense check_reload_status[635]: updating dyndns MODEM_DHCP Aug 5 20:27:20 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:27:20 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:27:20 pfSense check_reload_status[635]: Reloading filter Aug 5 20:27:21 pfSense php-fpm[35753]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:27:21 pfSense php-fpm[35753]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use MODEM_DHCP. Aug 5 20:27:24 pfSense ppp[46169]: [wan_link0] LCP: no reply to 3 echo request(s) Aug 5 20:27:27 pfSense php-fpm[90794]: /rc.dyndns.update: Curl error occurred: Could not resolve host: api.cloudflare.com Aug 5 20:27:34 pfSense ppp[46169]: [wan_link0] LCP: no reply to 4 echo request(s) Aug 5 20:27:36 pfSense rc.gateway_alarm[80033]: >>> Gateway alarm: OVPN_S2S_VPNV4 (Addr:10.25.25.2 Alarm:1 RTT:641.311ms RTTsd:354.537ms Loss:97%) Aug 5 20:27:36 pfSense check_reload_status[635]: updating dyndns OVPN_S2S_VPNV4 Aug 5 20:27:36 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:27:36 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:27:36 pfSense check_reload_status[635]: Reloading filter Aug 5 20:27:37 pfSense php-fpm[3237]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:27:37 pfSense php-fpm[3237]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use OVPN_S2S_VPNV4. Aug 5 20:27:37 pfSense rc.gateway_alarm[21737]: >>> Gateway alarm: WAN_PPPOE (Addr:10.98.238.224 Alarm:1 RTT:1141.616ms RTTsd:0ms Loss:99%) Aug 5 20:27:37 pfSense check_reload_status[635]: updating dyndns WAN_PPPOE Aug 5 20:27:37 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:27:37 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:27:37 pfSense check_reload_status[635]: Reloading filter Aug 5 20:27:38 pfSense php-fpm[3237]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:27:38 pfSense php-fpm[3237]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use WAN_PPPOE. Aug 5 20:27:44 pfSense ppp[46169]: [wan_link0] LCP: no reply to 5 echo request(s) Aug 5 20:27:44 pfSense ppp[46169]: [wan_link0] LCP: peer not responding to echo requests Aug 5 20:27:44 pfSense ppp[46169]: [wan_link0] LCP: state change Opened --> Stopping Aug 5 20:27:44 pfSense ppp[46169]: [wan_link0] Link: Leave bundle "wan" Aug 5 20:27:44 pfSense ppp[46169]: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Aug 5 20:27:44 pfSense ppp[46169]: [wan] IPCP: Close event Aug 5 20:27:44 pfSense ppp[46169]: [wan] IPCP: state change Opened --> Closing Aug 5 20:27:44 pfSense ppp[46169]: [wan] IPCP: SendTerminateReq #15 Aug 5 20:27:44 pfSense ppp[46169]: [wan] IPCP: LayerDown Aug 5 20:27:44 pfSense php-cgi[34956]: rc.kill_states: rc.kill_states: Removing states for IP "Redacted"/32 Aug 5 20:27:47 pfSense rc.gateway_alarm[37869]: >>> Gateway alarm: OVPN_S2S_VPNV4 (Addr:10.25.25.2 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%) Aug 5 20:27:47 pfSense check_reload_status[635]: updating dyndns OVPN_S2S_VPNV4 Aug 5 20:27:47 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:27:47 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:27:47 pfSense check_reload_status[635]: Reloading filter Aug 5 20:27:47 pfSense rc.gateway_alarm[40409]: >>> Gateway alarm: WAN_PPPOE (Addr:10.98.238.224 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%) Aug 5 20:27:47 pfSense check_reload_status[635]: updating dyndns WAN_PPPOE Aug 5 20:27:47 pfSense check_reload_status[635]: Restarting IPsec tunnels Aug 5 20:27:47 pfSense check_reload_status[635]: Restarting OpenVPN tunnels/interfaces Aug 5 20:27:47 pfSense check_reload_status[635]: Reloading filter Aug 5 20:27:48 pfSense php-fpm[3237]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:27:48 pfSense php-fpm[3237]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use OVPN_S2S_VPNV4. Aug 5 20:27:48 pfSense php-cgi[34956]: rc.kill_states: rc.kill_states: Removing states for interface pppoe0 Aug 5 20:27:48 pfSense check_reload_status[635]: Rewriting resolv.conf Aug 5 20:27:48 pfSense ppp[46169]: [wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address Aug 5 20:27:48 pfSense ppp[46169]: [wan] IFACE: Down event Aug 5 20:27:48 pfSense ppp[46169]: [wan] IFACE: Rename interface pppoe0 to pppoe0 Aug 5 20:27:48 pfSense ppp[46169]: [wan] IFACE: Set description "WAN" Aug 5 20:27:48 pfSense avahi-daemon[50228]: Withdrawing workstation service for pppoe0. Aug 5 20:27:48 pfSense ppp[46169]: [wan] IPCP: Down event Aug 5 20:27:48 pfSense ppp[46169]: [wan] IPCP: LayerFinish Aug 5 20:27:48 pfSense ppp[46169]: [wan] Bundle: No NCPs left. Closing links... Aug 5 20:27:48 pfSense ppp[46169]: [wan] IPCP: state change Closing --> Initial Aug 5 20:27:48 pfSense ppp[46169]: [wan] Bundle: Last link has gone, no links for bw-manage defined Aug 5 20:27:48 pfSense ppp[46169]: [wan_link0] LCP: SendTerminateReq #15 Aug 5 20:27:48 pfSense ppp[46169]: [wan_link0] LCP: LayerDown Aug 5 20:27:51 pfSense php-fpm[62262]: /rc.dyndns.update: Curl error occurred: Could not resolve host: api.cloudflare.com Aug 5 20:27:51 pfSense php-fpm[35753]: /rc.dyndns.update: Dynamic DNS cloudflare (@.mydomain.org): IP address could not be extracted from Check IP Service Aug 5 20:27:51 pfSense php-fpm[35753]: /rc.dyndns.update: Dynamic DNS (@.mydomain.org) There was an error trying to determine the public IP for interface - wan (pppoe0 ). Aug 5 20:27:52 pfSense php-fpm[62262]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Aug 5 20:27:52 pfSense php-fpm[62262]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use WAN_PPPOE. Aug 5 20:27:54 pfSense ppp[46169]: [wan_link0] LCP: SendTerminateReq #16 Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: state change Stopping --> Stopped Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: LayerFinish Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] PPPoE: connection closed Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: state change Stopped --> Starting Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] LCP: LayerStart Aug 5 20:27:56 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 1 in 1 seconds Aug 5 20:27:57 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 1 Aug 5 20:27:57 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to '' Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] PPPoE connection timeout after 9 seconds Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:28:06 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 2 in 4 seconds Aug 5 20:28:10 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 2 Aug 5 20:28:10 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to '' Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] PPPoE connection timeout after 9 seconds Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] Link: DOWN event Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] LCP: Down event Aug 5 20:28:19 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 3 in 3 seconds Aug 5 20:28:22 pfSense ppp[46169]: [wan_link0] Link: reconnection attempt 3 Aug 5 20:28:22 pfSense ppp[46169]: [wan_link0] PPPoE: Connecting to ''
However, I don't know if it might be related or not but I had graylog setup on another machine with pfsense sending the logs to it. And my graylog instance was offline for a longtime. The only syslog error that I could think of was this. I may be thinking too much but maybe due to these frequent errors pfsense ran out of memory?
-
Unlikely it ran out of memory, I'd expect to see a bunch of logs entries complaining about it. But you can check the historical RAM usage in Status > Monitoring.
It looks like you have something set to use IPv6 in that OpenVPN setup and there is no IPv6 on it. Dual gateways on an assigned interface perhaps?
'Address family for hostname not supported' means something is trying to use a hostname that resolves to only IPv4 (or only IPv6) in a place that requires the other address type.
For example an alias with a hostname in it that resolves as IPv4 only used in an IPv6 firewall rule.
I would expect that to be logged when the filter reloads though. Try going to Status > Filter Reload manually and make sure it loads cleanly.
-
Very weird,
Openvpn server is set to ipv4 only and there are only three gateways.
ipv6 is totally disabled on the firewall.memory also looks okay
-
I this setting in the OpenVPN settings:
Try setting that to IPv4 only if you don;t have an IPv6 address there and then re-check the logs when it connects.
-
@stephenw10 yep that one already set to ipv4 only.
-
Hmm, maybe you have static routes to an alias via the tunnel gateway?
-
@stephenw10 nope, there is no static routes defined.