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

ThomasF · Mar 8, 2007, 9:23 PM

It seems to be working just fine now, thanks!

freax · Mar 9, 2007, 6:17 PM

I've done a clean install with the latest official update from 08/03/2007 but my logs registeres the following rc.linkup message:

Last 50 system log entries
Mar 9 18:13:30 php: : Incorrect number of arguments passed rc.linkup…exiting.
Mar 9 18:13:30 php: : Arguments passed rc.linkup. ''
Mar 9 18:13:28 check_reload_status: rc.linkup starting
Mar 9 18:13:23 php: : phpDynDNS: No Change In My IP Address and/or 25 Days Has Not Past. Not Updating Dynamic DNS Entry.

It's normal ?

[]'s

sullrich · Mar 9, 2007, 6:29 PM

Yes, those are debugging statements and looks fine.

Krakke · Mar 12, 2007, 7:32 AM

1.0.1-SNAPSHOT-02-27-2007
Uptime 7 days, 16:51

Still running, updating to pfSense-Full-Update-1.0.1-SNAPSHOT-03-08-2007

sullrich · Mar 12, 2007, 6:37 PM

@Krakke:

1.0.1-SNAPSHOT-02-27-2007
Uptime 7 days, 16:51

Still running, updating to pfSense-Full-Update-1.0.1-SNAPSHOT-03-08-2007

Great! Thanks for the update.

Veni · Mar 13, 2007, 1:27 PM

Don't know if this is the same issue, but i noticed this yesterday.
Running 1.0.1-SNAPSHOT-03-18-2007 built on Thu Mar 8 22:14:44 EST 2007.

For some unknown reason, my pfSense box lost it's WAN dhcp ipaddress, but my
WatchGuard box connected to the same ISP outlet(i use a switch to get several ports)
did not have any problems recorded, and it to runs on a WAN dhcp. The WatchGuard box
uses something called udhcpc. I don't know if it's better, worse or the same as dhclient.

Pressing the Renew button in Status–>Interfaces had no problem of getting a ipaddress.
I pressed the button around 20:15.

Got this from the syslog(if was not at home when this happened):

| Mar 12 17:35:24 dhclient[261]: DHCPREQUEST on xl1 to 81.228.3.186 port 67 |
| Mar 12 17:41:13 last message repeated 3 times |
| Mar 12 17:44:02 dhclient[261]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 6 |
| Mar 12 17:44:02 dhclient[261]: DHCPOFFER from 81.236.128.1 |
| Mar 12 17:44:04 dhclient[261]: DHCPREQUEST on xl1 to 255.255.255.255 port 67 |
| Mar 12 17:44:04 dhclient[261]: DHCPACK from 81.236.128.1 |
| Mar 12 17:44:04 dhclient[261]: bound to 81.236.134.30 – renewal in 600 seconds. |
| Mar 12 17:44:34 SnortStartup[55432]: Ram free BEFORE starting Snort: 108M – Ram free AFTER starting Snort: 107M -- Mode ac-sparsebands -- Snort memory usage: |
| Mar 12 17:44:51 SnortStartup[55465]: Ram free BEFORE starting Snort: 107M – Ram free AFTER starting Snort: 108M -- Mode ac-sparsebands -- Snort memory usage: |
| Mar 12 17:54:04 dhclient[261]: DHCPREQUEST on xl1 to 81.228.3.186 port 67 |
| Mar 12 17:54:43 last message repeated 3 times |
| Mar 12 17:56:45 last message repeated 7 times |
| Mar 12 18:00:44 last message repeated 9 times |
| Mar 12 18:01:39 dnsmasq[572]: reading /etc/resolv.conf |
| Mar 12 18:01:39 dnsmasq[572]: using nameserver 195.67.199.41#53 |
| Mar 12 18:01:39 dnsmasq[572]: using nameserver 195.67.199.40#53 |
| Mar 12 18:01:39 dnsmasq[572]: using nameserver 195.67.199.39#53 |
| Mar 12 18:02:17 dhclient[261]: DHCPREQUEST on xl1 to 255.255.255.255 port 67 |
| Mar 12 18:02:17 dhclient[261]: DHCPACK from 81.236.128.1 |
| Mar 12 18:02:17 dhclient[261]: short write: wanted 21 got 0 bytes |
| Mar 12 18:02:17 dhclient[261]: exiting. |
| Mar 12 20:13:17 login: login on ttyv0 as root |
| Mar 12 20:15:57 dhclient[81132]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 5 |
| Mar 12 20:16:02 dhclient[81132]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 6 |
| Mar 12 20:16:08 dhclient[81132]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 7 |
| Mar 12 20:16:08 dhclient[81132]: DHCPOFFER from 81.236.128.1 |
| Mar 12 20:16:10 dhclient[81132]: DHCPREQUEST on xl1 to 255.255.255.255 port 67 |
| Mar 12 20:16:10 dhclient[81132]: DHCPACK from 81.236.128.1 |
| Mar 12 20:16:10 dhclient[81132]: bound to 81.236.134.30 – renewal in 600 seconds. |

sullrich · Mar 13, 2007, 7:53 PM

Remove snort and see if the problem persists.

Selective · Mar 14, 2007, 1:27 PM

removing snort won´t change a thing, he got the same error i do,and i don´t use snort. And as i said it only happens one time after reboot, pressing the renew button clears the problem.

the dhclient error is not fixed !

Veni · Mar 14, 2007, 2:48 PM

I removed Snort a couple of hours ago, and will give it a go
try to reproduce the issue by rebooting the pfSense computer
and not reinstalling Snort for a while.

sullrich · Mar 14, 2007, 7:35 PM

@Selective:

removing snort won´t change a thing, he got the same error i do,and i don´t use snort. And as i said it only happens one time after reboot, pressing the renew button clears the problem.

the dhclient error is not fixed !

Calm down there pal. Snort gets RELOADED at the same time that dhclient invokes… So you don't know what your talking about quite frankly.

Veni · Mar 15, 2007, 7:37 AM

Alright, it happened again a couple of minutes ago.
Pressing the Renew button gave me back my ipaddress within 5 seconds.
Checked traffic on my WatchGuard box and it did not record any problem with the internet.

I pressed the Renew button around 08:27.

This is what i have from syslog:

Mar 15 07:00:57 last message repeated 4 times
Mar 15 07:01:30 dhclient[269]: DHCPREQUEST on xl1 to 255.255.255.255 port 67
Mar 15 07:01:30 dhclient[269]: DHCPACK from 81.236.128.1
Mar 15 07:01:31 dhclient[269]: bound to 81.236.134.30 – renewal in 600 seconds.
Mar 15 07:11:30 dhclient[269]: DHCPREQUEST on xl1 to 81.228.3.186 port 67
Mar 15 07:12:01 last message repeated 3 times
Mar 15 07:14:07 last message repeated 4 times
Mar 15 07:18:51 last message repeated 12 times
Mar 15 07:19:58 dhclient[269]: DHCPREQUEST on xl1 to 255.255.255.255 port 67
Mar 15 07:19:58 dhclient[269]: DHCPACK from 81.236.128.1
Mar 15 07:19:59 dhclient[269]: bound to 81.236.134.30 – renewal in 600 seconds.
Mar 15 07:29:58 dhclient[269]: DHCPREQUEST on xl1 to 81.228.3.186 port 67
Mar 15 07:30:26 last message repeated 2 times
Mar 15 07:32:35 last message repeated 4 times
Mar 15 07:36:11 last message repeated 3 times
Mar 15 07:39:59 dhclient[269]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 7
Mar 15 07:40:06 dhclient[269]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 15
Mar 15 07:40:06 dhclient[269]: DHCPOFFER from 81.236.128.1
Mar 15 07:40:08 dhclient[269]: DHCPREQUEST on xl1 to 255.255.255.255 port 67
Mar 15 07:40:08 dhclient[269]: DHCPACK from 81.236.128.1
Mar 15 07:40:08 dhclient[269]: bound to 81.236.134.30 – renewal in 600 seconds.
Mar 15 07:42:02 dnsmasq[529]: reading /etc/resolv.conf
Mar 15 07:42:02 dnsmasq[529]: using nameserver 195.67.199.41#53
Mar 15 07:42:02 dnsmasq[529]: using nameserver 195.67.199.40#53
Mar 15 07:42:02 dnsmasq[529]: using nameserver 195.67.199.39#53
Mar 15 07:50:08 dhclient[269]: DHCPREQUEST on xl1 to 81.228.3.186 port 67
Mar 15 07:50:38 last message repeated 3 times
Mar 15 07:52:41 last message repeated 5 times
Mar 15 07:55:06 dhclient[269]: DHCPREQUEST on xl1 to 81.228.3.186 port 67
Mar 15 08:00:10 dhclient[269]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 3
Mar 15 08:00:10 dhclient[269]: DHCPOFFER from 81.236.128.1
Mar 15 08:00:12 dhclient[269]: DHCPREQUEST on xl1 to 255.255.255.255 port 67
Mar 15 08:00:12 dhclient[269]: DHCPACK from 81.236.128.1
Mar 15 08:00:12 dhclient[269]: bound to 81.236.134.30 – renewal in 600 seconds.
Mar 15 08:01:33 dnsmasq[529]: reading /etc/resolv.conf
Mar 15 08:01:33 dnsmasq[529]: using nameserver 195.67.199.41#53
Mar 15 08:01:33 dnsmasq[529]: using nameserver 195.67.199.40#53
Mar 15 08:01:33 dnsmasq[529]: using nameserver 195.67.199.39#53
Mar 15 08:10:12 dhclient[269]: DHCPREQUEST on xl1 to 81.228.3.186 port 67
Mar 15 08:10:33 last message repeated 2 times
Mar 15 08:11:41 last message repeated 4 times
Mar 15 08:15:34 last message repeated 2 times
Mar 15 08:20:13 dhclient[269]: short write: wanted 22 got 0 bytes
Mar 15 08:20:13 dhclient[269]: exiting.
Mar 15 08:27:37 dhclient[68835]: DHCPDISCOVER on xl1 to 255.255.255.255 port 67 interval 8
Mar 15 08:27:37 dhclient[68835]: DHCPOFFER from 81.236.128.1
Mar 15 08:27:39 dhclient[68835]: DHCPREQUEST on xl1 to 255.255.255.255 port 67
Mar 15 08:27:39 dhclient[68835]: DHCPACK from 81.236.128.1
Mar 15 08:27:40 dhclient[68835]: bound to 81.236.134.30 – renewal in 600 seconds.
Mar 15 08:27:42 login: login on ttyv0 as root
Mar 15 08:28:03 dnsmasq[529]: reading /etc/resolv.conf
Mar 15 08:28:03 dnsmasq[529]: using nameserver 195.67.199.41#53
Mar 15 08:28:03 dnsmasq[529]: using nameserver 195.67.199.40#53
Mar 15 08:28:03 dnsmasq[529]: using nameserver 195.67.199.39#53

sullrich · Mar 15, 2007, 4:19 PM

We REALLY wish that we could reproduce this… Everything we have tried does not reproduce it :(

Veni · Mar 16, 2007, 1:17 PM

Is there a way of asking dhclient to produce more info for debugging purposes?
I would glady run it in a mode like that :).

I don't really know what short write is, but from the looks of it, is it possible
to alter dhclient so that it does not invoke a shutdown of it self when the
short write event occurs?

??? What is short write?
??? What is the criteria for triggering that kind of response from the dhclient?

Selective, it would be interesting to know what country you are from and what
ISP you are using plus what type of physical connection the ISP delivers to you.

My ISP is TeliaSonera in Sweden and they deliver my internetaccess to a standard
RJ45 LAN Cat5(e?) port.

Selective · Mar 16, 2007, 3:39 PM

im using telia as well, but through ADSL.

The strange thing is that it only happens once, after reboot, so it must be something wrong with boot process..

sullrich · Mar 16, 2007, 4:11 PM

I doubt it has anything to do with the boot sequence.

Short writes in this case is the privilege separation code. This appears to be a deep FreeBSD bug of some sort.

Krakke · Mar 19, 2007, 9:11 PM

sullrich thank you :D

Version 1.0.1-SNAPSHOT-03-08-2007
Uptime 7 days, 13:06

Still running! Time to close this thread?

Ethernet connection 100/10 megabits (ISP BBB Sweden)

my own little world http://www.krakke.com/bilder/serverrum/IMG_6725_th_ex.jpg ;)

UrbanSk · Mar 20, 2007, 7:38 AM

Hi all!

I just jumped in to this tread as i experience the same problem.
After a reboot the wan interface looses its IP-adress. A renew fixes it until the next reboot.

My version:
1.0.1-SNAPSHOT-03-08-2007
built on Sat Mar 10 00:05:34 EST 2007

Selective and Veni uses Telia as ISP just as i am.

Can the problem be related to our ISP hense you can not reproduce the problem.

My knowledge of FreeBSD is limited but I will assist in any way I can if needed.

Found some new information on this link:

http://www.clavister.com/support/kb/10078/

Regards,

UrbanSk

sullrich · Mar 20, 2007, 2:54 PM

Maybe one of you (or all) can call the ISP and ask them what is going on.

sai · Mar 22, 2007, 5:26 PM

from the Clavister site:

Symptom:
The firewall fails to receive an IP address from DHCP.

Note: The swedish ISP Telia has some servers that causes problems with the default settings. Changing the settings to the following is known to work in those cases:
DHCP_MinimumLeaseTime 60
DHCP_ValidateBcast NO
DHCP_AllowGlobalBcast YES
DHCP_UseLinkLocalIP NO
DHCP_DisableArpOnOffer NO

Veni · Mar 23, 2007, 12:32 PM

This is what i found about the options mentioned above:

DHCP_MinimumLeaseTime
Minimum lease time (seconds) accepted from the DHCP server.

Default: 60

DHCP_ValidateBcast
Require that the assigned broadcast address is the highest address in the assigned network

Default: Enabled

DHCP_AllowGlobalBcast
Allow DHCP server to assign 255.255.255.255 as broadcast. (Non-standard.)

Default: Disabled

DHCP_UseLinkLocalIP
If this is enabled the firewall will use a Link Local IP (169.254..) instead of 0.0.0.0 while waiting for a lease.

Default: Disabled

DHCP_DisableArpOnOffer
Disable the arp check done by the firewall on the offered IP.

DHCP client can now be configured to not check for IP conflicts
Issue: The DHCP client normally checks if the IP address in an offer is already taken on the local network by performing an ARP query for it. However, some routers may ARP publish IP addresses while the DHCP transaction is running and cause false positives. One such example is the Clavister Firewall DHCP relayer before v8.30.01, in certain configurations. There are also others.
Change: As of v8.30.01, the DHCP client can be configured to not check for IP conflicts in offered leases via "Advanced Settings" -> "DHCP" -> "DHCP_DisableArpOnOffer".

Default: Disabled

The default settings in advanced settings->DHCP client is following:
DHCP_MinimumLeaseTime 60
DHCP_ValidateBcast YES
DHCP_AllowGlobalBcast NO
DHCP_UseLinkLocalIP NO
DHCP_DisableArpOnOffer NO

However. To have the firewall accept uncommon IP offers you might have to make adjustments on the settings.
DHCP_MinimumLeaseTime 60
DHCP_ValidateBcast NO
DHCP_AllowGlobalBcast YES
DHCP_UseLinkLocalIP NO
DHCP_DisableArpOnOffer YES

And then there is the one that sai posted about Clavister and TeliaSonera.