DHCP changes IP address every 5 minutes

[idefix]

When I connect my Haiku computer to my Windows XP computer (with Internet Connection Sharing enabled), Haiku gets a new IP-address every 5 minutes. BeOS R5 (on the Haiku computer) doesn't show this behaviour.

The network card Haiku uses is a 3Com Etherlink XL 3C900B.

[idefix]

Normally this computer gets its IP from the ADSL-modem's DHCP-server, but it gives the same IP adddress every time. I still haven't found out how to get the modem to log DHCP requests...

[idefix]

Tested again on hrev27964, with RTL8139 network card.

DHCP requests captured on Windows XP with Wireshark. See 'Haiku DHCP requests (hrev27964).txt' (formatted the first couple of lines for readability).
(BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

Packet 259 shows the various DHCP-values. See 'Packet 259.txt'.

[idefix]

Wireshark log of DHCP requests by Haiku hrev27964. (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[idefix]

Details of packet 259, showing various DHCP values.

[idefix]

Tested also on the same computer with BeOS. See 'BeOS DHCP requests.txt' (let the computer running for 45 minutes).

[idefix]

Wireshark log of DHCP requests by BeOS. (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[axeld]

At least the renewal time looks good :-)

Is it possible that you provide more detailed packet data such as 259? It would be interesting to get a DHCP request + the corresponding ack packet for Haiku (when it tries to renew the lease), and BeOS. Thanks so far!

[idefix]

The first 25 minutes Haiku obeys the 5 minutes interval, but after that it uses an interval of 2 seconds. Tested with hrev28358:

Summary: 'Haiku hrev28358 summary.txt'
Details: 'Haiku hrev28358 details.txt'
Pcap: 'Haiku hrev28358.pcap'

[idefix]

Wireshark log of DHCP requests by Haiku hrev28358 (summary). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[idefix]

Wireshark log of DHCP requests by Haiku hrev28358 (details). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[idefix]

Wireshark log of DHCP requests by Haiku hrev28358 (pcap). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[idefix]

To compare with BeOS R5:

Summary: 'BeOS R5 summary.txt'
Details: 'BeOS R5 details.txt'
Pcap: 'BeOS R5.pcap'

[idefix]

Wireshark log of DHCP requests by BeOS R5 (summary). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer)

[idefix]

Wireshark log of DHCP requests by BeOS R5 (details). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer)

[idefix]

Wireshark log of DHCP requests by BeOS R5 (pcap). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer)

[idefix]

To compare with FreeBSD 7.0:

Summary: 'FreeBSD 7.0 summary.txt'
Details: 'FreeBSD 7.0 details.txt'
Pcap: 'FreeBSD 7.0.pcap'

[idefix]

Wireshark log of DHCP requests by FreeBSD 7.0 (summary).

[idefix]

Wireshark log of DHCP requests by FreeBSD 7.0 (details).

[idefix]

Wireshark log of DHCP requests by FreeBSD 7.0 (pcap).

[Adek336]

Would you care for debugging the problem by adding some diagnostic messages to the source code if I sent in a diff?

[idefix]

Sure, no problem.

[Adek336]

dhcp.1.diff: let's take a look at who calls DHCLient::DHCLient and DHCLient::_Negotiate.

If you haven't yet, please enable tracing:

mkdir build/user_config_headers
cp build/config_headers/tracing_config.h build/user_config_headers/

and edit build/user_config_headers/tracing_config.h so that you have "# define ENABLE_TRACING 1" instead of "# define ENABLE_TRACING 0".

[Adek336]

After rebooting and having Haiku send a few dhcp requests, please press F12 and type trac 0 80 and attach a screenshot of the result.

[idefix]

Unfortunately my computer (400 MHz PII, 64 MB) is not really up to the task of building Haiku, but specific components can be build.
Which jam targets should I build after enabling kernel tracing?

[Adek336]

These are kernel_x86 and net_server.

[Adek336]

Also apply the patch.

[axeld]

Did hrev28749 change anything?

[idefix]

Unfortunately, no. Tested with hrev28749:

Summary: 'Haiku hrev28749 summary.txt'
Details: 'Haiku hrev28749 details.txt'
Pcap: 'Haiku hrev28749.pcap'

[idefix]

Wireshark log of DHCP requests by Haiku hrev28749 (summary). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[idefix]

Wireshark log of DHCP requests by Haiku hrev28749 (details). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[idefix]

Wireshark log of DHCP requests by Haiku hrev28749 (pcap). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[idefix]

Replying to Adek336:

After rebooting and having Haiku send a few dhcp requests, please press F12 and type trac 0 80 and attach a screenshot of the result.

I must have done something wrong, as haiku hrev28749 won't send any DHCP request after enabling kernel tracing. The system is also behaving strange: slow booting; Tracker won't show the desktop-icons; ProcessController is not shown in the Desktop; applications won't start from the start menu. I think the amount of memory reserved for kernel tracing is a bit high for this machine.

'trac 0 80' gives:

kdebug> trac 0 80
    1. [    49]   63575839: user: DHCP: src/servers/net/NetServer.cpp: _BringUpInterfaces: 830
    2. [    49]   63575857: user: DHCP: src/servers/net/NetServer.cpp: _ConfigureInterface: 490
    3. [    49]   63993595: user: DHCP: src/servers/net/NetServer.cpp: _ConfigureInterface: 682
printed 3 entries within range 1 to 3 (3 of 3 total, 3 ever)

[idefix]

I think I found the culprit: MAX_TRACE_SIZE defaults to 20 MB.
I thought it was ​1 MB.

[idefix]

Setting MAX_TRACE_SIZE to 1 MB got it working:

Trace: 'Haiku hrev28749 v2 trace.txt'
Summary: 'Haiku hrev28749 v2 summary.txt'

[idefix]

Output of 'trac 0 80' in Haiku hrev28749.

[idefix]

Wireshark log of DHCP requests by Haiku hrev28749 (summary). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[Adek336]

Hah, 20 megs, that's the third of what you have, no wonder it didn't work very well :-)

So DHCP acks are sent, but _Negotiate loops many times trying to fetch one. Btw, how did you manage to save the trace output to a text file? I hope you didn't have to write it down by hand...

Attached is dhcp.2.diff, which will show what happens in the loop. You have to rebuild only the net_server target. Again, trac 0 80 is of interest.

[idefix]

I hope 'trac 0 200' is ok with you? (Why limit yourself to 80 if you can have it all?) :)

Trace: 'Haiku hrev28749 v3 trace.txt'
Summary: 'Haiku hrev28749 v3 summary.txt'

[...] Btw, how did you manage to save the trace output to a text file? I hope you didn't have to write it down by hand...

No, my null modem cable and HyperTerminal do all the hard work for me. :)

[idefix]

Output of 'trac 0 80' in Haiku hrev28749. (dhcp.2.diff applied)

[idefix]

Wireshark log of DHCP requests by Haiku hrev28749 (summary). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[Adek336]

Thanks! Replying to idefix:

I hope 'trac 0 200' is ok with you? (Why limit yourself to 80 if you can have it all?) :)

The more the merrier:)

It looks like it's getting an ACK but rejects it because it finds the value of "state" disheartening.

dhcp.3.diff dhcp.3.2.diff same files. They will trace the value of "state".

[Adek336]

Skip dhcp.3.diff, go for dhcp.4.diff.

[idefix]

Haiku hrev28749 with dhcp.4.diff applied:

Trace: 'Haiku hrev28749 v4 trace.txt'
Summary: 'Haiku hrev28749 v4 summary.txt'

[idefix]

Output of 'trac 0 500' in Haiku hrev28749. (dhcp.4.diff applied)

[idefix]

Wireshark log of DHCP requests by Haiku hrev28749 (summary). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[Adek336]

this line comes from _CurrentState:
        78. [    64]  709288070: user: DHCP: now 709288017, fLeaseTime 605209288055, fRebindingTime 454009288055, fRenewalTime 709288055
this line means we are supposed to get a new lease:
        79. [    64]  709288089: user: DHCP: src/servers/net/DHCPClient.cpp: MessageReceived: 888
this line should read "RENEWAL"
        80. [    64]  709288099: user: DHCP: state BOUND

It looks like if the message sent from _RestartLease comes ~30 usec early ("now 709288017" < "fRenewalTime 709288055); that sets "state" to BOUND, which _Negotiate doesn't handle very well.

patch.1.diff is proposed patch: send the message 1ms later
dhcp.5.diff is some new debugging code + proposed patch

Apply dhcp.5.diff so if the patch doesn't help, we get some debugging output.

[Adek336]

Use dhcp.5.2.diff, which includes the patch, instead of dhcp.5.diff which doesn't.

[idefix]

Looks like your patch fixed the bug.
Haiku hrev28749 with dhcp.5.2.diff applied:

Trace: 'Haiku hrev28749 v5 trace.txt'
Summary: 'Haiku hrev28749 v5 summary.txt'

[idefix]

Output of 'trac 0 500' in Haiku hrev28749. (dhcp.5.2.diff applied)

[idefix]

Wireshark log of DHCP requests by Haiku hrev28749 (summary). (BellTech_b5:d0:d1 is network card in 'Windows XP'-computer, SurecomT_52:3d:c3 is network card in Haiku-computer)

[Adek336]

That's great !

I wonder if it's acceptable for BMessageRunner to be early, isn't it supposed to guarantee not being early.

[Adek336]

Hello, it looks like BMessageRunner is all well and the problem is that fRenewalTime is fed with system_time() after registering a BMessageRunner which makes the message come early in comparison to fRenewalTime.

Please revert DHCPClient.cpp and then apply patch-dhcp.2.diff, I'm pretty sure that this will help, and we'll call it a day !

[idefix]

patch-dhcp.2.diff also fixed the bug. Thanks for fixing!

Can't upload any logs as Trac is broken.

[Adek336]

Can this patch be commited now?

[anevilyak]

Assuming no one beats me to it, I can commit once I'm back home friday evening. Sorry this sort of slipped under the radar!

[anevilyak]

Applied in hrev28817, thanks!