ESP32- S2: Investigate unexpected I2C / wifi problems

[dhalbert]

It is not clear why the fix in pr #4387 prevents i2c_driver_delete() from interfering with wifi. Rather than continue to discuss that in a closed PR, I'm opening a new issue about this for further discussion.

---

@dhalbert I think we can get the idf patch in v4.3 since its a pre-release at the moment.

I agree, it would be good to PR upstream, but I am still somewhat bothered by the whole thing because I don't see why the IDF fix works. I did some more experiments yesterday and re-read a bunch of our code and their code. I came to no new conclusion. I haven't gotten feedback from igrr about it. Also I inquired with FreeRTOS: https://forums.freertos.org/t/vsemaphoredelete-immediately-after-xsemaphoretake/11956.

Ideally I would like to reproduce this in a simple ESP-IDF program, because they might ask for a test case, but I don't have any experience writing one. I could submit a PR and see what happens, but the fix seems a bit superstitious. There are other examples of Take followed by Delete in the ESP-IDF, mostly in test code. There are also a couple of examples of Take-Give-Delete. Do you have an intuition about this?

Originally posted by @dhalbert in #4387 (comment)

[dhalbert]

Do you have an intuition about this?

No clue at the moment, I'll try to replicate this behavior in an IDF program.

Originally posted by @microdev1 in #4387 (comment)

[dhalbert]

No clue at the moment, I'll try to replicate this behavior in an IDF program.

When I look at the multiple threads running in a "crashed" program vs one running this fix, they look the same. In other words, it is not a hard crash, but some kind of loop or other problem. The clue with my simple tests above is that the REPL stops working, and eventually disconnects. So perhaps some program that does some USB serial activitiy would hang up. Perhaps also some wifi or I2C activity would fail - that might be easier to test.

Originally posted by @dhalbert in #4387 (comment)

[dhalbert]

This is the simplest example that reliably fails without the fix. It prints >>> after the import wifi but then the REPL hangs.

import board,busio

i2c = busio.I2C(board.SCL, board.SDA)
i2c.deinit()

import wifi

Originally posted by @dhalbert in #4387 (comment)

[dhalbert]

It prints >>> after the import wifi but then the REPL hangs.

Yes, I get the same behavior... it hangs and no backtrace. From the debug print I see that wifi starts initializing but stops abruptly.
This also happens on V4.3. I am going to replicate the sequence of code that is executed with these commands.

Originally posted by @microdev1 in #4387 (comment)

[dhalbert]

So the essence of the above is (you can double check this):

// From busio.I2C().
i2c_driver_delete(NULL);   // does nothing
i2c_param_config();
i2c_driver_install();
// i2c.deinit().
i2c_driver_delete();

// Below from common_hal_wifi_init() and common_hal_wifi_radio_set_enabled().
esp_netif_init();               
esp_event_loop_create_default();
 xEventGroupCreateStatic();
esp_event_handler_instance_register();
esp_event_handler_instance_register();
esp_wifi_init();
esp_wifi_set_mode();
esp_wifi_start();

I tried moving the esp_event_loop_create_default() to earlier, doing it during port_init(), but that was worse.

Originally posted by @dhalbert in #4387 (comment)

[dhalbert]

So the essence of the above is

Yup! that's it... you want to go ahead with the IDF program? If not I can run this sequence tomorrow.

Originally posted by @microdev1 in #4387 (comment)

[dhalbert]

I'll try to get the time; I'll let you know. I guess I can gut one of their examples and put that in.

Originally posted by @dhalbert in #4387 (comment)

[dhalbert]

Glad someone is also wondering why it works. I just got in and all my questions have been posed.

Originally posted by @skieast in #4387 (comment)

[dhalbert]

I worked some more on this today. I put some logging in before and after the call to esp_wifi_start() in Radio.c. What's interesting is that in the "fixed version", there is an extra logging entry during that call:

...
I (8988) wifi_init: tcp tx win: 2880
I (8998) wifi_init: tcp rx win: 2880
I (8998) wifi_init: tcp mss: 1440
I (11693178) wifi_init: WiFi IRAM OP enabled
I (11693178) wifi_init: WiFi RX IRAM OP enabled
I (11693188) common_hal_wifi_radio_set_enabled: > esp_wifi_start()         <--- just before call
I (11693198) wifi:enable tsf
I (11693198) wifi:mode : sta (7c:df:a1:00:46:a3)
W (11693198) wifi: start                                                   <--- note this
I (11693198) common_hal_wifi_radio_set_enabled: < esp_wifi_start()         <--- just after call

In the unfixed case, where import wifi causes the REPL to hang, the wifi: start is not present:

[previous "wifi"` logging lines are same as above]
I (9018) common_hal_wifi_radio_set_enabled: > esp_wifi_start()         <--- just before call
I (9128) phy: phy_version: 603, 72dfd77, Jul  7 2020, 19:57:05, 0, 2
I (9128) wifi:enable tsf
I (9138) wifi:mode : sta (7c:df:a1:00:46:a3)
                                                                       <--- NO `wifi: start` here [blank line added for emphasis]
I (9138) common_hal_wifi_radio_set_enabled: < esp_wifi_start()         <--- just after call

So esp_wifi_start() is not doing something for some reason, but we don't know why. Very unfortunately, the code for this is closed source, in components/esp_wifi/lib/esp32s2/lib*.a.

[dhalbert]

Closed by #4387.