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

    Keep loosing WAN IP Address - dhclient does not seem to do update

    DHCP and DNS
    27
    199
    108.2k
    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.
    • H
      hoba
      last edited by

      Any chance that you are using dhcp on more than 1 interface? The current dhclient-switch doesn't handle multiple dhcp interfaces correctly atm. We need to improve this a bit to handle these kind of situations.

      1 Reply Last reply Reply Quote 0
      • S
        sullrich
        last edited by

        @hoba:

        Any chance that you are using dhcp on more than 1 interface? The current dhclient-switch doesn't handle multiple dhcp interfaces correctly atm. We need to improve this a bit to handle these kind of situations.

        Bad news.  Looks like we are going to have to revert back to the previous code.  This newer code breaks our multi-wan dhcp.

        1 Reply Last reply Reply Quote 0
        • A
          adrianhensler
          last edited by

          Just to follow up on my previous information; I see this in the system.log:

          Dec 28 08:39:40 chunder dhclient: execve (/usr/local/sbin/dhclient-script, …): No such file or directory
Dec 28 08:39:40 chunder dhclient: execve (/usr/local/sbin/dhclient-script, ...): No such file or directory
Dec 28 08:39:40 chunder dhclient: /y: not found
Dec 28 08:39:40 chunder dhclient: /y: not found

          dhclient-script is in /sbin ?

          I'm still using the install from 12-23 and I used the fetch from another thread. Maybe I just made a mess…. Maybe I'll copy that over and see what happens; or maybe I'll get a chance to take a better look at it and see what put it there.

          1 Reply Last reply Reply Quote 0
          • H
            hoba
            last edited by

            Investigating this error is riding a dead horse. We have to go back to the previous dhclient due to multi interface dhclient issues with the isc client that can't be worked around. The next snapshot will be back at the "old" openbsd dhclient.

            1 Reply Last reply Reply Quote 0
            • F
              freax
              last edited by

              Hi !

              Does the following code work to workaround temporarily this problem ?

              /etc/rc.newwanip

              if($curwanip == "0.0.0.0") {
                      log_error("Failed to update WAN IP, restarting dhclient.");
                      exec("dhclient fxp0");

              Thanks in advance.

              1 Reply Last reply Reply Quote 0
              • F
                freax
                last edited by

                I don't want to stress anybody but I didn't received any answer and this topic seems to be stopped.
                This issue is being solved ?
                I'm having this problem too.

                Thanks in advance.

                1 Reply Last reply Reply Quote 0
                • S
                  sullrich
                  last edited by

                  @freax:

                  I don't want to stress anybody but I didn't received any answer and this topic seems to be stopped.
                  This issue is being solved ?
                  I'm having this problem too.

                  Thanks in advance.

                  No, work has halted.  Sorry.

                  1 Reply Last reply Reply Quote 0
                  • S
                    sullrich
                    last edited by

                    I have commited some work around code to this bug.  Please test a snapshot in about an hour from now and see if it works around the issue.

                    1 Reply Last reply Reply Quote 0
                    • F
                      freax
                      last edited by

                      Hi again.

                      I did the update but I lost my connection at this moment again where it didn't happened with an old pfsense with the same hardware:

                      php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                      Jan 30 10:28:24 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                      Jan 30 10:28:23 check_reload_status: rc.linkup starting
                      Jan 30 10:28:23 mpd: [pt1] LCP: no reply to 1 echo request(s)
                      Jan 30 10:28:22 kernel: vr0: link state changed to UP
                      Jan 30 10:28:19 kernel: vr0: link state changed to DOWN
                      Jan 30 10:28:19 mpd: [pt0] LCP: no reply to 1 echo request(s)
                      Jan 30 10:28:08 php: : DEVD Ethernet attached event for fxp0
                      Jan 30 10:28:08 kernel: vr0: link state changed to UP
                      Jan 30 10:28:08 check_reload_status: rc.linkup starting
                      Jan 30 10:28:04 kernel: fxp0: link state changed to UP
                      Jan 30 10:28:03 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                      Jan 30 10:28:03 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                      Jan 30 10:28:03 php: : DEVD Ethernet detached event for fxp0
                      Jan 30 10:28:03 check_reload_status: rc.linkup starting
                      Jan 30 10:28:00 kernel: vr0: link state changed to DOWN
                      Jan 30 10:27:59 kernel: vr0: link state changed to UP
                      Jan 30 10:27:58 kernel: fxp0: link state changed to DOWN
                      Jan 30 10:27:58 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                      Jan 30 10:27:58 check_reload_status: rc.linkup starting
                      Jan 30 10:27:53 kernel: vr0: link state changed to DOWN
                      Jan 30 10:21:44 mpd: [pt1] IFACE: Up event
                      Jan 30 10:21:44 mpd: [pt1] exec: /usr/local/sbin/vpn-linkup ng2 inet 172.16.99.1 172.16.99.97 USERXXX
                      Jan 30 10:21:44 mpd: [pt1] exec: command returned 256
                      Jan 30 10:21:44 mpd: [pt1] exec: /sbin/route add 172.16.99.1 -iface lo0
                      Jan 30 10:21:44 mpd: [pt1] no interface to proxy arp on for 172.16.99.97
                      Jan 30 10:21:44 mpd: [pt1] exec: /sbin/ifconfig ng2 172.16.99.1 172.16.99.97 netmask 0xffffffff -link0
                      Jan 30 10:21:44 mpd: [pt1] setting interface ng2 MTU to 1396 bytes
                      Jan 30 10:21:44 mpd: [pt1] IFACE: Up event
                      Jan 30 10:21:44 mpd: 172.16.99.1 -> 172.16.99.97
                      Jan 30 10:21:44 mpd: [pt1] IPCP: LayerUp
                      Jan 30 10:21:44 mpd: [pt1] IPCP: state change Ack-Sent –> Opened
                      Jan 30 10:21:44 mpd: IPADDR 172.16.99.1
                      Jan 30 10:21:44 mpd: [pt1] IPCP: rec'd Configure Ack #13 link 0 (Ack-Sent)
                      Jan 30 10:21:44 mpd: [pt1] IPCP: state change Req-Sent –> Ack-Sent
                      Jan 30 10:21:44 mpd: IPADDR 172.16.99.97
                      Jan 30 10:21:44 mpd: [pt1] IPCP: SendConfigAck #7
                      Jan 30 10:21:44 mpd: 172.16.99.97 is OK
                      Jan 30 10:21:44 mpd: IPADDR 172.16.99.97
                      Jan 30 10:21:44 mpd: [pt1] IPCP: rec'd Configure Request #7 link 0 (Req-Sent)
                      Jan 30 10:21:44 mpd: [pt1] setting interface ng2 MTU to 1396 bytes
                      Jan 30 10:21:44 mpd: Decompress using: MPPE, 128 bit, stateless
                      Jan 30 10:21:44 mpd: Compress using: MPPE, 128 bit, stateless
                      Jan 30 10:21:44 mpd: [pt1] CCP: LayerUp
                      Jan 30 10:21:44 mpd: [pt1] CCP: state change Ack-Rcvd –> Opened
                      Jan 30 10:21:44 mpd: 0x01000040: MPPE, 128 bit, stateless
                      Jan 30 10:21:44 mpd: MPPC
                      Jan 30 10:21:44 mpd: [pt1] CCP: SendConfigAck #6
                      Jan 30 10:21:44 mpd: [pt1] CCP: Checking whether 128 bits are acceptable -> yes
                      Jan 30 10:21:44 mpd: 0x01000040: MPPE, 128 bit, stateless

                      Thanks.

                      1 Reply Last reply Reply Quote 0
                      • F
                        freax
                        last edited by

                        Don't know if this help but here it is another log from today.

                        Don't know if is coincidence but the same vpn user is present in logs trying to connect when this appens:

                        php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                        Jan 31 14:30:26 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                        Jan 31 14:30:26 check_reload_status: rc.linkup starting
                        Jan 31 14:30:24 kernel: vr0: link state changed to UP
                        Jan 31 14:30:22 kernel: vr0: link state changed to DOWN
                        Jan 31 14:30:11 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                        Jan 31 14:30:11 check_reload_status: rc.linkup starting
                        Jan 31 14:30:10 kernel: vr0: link state changed to UP
                        Jan 31 14:30:06 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                        Jan 31 14:30:06 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                        Jan 31 14:30:05 check_reload_status: rc.linkup starting
                        Jan 31 14:30:03 kernel: vr0: link state changed to DOWN
                        Jan 31 14:30:01 kernel: vr0: link state changed to UP
                        Jan 31 14:30:00 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                        Jan 31 14:30:00 check_reload_status: rc.linkup starting
                        Jan 31 14:29:56 kernel: vr0: link state changed to DOWN
                        Jan 31 14:07:54 mpd: pptp0: killing connection with XXX.XXX.XXX.XXX:4160
                        Jan 31 14:07:54 mpd: [pt0] device is now in state DOWN
                        Jan 31 14:07:54 mpd: [pt0] device: CLOSE event in state DOWN
                        Jan 31 14:07:54 mpd: [pt0] LCP: LayerFinish
                        Jan 31 14:07:54 mpd: [pt0] LCP: state change Starting –> Initial
                        Jan 31 14:07:54 mpd: [pt0] LCP: Close event
                        Jan 31 14:07:54 mpd: [pt0] link: CLOSE event
                        Jan 31 14:07:54 mpd: [pt0] device is now in state DOWN
                        Jan 31 14:07:54 mpd: [pt0] pausing 9 seconds before open
                        Jan 31 14:07:54 mpd: [pt0] device: OPEN event in state DOWN
                        Jan 31 14:07:54 mpd: [pt0] closing link "pt0"…
                        Jan 31 14:07:54 mpd: [pt0] bundle: CLOSE event in state OPENED
                        Jan 31 14:07:54 mpd: [pt0] LCP: LayerDown
                        Jan 31 14:07:54 mpd: [pt0] CCP: LayerFinish
                        Jan 31 14:07:54 mpd: [pt0] CCP: state change Starting –> Initial
                        Jan 31 14:07:54 mpd: [pt0] CCP: Close event
                        Jan 31 14:07:54 mpd: [pt0] CCP: LayerDown
                        Jan 31 14:07:54 mpd: [pt0] CCP: state change Opened –> Starting
                        Jan 31 14:07:54 mpd: [pt0] CCP: Down event
                        Jan 31 14:07:54 mpd: [pt0] IPCP: state change Closing –> Initial
                        Jan 31 14:07:54 mpd: [pt0] IPCP: LayerFinish
                        Jan 31 14:07:54 mpd: [pt0] IPCP: Down event
                        Jan 31 14:07:54 mpd: [pt0] RADIUS: Down Event
                        Jan 31 14:07:54 mpd: [pt0] up: 0 links, total bandwidth 9600 bps
                        Jan 31 14:07:54 mpd: [pt0] setting interface ng1 MTU to 1500 bytes
                        Jan 31 14:07:54 mpd: [pt0] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user userXXX
                        Jan 31 14:07:54 mpd: [pt0] RADIUS: RadiusAccount: Sending accounting data (Type: 2)
                        Jan 31 14:07:54 mpd: [pt0] RADIUS: Termination cause: , RADIUS: 10
                        Jan 31 14:07:54 mpd: [pt0] RADIUS: RadiusAddServer Adding 192.168.99.1
                        Jan 31 14:07:54 mpd: [pt0] RADIUS: RadiusAccount for: userXXX
                        Jan 31 14:07:54 mpd: [pt0] LCP: phase shift NETWORK –> DEAD
                        Jan 31 14:07:54 mpd: [pt0] LCP: state change Opened –> Starting
                        Jan 31 14:07:54 mpd: [pt0] LCP: Down event
                        Jan 31 14:07:54 mpd: [pt0] link: DOWN event

                        1 Reply Last reply Reply Quote 0
                        • F
                          freax
                          last edited by

                          Hi again.

                          There is another log but the symptom seems the same: the interface vr0 that is connected to a router goes down then it can't goe up again:

                          php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                          Feb 2 11:09:46 check_reload_status: rc.linkup starting
                          Feb 2 11:09:41 kernel: vr0: link state changed to UP
                          Feb 2 11:09:41 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                          Feb 2 11:09:41 check_reload_status: rc.linkup starting
                          Feb 2 11:09:39 kernel: vr0: link state changed to DOWN
                          Feb 2 11:09:31 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                          Feb 2 11:09:30 check_reload_status: rc.linkup starting
                          Feb 2 11:09:27 kernel: vr0: link state changed to UP
                          Feb 2 11:09:20 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                          Feb 2 11:09:20 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                          Feb 2 11:09:20 check_reload_status: rc.linkup starting
                          Feb 2 11:09:19 kernel: vr0: link state changed to DOWN
                          Feb 2 11:09:18 kernel: vr0: link state changed to UP
                          Feb 2 11:09:15 php: : Hotplug event detected for vr0 but ignoring since interface is not set for DHCP
                          Feb 2 11:09:15 check_reload_status: rc.linkup starting
                          Feb 2 11:09:13 kernel: vr0: link state changed to DOWN
                          Feb 2 10:51:31 mpd: pptp0: killing connection with 87.103.50.134:2118
                          Feb 2 10:51:31 mpd: [pt0] LCP: Down event
                          Feb 2 10:51:31 mpd: [pt0] link: DOWN event
                          Feb 2 10:51:31 mpd: [pt0] LCP: phase shift ESTABLISH –> DEAD
                          Feb 2 10:51:31 mpd: [pt0] LCP: state change Closed –> Initial
                          Feb 2 10:51:31 mpd: [pt0] LCP: Down event
                          Feb 2 10:51:31 mpd: [pt0] link: DOWN event
                          Feb 2 10:51:31 mpd: [pt0] device is now in state DOWN
                          Feb 2 10:51:31 mpd: [pt0] device: DOWN event in state DOWN
                          Feb 2 10:51:31 mpd: [pt0] LCP: state change Stopped –> Closed
                          Feb 2 10:51:31 mpd: [pt0] LCP: Close event
                          Feb 2 10:51:31 mpd: [pt0] link: CLOSE event
                          Feb 2 10:51:31 mpd: [pt0] device is now in state DOWN
                          Feb 2 10:51:31 mpd: [pt0] device: DOWN event in state CLOSING
                          Feb 2 10:51:31 mpd: [pt0] closing link "pt0"…
                          Feb 2 10:51:31 mpd: [pt0] bundle: CLOSE event in state OPENED
                          Feb 2 10:51:31 mpd: [pt0] device is now in state CLOSING
                          Feb 2 10:51:31 mpd: [pt0] IFACE: Close event
                          Feb 2 10:51:31 mpd: pptp0: closing connection with 87.103.50.134:2118
                          Feb 2 10:51:31 mpd: [pt0] IFACE: Close event
                          Feb 2 10:51:31 mpd: [pt0] IPCP: LayerFinish
                          Feb 2 10:51:31 mpd: [pt0] IPCP: state change Starting –> Initial
                          Feb 2 10:51:31 mpd: [pt0] IPCP: Close event
                          Feb 2 10:51:31 mpd: [pt0] IFACE: Close event
                          Feb 2 10:51:31 mpd: [pt0] PPTP call terminated
                          Feb 2 10:51:31 mpd: pptp0-0: killing channel
                          Feb 2 10:51:31 mpd: pptp0-0: clearing call
                          Feb 2 10:51:31 mpd: [pt0] device: CLOSE event in state UP
                          Feb 2 10:51:31 mpd: [pt0] LCP: LayerFinish
                          Feb 2 10:51:31 mpd: [pt0] LCP: phase shift TERMINATE –> ESTABLISH
                          Feb 2 10:51:31 mpd: [pt0] LCP: state change Stopping –> Stopped
                          Feb 2 10:51:31 mpd: [pt0] LCP: SendTerminateAck #138
                          Feb 2 10:51:31 mpd: [pt0] LCP: rec'd Terminate Request #10 link 0 (Stopping)

                          1 Reply Last reply Reply Quote 0
                          • S
                            sullrich
                            last edited by

                            Is that interface marked for DHCP?  It thinks that it is not.

                            1 Reply Last reply Reply Quote 0
                            • F
                              freax
                              last edited by

                              No, it's not.

                              No dhcp in vr0.
                              The dhcp on router is deactivated too.

                              Thanks in advance.

                              1 Reply Last reply Reply Quote 0
                              • S
                                sullrich
                                last edited by

                                Then I am confused… What is vr0?

                                1 Reply Last reply Reply Quote 0
                                • F
                                  freax
                                  last edited by

                                  The vr0 is the network interface of the firewall of our second link to workstations. It is connected to a router.

                                  1 Reply Last reply Reply Quote 0
                                  • S
                                    sullrich
                                    last edited by

                                    @freax:

                                    The vr0 is the network interface of the firewall of our second link to workstations. It is connected to a router.

                                    This makes the situation even more puzzling.  Why would it think that you are unplugging or plugging in vr0?!

                                    1 Reply Last reply Reply Quote 0
                                    • S
                                      sullrich
                                      last edited by

                                      Check your gmail account freax … I am working on this issue now and need your help.  I cannot guarantee when I'll have time or interest to work on it again so right now is your chance to get it solved!

                                      1 Reply Last reply Reply Quote 0
                                      • S
                                        sullrich
                                        last edited by

                                        Please test the latest snapshot if you are still having problems and post the logs.  I have added some debugging information.

                                        1 Reply Last reply Reply Quote 0
                                        • S
                                          Selective
                                          last edited by

                                          im using snapshot 02-02 and it still dosn´t work:

                                          Feb 3 00:46:20 dhclient[275]: exiting.
                                          Feb 3 00:46:20 dhclient[275]: exiting.
                                          Feb 3 00:46:20 dhclient[275]: short write: wanted 21 got 0 bytes
                                          Feb 3 00:46:20 dhclient[275]: short write: wanted 21 got 0 bytes
                                          Feb 3 00:46:20 dhclient[275]: DHCPACK from 90.224.168.1
                                          Feb 3 00:46:20 dhclient[275]: DHCPREQUEST on rl0 to 255.255.255.255 port 67

                                          1 Reply Last reply Reply Quote 0
                                          • F
                                            freax
                                            last edited by

                                            Hi again.

                                            I'm at 180 km from the firewall so I will test it monday.

                                            Thanks.

                                            1 Reply Last reply Reply Quote 0
                                            • First post
                                              Last post