Willow Application Server #211

We keep hitting Task Watchdog Timer timeouts when running multinet. Let's increase the TWDT timeout to 30s when using multinet.

…nd config

This is rather ugly, as we need a valid esp_netif_t pointer to set the hostname, but we only get this after starting the Wi-Fi peripheral. We also need to set the hostname before the Wi-Fi is connected, otherwise the hostname from sdkconfig will be used. There is a chance that Wi-Fi connects before we can set the hostname, but it's probably very small. We could check if the Wi-Fi peripheral is connected before setting the hostname, and disconnect it, set the hostname, and then reconnect, but this is even uglier. We can probably improve this by not using ESP-ADF's Wi-Fi peripheral, but that would require a lot of new code.

And print parsed config.

If there is no config file on the flash, we want to request it from WAS during boot. Add a function for that and call it if config_read returns NULL.

If we want to use config values from the config file, we need to parse it early. Parse it after initializing the display, SPIFFS, and UI.

Requesting config before causes a crash.

It appears the WebSocket client does not automatically reconnect after WEBSOCKET_EVENT_CLOSED.

For this we need to make the cJSON pointer a global variable.

And parse config before initializing UI for a correct startup message.

And drop the conditional in hdl_ev_hs. The function pointer will point to noop() if audio response type is none.

Add a deinit function to avoid WebSocket client errors when calling esp_restart to reload config or finish OTA.

In new source files we're defining a different TAG variable instead of using the one from shared.h. This causes redefinition errors if we include shared.h. Move timer variables to timer.h so we don't need to include shared.h to be able to control timers.

Once you've done an OTA and use `./utils.sh flash`, you might still boot from ota_1 partition so you will not boot what you just flashed. This can lead to serious WTF moments. You can use otatool to force the boot partition to ota_0. otatool.py switch_ota_partition --slot 0 Unfortunately esptool does not support that, and otatool is part of ESP-IDF, so this should be done in the container and we need to pass the device node to the container again. As we enabled app rollback in the bootloader, a full flash is required.

Add a state enum to track where we are in the boot phase. When we fail to read the Wi-Fi credentials from NVS, we skip connecting to Wi-Fi and WAS, and wait forever. As of this commit, the NVS partition will need to have a namezone "WIFI" with 2 keys "PSK" and "SSID", or you will no longer be able to connected to Wi-Fi. NVS partition can be generated with the instructions in NOTES.md, or on https://www.linux-ipv6.be/esp-nvs/ (temp URL). The resulting NVS partition can then be flashed with this command: esptool.py --port /dev/ttyACM0 write_flash 0x9000 ~/tmp/nvs.bin Alternatively, you can use https://espressif.github.io/esptool-js/. Make sure to set the offset to 0x9000.

…rging nvs into full firmware image

We're currently repositioning line 3 to print stuff in the middle of the screen. This requires us to keep track of when we have to reposition it again. To make our lives easier, just use 5 lines instead and use line 3 for things that go in the middle.

Right now we instantly restart after a config or OTA update. Add a delayed restart function so we can print a message on the display and give the user time to actually see it. And use it in config and ota.

Aside from Wi-Fi credentials, having the WAS URL is also a hard requirement. Include the WAS URL in NVS and read it from there in main.

Currently setting a TAG in source files that include shared.h we get redefintion errors. Solve this removing TAG from shared.h and setting a TAG per source file where ESP_LOG macros are used. As esp_log_level_set only supports "*" but not "WILLOW/*", we need to set the log level for all these tags. To not further bloat main.c with all these calls, move logging initialization to log.c. Oneliner to generate the calls: git grep "static const char" | awk '{ print $6 }' | sed 's/;$//' | sort | while read f ; do printf " esp_log_level_set(%s, WILLOW_LOG_LEVEL);\n" "$f"; done

While working on WAS it turned out the ESP WebSocket client does not reconnect when the WebSocket connection is being closed. Improve the HA WebSocket event handling to reconnect when the WebSocket connection is closed, and to avoid logging useless messages like this: I (01:39:19.220) WILLOW/HASS: WS event ID: 1 I (01:39:29.223) WILLOW/HASS: WS event ID: 4

And call it before starting OTA.

For this to work we need to move display initialization to run after loading the config from SPIFFS.

If a device has no config, we don't setup any audio. The device will ask WAS for a config, WAS calls deinit_audio, and we get a null pointer dereference. Add null checks to avoid this.

If we're requesting a config from WAS it means we don't have a valid config. Continuing after requesting the config doesn't make sense, as it will cause a lot of errors. Since we're restarting after receiving the config from WAS anyway, let's just wait indefinitely in the main task after requesting config from WAS.

When booting with mute enabled, audio_board_init failes, and throws a whole lot of errors before it does. Check mute status before calling audio_board_init. If mute is enabled, print a message on the display to inform the user to unmute to continue, and check the GPIO status in a loop until the user unmutes, then continue boot. Fixes #192.

And use it where appropriate. This is an initial attempt to reduce the various lvgl calls all over the place.

Instead of maintaining and applying patches for ESP-ADF in the Willow repository we will clone ESP-ADF from our fork. The willow branch has our required changes. We are in the process of submitting those changes upstream, but until we've done so, and all changes are accepted, this is a much cleaner way of maintaining and using our ESP-ADF changes. Drop the patches directory and do_patch function since we no longer need them. This will require build-docker and ./utils.sh destroy.

We now have an experiment multinet command editor in WAS. It can pull entities from HA, generate commands for those entities, with the option to add/modify/delete them.

On tagged commit, this will use the tag. We also don't need to manually append the -dirty tag.

This needs work; we need to cleanly disable MultiNet everywhere, and ideally print an error message that MultiNet is not supported with release images for now.

This will be used to build and publish Willow images.

Ideally we would only build a container when there are changes to the Dockerfile or the workflow config that builds the container. Unfortunately GH actions is so incredibly inflexbile that this seems impossible. As we need to have a build container with a tag corresponding to the git branch or tag, when we create a new branch or tag, we need to build the container first, before we can start the dist build. But the documentation for the push event states this: > If you use both the branches filter and the paths filter, the workflow will only run when both filters are satisfied. It doesn't mention anything about "OR". So to not further lose time with GH actions, just build the container anyway. It's a shame this is so needlessly complex that people have to resort to workaround that waste CPU cycles.

As it seems to be completely impossible to add any kind of usable dependency between different workflows, let's move everything to a single workflow instead.

With the default configuration, the docker/metadata-action uses multiple tags, in the following order: type=schedule type=ref,event=branch type=ref,event=tag type=ref,event=pr We don't use schedule, and when we build for a tag, we want to use the git tag rather than the branch name as container image tag first, so we can use index 0 of the tags array to later select which container image we use to do the Willow dist build.

Apparently the artifact is unzipped by the download action.

Even though we run things as root inside the container and /willow is owned by root, we get the following error: fatal: detected dubious ownership in repository at '/willow' To add an exception for this directory, call: git config --global --add safe.directory /willow Most likely because of this, we get an empty Willow verion: Willow build version: Add /willow to the safe directories to fix this. Ideally we should not run as root, but that's something to optimize later.

Running on push was to test during development. Switch to run on pull request, and on push with tag now that we're almost ready for merge.

Also add a short delay before starting OTA, to let deinit settle down.

…or chimes

…p32s3 optimized mem copy/set

While we already have the MAC address in the hostname, this is not very flexible. If users want to use custom hostnames, we can no longer get the MAC address from it. As the ESP32 does not have a unique serial number, but it is programmed with a unique MAC address at manufacture, the MAC address from the EFUSE is the most reliable unique identifier. If we want to keep a persistent inventory in WAS, we will need a unique identifier. Therefore, add the MAC address from the EFUSE in the hello message.

In commit 2bc77a4 ("hass: increase WebSocket buffer size") we increased the WebSocket buffer size to 4096 byte, because responses over encrypted WebSocket would be truncated at 4092 byte. While looking into this again, it appears this truncation is no longer happening. Since I'm hitting this 4096 byte limit with the Home Assistant intent "how many lights are on?", let's increase this buffer size. My Home Assistant has 44 light entities, and the WebSocket message containing the response to that intent is 4691 byte. As we allocate memory in SPIRAM by default, we don't have to worry too much about making the buffer too large, but at the same time we shouldn't impact performance too much. Let's settle on a 16384 byte buffer for now.

We sometimes hit a deadlock when calling lvgl_port_lock(0). Calling lvgl_port_lock with argument 0 will wait indefinitely for the semaphore to become available, hence greatly increasing the risk to deadlock. Limit the time to wait for the LVGL lock to 500ms to avoid deadlocking. Since we do not wait indefinitely anymore, there is a change we will not be able to get the lock. Hence, we should check the return status of the lvgl_port_lock calls, and skip LVGL calls if we don't have the lock. With this change, we will not update the screen in rare occasions, but not locking up is far more important than correctly printing everything to the screen. Finally, move some non-LVGL calls outside of the conditional, to avoid not playing an audio response or logging to the console in case we cannot get the lock.

We set volume to 0 in i2s_stream_cfg_t in start_rec. Move the call to set volume to the value in willow.json after the call to start_rec to make sure we actually set the volume to the configured value.

The reason ESP Audio's async play appeared to not play anything is because we disable the power amplifier right after the esp_audio_play call. As this call immediately returns, we're disabling the PA before ESP Audio actually plays the audio. Add an event queue so we can move disabling the PA out of the play_audio functions into an event handler.

And have it disable the power amplifier for events PAUSED, STOPPED, FINISHED and ERROR.

Fixes: dc3f443 ("main: add cancel button")

We're modifying the recording variable in one task, and we read it in another. Make the variable volatile, to be sure we don't read an optimized or cached value.

Don't send STOP on WAKE when we're already recording, just avoid sending START again, and let the STOP on WAKE END trigger everything. Don't stop streaming to WIS when reading from the recorder returns 0. This should avoid early cut-off when something can't keep up for some reason.

During a torture run with WIS over HTTPS we've seen the following crash: ***ERROR*** A stack overflow in task http_stream_writer has been detected. Increase the task stack size to avoid this.

During a torture run with heap poisoning enabled, the following crash was observed: Guru Meditation Error: Core 1 panic'ed (StoreProhibited). Exception was unhandled. Core 1 register dump: PC : 0x4038abca PS : 0x00060033 A0 : 0x8038b847 A1 : 0x3fcc9150 A2 : 0x3d800014 A3 : 0x0000000c A4 : 0x3d800038 A5 : 0x3d800274 A6 : 0x00060023 A7 : 0x00000000 A8 : 0x3d800014 A9 : 0x00000394 A10 : 0x3d9a28f4 A11 : 0x00000038 A12 : 0xabba1234 A13 : 0x00000003 A14 : 0x0000001e A15 : 0x3d80007c SAR : 0x0000001f EXCCAUSE: 0x0000001d EXCVADDR: 0xabba1240 LBEG : 0x400570e8 LEND : 0x400570f3 LCOUNT : 0x00000000 /opt/esp/idf/components/heap/heap_tlsf.c:206 /opt/esp/idf/components/heap/multi_heap.c:187 /opt/esp/idf/components/heap/multi_heap_poisoning.c:234 /opt/esp/idf/components/heap/multi_heap_poisoning.c:229 /opt/esp/idf/components/heap/heap_caps.c:175 /opt/esp/idf/components/heap/heap_caps.c:239 /opt/esp/idf/components/newlib/heap.c:24 /opt/esp/idf/components/json/cJSON/cJSON.c:243 /opt/esp/idf/components/json/cJSON/cJSON.c:1633 /opt/esp/idf/components/json/cJSON/cJSON.c:1674 /opt/esp/idf/components/json/cJSON/cJSON.c:1674 /opt/esp/idf/components/json/cJSON/cJSON.c:1116 /opt/esp/idf/components/json/cJSON/cJSON.c:1087 /opt/esp/idf/components/json/cJSON/cJSON.c:1173 /willow/main/endpoint/hass.c:58 /opt/esp/idf/components/esp_event/esp_event.c:145 /opt/esp/idf/components/esp_websocket_client/esp_websocket_client.c:155 /opt/esp/idf/components/esp_websocket_client/esp_websocket_client.c:555 Line 59 in hass.c is cJSON_Parse(resp). Let's add a few extra checks to make sure we do not call cJSON_Parse on garbage data.

We're regularly observing LVGL using 100% CPU with scrolling text. This seems to cause all kinds of random behaviour. Disable it for now.

We've observed the following crash: Guru Meditation Error: Core 0 panic'ed (Double exception). Core 0 register dump: PC : 0x4038424a PS : 0x00040936 A0 : 0x820e7897 A1 : 0x3d9a74b0 A2 : 0x00000000 A3 : 0x3d9a74f0 A4 : 0x00000000 A5 : 0x00000000 A6 : 0x00000000 A7 : 0x00000000 A8 : 0x820ed3f3 A9 : 0x3d9a7490 A10 : 0x00000003 A11 : 0x3d99ecd4 A12 : 0x00000000 A13 : 0x00000000 A14 : 0x3d9a74f0 A15 : 0x00000000 SAR : 0x00000019 EXCCAUSE: 0x00000002 EXCVADDR: 0xfffffff0 LBEG : 0x42148bf1 LEND : 0x42148bfc LCOUNT : 0x00000000 Backtrace: 0x40384247:0x3d9a74b0 0x420e7894:0x00000000 |<-CORRUPTED /opt/esp/tools/xtensa-esp32s3-elf/esp-2021r2-patch5-8.4.0/xtensa-esp32s3-elf/bin/xtensa-esp32s3-elf-addr2line -e build/willow.elf 0x40384247:0x3d9a74b0 0x420e7894:0x00000000 /opt/esp/idf/components/freertos/port/xtensa/xtensa_context.S:194 /opt/esp/idf/components/mbedtls/mbedtls/library/md.c:601 On this line, mbedtls_sha512_finish_ret is called. Let's disable SHA hardware acceleration, as we're suspecting this causes issues.

We've experienced the following crash during boot after disabling SHA hardware acceleration: ***ERROR*** A stack overflow in task websocket_task has been detected. Increase the task stack size to avoid this.

Found with clang-tidy: /willow/main/endpoint/openhab.c:70:9: warning: Null pointer passed as 1st argument to string length function [clang-analyzer-unix.cstring.NullArg]

Found with clang-tidy.

Found with clang-tidy: /willow/main/was.c:104:21: warning: 1st function call argument is an uninitialized value [clang-analyzer-core.CallAndMessage]

And define it to the same value used in sdkconfig.willow if it doesn't. Fixes the following error running clang-check: /willow/main/audio.c:655:42: error: use of undeclared identifier 'CONFIG_TASK_WDT_PANIC' [clang-diagnostic-error]

Fixes the following clang-tidy warnings: /willow/main/endpoint/hass.c:278:5: warning: Value stored to 'ret' is never read [clang-analyzer-deadcode.DeadStores] /willow/main/endpoint/hass.c:278:5: note: Value stored to 'ret' is never read /willow/main/endpoint/hass.c:319:5: warning: Value stored to 'ret' is never read [clang-analyzer-deadcode.DeadStores] /willow/main/endpoint/hass.c:319:5: note: Value stored to 'ret' is never read We print an error message in hass_set_http_auth so we don't need to print an error message in the callers. We might consider returning early in the caller when hass_set_http_auth returns false, or changing the function to void if we keep the current behaviour. Not sure which one would be best, so let's just fix the warnings for now.

The audio_board_lcd_init returns a void pointer so we need to cast it to esp_lcd_panel_handle_t.

Saying wake word when VAD_END/WAKEUP_END hasn't been trigger yet causes multiple session timers to start. Let's do like we do for VAD_START and do nothing when we're already recording.

Terminating the audio pipeline will destroy the tasks for the elements in the pipeline, so the tasks have to be recreated every time we stream to WIS. This isn't very efficient, and it doesn't appear to be needed. We also suspect this could leak memory, and sometimes causes this error: E (16:45:01.400) AUDIO_PIPELINE: audio_pipeline_resume failed After this error, the device is no longer able to stream to WIS.

The ESP_AUDIO_PREFER_MEM mode seems to destroy and recreate its element tasks on every run. This is not very efficient, and as we have plenty of free memory, we can perfectly use the ESP_AUDIO_PREFER_SPEED mode instead. TTS log of 2nd wake before this change: I (02:13:12.437) WILLOW/AUDIO: Using WIS TTS URL 'https://wis.local:19000/api/tts?format=WAV&speaker=CLB&text=0' I (02:13:12.450) AUDIO_PIPELINE: audio_pipeline_unlinked W (02:13:12.454) AUDIO_PIPELINE: There are no listener registered I (02:13:12.461) AUDIO_PIPELINE: link el->rb, el:0x3d9f7c78, tag:IN_http, rb:0x3db20950 I (02:13:12.470) AUDIO_PIPELINE: link el->rb, el:0x3d9f8484, tag:DEC_auto, rb:0x3db20988 I (02:13:12.478) AUDIO_PIPELINE: link el->rb, el:0x3db1968c, tag:Audio_forge, rb:0x3db132cc I (02:13:12.488) AUDIO_ELEMENT: [IN_http-0x3d9f7c78] Element task created I (02:13:12.495) AUDIO_ELEMENT: [IN_http] AEL_MSG_CMD_RESUME,state:1 I (02:13:12.503) AUDIO_ELEMENT: [DEC_auto-0x3d9f8484] Element task created I (02:13:12.509) AUDIO_ELEMENT: [DEC_auto] AEL_MSG_CMD_RESUME,state:1 I (02:13:13.285) AUDIO_ELEMENT: [Audio_forge-0x3db1968c] Element task created I (02:13:13.285) AUDIO_ELEMENT: [Audio_forge] AEL_MSG_CMD_RESUME,state:1 I (02:13:13.289) AUDIO_ELEMENT: [OUT_iis-0x3da17d48] Element task created I (02:13:13.297) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1 I (02:13:13.308) AUDIO_ELEMENT: IN-[IN_http] AEL_IO_DONE,0 I (02:13:13.310) AUDIO_ELEMENT: IN-[DEC_auto] AEL_IO_DONE,-2 I (02:13:13.785) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2 I (02:13:13.933) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2 I (02:13:14.340) AUDIO_ELEMENT: [http_stream_writer] AEL_MSG_CMD_PAUSE TTS log of 2nd wake after this change: I (02:18:19.707) WILLOW/AUDIO: Using WIS TTS URL 'https://wis.local:19000/api/tts?format=WAV&speaker=CLB&text=0' I (02:18:19.718) AUDIO_ELEMENT: [IN_http] AEL_MSG_CMD_RESUME,state:1 I (02:18:19.725) AUDIO_ELEMENT: [DEC_auto] AEL_MSG_CMD_RESUME,state:1 I (02:18:20.513) AUDIO_ELEMENT: [Audio_forge] AEL_MSG_CMD_RESUME,state:1 I (02:18:20.514) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1 I (02:18:20.525) AUDIO_ELEMENT: IN-[IN_http] AEL_IO_DONE,0 I (02:18:20.526) AUDIO_ELEMENT: IN-[DEC_auto] AEL_IO_DONE,-2 I (02:18:20.996) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2 I (02:18:21.146) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2 I (02:18:21.616) AUDIO_ELEMENT: [http_stream_writer] AEL_MSG_CMD_PAUSE This also appears to work around the following observed behavior with task heap debugging using esp_dump_per_task_heap_info: Task: main -> CAP_8BIT: 1392004 CAP_32BIT: 0 Task: esp_periph -> CAP_8BIT: 25296 CAP_32BIT: 0 Task: wifi -> CAP_8BIT: 105068 CAP_32BIT: 0 Task: Pre-Scheduler allocs -> CAP_8BIT: 4068 CAP_32BIT: 0 Task: ipc0 -> CAP_8BIT: 30028 CAP_32BIT: 0 Task: tiT -> CAP_8BIT: 2908 CAP_32BIT: 0 Task: sys_evt -> CAP_8BIT: 100 CAP_32BIT: 0 Task: websocket_task -> CAP_8BIT: 724 CAP_32BIT: 0 Task: websocket_task -> CAP_8BIT: 25708 CAP_32BIT: 0 Task: i2s_stream_read -> CAP_8BIT: 2048 CAP_32BIT: 0 Task: at_read -> CAP_8BIT: 10584 CAP_32BIT: 0 Task: feed_task -> CAP_8BIT: 8192 CAP_32BIT: 0 Task: ipc1 -> CAP_8BIT: 24 CAP_32BIT: 0 Task: btm_rrm_t -> CAP_8BIT: 100 CAP_32BIT: 0 Task: esp_timer -> CAP_8BIT: 208 CAP_32BIT: 0 Task: media_task -> CAP_8BIT: 41456 CAP_32BIT: 0 Task: recorder_task -> CAP_8BIT: 24 CAP_32BIT: 0 Task: http_stream_wri -> CAP_8BIT: 4904 CAP_32BIT: 0 Task: �� Tasks like the latter would appear randomly, sometimes with a short sequence of binary data for task name, but regularly with multiple lines (100+) full of it, eventually slowing things down so badly that the TWDT triggers a restart.

We're still able to lock up the display. When this happens, the audio being sent to WIS is often incomplete. Enable SPIRAM_RODATA and SPIRAM_FETCH_INSTRUCTIONS to hopefully finally fix this.

We only stop the audio pipeline to stream to WIS when the session timer expires. VAD_END and WAKE_END will potentially trigger afterwards. If this happens when a new stream to WIS was already started, all kinds of weirdness can occur. Force stop the recorder when the session timer expires to avoid this.

We were still able to lock up the display, with both our custom font and montserat. Enable LCD_RGB_ISR_IRAM_SAFE to test if this helps.

During several torture runs, the following error appeared sporadically: E (23:45:27.704) esp-tls-mbedtls: read error :-0x7180: E (23:45:27.705) TRANSPORT_BASE: esp_tls_conn_read error, errno=Success Disabling AES hardware acceleration seems to fix those.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Willow Application Server #211

Willow Application Server #211

Commits on Aug 16, 2023