TimeoutError: Timed out waiting for SPI char (Teensy 4.0 + Adafruit AirLift FeatherWing - ESP32 WiFi Co-Processor)

[wiseac]

Hello i just installed CircuitPython on my Teensy 4.0. Im trying to use a Adafruit AirLift FeatherWing - ESP32 WiFi Co-Processor. Following the guide i installed all the dependencies/ libraries and have the Wifi Co-Processor up to date. Using the ScanNetwork Arduino sketch it runs fine and i can see available networks. As soon as i use CircuitPython i get this error.

code.py output:
ESP32 SPI hardware test
Traceback (most recent call last):
  File "code.py", line 20, in <module>
  File "/lib/adafruit_esp32spi/adafruit_esp32spi.py", line 342, in status
  File "/lib/adafruit_esp32spi/adafruit_esp32spi.py", line 332, in _send_command_get_response
  File "/lib/adafruit_esp32spi/adafruit_esp32spi.py", line 299, in _wait_response_cmd
  File "/lib/adafruit_esp32spi/adafruit_esp32spi.py", line 278, in _wait_spi_char
TimeoutError: Timed out waiting for SPI char

I saw a similar problem arise and followed the outlined steps but i still have the problem.

If anyone has any recommendations id much appreciate it.
Best,
W

Example code:

import board
import busio
from digitalio import DigitalInOut
import adafruit_requests as requests
import adafruit_esp32spi.adafruit_esp32spi_socket as socket
from adafruit_esp32spi import adafruit_esp32spi

print("ESP32 SPI hardware test")

esp32_cs = DigitalInOut(board.D5)
esp32_ready = DigitalInOut(board.D9)
esp32_reset = DigitalInOut(board.D6)
esp32_gpio0 = DigitalInOut(board.D10)

spi = busio.SPI(board.SCK, board.MOSI, board.MISO)
esp = adafruit_esp32spi.ESP_SPIcontrol(spi, esp32_cs, esp32_ready, esp32_reset, esp32_gpio0)

requests.set_socket(socket, esp)

if esp.status == adafruit_esp32spi.WL_IDLE_STATUS:
    print("ESP32 found and in idle mode")
print("Firmware vers.", esp.firmware_version)
print("MAC addr:", [hex(i) for i in esp.MAC_address])

for ap in esp.scan_networks():
    print("\t%s\t\tRSSI: %d" % (str(ap['ssid'], 'utf-8'), ap['rssi']))

print("Done!")

library folder:

[wiseac]

At this point in time I have it running which is great. I changed the baud rate of 8000000 (Which isn't very common, or common at all) to common values such as 115200 or the highest common 921600 and it worked.

154: self._spi_device = SPIDevice(spi, cs_dio, baudrate=921600)

I did run into some scanning network problems for CircuitPython 8 alpha for the Teensy4.0 but the 7.3.1 version works great!

This is a bit of self closure but Im interested in why the baudrate is set so high? Might just be a teensy thing and it not understand that number means more limitless and needs a defined common rate.

Im going to leave this open a tad bit longer to see if I run into any other problems and to see if my question gets answered.
Best,
W

[dhalbert]

At this point in time I have it running which is great. I changed the baud rate of 8000000 (Which isn't very common, or common at all) to common values such as 115200 or the highest common 921600 and it worked.

This the the SPI clock frequency -- it's not a UART baud rate, so it can be much higher. However, it's interesting that reducing the SPI clock rate improved things for you.

[HowdyMoto]

Hi there,

I've been having this problem with my Pyportal Titano for the last year. It will crash randomly after making network requests - sometimes on the first try, sometime after many hours of working smoothly. I have the latest Nina 1.7.4 firmware installed, and I've tried 6.x, 7.x and all the newest 8.x CP builds and libraries as well. I have tested three different Titanos, and they all do this, so it doesn't seem to be a problems that's unique to one of them.

I'm a novice programmer, so it's not been easy trying to figure out how to fix this, and I'm trying to make gadgets that will work reliably and indefinitely without crashing. Are there any resolution to this problem in the works for future released? AFAICT, it looks like I need to compile my own version of adafruit_esp32spi with a baud rate change to fix this. I would be so happy to have this officially resolved, so that I can distribute my gadgets in a way where future updates won't always require custom hacked libs.

[anecdata]

@HowdyMoto When you say "crash", does that mean: the PyPortal becomes completely unresponsive until reset? the PyPortal gets a hardfault? the PyPortal exits your code with an exception? Depending on which behavior, there are a number of things to try.

Under normal circumstances, it should not be necessary to reduce the SPI frequency. Generally, the PyPortal devices and typical libraries are stable under 7.3.3, and even under the 8.0.0-betas.

It is expected that networking code will get exceptions, so the try: / except: construct in Python code is essential around networking calls. When failures occur, you can skip, retry, reset the ESP32, reload the code, or reset the PyPortal (somewhat in that order if things continue not to work). There is also debugging that can be turned on for the ESP32SPI library, and separately for the NINA firmware on the ESP32 chip - these sometimes provide more clues on unusual issues.

https://adafru.it/discord is a great place to go for support questions.

[HowdyMoto]

Thanks for this! When I say "crash", I mean that I get the this error:
File "/lib/adafruit_esp32spi/adafruit_esp32spi.py", line 278, in _wait_spi_char TimeoutError: Timed out waiting for SPI char

which halts the program. I tried try/catch blocks, and tried resetting the esp with esp.reset(), followed by re-initializing it and re-conecting to Wifi, but after that error is thrown, it never seem to be able to recover until I reboot the device.

My program is based on this:
https://github.com/adafruit/Adafruit_Learning_System_Guides/blob/main/PyPortal_Google_Calendar/code.py

However, as I got frustrated from these crashes, I re-wrote the entire thing just to expose the esp.reset() function, which I seem to recall isn't exposed when you're using the Pyportal libs.

Here's my new code. Unfortunately, worldtimeapi.org went down last week. so it won't run anymore -
https://github.com/HowdyMoto/PyPortal_Google_Calendar/blob/main/code-no-portal-libs.py

Here's one piece of code that generated this error - when it happens, I try to reset the esp and re-inititialize it, and reconnect to wifi, but it doesn't work (and unfortuantely it won't run at all right now, and I forget what exactly the error is)

while True:
     try:
         response = requests.get( url, headers=headers )
         error_label.color = GREEN
         error_label.text = "Success: Get calendar"
         break
     except (ValueError, RuntimeError, ConnectionError, OSError) as e:
         print("Request for Calendar data failed, retrying\n", e)
         error_label.text = "Error: Get calendar"
         esp.reset()
         espWifiConnect() 

[anecdata]

btw, you can init the esp separately, then pass it in to the PyPortal https://docs.circuitpython.org/projects/pyportal/en/latest/api.html#adafruit_pyportal.PyPortal, then you have access to esp.reset() and other esp functions while still using the PyPortal library.

It is unusual that esp.reset() doesn't recover. More detail on what's happening there would help. Discord is a great place for that level of discussion. esp.reset() is a bit severe. but otoh it only takes a second (I add a delay after that call to make sure the firmware is fully up before any subsequent operations), and if the code timing can handle it, then do it as often as you like.

[slootsky]

I'm also getting this timeout error with my PyPortal.
I just updated my nina fw to 1.7.5
I'm running circuitpython 8.2.2

my_minimqtt is adafruit_minimqtt with modifications (primarily moving SUBACK to _wait_for_msg and adding a code to MMQTTException that can be checked)

  File "deskweather_with_mqtt_outdoor.py", line 348, in <module>
  File "deskweather_with_mqtt_outdoor.py", line 67, in safe_mqttPublish
  File "/lib/my_minimqtt/my_minimqtt.py", line 806, in publish
  File "adafruit_esp32spi/adafruit_esp32spi_socket.py", line 88, in send
  File "adafruit_esp32spi/adafruit_esp32spi.py", line 758, in socket_write
  File "adafruit_esp32spi/adafruit_esp32spi.py", line 341, in _send_command_get_response
  File "adafruit_esp32spi/adafruit_esp32spi.py", line 308, in _wait_response_cmd
  File "adafruit_esp32spi/adafruit_esp32spi.py", line 287, in _wait_spi_char
TimeoutError: Timed out waiting for SPI char

I tried adjusting the baudrate as above, but it still ocurred

I was able to get around the issue with the following code block in my main loop

    except TimeoutError as e:
        print(e, "... resetting esp")
        esp.reset()
        time.sleep(5)
        connectNeeded = True
        espResetCounter+=1

the connectNeeded is an indicator to reconnect to wifi & mqtt, etc

[HowdyMoto]

Hi all, here is a solution to this problem. I can confirm that my device now runs forever without crashing with this approach.

You can see my approach here on line 93:

https://github.com/HowdyMoto/PyPortal_Google_Calendar/blob/46a144875846bf7863fddd073166bc494ca535be/code.py#L93

In short, you'l need to do the following:

from adafruit_esp32spi import adafruit_esp32spi
from adafruit_pyportal import PyPortal
...

esp = adafruit_esp32spi.ESP_SPIcontrol(SPI, ESP32_CS, ESP32_READY, ESP32_RESET )
pyportal = PyPortal(esp=esp, external_spi=SPI, debug=PYPORTAL_DEBUG)

# write code like this in a try/except to detect esp problems and simply brute-force reset the esp chip:
    while True:
        try:
            pyportal.get_local_time(secrets["timezone"])
            break
        except (ValueError, RuntimeError, ConnectionError, OSError) as e:
            print("esp has an issue, reset and retry\n", e)
            esp.reset()
            esp.disconnect()
            pyportal.network.connect()
            time.sleep(5)

Voila! Works perfectly. Good luck, friends!

[eloekset]

@HowdyMoto are you still sure your application runs forever without freezing? Referring to the issue I linked to above, my PyPortal Titano still freezes after doing the same error handling as you do. I even bought a new device in case it was hardware related. The new device ran 1120 iterations reloading API data before freezing, which is way more than my first device. But that might be a coincidence.

    # only query the weather every 10 minutes (and on first run) #> 600
    if (not weather_refresh) or (time.monotonic() - weather_refresh) > 60:
        while True:
            try:
                print("Fetching data from API...")
                headers = {
                    "Accept": "application/json",
                    "Content-Length": "0"
                }
                response = pyportal.network.requests.get(DATA_SOURCE, headers=headers)
                value = response.json()
                response.close()
                reload_count = reload_count + 1
                print("#%d: Response is" % reload_count, value)
                gfx.draw_display(value)
                gfx.clear_error()
                weather_refresh = time.monotonic()
                break
            except (ValueError, RuntimeError, ConnectionError, OSError, TimeoutError) as e:
                print("Some error occured, retrying! -", e)
                esp.reset()
                esp.disconnect()
                pyportal.network.connect()
                time.sleep(5)

Console log between iteration 1120 and 1121:

Fetching data from API...
#1120: Response is {'widgets': [{'minTime': '25.09 01:11', 'maxTime': '25.09 13:58', 'maxValue': '24.0°C', 'description': 'Stua', 'minValue': '22.8°C', 'type': 'temperature', 'value': '23.9°C', 'trend': 'stable'}, {'minTime': '24.09 22:01', 'maxTime': '25.09 14:31', 'maxValue': '16.8°C', 'description': 'Boden', 'minValue': '13.1°C', 'type': 'temperature', 'value': '16.8°C', 'trend': 'stable'}, {'minTime': '24.09 22:04', 'maxTime': '25.09 14:23', 'maxValue': '20.0°C', 'description': 'Vestveggen ute', 'minValue': '10.7°C', 'type': 'temperature', 'value': '19.4°C', 'trend': 'stable'}, {'minTime': '25.09 02:01', 'maxTime': '25.09 14:13', 'maxValue': '28.3°C', 'description': 'Serverskapet', 'minValue': '27.7°C', 'type': 'temperature', 'value': '28.2°C', 'trend': 'stable'}, {'minTime': '24.09 22:01', 'maxTime': '25.09 12:55', 'maxValue': '18.2°C', 'description': 'Østveggen ute', 'minValue': '10.8°C', 'type': 'temperature', 'value': '17.9°C', 'trend': 'stable'}, {'outTemp': 19.4, 'batteryIndicators': [{'moduleName': 'Vestveggen ute', 'batteryLevel': 73}, {'moduleName': 'Serverskapet', 'batteryLevel': 74}, {'moduleName': 'Østveggen ute', 'batteryLevel': 82}, {'moduleName': 'EiVind', 'batteryLevel': 76}], 'description': 'Vestveggen ute', 'sunOrMoon': 'sun', 'type': 'humidity', 'value': '52', 'batteryLevel': 73}, {'outTemp': 28.2, 'batteryIndicators': [{'moduleName': 'Vestveggen ute', 'batteryLevel': 73}, {'moduleName': 'Serverskapet', 'batteryLevel': 74}, {'moduleName': 'Østveggen ute', 'batteryLevel': 82}, {'moduleName': 'EiVind', 'batteryLevel': 76}], 'description': 'Serverskapet', 'sunOrMoon': 'sun', 'type': 'humidity', 'value': '33', 'batteryLevel': 74}, {'outTemp': 17.9, 'batteryIndicators': [{'moduleName': 'Vestveggen ute', 'batteryLevel': 73}, {'moduleName': 'Serverskapet', 'batteryLevel': 74}, {'moduleName': 'Østveggen ute', 'batteryLevel': 82}, {'moduleName': 'EiVind', 'batteryLevel': 76}], 'description': 'Østveggen ute', 'sunOrMoon': 'sun', 'type': 'humidity', 'value': '55', 'batteryLevel': 82}, {'angle': '227', 'maxAngle': '188', 'maxValue': '9.2m/s', 'description': 'Vind', 'maxTime': '25.09 09:07', 'type': 'wind', 'value': '2.2m/s', 'batteryLevel': 76}, {'angle': '227', 'maxAngle': '188', 'maxValue': '9.2m/s', 'description': 'Kast', 'maxTime': '25.09 09:07', 'type': 'wind', 'value': '5.3m/s', 'batteryLevel': 76}]}
tempInt:  23
tempDec:  .9°C
Set trend icon to /icons/wi-trend-flat.bmp
tempInt:  23
tempDec:  .9°C
Set trend icon to /icons/wi-trend-flat.bmp
modules length: 2
This temp: 17.9°C was parsed to 17.9
low temp: 19.4°C was parsed to 19.4
lowTempModule: {'minTime': '24.09 22:01', 'maxTime': '25.09 12:55', 'maxValue': '18.2°C', 'description': 'Østveggen ute', 'minValue': '10.8°C', 'type': 'temperature', 'value': '17.9°C', 'trend': 'stable'}
tempInt:  17
tempDec:  .9°C
Set trend icon to /icons/wi-trend-flat.bmp
modules length: 2
This temp: 17.9°C was parsed to 17.9
low temp: 19.4°C was parsed to 19.4
lowTempModule: {'minTime': '24.09 22:01', 'maxTime': '25.09 12:55', 'maxValue': '18.2°C', 'description': 'Østveggen ute', 'minValue': '10.8°C', 'type': 'temperature', 'value': '17.9°C', 'trend': 'stable'}
tempInt:  17
tempDec:  .9°C
Set trend icon to /icons/wi-trend-flat.bmp
Set weather icon to /icons/wi-day-sunny.bmp
Set weather icon to /icons/wi-day-sunny.bmp
Set weather icon to /icons/wi-day-sunny.bmp
wind strength:  2.2
wind angle:  227.0
wind strength:  5.3
wind angle:  227.0
Free mem after updates: 33136B
This iteraton took 0B 
Free mem before updates: 33136B
Free mem after updates: 33136B
This iteraton took 0B 
Free mem before updates: 33136B
Fetching data from API...
Some error occured, retrying! - ESP32 not responding
Connecting to AP GID12A_Serverskapet
Fetching data from API...

Connecting to AP GID12A_Serverskapet indicates that the pyportal.network.connect() line has executed before the next refetch, which means the except block was executed right before the freeze. I searched the console log as far back as it got, iteration 1098, and iteration 1120 was the first time Connecting to AP was executed among those.

[HowdyMoto]

I found that the problem went away completely, but I suppose it's possible that a different version of CircuitPython/different libraries could cause you problems.

This is the app I made that seemed to work fine, if you want to try it out:
https://github.com/HowdyMoto/PyPortal_Google_Calendar/tree/46a144875846bf7863fddd073166bc494ca535be