Dhclient loosing WAN connection
-
I really don't have much to go on yet but I'm having trouble
looking the WAN connection frequently.The workaround right now which isin't much of a workaround is to
go to Status:Interfaces and do a "release" "renew" on the interface.The interface it a ue0 (Belkin usb -> ethernet) which was working fine under 2.0 so
I don't think the hardware is specially an issue.One of the reason for the switch to 2.1 was to try out the ipv6 support and stop
using the hand crafted scripts to bring up a SiXX tunnel.I did get it working finally but I don't know if the ipv6 tunnel has anything to do
with the wan going down. -
Ok started logging to a remote host.
It looks like apinger is triggering things to go bad?Apr 5 11:49:56 fw0 apinger: ALARM: GW_WAN(66.41.24.1) *** down ***
Apr 5 11:49:56 fw0 php: : Deny router advertisements for interface wan
Apr 5 11:49:56 fw0 dhclient[43256]: dhclient already running, pid: 39759.
Apr 5 11:49:56 fw0 dhclient[43256]: exiting.
Apr 5 11:49:56 fw0 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf ue0 > /tmp/ue0_output > /tmp/ue0_error_output' returned exit code '1', the output was ''
Apr 5 11:49:56 fw0 php: : The command '/sbin/ifconfig gif0 tunnel 213.204.193.2' returned exit code '1', the output was 'ifconfig: 'tunnel' requires 2 arguments'Guess I'll look at apinger
-
Ok so apinger was just telling me when there was a problem.
Further investigation into the logs pointed to check_reload_status.
To test this I killed the process and removed the execute bit from the
program.So far the wan link has remained stable, about 20 hours now.
-
post more logs around the time that happens. By getting rid of check_reload_status you're going to break almost every part of the system.
-
So I let the system run for several days without check_reload_status running and
the wan connection remained up.
But it appears that the controller is a bit unstable
Apr 9 10:39:30 fw0 kernel: ue0: link state changed to DOWN
Apr 9 10:39:30 fw0 kernel: ue0: link state changed to UP
Apr 9 13:43:44 fw0 kernel: ue0: link state changed to DOWN
Apr 9 13:43:44 fw0 kernel: ue0: link state changed to UP
Apr 9 13:43:44 fw0 kernel: ue0: link state changed to DOWN
Apr 9 13:43:44 fw0 kernel: ue0: link state changed to UP
Apr 9 14:43:48 fw0 kernel: ue0: link state changed to DOWN
Apr 9 14:43:48 fw0 kernel: ue0: link state changed to UP
Apr 9 16:31:57 fw0 kernel: ue0: link state changed to DOWN
Apr 9 16:31:57 fw0 kernel: ue0: link state changed to UP
Apr 9 17:24:01 fw0 kernel: ue0: link state changed to DOWN
Apr 9 17:24:01 fw0 kernel: ue0: link state changed to UP
Apr 9 19:12:09 fw0 kernel: ue0: link state changed to DOWN
Apr 9 19:12:09 fw0 kernel: ue0: link state changed to UP
Apr 9 19:12:09 fw0 kernel: ue0: link state changed to DOWN
Apr 9 19:12:09 fw0 kernel: ue0: link state changed to UP
Apr 9 21:28:20 fw0 kernel: ue0: link state changed to DOWN
Apr 9 21:28:20 fw0 kernel: ue0: link state changed to UP
Apr 9 23:36:30 fw0 kernel: ue0: link state changed to DOWN
Apr 9 23:36:30 fw0 kernel: ue0: link state changed to UP
Apr 10 11:21:23 fw0 kernel: ue0: link state changed to DOWN
Apr 10 11:21:24 fw0 check_reload_status: Linkup starting ue0After turning check_reload_status back on it appears that is tries
to deal with the the link going down and either kicks dhclient or restarts
it. Either way dhclient has to manually be killed and restarted to get
the link back.So it seems like the first issue to figure out is why the link is not stable :-(
The second is why dhclient is getting messed up, presumably by check_reload_status.
Here is a excerpt from the log.
Apr 10 11:09:33 fw0 dhcpd: DHCPREQUEST for 10.0.0.90 from 90:84:0d:5e:5e:05 via fxp0
Apr 10 11:09:33 fw0 dhcpd: DHCPACK on 10.0.0.90 to 90:84:0d:5e:5e:05 via fxp0
Apr 10 11:09:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074174 1f2a49fb60033d1734dce812e237320e
Apr 10 11:10:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074234 00d1c0b873a2f9b830d3530cae70c0c8
Apr 10 11:11:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074294 d5710bcf1f833d2460b32bfec446cd11
Apr 10 11:12:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074354 a234581277adb6983e314482d32d58dc
Apr 10 11:13:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074414 a466e9c3c8835d781b874e359844beb6
Apr 10 11:14:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074474 dc215d681a1d9b079a806a81dbab67a9
Apr 10 11:15:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074534 a8274589401fb4853dc25fa40b648bb3
Apr 10 11:16:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074594 2a27ae56b33fa44581c3ab9175efe263
Apr 10 11:17:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074654 ef00ecd1e77bc5fa31fcdcc6ba6ae5ee
Apr 10 11:18:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074714 e7f00d25fa3d96b027dfe3f8ae34ee07
Apr 10 11:19:10 fw0 dhcpd: DHCPREQUEST for 10.0.0.22 from 00:12:17:f1:45:c3 via fxp0
Apr 10 11:19:10 fw0 dhcpd: DHCPACK on 10.0.0.22 to 00:12:17:f1:45:c3 via fxp0
Apr 10 11:19:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074774 cd8b4ee14c623164657eaef54a8d673b
Apr 10 11:20:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334074834 a142f898c67ca5fbe782babc6cc3ca65
Apr 10 11:21:23 fw0 kernel: ue0: link state changed to DOWN
Apr 10 11:21:24 fw0 check_reload_status: Linkup starting ue0
Apr 10 11:21:24 fw0 kernel: ue0: link state changed to UP
Apr 10 11:21:24 fw0 check_reload_status: Linkup starting ue0
Apr 10 11:21:29 fw0 php: : DEVD Ethernet detached event for wan
Apr 10 11:21:29 fw0 php: : Calling interface down for interface wan, destroy is
Apr 10 11:21:29 fw0 php: : DEVD Ethernet attached event for wan
Apr 10 11:21:29 fw0 dhclient[5360]: connection closed
Apr 10 11:21:29 fw0 dhclient[5360]: connection closed
Apr 10 11:21:29 fw0 dhclient[5360]: exiting.
Apr 10 11:21:29 fw0 dhclient[5360]: exiting.
Apr 10 11:21:29 fw0 php: : HOTPLUG: Configuring interface wan -
Another log excerpt from the latest link down
Apr 10 13:33:34 fw0 check_reload_status: Linkup starting ue0
Apr 10 13:33:34 fw0 kernel: ue0: link state changed to DOWN
Apr 10 13:33:34 fw0 kernel: ue0: link state changed to UP
Apr 10 13:33:34 fw0 check_reload_status: Linkup starting ue0
Apr 10 13:33:34 fw0 kernel: ue0: link state changed to DOWN
Apr 10 13:33:34 fw0 kernel: ue0: link state changed to UP
Apr 10 13:33:34 fw0 check_reload_status: Linkup starting ue0
Apr 10 13:33:34 fw0 check_reload_status: Linkup starting ue0
Apr 10 13:33:34 fw0 sixxs-aiccu: [HB] HEARTBEAT TUNNEL 2001:4978:f:3cf::2 sender 1334082814 ee87a087e7581d5991da0950af6981cd
Apr 10 13:33:39 fw0 php: : DEVD Ethernet detached event for wan
Apr 10 13:33:39 fw0 php: : Calling interface down for interface wan, destroy is
Apr 10 13:33:39 fw0 dhclient[780]: connection closed
Apr 10 13:33:39 fw0 dhclient[780]: connection closed
Apr 10 13:33:39 fw0 dhclient[780]: exiting.
Apr 10 13:33:39 fw0 dhclient[780]: exiting. -
The root cause of the issue is the fact you're losing and regaining link multiple times in a second at times, and just frequently in general. Unless the NIC or what it's connecting to has broken, or you have a cabling issue, that would be a driver regression of some sort between FreeBSD 8.1 and 8.3 for ue. Switching back to 2.0 for a period of time would confirm or deny that.