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

    Connection does not recover if lost

    Scheduled Pinned Locked Moved 2.1 Snapshot Feedback and Problems - RETIRED
    16 Posts 6 Posters 3.9k 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.
    • swinnS Offline
      swinn
      last edited by

      Ok, it happened again this morning. Here are the contents of the em0 files and the portion of the log:

      em0_defaultgw:
75.131.112.1

em0_defaultgwv6:
2602:100:4472:a501::

em0_error_output:
dhclient: PREINIT
dhclient: Starting delete_old_states()
OLD_IP: not found
dhclient: Comparing IPs: Old:  New: 
OLD_ROUTER: not found
dhclient: Comparing Routers: Old:  New: 
DHCPREQUEST on em0 to 255.255.255.255 port 67
DHCPREQUEST on em0 to 255.255.255.255 port 67
DHCPREQUEST on em0 to 255.255.255.255 port 67

em0_output:

em0_routerv6:
2602:100:4472:a501::

system log:
Jan 18 09:32:14 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:13 miniupnpd[88244]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Jan 18 09:32:13 miniupnpd[88244]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Jan 18 09:32:13 miniupnpd[88244]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Jan 18 09:32:13 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:13 kernel: em0: link state changed to UP 
Jan 18 09:32:12 php: : Created 6rd interface stf0 2602:100::/32 
Jan 18 09:32:12 php: : The command '/sbin/ifconfig stf0 create' returned exit code '1', the output was 'ifconfig: create: bad value' 
Jan 18 09:32:12 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 '' 
Jan 18 09:32:12 dhclient[84176]: exiting. 
Jan 18 09:32:12 dhclient[84176]: connection closed 
Jan 18 09:32:12 php: : Calling interface down for interface wan, destroy is false 
Jan 18 09:32:12 php: : DEVD Ethernet detached event for wan 
Jan 18 09:32:12 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:12 dhclient[84136]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Jan 18 09:32:11 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:11 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:10 kernel: em0: link state changed to DOWN 
Jan 18 09:32:10 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:10 check_reload_status: Linkup starting em0 
Jan 18 09:32:10 dhclient[84136]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Jan 18 09:32:09 dhclient[84136]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Jan 18 09:32:09 dhclient: Comparing Routers: Old: New: 
Jan 18 09:32:09 dhclient: Comparing IPs: Old: New: 
Jan 18 09:32:09 dhclient: Starting delete_old_states() 
Jan 18 09:32:09 miniupnpd[88244]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Jan 18 09:32:09 dhclient: PREINIT 
Jan 18 09:32:08 php: : Calling interface down for interface wan, destroy is false 
Jan 18 09:32:08 php: : Deny router advertisements for interface wan 
Jan 18 09:32:08 php: : HOTPLUG: Configuring interface wan 
Jan 18 09:32:08 php: : DEVD Ethernet attached event for wan 
Jan 18 09:32:08 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:06 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:06 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:06 kernel: em0: link state changed to UP 
Jan 18 09:32:06 check_reload_status: Linkup starting em0 
Jan 18 09:32:05 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:05 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:32:03 miniupnpd[88244]: Failed to get ip address for interface em0 
Jan 18 09:32:03 miniupnpd[88244]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Jan 18 09:31:59 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:31:59 miniupnpd[88244]: Failed to get ip address for interface em0 
Jan 18 09:31:59 miniupnpd[88244]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Jan 18 09:31:59 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:31:59 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 18 09:31:58 kernel: arpresolve: can't allocate llinfo for 75.131.112.1
      1 Reply Last reply Reply Quote 0
      • B Offline
        bardelot
        last edited by

        The connection seems to drop multiple times very quickly while pfSense is trying to reconfigure the interface. There might be interference as it takes a few seconds to reconfigure. My best guess would be a workaround using a cron job that checks every few minutes if DHCP is down and restarts it or even reconfigures the interface from scratch.

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

          Seeing this even in 2.0.2 - twice for me since updating from 2.0.1  :(

          Jan 18 09:53:47	php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em3 > /tmp/em3_output > /tmp/em3_error_output' returned exit code '15', the output was ''

          Much like the OP, I had to re-configure the interface on the box to get DHCP working and therefore an active connection.

          1 Reply Last reply Reply Quote 0
          • W Offline
            wallabybob
            last edited by

            Unfortunately the dhclient man page doesn't give an explanation of the various exit codes used so I suppose someone should fix the command so stderr gets captured into a file and troll through the source code to see the significance of exit code 15.

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

              Pardon my n00bishness…

              Does it matter that the .conf it is trying to load shows a retry of 1.  Maybe that simply means "true" and it will keep retrying?

              interface "em3" {
timeout 60;
retry 1;
select-timeout 0;
initial-interval 1;

	script "/sbin/dhclient-script";
}
              1 Reply Last reply Reply Quote 0
              • B Offline
                bardelot
                last edited by

                It's the minimum time before sending another DHCP request when no server has answered.

                retry time;
                    The retry statement determines the time that must pass after the
                    client has determined that there is no DHCP server present before
                    it tries again to contact a DHCP server.  By default, this is
                    five minutes.

                The dhclient dies when the interface goes down but the interface (and dhclient) is reconfigured when a linkup is detected.

                [1] http://www.freebsd.org/cgi/man.cgi?query=dhclient.conf&sektion=5

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

                  Have updated to 2.1 and maybe my issue goes away  :D

                  1 Reply Last reply Reply Quote 0
                  • P Offline
                    phil.davis
                    last edited by

                    Once the "kernel: arpresolve: can't allocate llinfo" message starts happening, it seems to always require the DHCP release/renew sequence (whatever the button on status interfaces does) in order to get it back. In my case, my test system WAN is connected to a little switch on my desk that is 220V, but I am in a location that has really bad power, often dipping to less than 150V. The power supply is not a 110-220V one! When the switch starts to go "funny" on low voltage, the pfSense WAN is coming and going quickly. That induces the above effects, the WAN comes back and is gone again while pfSense software is still reacting to it having come back. Ideally the software would handle all sorts of nasty things happening half-way through processing, but it doesn't. So, a dodgy WAN connection that comes-and-goes can induce this issue.

                    As the Greek philosopher Isosceles used to say, "There are 3 sides to every triangle."
                    If I helped you, then help someone else - buy someone a gift from the INF catalog http://secure.inf.org/gifts/usd/

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

                      I reconfigured the router last night. Updated build, installed packages from scratch and reconfigured. This never occurred with 2.0.1 - it would always recover just fine. Someone else reported they saw it happen with 2.0.2 but I haven't tried that version.

                      From this morning:

                      Jan 23 06:41:14 miniupnpd[92366]: upnp_event_send: send(): Broken pipe 
Jan 23 06:41:14 miniupnpd[92366]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Jan 23 06:41:14 miniupnpd[92366]: ioctl(s, SIOCGIFADDR, ...): Can't assign requested address 
Jan 23 06:41:09 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 23 06:40:21 kernel: arpresolve: can't allocate llinfo for 75.131.112.1 
Jan 23 06:40:20 miniupnpd[92366]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Jan 23 06:40:19 kernel: em0: link state changed to UP 
Jan 23 06:40:19 php: : Created 6rd interface stf0 2602:100::/32 
Jan 23 06:40:19 php: : The command '/sbin/ifconfig stf0 create' returned exit code '1', the output was 'ifconfig: create: bad value' 
Jan 23 06:40:19 php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf em0 > /tmp/em0_output 2> /tmp/em0_error_output' returned exit code '15', the output was '' 
Jan 23 06:40:19 dhclient[86506]: exiting. 
Jan 23 06:40:19 dhclient[86506]: connection closed 
Jan 23 06:40:18 php: : Calling interface down for interface wan, destroy is false 
Jan 23 06:40:18 php: : DEVD Ethernet detached event for wan 
Jan 23 06:40:17 dhclient[86298]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Jan 23 06:40:16 kernel: em0: link state changed to DOWN 
Jan 23 06:40:16 check_reload_status: Linkup starting em0 
Jan 23 06:40:15 dhclient[86298]: DHCPREQUEST on em0 to 255.255.255.255 port 67 
Jan 23 06:40:15 dhclient: Comparing Routers: Old: New: 
Jan 23 06:40:15 dhclient: Comparing IPs: Old: New: 
Jan 23 06:40:15 dhclient: Starting delete_old_states() 
Jan 23 06:40:15 miniupnpd[92366]: SendNATPMPPublicAddressChangeNotification: sendto(s_udp=14): No route to host 
Jan 23 06:40:15 dhclient: PREINIT 
Jan 23 06:40:14 php: : Calling interface down for interface wan, destroy is false 
Jan 23 06:40:14 php: : Deny router advertisements for interface wan 
Jan 23 06:40:14 php: : HOTPLUG: Configuring interface wan 
Jan 23 06:40:14 php: : DEVD Ethernet attached event for wan 
Jan 23 06:40:12 kernel: em0: link state changed to UP 
Jan 23 06:40:12 check_reload_status: Linkup starting em0
                      1 Reply Last reply Reply Quote 0
                      • J Offline
                        JWU42
                        last edited by

                        Not encouraging to see this is still around in 2.1  ::)

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