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

    Connection does not recover if lost

    2.1 Snapshot Feedback and Problems - RETIRED
    6
    16
    3.7k
    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
      swinn
      last edited by

      My current version is:
      2.1-BETA1  (i386)
      built on Mon Jan 7 16:18:13 EST 2013
      FreeBSD 8.3-RELEASE-p5

      This has been happening for a couple of months. I update builds about once a week or so.

      After looking at the em0 files, they have all been overwritten since the time the connection was lost. Next time it happens, I'll save them so I can post their contents.

      1 Reply Last reply Reply Quote 0
      • swinnS
        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
          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
            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
              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
                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
                  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
                    JWU42
                    last edited by

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

                    1 Reply Last reply Reply Quote 0
                    • P
                      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
                        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
                          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.