lvgl_port_deinit() returns ESP_OK before the LVGL task has actually stopped (BSP-442)

[cdollar393]

Summary

The lvgl_port_deinit() method sets a variable to stop the background LVGL task, but it doesn't wait to ensure that the task has actually been stopped before returning ESP_OK, which can lead to multiple problems. Ideally, the method should wait for notification that the LVGL task has stopped before returning.

Details

My current project utilizes an ESP32 with a monochrome OLED display connected via I2C, using the SH1107 I2C driver[^1], ESP LVGL port, and LVGL 8.x. The code design has the device repeatedly waking from deep-sleep, performing a few operations which could be displayed on the OLED, and then returning to deep-sleep. The codebase I'm using includes the fix for the issue that caused the LVGL task to not attempt to be stopped. Thanks for accepting that PR, BTW :)

When entering deep-sleep, my project code calls lvgl_port_deinit() to stop LVGL and then tells the OLED display to turn off:

void displayOff() {
  // not shown is code that draws a blank screen to the display first
  ESP_ERROR_CHECK(lvgl_port_deinit());
  ESP_ERROR_CHECK(esp_lcd_panel_disp_on_off(panelHandle, false));
}

The setup above works great 90+% of the time, but occasionally when the device would enter into deep-sleep I'd see:

1. visual display artifacts remaining on the OLED, along with ~5mA current usage by the OLED (when properly turned off the OLED is totally blank and only draws a few uA), or
2. the device and OLED would seem to hang/freeze-up.

In the first case the device would still enter and awake from deep-sleep correctly, although I'd observe the artifacts and extra current usage the entire time the device was in deep-sleep.

In the second case the device would seem to freeze with normal data being displayed on the OLED. It would not enter deep-sleep, and would seem to hang indefinitely. I forced the device to do a core dump one of the times that I observed this freezup behavior, and got the data displayed below (full core dump attached). It seems like the LVGL task and the main task trying to turn off the display were both trying to send an I2C command:

=================== THREAD 9 (TCB: 0x3ffafe78, name: 'main') =====================
#0  0x4000bff0 in ?? ()
#1  0x4008e19e in vPortClearInterruptMaskFromISR (prev_level=<optimized out>) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:568
#2  vPortExitCritical (mux=<optimized out>) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:532
#3  0x4008bcb8 in xQueueReceive (xQueue=0x3ffdfd80, pvBuffer=0x3ffc5280, xTicksToWait=<optimized out>) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/queue.c:1576
#4  0x4010e4b4 in i2c_master_cmd_begin (i2c_num=I2C_NUM_0, cmd_handle=<optimized out>, ticks_to_wait=4294967295) at /Users/chris/esp/esp-idf/components/driver/i2c/i2c.c:1557
#5  0x400ec7c8 in panel_io_i2c_tx_buffer (io=0x3ffddbf8, lcd_cmd=0, buffer=0x3ffc5350, buffer_size=1, is_param=true) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_io_i2c.c:177
#6  0x400ec838 in panel_io_i2c_tx_param (io=0x3ffddbf8, lcd_cmd=0, param=0x3ffc5350, param_size=1) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_io_i2c.c:202
#7  0x400ec56d in esp_lcd_panel_io_tx_param (io=0x3ffddbf8, lcd_cmd=0, param=0x3ffc5350, param_size=1) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_io.c:23
#8  0x400ebafe in panel_sh1107_disp_on_off (panel=0x3ffdfddc, on_off=false) at /Users/chris/cl-project/firmware-esp32/components/esp_lcd_sh1107/esp_lcd_sh1107.c:327
#9  0x400ecd29 in esp_lcd_panel_disp_on_off (panel=0x3ffdfddc, on_off=false) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_ops.c:64
#10 0x400eb084 in displayOff () at /Users/chris/cl-project/firmware-esp32/components/sh1107_ui/SH1107Panel.c:101
#11 0x400e308d in clUiDestroy () at /Users/chris/cl-project/firmware-esp32/main/CLUiController.c:406
#12 0x400db227 in enterDeepSleep (sleepMillis=261890) at /Users/chris/cl-project/firmware-esp32/main/CLMain.c:578
#13 0x400db6ed in app_main () at /Users/chris/cl-project/firmware-esp32/main/CLMain.c:262
#14 0x401b7646 in main_task (args=<optimized out>) at /Users/chris/esp/esp-idf/components/freertos/app_startup.c:208
#15 0x4008deb8 in vPortTaskWrapper (pxCode=0x401b7590 <main_task>, pvParameters=0x0) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 10 (TCB: 0x3ffdddac, name: 'LVGL task') =====================
#0  0x4000bff0 in ?? ()
#1  0x4008e19e in vPortClearInterruptMaskFromISR (prev_level=<optimized out>) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:568
#2  vPortExitCritical (mux=<optimized out>) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:532
#3  0x4008bdc5 in xQueueSemaphoreTake (xQueue=0x3ffdfd28, xTicksToWait=<optimized out>) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/queue.c:1796
#4  0x4010e3ec in i2c_master_cmd_begin (i2c_num=I2C_NUM_0, cmd_handle=0x3ffddc30, ticks_to_wait=4294967295) at /Users/chris/esp/esp-idf/components/driver/i2c/i2c.c:1507
#5  0x400ec7c8 in panel_io_i2c_tx_buffer (io=0x3ffddbf8, lcd_cmd=0, buffer=0x3ffe9561, buffer_size=1, is_param=true) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_io_i2c.c:177
#6  0x400ec838 in panel_io_i2c_tx_param (io=0x3ffddbf8, lcd_cmd=0, param=0x3ffe9561, param_size=1) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_io_i2c.c:202
#7  0x400ec56d in esp_lcd_panel_io_tx_param (io=0x3ffddbf8, lcd_cmd=0, param=0x3ffe9561, param_size=1) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_io.c:23
#8  0x400ebc37 in panel_sh1107_draw_bitmap (panel=<optimized out>, x_start=<optimized out>, y_start=<optimized out>, x_end=128, y_end=<optimized out>, color_data=0x3ffe9814) at /Users/chris/cl-project/firmware-esp32/components/esp_lcd_sh1107/esp_lcd_sh1107.c:239
#9  0x400ecc49 in esp_lcd_panel_draw_bitmap (panel=0x3ffdfddc, x_start=0, y_start=0, x_end=128, y_end=64, color_data=0x3ffe9814) at /Users/chris/esp/esp-idf/components/esp_lcd/src/esp_lcd_panel_ops.c:34
#10 0x400ec092 in lvgl_port_flush_callback (drv=<optimized out>, area=0x3ffe95f0, color_map=0x3ffe9814) at /Users/chris/cl-project/firmware-esp32/managed_components/esp_lvgl_port/esp_lvgl_port.c:741
#11 0x401ae1e4 in call_flush_cb (drv=0x3ffddf10, area=<optimized out>, color_p=0x3ffe9814) at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/core/lv_refr.c:1327
#12 0x400f3496 in draw_buf_flush (disp=0x3ffb74fc <work_mem_int+1352>) at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/core/lv_refr.c:1302
#13 0x400f3a64 in refr_area_part (draw_ctx=0x3ffb7670 <work_mem_int+1724>) at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/core/lv_refr.c:798
#14 0x400f3ad8 in refr_area (area_p=<optimized out>) at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/core/lv_refr.c:646
#15 0x400f3ccc in refr_invalid_areas () at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/core/lv_refr.c:618
#16 0x400f3e85 in _lv_disp_refr_timer (tmr=<optimized out>) at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/core/lv_refr.c:325
#17 0x400f9614 in lv_timer_exec (timer=0x3ffb76cc <work_mem_int+1816>) at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/misc/lv_timer.c:313
#18 0x400f96c5 in lv_timer_handler () at /Users/chris/cl-project/firmware-esp32/managed_components/lvgl__lvgl/src/misc/lv_timer.c:109
#19 0x400ec4f3 in lvgl_port_task (arg=<optimized out>) at /Users/chris/cl-project/firmware-esp32/managed_components/esp_lvgl_port/esp_lvgl_port.c:691
#20 0x4008deb8 in vPortTaskWrapper (pxCode=0x400ec4c4 <lvgl_port_task>, pvParameters=0x0) at /Users/chris/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

At this point I started digging into the code and discovered that lvgl_port_deinit() returned immediately, not waiting to ensure that the LVGL task had stopped, and suspected that this might be the cause of the freeze-up.

To test this I changed the LVGL port code to use a semaphore and timeout value to track if/when the LVGL task actually stopped, so that my project code wouldn't be trying to turn off the display until after that had happened. After making this change I've not observed any more visual artifacts for freeze-ups when the device enters deep-sleep.

I currently don't have access to any other displays to test with, so I'm not sure if this issue is limited to the SH1107 driver, only I2C displays, or a wider range of displays? It seems like a timing/race condition that might not happen in all environments.

I'm happy to make any desired changes and create a pull request for this if you'd like consider merging into the mainline BSP.

[^1] I'm using a derivitive of the SH1107 driver from this repo, with one minor change. Code is here.
coredump-for-github-lvgl-jan12.log

[VojtechBartoska]

@espzav Can you please help with triage of this issue in meantime? Thanks!

[espzav]

It will be fixed by this PR: #320