* Received DHCP Message is not OFFER

[bytelinker]

Hi dherrada,
with
adafruit-circuitpython-grandcentral_m4_express-en_US-5.3.0.uf2 and
adafruit-circuitpython-grandcentral_m4_express-en_US-5.4.0-beta.0.uf2

I run:
import board
import busio
from digitalio import DigitalInOut
from adafruit_wiznet5k.adafruit_wiznet5k import WIZNET5K
import adafruit_wiznet5k.adafruit_wiznet5k_socket as socket
import adafruit_requests as requests
cs = DigitalInOut(board.D10)
spi_bus = busio.SPI(board.SCK, MOSI=board.MOSI, MISO=board.MISO)

Initialize ethernet interface with DHCP

eth = WIZNET5K(spi_bus, cs,is_dhcp=True,debug=True)

I get

• Received DHCP Message is not OFFER,
  and
• DNS ERROR: Invalid flags, 33155
• DNS ERROR: Failed to resolve DNS response, retrying...
• socket_available called with protocol 2
• socket_available called with protocol 2

But the adafruit_wiznet5k answers ping.

On DNS server (Windows Server 2008R2) I get:
11,05/22/20,14:07:52,renew,10.70.74.45,WIZnetÌ¡¥´¦¦.xxxx.local,DEADCDEFFEED,,2701393920,0,,,

There shouldn't be the non ascii symbols (tÌ¡¥´¦¦).

It would be great if the hostname could be set to custom values.
eth = WIZNET5K(spi_bus, cs,is_dhcp=True,debug=True,hostname='mydevice')

Where to find the documentation, to set the config for static IP, DNS, Route, Subnet mask, please?

Regards bytelinker

[brentru]

There shouldn't be the non ascii symbols (tÌ¡¥´¦¦).

Hm, I didn't see them on my Wireshark capture. Could you provide more info?

Where to find the documentation, to set the config for static IP, DNS, Route, Subnet mask, please?

This example (https://github.com/adafruit/Adafruit_CircuitPython_Wiznet5k/blob/master/examples/wiznet5k_simpletest_manual_network.py) allows you to set a static IP, DNS server, gateway address and subnet mask.

It would be great if the hostname could be set to custom values.
eth = WIZNET5K(spi_bus, cs,is_dhcp=True,debug=True,hostname='mydevice')

Agreed, please open a separate issue for this feature if you'd like to see it implemented.

[bytelinker]

The DHCP server is running W2008R2 German. It could be a problem of encoding. But this was not seen from many different clients.

[xorbit]

I get something similar.

MAC address: 04:91:62:c7:a1:b5
* Initializing DHCP
*** Get socket
Allocated socket #0
* w5k socket connect, protocol=2, port=67, ip=255.255.255.255
*** Opening socket 0
* Opening W5k Socket, protocol=2
* DHCP: Discover
* DHCP: Parsing OFFER
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* socket_available called with protocol 2
* Received DHCP Message is not OFFER
*** Closing socket #0
Done!

Is it possible to add a debug print to show WHAT message is coming back?

Oddly, in my case, this happens the first time a DHCP request is done, and the next try I do get an address.

[brentru]

@xorbit Odd that it works the second time.

Is it possible to add a debug print to show WHAT message is coming back?

Yes - the adafruit_wiznet5k's set_dhcp method passes the wiznet object's debug parameter to the dhcp class (https://github.com/adafruit/Adafruit_CircuitPython_Wiznet5k/blob/master/adafruit_wiznet5k/adafruit_wiznet5k.py#L188). You'd need to enable debugging on the wiznet5k module by doing: eth = WIZNET5K(spi_bus, cs, debug=True). DHCP should print the current DHCP state as well as the parsed response to the REPL.

[xorbit]

The log above was with the debug=True parameter set. It only seems to report it received something that's not an OFFER reply, but it doesn't say what reply it did receive.

Since the code you linked to was last updated on April 9, I'm pretty sure that's what I'm running.

I'm handling the problem at the moment with the following code:

dhcp_retries = 3
while dhcp_retries:
  try:
    eth = WIZNET5K(spi_bus, cs, debug=True)
    break
  except:
    dhcp_retries = dhcp_retries - 1
if not dhcp_retries:
  print("Failed to get IP address from DHCP")

It's kind of a kludge I'd rather avoid, but it seems to solve my problem for now.

[brentru]

@xorbit It should print out the subnet mask, gateway ip, etc (https://github.com/adafruit/Adafruit_CircuitPython_Wiznet5k/blob/master/adafruit_wiznet5k/adafruit_wiznet5k_dhcp.py#L332) along with the contents of the buffer received by the socket (https://github.com/adafruit/Adafruit_CircuitPython_Wiznet5k/blob/master/adafruit_wiznet5k/adafruit_wiznet5k_dhcp.py#L250).

Could you drop the if self._debug and adjust the code to simply print at those locations? It could be attempting to parse an offer packet incorrectly the first time, I'm curious what it's receiving back from the router.

[xorbit]

Ok, I think I got to the bottom of this.

The print at line 250 never gets executed because the problem is a timeout. The code calls parse_dhcp_response with response_timeout = 1 and quits before a response is received. A 1 second timeout is just too short for my DHCP server it seems.

The timeout setting throughout the call chain seems to be a mess actually. The DHCP object has both a timeout and timeout_response, timeout_response sets self._response_timeout which is actually never used. timeout sets self._timeout, which is then used as the parameter to parse_dhcp_response's response_timeout parameter.

Higher up the chain, the DHCP constructor is called with a response_timeout variable actually setting the timeout parameter, set_dhcp has a default for response_timeout of 1 second, and is called without parameter, leaving this default value in place.

Bottom line is that the DHCP expects a response in 1 second, and there is no way for the user to override this.

[brentru]

@xorbit Ok, thanks for taking a deep dive into this.

timeout_response sets self._response_timeout which is actually never used.

Ok, this is confusing.. Let's keep the response_timeout variable consistent from the DHCP constructor -> the DHCP object and rename the timeouttoresponse_timeout. We would also need to remove the unused _response_timeout` parameter as well.

Bottom line is that the DHCP expects a response in 1 second, and there is no way for the user to override this.
Since DHCP occurs "automatically", would be you want to create a PR adding a response_timeout to the wiznet5k's kwargs?

If not, I'll assign myself and make a PR

[xorbit]

Created a PR.
Not sure why CI fails on formatting.

[xorbit]

DHCP timeout and hostname fixed plus made settable in my pull request #20.

[evaherrada]

hi @bytelinker it looks like @brentru and @xorbit have already handled this, and I probably wouldn't have been much help anyway since I don't really know a whole lot about this and I was out most of last week, but if you tag someone using an @ sign, it'll send them a notification that they've been mentioned. I get a lot of emails from github, and tend to just kind of skim through the ones I wasn't assigned or wasn't mentioned in.