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

    DHCP on WAN suddenly started failing

    Scheduled Pinned Locked Moved DHCP and DNS
    67 Posts 17 Posters 28.6k 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.
    • jimpJ Offline
      jimp Rebel Alliance Developer Netgate
      last edited by

      You might try a 2.0.3 image:

      http://snapshots.pfsense.org/FreeBSD_RELENG_8_1/i386/pfSense_RELENG_2_0/?C=M;O=D
      http://snapshots.pfsense.org/FreeBSD_RELENG_8_1/amd64/pfSense_RELENG_2_0/?C=M;O=D

      Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

      Need help fast? Netgate Global Support!

      Do not Chat/PM for help!

      1 Reply Last reply Reply Quote 0
      • P Offline
        PertFlavus
        last edited by

        I'm trying out this guy:
        pfSense-Full-Update-2.0.3-PRERELEASE-i386-20130129-0807.tgz

        I'll let you know if I have any issues. Thanks.

        1 Reply Last reply Reply Quote 0
        • J Offline
          jsquyres
          last edited by

          FWIW, I don't see anything in https://github.com/bsdperimeter/pfsense/commits/RELENG_2_0?page=1 that would seem to indicate that something has changed with regards to the WAN DHCP client.

          Also FWIW, I notice that if I run dhclient myself, it's just not getting anything back:

          
[2.0.2-RELEASE][admin@pfsense.squyres.com]/(8): dhclient -c /var/etc/dhclient_wan.conf -d sk0
dhclient: PREINIT
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 1
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 1
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 2
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 3
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 8
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 13
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 7
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 14
DHCPDISCOVER on sk0 to 255.255.255.255 port 67 interval 12
No DHCPOFFERS received.
No working leases in persistent database - sleeping.

          This tends to imply that it's dhclient itself – or perhaps the driver for my NIC -- that is borked. Not pfsense core/proper.

          Is there a way to tell if dhclient or the NIC driver has been updated since 2.0.1?  My IP interface is sk0, if that helps identify the driver (sorry, I don't know anything about the BSD OS...).

          1 Reply Last reply Reply Quote 0
          • P Offline
            PertFlavus
            last edited by

            I have the same problem as before in 2.0.3. my link loses the ip address and my internet is down until I renew the IP through the gui.

            Below is a tail of my system.logs
            Jan 31 02:56:11 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:12 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:12 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:14 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:14 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:14 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:15 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:15 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1
            Jan 31 02:56:16 pfsense kernel: arpresolve: can't allocate llinfo for 72.208.8.1

            Note that my internet went down several hours later, at 08:14. I don't think these are significant but i'll let you decide.. If you'd like me to get any other logs please provide me with the log location.

            Thanks
            Matt

            1 Reply Last reply Reply Quote 0
            • jimpJ Offline
              jimp Rebel Alliance Developer Netgate
              last edited by

              Start with the rest of the system log, especially at/near the time of the actual failure.

              Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

              Need help fast? Netgate Global Support!

              Do not Chat/PM for help!

              1 Reply Last reply Reply Quote 0
              • P Offline
                PertFlavus
                last edited by

                Well I'm pretty sure the time of failure was 8 am and the snippet I pasted you was the output from tail, thus the most recent. However given that it is the first thing in the morning I may be mistaken about it actually working.

                Here are some other noteworthy logs I saw:
                Jan 31 02:52:23 pfsense kernel: rl1: link state changed to DOWN
                Jan 31 02:52:23 pfsense check_reload_status: Linkup starting rl1

                Jan 31 02:52:24 pfsense php: : DEVD Ethernet attached event for wan
                Jan 31 02:52:24 pfsense php: : HOTPLUG: Configuring interface wan

                Jan 31 02:52:24 pfsense check_reload_status: Reloading filter

                Jan 31 02:52:25 pfsense kernel: rl1: link state changed to UP
                Jan 31 02:52:25 pfsense dhclient: PREINIT

                Jan 31 02:52:25 pfsense dhclient[21193]: DHCPREQUEST on rl1 to 255.255.255.255 port 67
                Jan 31 02:52:26 pfsense dhclient[21193]: DHCPREQUEST on rl1 to 255.255.255.255 port 67

                Jan 31 02:52:30 pfsense dhclient[21193]: DHCPREQUEST on rl1 to 255.255.255.255 port 67
                Jan 31 02:52:30 pfsense php: : DEVD Ethernet detached event for wan
                Jan 31 02:52:30 pfsense dhclient[21722]: connection closed
                Jan 31 02:52:30 pfsense dhclient[21722]: connection closed
                Jan 31 02:52:30 pfsense dhclient[21722]: exiting.
                Jan 31 02:52:30 pfsense dhclient[21722]: exiting.
                Jan 31 02:52:30 pfsense php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf rl1 > /tmp/rl1_output > /tmp/rl1_error_output' returned exit code '15', the output was ''

                Note that I have omitted the lines from arpresolve only.

                1 Reply Last reply Reply Quote 0
                • P Offline
                  PertFlavus
                  last edited by

                  And here are the details from ifconfig, so you can see which interface is what:
                  rl0: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500
                          options=8 <vlan_mtu>ether 00:01:c0:03:dc:77
                          inet 192.168.0.254 netmask 0xffffff00 broadcast 192.168.0.255
                          inet6 fe80::201:c0ff:fe03:dc77%rl0 prefixlen 64 scopeid 0x1
                          nd6 options=43 <performnud,accept_rtadv>media: Ethernet autoselect (100baseTX <full-duplex>)
                          status: active
                  rl1: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500
                          options=8 <vlan_mtu>ether 00:01:c0:03:d3:dc
                          inet6 fe80::201:c0ff:fe03:d3dc%rl1 prefixlen 64 scopeid 0x2
                          inet 72.208.12.250 netmask 0xfffff800 broadcast 72.208.15.255
                          nd6 options=43 <performnud,accept_rtadv>media: Ethernet autoselect (100baseTX <full-duplex>)
                          status: active</full-duplex></performnud,accept_rtadv></vlan_mtu></up,broadcast,running,simplex,multicast></full-duplex></performnud,accept_rtadv></vlan_mtu></up,broadcast,running,simplex,multicast>

                  1 Reply Last reply Reply Quote 0
                  • jimpJ Offline
                    jimp Rebel Alliance Developer Netgate
                    last edited by

                    Odd that if you look at the log, it appears that the devd events are reversed for what they should be.

                    Jan 31 02:52:23 pfsense kernel: rl1: link state changed to DOWN
Jan 31 02:52:24 pfsense php: : DEVD Ethernet attached event for wan
Jan 31 02:52:24 pfsense php: : HOTPLUG: Configuring interface wan
Jan 31 02:52:25 pfsense kernel: rl1: link state changed to UP
Jan 31 02:52:30 pfsense php: : DEVD Ethernet detached event for wan

                    Though when I test that on my VM with em NICs, it gets it right.

                    Can you watch the log and see if when you unplug the NIC it does the same thing each time?

                    When you unplug it should log an "ethernet detached" event.
                    When you plug it in, it should log an "ethernet attached" event.

                    Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

                    Need help fast? Netgate Global Support!

                    Do not Chat/PM for help!

                    1 Reply Last reply Reply Quote 0
                    • swinnS Online
                      swinn
                      last edited by

                      It's happening to me as well on 2.0.3 (just as it is on 2.1). Log below is in reverse time order:

                      Feb 3 11:19:21 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:14 kernel: em0: link state changed to UP 
Feb 3 11:19:14 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' 
Feb 3 11:19:14 dhclient[40067]: exiting. 
Feb 3 11:19:14 dhclient[40067]: exiting. 
Feb 3 11:19:14 dhclient[40067]: connection closed 
Feb 3 11:19:14 dhclient[40067]: connection closed 
Feb 3 11:19:14 php: : DEVD Ethernet detached event for wan 
Feb 3 11:19:12 kernel: em0: link state changed to DOWN 
Feb 3 11:19:12 check_reload_status: Linkup starting em0 
Feb 3 11:19:12 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:19:10 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Feb 3 11:19:10 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:10 dhclient: PREINIT 
Feb 3 11:19:10 php: : HOTPLUG: Configuring interface wan 
Feb 3 11:19:10 php: : DEVD Ethernet attached event for wan
                      1 Reply Last reply Reply Quote 0
                      • W Offline
                        wallabybob
                        last edited by

                        I suspect @swinn:

                        
Feb 3 11:19:14 kernel: em0: link state changed to UP

                        should have triggered a restart of dhclient. There is no sign of that happening, but that might be because you didn't show enough of the log file.

                        Because the previous incarnation of dhclient exited and dhclient (apparently) wasn't restarted it appears there is no running dhclient to issue a DHCP request for configuration.

                        MAYBE there are too many link state transitions in too short a period.

                        1 Reply Last reply Reply Quote 0
                        • swinnS Online
                          swinn
                          last edited by

                          Here is the log from the time the interface went down to the time I logged in and pressed the renew dhcp button. This is in reverse order again:

                          Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:21:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:13:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:13:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 14:13:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:06:47 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:06:46 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 14:06:46 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 14:05:29 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:57:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:56:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:52 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:12 miniupnpd[53901]: upnp_event_send: send(): Broken pipe 
Feb 3 13:52:12 miniupnpd[53901]: upnp_event_send: send(): Broken pipe 
Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:52:12 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:51:03 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 13:51:03 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 13:51:02 kernel: em0: link state changed to UP 
Feb 3 13:51:02 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' 
Feb 3 13:51:02 dhclient[50586]: exiting. 
Feb 3 13:51:02 dhclient[50586]: exiting. 
Feb 3 13:51:02 dhclient[50586]: connection closed 
Feb 3 13:51:02 dhclient[50586]: connection closed 
Feb 3 13:51:02 php: : DEVD Ethernet detached event for wan 
Feb 3 13:51:00 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 13:50:59 kernel: em0: link state changed to DOWN 
Feb 3 13:50:59 check_reload_status: Linkup starting em0 
Feb 3 13:50:59 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 13:50:58 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 13:50:57 dhclient[50273]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 13:50:57 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 13:50:57 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 13:50:57 dhclient: PREINIT 
Feb 3 13:50:57 php: : HOTPLUG: Configuring interface wan 
Feb 3 13:50:57 php: : DEVD Ethernet attached event for wan 
Feb 3 13:50:55 kernel: em0: link state changed to UP 
Feb 3 13:50:55 check_reload_status: Linkup starting em0 
Feb 3 13:50:44 php: : DEVD Ethernet detached event for wan 
Feb 3 13:50:42 kernel: em0: link state changed to DOWN 
Feb 3 13:50:42 check_reload_status: Linkup starting em0 
Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:47:20 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:38:45 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:38:45 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 13:38:45 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 13:38:33 dnsmasq[37297]: read /etc/hosts - 21 addresses 
Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:32:53 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:32:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 13:32:53 miniupnpd[53901]: upnp_event_recv: recv(): Connection reset by peer 
Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:18:16 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:11:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 13:02:04 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:47:55 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:41:35 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:36:14 dnsmasq[37297]: read /etc/hosts - 21 addresses 
Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:32:50 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerSpamhausEDrop does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerBluetackDShield does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerBluetackHijacked does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerZeusBlocklist does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerDShieldAttackers does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerSpamhausDrop does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerTopSpammers does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerEurope does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerAsia does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: pfBlockerAfrica does not need updated. 
Feb 3 12:30:54 php: : /etc/rc.update_urltables: Starting URL table alias updates 
Feb 3 12:30:00 php: : /etc/rc.update_urltables: Sleeping for 54 seconds. 
Feb 3 12:30:00 php: : /etc/rc.update_urltables: Starting up. 
Feb 3 12:28:19 miniupnpd[53901]: HTTP Connection closed unexpectedly 
Feb 3 12:28:19 miniupnpd[53901]: HTTP Connection closed unexpectedly 
Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 12:27:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:47:31 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:47:31 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:47:30 kernel: em0: link state changed to UP 
Feb 3 11:47:30 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' 
Feb 3 11:47:30 dhclient[21788]: exiting. 
Feb 3 11:47:30 dhclient[21788]: exiting. 
Feb 3 11:47:30 dhclient[21788]: connection closed 
Feb 3 11:47:30 dhclient[21788]: connection closed 
Feb 3 11:47:30 php: : DEVD Ethernet detached event for wan 
Feb 3 11:47:29 dhclient[21773]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:47:28 kernel: em0: link state changed to DOWN 
Feb 3 11:47:28 check_reload_status: Linkup starting em0 
Feb 3 11:47:27 dhclient[21773]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:47:26 dhclient[21773]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:47:26 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:47:26 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:47:26 dhclient: PREINIT 
Feb 3 11:47:26 php: : HOTPLUG: Configuring interface wan 
Feb 3 11:47:26 php: : DEVD Ethernet attached event for wan 
Feb 3 11:47:23 kernel: em0: link state changed to UP 
Feb 3 11:47:23 check_reload_status: Linkup starting em0 
Feb 3 11:47:12 php: : DEVD Ethernet detached event for wan 
Feb 3 11:47:10 kernel: em0: link state changed to DOWN 
Feb 3 11:47:10 check_reload_status: Linkup starting em0 
Feb 3 11:36:38 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:36:38 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:36:38 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:30:21 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:30:21 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:30:20 kernel: em0: link state changed to UP 
Feb 3 11:30:20 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' 
Feb 3 11:30:20 dhclient[32235]: exiting. 
Feb 3 11:30:20 dhclient[32235]: exiting. 
Feb 3 11:30:20 dhclient[32235]: connection closed 
Feb 3 11:30:20 dhclient[32235]: connection closed 
Feb 3 11:30:20 php: : DEVD Ethernet detached event for wan 
Feb 3 11:30:19 dhclient[31973]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:30:18 kernel: em0: link state changed to DOWN 
Feb 3 11:30:18 check_reload_status: Linkup starting em0 
Feb 3 11:30:17 dhclient[31973]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:30:16 dhclient[31973]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:30:16 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:30:16 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:30:16 dhclient: PREINIT 
Feb 3 11:30:16 php: : HOTPLUG: Configuring interface wan 
Feb 3 11:30:16 php: : DEVD Ethernet attached event for wan 
Feb 3 11:30:13 kernel: em0: link state changed to UP 
Feb 3 11:30:13 check_reload_status: Linkup starting em0 
Feb 3 11:30:03 php: : DEVD Ethernet detached event for wan 
Feb 3 11:30:00 kernel: em0: link state changed to DOWN 
Feb 3 11:30:00 check_reload_status: Linkup starting em0 
Feb 3 11:25:20 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:24:16 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:23:12 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:22:35 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:22:32 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:22:32 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:22:32 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:22:31 dnsmasq[37297]: read /etc/hosts - 20 addresses 
Feb 3 11:22:08 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:21:47 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:21:04 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:21:03 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:21:03 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:21:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:21:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:20:59 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:20:14 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:20:11 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:20:10 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:50 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:49 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:36 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:30 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:30 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:26 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:23 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:23 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:22 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:21 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:21 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:21 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:21 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:21 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:21 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:15 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:15 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:15 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:14 kernel: em0: link state changed to UP 
Feb 3 11:19:14 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output > /tmp/em0_error_output' returned exit code '15', the output was '' 
Feb 3 11:19:14 dhclient[40067]: exiting. 
Feb 3 11:19:14 dhclient[40067]: exiting. 
Feb 3 11:19:14 dhclient[40067]: connection closed 
Feb 3 11:19:14 dhclient[40067]: connection closed 
Feb 3 11:19:14 php: : DEVD Ethernet detached event for wan 
Feb 3 11:19:12 kernel: em0: link state changed to DOWN 
Feb 3 11:19:12 check_reload_status: Linkup starting em0 
Feb 3 11:19:12 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:19:10 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:19:10 dhclient[39818]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:10 miniupnpd[53901]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Feb 3 11:19:10 dhclient: PREINIT 
Feb 3 11:19:10 php: : HOTPLUG: Configuring interface wan 
Feb 3 11:19:10 php: : DEVD Ethernet attached event for wan 
Feb 3 11:19:09 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:09 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:09 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:09 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:08 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:08 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:08 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:07 kernel: em0: link state changed to UP 
Feb 3 11:19:07 check_reload_status: Linkup starting em0 
Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:05 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:05 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:03 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:03 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:19:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:19:03 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:18:59 kernel: arpresolve: can't allocate llinfo for 75.131.xxx.xxx 
Feb 3 11:18:59 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:18:59 miniupnpd[53901]: Failed to get ip address for interface em0 
Feb 3 11:18:59 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:18:59 miniupnpd[53901]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Feb 3 11:18:56 dhclient[4995]: exiting. 
Feb 3 11:18:56 dhclient[4995]: exiting. 
Feb 3 11:18:56 dhclient[4995]: connection closed 
Feb 3 11:18:56 dhclient[4995]: connection closed 
Feb 3 11:18:56 php: : DEVD Ethernet detached event for wan 
Feb 3 11:18:54 kernel: em0: link state changed to DOWN 
Feb 3 11:18:54 check_reload_status: Linkup starting em0 
Feb 3 11:18:47 check_reload_status: Reloading filter 
Feb 3 11:18:37 apinger: ALARM: WAN(75.131.xxx.xxx) *** down ***
                          1 Reply Last reply Reply Quote 0
                          • jimpJ Offline
                            jimp Rebel Alliance Developer Netgate
                            last edited by

                            I flipped these log entries around because trying to follow the flow of messages in reverse-order logs is bothersome…

                            Feb 3 11:19:12 kernel: em0: link state changed to DOWN 
Feb 3 11:19:14 php: : DEVD Ethernet detached event for wan 
Feb 3 11:19:14 kernel: em0: link state changed to UP

                            If I had to guess I'd say that the link cycled too fast and either DEVD did not fire the event to bring it back up or the event was lost somewhere in between devd and check_reload_status.

                            Are you spoofing a MAC on that interface? Or setting any other custom values other than the interface name and setting it for DHCP?

                            Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

                            Need help fast? Netgate Global Support!

                            Do not Chat/PM for help!

                            1 Reply Last reply Reply Quote 0
                            • swinnS Online
                              swinn
                              last edited by

                              No MAC spoofing or anything unusual. It is a very basic home setup.

                              1 Reply Last reply Reply Quote 0
                              • jimpJ Offline
                                jimp Rebel Alliance Developer Netgate
                                last edited by

                                Could be something sketchy happening at the modem then…

                                Ermal is looking into a fix, I started a ticket here: https://redmine.pfsense.org/issues/2792

                                Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

                                Need help fast? Netgate Global Support!

                                Do not Chat/PM for help!

                                1 Reply Last reply Reply Quote 0
                                • swinnS Online
                                  swinn
                                  last edited by

                                  It looks like anytime the cable goes out or I get a T4 error (causes modem reboot), it happens. It's a Motorola 6120. We had an all out outage yesterday which caused the log I posted above. Sometimes I'll get a T4 error which causes the modem to reboot and pfSense doesn't recover. pfSense 2.0.1 would recover just fine.

                                  I'm actually going to buy a new modem today in hopes it will fix something. If not I'll go back to 2.0.1 but wanted to remain on the newer versions to help fix it. I can't have the wife with no Internet while I'm at work - I get nasty calls :)

                                  1 Reply Last reply Reply Quote 0
                                  • jimpJ Offline
                                    jimp Rebel Alliance Developer Netgate
                                    last edited by

                                    OK, snaps up now should have a potential fix in for this.

                                    2.0.3 snaps can be found here: http://forum.pfsense.org/index.php/topic,58203.msg311614.html#msg311614
                                    2.1 snaps are on http://snapshots.pfsense.org/

                                    Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

                                    Need help fast? Netgate Global Support!

                                    Do not Chat/PM for help!

                                    1 Reply Last reply Reply Quote 0
                                    • G Offline
                                      goliy
                                      last edited by

                                      It's awful bug! But to install a "snap" it's much more unsafely IMHO.
                                      You can use my temp solution:
                                      Repeat every minute by cron smth like this

                                      $ cat /root/renew-ip.sh
#!/bin/sh

GW=`netstat -rn | grep default | egrep -o "[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}"`
lan_inf="em1"

ping -c 5 -i 0.1 -q $GW >/dev/null
  if [ $? != 0 ]; then
    logger "GW:$GW sucks"
    ping -c 5 -q ya.ru >/dev/null 
      if [ $? != 0 ]; then
         /sbin/dhclient $lan_inf
        logger "GW:$GW Crash!"
	sleep 30
      fi
  fi
exit 1

                                      It works for me since 2.0.2 upgrade comes

                                      2.0.2-RELEASE (i386)
                                      Intel(R) Atom(TM) CPU 330 @ 1.60GHz
                                      eth: Intel 82574L
                                      DOM sata, 1Gb
                                      over 150 users

                                      1 Reply Last reply Reply Quote 0
                                      • jimpJ Offline
                                        jimp Rebel Alliance Developer Netgate
                                        last edited by

                                        2.0.3 snaps are safe. Releases are just snapshots we deemed worthy of being called releases.

                                        The only thing holding back 2.0.3 from release right now is that we're waiting on FreeBSD to issue an OpenSSL security advisory any time now, and we have to account for that once it comes out.

                                        Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

                                        Need help fast? Netgate Global Support!

                                        Do not Chat/PM for help!

                                        1 Reply Last reply Reply Quote 0
                                        • J Offline
                                          jsquyres
                                          last edited by

                                          I upgraded to the latest snap image today (Feb 13 1243), and I am still having the problem that originally started this thread.

                                          1 Reply Last reply Reply Quote 0
                                          • jimpJ Offline
                                            jimp Rebel Alliance Developer Netgate
                                            last edited by

                                            Gather the info again (the syslog logs, etc) and post it again from the new snapshot.

                                            Remember: Upvote with the 👍 button for any user/post you find to be helpful, informative, or deserving of recognition!

                                            Need help fast? Netgate Global Support!

                                            Do not Chat/PM for help!

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