[w5500] DHCP hang and IndexError on static ip's.

[bill88t]

Using this as a man-in-the-middle driver. With 5f501fd0fc73c1459d6fe9ba3c9ca0d789dd68fc loaded on the board.

The w5500 device I am using is a rando external w5500 i found for cheap: (kapton tape on the bottom for safety)

With dhcp:

Adafruit CircuitPython 7.3.3 on 2022-08-29; Raspberry Pi Pico with rp2040
>>> import board
>>> from drivers.driver_w5500spi import driver_w5500spi
>>> a = driver_w5500spi()
>>> a.connect(board.GP11, board.GP12, board.GP10, board.GP13, debug=True)
w5500spi: cs&spi created
My Link is: 0
My Link is: 0
My Link is: 0
My Link is: 0
My Link is: 0
* Initializing DHCP
(hang forever)

Without dhcp:

Adafruit CircuitPython 7.3.3 on 2022-08-29; Raspberry Pi Pico with rp2040
>>> import board
>>> from drivers.driver_w5500spi import driver_w5500spi
>>> a = driver_w5500spi()
>>> a.connect(board.GP11, board.GP12, board.GP10, board.GP13, ip="192.168.1.240", gateway="192.168.1.1", dns="192.168.1.230", debug=True)
w5500spi: cs&spi created
My Link is: 0
My Link is: 0
My Link is: 0
My Link is: 0
My Link is: 0
w5500spi: Interface created
w5500spi: Interface detection done (w5500)
w5500spi: Link ok
* Initializing DHCP
*** Get socket
Allocated socket #4
* Listening on port=68, ip=0.0.0.0
*** Opening socket 4
* Opening W5k Socket, protocol=2
* w5k socket connect, protocol=2, port=67, ip=255.255.255.255
*** Opening socket 4
* Opening W5k Socket, protocol=2
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "driver_w5500spi", line 1, in connect
  File "adafruit_wiznet5k", line 1, in set_dhcp
  File "adafruit_wiznet5k_dhcp", line 1, in request_dhcp_lease
  File "adafruit_wiznet5k_dhcp", line 1, in _dhcp_state_machine
  File "adafruit_wiznet5k_socket", line 1, in connect
  File "adafruit_wiznet5k", line 1, in socket_connect
IndexError: list index out of range
>>>

Same on cp 8.0-latest.

[anecdata]

Can you reproduce this without the intervening driver? That would make it easier for others to replicate and debug.

[bill88t]

I disabled mpy-cross optimization and it now produces different results:

With dhcp it actually works now:

>>> import board
>>> from adafruit_wiznet5k.adafruit_wiznet5k import WIZNET5K
>>> import adafruit_wiznet5k.adafruit_wiznet5k_socket as socket
>>> from digitalio import DigitalInOut
>>> from busio import SPI
>>> cs = DigitalInOut(board.GP13)
>>> spi = SPI(clock=board.GP10, MOSI=board.GP11, MISO=board.GP12)
>>> interface = WIZNET5K(spi, cs, is_dhcp=True, debug=True)
* Initializing DHCP
*** Get socket
Allocated socket #0
* Listening on port=68, ip=0.0.0.0
*** Opening socket 0
* Opening W5k Socket, protocol=2
* w5k socket connect, protocol=2, port=67, ip=255.255.255.255
*** Opening socket 0
* Opening W5k Socket, protocol=2
* DHCP: Send discover to (255, 255, 255, 255)
* socket_available called on socket 0, protocol 2
Bytes avail. on sock:  308
         * Processing 8 bytes of data
* DHCP: Parsing OFFER
* socket_available called on socket 0, protocol 2
Bytes avail. on sock:  300
         * Processing 300 bytes of data
DHCP Response:  b'\x02\x01\x06\x00\xb7\x16T\x1e\x00\x00\x80\x00\x00\x00\x00\x00\xc0\xa8\x01W\xc0\xa8\x01\xe6\x00\x00\x00\x00\xde\xad\xbe\xef\xfe\xed\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00c\x82Sc5\x01\x026\x04\xc0\xa8\x01\xe63\x04\x00\t:\x80:\x04\x00\x04\x9d@;\x04\x00\x08\x130\x01\x04\xff\xff\xff\x00\x1c\x04\xc0\xa8\x01\xff\x06\x04\xc0\xa8\x01\xe6\x0f\x03lan\x03\x04\xc0\xa8\x01\x01\xff\x00\x00\x00'
Msg Type: 2
Subnet Mask: (255, 255, 255, 0)
DHCP Server IP: (192, 168, 1, 230)
DNS Server IP: (192, 168, 1, 230)
Gateway IP: (192, 168, 1, 1)
Local IP: (192, 168, 1, 87)
T1: 302400
T2: 529200
Lease Time: 604800
* DHCP: Send request to (192, 168, 1, 230)
* socket_available called on socket 0, protocol 2
Bytes avail. on sock:  308
         * Processing 8 bytes of data
* DHCP: Parsing ACK
* socket_available called on socket 0, protocol 2
Bytes avail. on sock:  300
         * Processing 300 bytes of data
DHCP Response:  b'\x02\x01\x06\x00\xb8\x16T\x1e\x00\x00\x80\x00\x00\x00\x00\x00\xc0\xa8\x01W\xc0\xa8\x01\xe6\x00\x00\x00\x00\xde\xad\xbe\xef\xfe\xed\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00c\x82Sc5\x01\x056\x04\xc0\xa8\x01\xe63\x04\x00\t:\x80:\x04\x00\x04\x9d@;\x04\x00\x08\x130\x01\x04\xff\xff\xff\x00\x1c\x04\xc0\xa8\x01\xff\x06\x04\xc0\xa8\x01\xe6\x0f\x03lan\x03\x04\xc0\xa8\x01\x01\xff\x00\x00\x00'
Msg Type: 5
Subnet Mask: (255, 255, 255, 0)
DHCP Server IP: (192, 168, 1, 230)
DNS Server IP: (192, 168, 1, 230)
Gateway IP: (192, 168, 1, 1)
Local IP: (192, 168, 1, 87)
T1: 302400
T2: 529200
Lease Time: 604800
* DHCP: Successful lease
*** Closing socket #0
* Found DHCP Server:
IP: bytearray(b'\xc0\xa8\x01W')
Subnet Mask: bytearray(b'\xff\xff\xff\x00')
GW Addr: bytearray(b'\xc0\xa8\x01\x01')
DNS Server: (192, 168, 1, 230)

(skipping stuff)

Bytes avail. on sock:  29
         * Processing 29 bytes of data
This is a test of Adafruit WiFi!
If you can read this, its working :)
>>> r.close()
>>>

However manual still is broken:

Adafruit CircuitPython 7.3.3 on 2022-08-29; Raspberry Pi Pico with rp2040
>>> import board
>>> from adafruit_wiznet5k.adafruit_wiznet5k import WIZNET5K
>>> import adafruit_wiznet5k.adafruit_wiznet5k_socket as socket
>>> from digitalio import DigitalInOut
>>> from busio import SPI
>>> cs = DigitalInOut(board.GP13)
>>> spi = SPI(clock=board.GP10, MOSI=board.GP11, MISO=board.GP12)
>>> interface = WIZNET5K(spi, cs, is_dhcp=False, debug=True)
>>> print(interface.detect_w5500())
1   
>>> print(interface.link_status)
1   
>>> interface.ifconfig = ((192, 168, 1, 87), (255, 255, 255, 0), (192, 168, 1, 1), (192, 168, 1, 230))
>>> import adafruit_requests as requests
>>> requests.set_socket(socket, interface)
>>> r = requests.get("http://wifitest.adafruit.com/testwifi/index.html")
* Get host by name
*** Get socket
Allocated socket #0
* Listening on port=53, ip=192.168.1.87
*** Opening socket 0
* Opening W5k Socket, protocol=2
* w5k socket connect, protocol=2, port=53, ip=192.168.1.230
*** Opening socket 0
* Opening W5k Socket, protocol=2
* DNS: Sending request packet...
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* socket_available called on socket 0, protocol 2
* DNS ERROR: Did not receive DNS response!
* DNS ERROR: Failed to resolve DNS response, retrying...
(loops forever)

Tried with dns being 1.1.1.1, 192.168.1.1 (ip -> isp's), 192.168.1.230 (trustworthy pihole)

[anecdata]

Replicated on Adafruit CircuitPython 8.0.0-beta.0 on 2022-08-18; W5500-EVB-Pico with rp2040 & library using fix from #64 with:

import board
import busio
import digitalio
from adafruit_wiznet5k.adafruit_wiznet5k import WIZNET5K
import adafruit_wiznet5k.adafruit_wiznet5k_socket as socket
import adafruit_requests as requests

SPI0_SCK = board.GP18
SPI0_TX = board.GP19
SPI0_RX = board.GP16
SPI0_CSn = board.GP17
W5x00_RSTn = board.GP20

spi = busio.SPI(SPI0_SCK, MOSI=SPI0_TX, MISO=SPI0_RX)
cs = digitalio.DigitalInOut(SPI0_CSn)

interface = WIZNET5K(spi, cs, is_dhcp=False, debug=True)
print(interface.detect_w5500())
print(interface.link_status)
interface.ifconfig = ((192, 168, 6, 249), (255, 255, 252, 0), (192, 168, 4, 1), (1, 1, 1, 1))
requests.set_socket(socket, interface)
r = requests.get("http://wifitest.adafruit.com/testwifi/index.html")
print(r.status_code, r.reason, r.content)

The device does not show up in the router.

Output (ends with exception rather than infinite loop): w5500 output.txt

[bill88t]

I am very concerned as to why it broke even more when it was optimized.. A lot of the debug texts were missing too..

[BiffoBear]

Replicated on Adafruit CircuitPython 8.0.0-beta.0 on 2022-08-18; W5500-EVB-Pico with rp2040 & library using fix from #64 with: print(interface.detect_w5500())

Calling detect_w5500 resets the W5500 chip (as does detect_w5100s). The code runs fine for me if I comment out this line. This function shouldn't be public.

[anecdata]

@bill88t Can you re-test and confirm the code from PR 81 solves this issue?

[bill88t]

Really busy these days, I will try to get it tested by tomorrow.

[bill88t]

Retested with latest commit. Using Anecdata's code snippet.

The results differ is the module has been .mpy'ed with optimisations.

Files as .mpy:

By editing is_dhcp=True it's still a hang.

With is_dhcp=False and using interface.set_dhcp() we get a nice IndexError. And Trying the snippet 'as is' (ip's changed) results to:

>>> r = requests.get("http://wifitest.adafruit.com/testwifi/index.html")
* Get host by name
*** Get socket
Allocated socket #0
* Listening on port=53, ip=192.168.1.249
*** Opening socket 0
* Opening W5k Socket, protocol=2
* w5k socket connect, protocol=2, port=53, ip=1.1.1.1
*** Opening socket 0
* Opening W5k Socket, protocol=2
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "adafruit_requests", line 1, in get
  File "adafruit_requests", line 1, in request
  File "adafruit_requests", line 1, in _get_socket
  File "adafruit_wiznet5k_socket", line 1, in getaddrinfo
  File "adafruit_wiznet5k_socket", line 1, in gethostbyname
  File "adafruit_wiznet5k", line 1, in get_host_by_name
  File "adafruit_wiznet5k_dns", line 1, in gethostbyname
  File "adafruit_wiznet5k_socket", line 1, in connect
  File "adafruit_wiznet5k", line 1, in socket_connect
IndexError: index out of range

The device is responding to pings just fine through that ip though.

Trying without .mpy'ing them (just the whole folder copied over):

On is_dhcp=False:

>>> r = requests.get("http://wifitest.adafruit.com/testwifi/index.html")
* Get host by name
*** Get socket
Allocated socket #1
* Listening on port=53, ip=192.168.1.249
*** Opening socket 1
* Opening W5k Socket, protocol=2
* w5k socket connect, protocol=2, port=53, ip=1.1.1.1
*** Opening socket 1
* Opening W5k Socket, protocol=2
* DNS: Sending request packet...
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* socket_available called on socket 1, protocol 2
* DNS ERROR: Did not receive DNS response!
* DNS ERROR: Failed to resolve DNS response, retrying...

Loops forever.

is_dhcp=True:

It actually worked!

So something is definately wrong with optimisation and static ip's are still broken.

[bill88t]

Oh wait #81, that isn't merged, I tested latest commit, brb.

[bill88t]

Both static and dhcp work with #81, with .py. With optimised .mpy's: On dhcp it's yet again a hang and on static RuntimeError: Failed to allocate socket. during the requests.get detect_w5500 is also gone.

[anecdata]

.chip will get the chip type (5100S vs. 5500)

Can you describe the .mpy optimization process?

[bill88t]

To sum it up ./mpy-cross source.py -s name -v -O3 -o destination.mpy Though I use scripts to automate it.

[anecdata]

Using the 8.x-mpy build artifacts from PR 81 with a WIZnet W5100s hat (chip detect changed to print(eth.chip), and looping requests):

Adafruit CircuitPython 8.0.0-beta.5 on 2022-12-08; Adafruit QT Py ESP32S2 with ESP32S2
>>> 

Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.
code.py output:
w5100s
1
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'

# etc...

I'll try it with a W5500...

[anecdata]

An mpy-cross optimization bug, rather than a PR 81 bug?

[bill88t]

Oh I didnt see it has mpy build artifacts, I will try them tomorrow for verification. It could be a matter of -O3.

[anecdata]

Same 8.x-mpy artifacts and code, with Adafruit Ethernet FeatherWing:

Adafruit CircuitPython 8.0.0-beta.4 on 2022-10-30; Adafruit Feather RP2040 with rp2040
>>> 

Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.
code.py output:
w5500
1
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'
200 bytearray(b'OK') b'This is a test of Adafruit WiFi!\nIf you can read this, its working :)'

# etc...

[bill88t]

Everything works for me too with the 8.x-mpy build artifacts.

By further testing I determined that optimisation level >0 is what breaks it. Even -O1 is enough to cause the issues previously stated. However, if I mpy-cross them without any optimisation they work just the same as the artifacts.

So the remaining issues are due to mpy-cross. A new issue should be created in the circuitpython repo.

[jepler]

Using any nonzero -O level with mpy-cross causes Python assert statements to not be included.

This is not compatible with the way that wiznet5k uses assert statements, because it depends on the assert statement's expression being evaluated for correct operation. For example,

assert self._w5100_init() == 1, "Failed to initialize WIZnet module."

Because Adafruit's circuitpython-build-tools never specify a -O level, this problem will not affect mpy files we generate or ship to users.

However, fixing the way asserts are used (probably by replacing them with a variation on if not condition: raise RuntimeError("message") in the case where the side-effect of the expression is required) would be welcome from contributors.

If you agree with this analysis, I recommend either re-titling and updating the initial comment on this issue, or closing it and opening a fresh one to reflect the conclusion.

[dhalbert]

I have closed this issue in favor of #83, which says code needs a rewrite.

[BiffoBear]

I have closed this issue in favor of #83, which says code needs a rewrite.

Hi Dan, the original code was failing even in a raw.py file because interface.detect_w5500() resets the Wiznet SOC. It should only be called by __init__(). The mpy-cross problem with asserts is a separate issue. Please will you reopen this so that detect_w5500 can be made a private method?

[bill88t]

This issue should only be closed by the merge of #81. However https://github.com/adafruit/circuitpython/issues/7363 should stay closed. I will do the pr to convert all the assert's on my own, since it seems a simple enough fix. The mpy-cross issue was just discovered along the way. And is similar yet irrelevant. Only now with #81 did the 2 issues seperate.

[anecdata]

Everything works for me too with the 8.x-mpy build artifacts.

OK, I'll approve 81, which will close this issue when merged.