Weird behaviour on ESP-IDF v5.3

huming2207 commented 3 weeks ago

I've assembled five EPDIY v7 boards via JLCSMT and soldered the ESP32-S3 module by myself last night. Initially I compiled the screen_diag sample project with ESP-IDF v5.3. I've also bought some ED060XC3 and ED060XD4 panels from AliExpress.

Initially it couldn't compile because Espressif made some changes on their LCD driver. So I made some quick changes. Here's the diff showing what I did:

diff --git a/src/output_lcd/lcd_driver.c b/src/output_lcd/lcd_driver.c
index 25c5222..5f25bf1 100644
--- a/src/output_lcd/lcd_driver.c
+++ b/src/output_lcd/lcd_driver.c
@@ -518,7 +518,7 @@ static esp_err_t init_lcd_peripheral() {

     // enable RGB mode and set data width
     lcd_ll_enable_rgb_mode(lcd.hal.dev, true);
-    lcd_ll_set_data_width(lcd.hal.dev, lcd.config.bus_width);
+    lcd_ll_set_data_wire_width(lcd.hal.dev, lcd.config.bus_width);
     lcd_ll_set_phase_cycles(lcd.hal.dev, 0, (lcd.dummy_bytes > 0), 1);  // enable data phase only
     lcd_ll_enable_output_hsync_in_porch_region(lcd.hal.dev, false);     // enable data phase only

@@ -612,7 +612,8 @@ void epd_lcd_set_pixel_clock_MHz(int frequency) {

     // set pclk
     int flags = 0;
-    uint32_t freq = lcd_hal_cal_pclk_freq(&lcd.hal, 240000000, lcd.config.pixel_clock, flags);
+    hal_utils_clk_div_t div = {};
+    uint32_t freq = lcd_hal_cal_pclk_freq(&lcd.hal, 240000000, lcd.config.pixel_clock, flags, &div);
     ESP_LOGI(TAG, "pclk freq: %d Hz", freq);
     lcd.line_length_us = (lcd.lcd_res_h + lcd.config.le_high_time + lcd.config.line_front_porch - 1)
                              * 1000000 / lcd.config.pixel_clock

With these changes, the code can compile but on a ED060XC3 or XD4 display, it can't render stuff properly. Here's what it looks like if I fill a 100x100 rectangle (by running fill_rect 0 0 100 100):

This is another display after calling full_clear_screen, the screen also wasn't clearing properly:

Then I reverted my changes and downgraded ESP-IDF to v5.2.2, and it seemed to be working fine afterwards. This is what it looks like if I run fill_rect 0 0 100 100 and then fill_rect 100 100 100 100, and then wrote some text afterwards:

So far I don't know what's happened at the low-level but it seems like the new LCD driver on ESP-IDF v5.3 didn't send the sync/shift signal to the panel driver chip properly. Or maybe I did something wrong on changing the API?

martinberlin commented 2 weeks ago

Hello @huming2207 this is duplicated with #285 as you discovered already epdiy works till 5.2 and I guess we need a further update to make this work in 5.3 Since you are advanced in the topic already let’s plan to make a Pull request and fix it together

huming2207 commented 2 weeks ago

this is duplicated with https://github.com/vroland/epdiy/issues/285 as you discovered already epdiy works till 5.2 and I guess we need a further update to make this work in 5.3

Oops sorry I should've searched deeper first... 😅

Since you are advanced in the topic already let’s plan to make a Pull request and fix it together

I'll see if I can capture something on the logic analyser. But I need a breakout board to do so. Do you have any idea where I can get one of those? @martinberlin

huming2207 commented 2 weeks ago

Hi @martinberlin @vroland

I just saw this:

So, since I've got the issues on this way around:

I'm wondering maybe the CKV timing is wrong somehow, so that some gate lines are skipped/duplicated?

I don't know, I'm a bit lost on this... 😅

huming2207 commented 2 weeks ago

A few things I found:

At lcd_hal.c:
- v5.2 has a lcd_ll_set_group_clock_coeff call: https://github.com/espressif/esp-idf/blob/release/v5.2/components/hal/lcd_hal.c#L36
- v5.3 somehow doesn't have that: https://github.com/espressif/esp-idf/blob/release/v5.3/components/hal/lcd_hal.c#L34
I should use lcd_ll_set_dma_read_stride instead of lcd_ll_set_data_wire_width, because lcd_ll_set_data_wire_width is no-op: https://github.com/espressif/esp-idf/blob/release/v5.3/components/hal/esp32s3/include/hal/lcd_ll.h#L374
It seems like no much change for RMT low-level driver on ESP32-S3 between v5.2 and v5.3

martinberlin commented 2 weeks ago

Don’t worry just closed the other issue. I will update my IDF to 5.3 today and help you debugging this one. Maybe tonight or tomorrow I can post my results here

huming2207 commented 2 weeks ago

Don’t worry just closed the other issue. I will update my IDF to 5.3 today and help you debugging this one. Maybe tonight or tomorrow I can post my results here

Yep thanks. I will do some digging later tonight as well. I suspect those two lcd_ll calls are likely to be the troublemaker.

huming2207 commented 2 weeks ago

I suspect those two lcd_ll calls are likely to be the troublemaker.

Yes this indeed is the issue. I think I fixed it, gonna will submit pull request soon...

huming2207 commented 2 weeks ago

Done

martinberlin commented 2 weeks ago

Thanks @huming2207 this PR looks very clean. Short question: Did you also get this bug when upgrading to idf v 5.3 ? https://github.com/espressif/esp-idf/issues/14215

Funny it seems gone when doing again a: idf.py set-target esp32s3 (even though the target already was S3)

martinberlin commented 2 weeks ago

Sorry I closed this as an accident with mouse :P I tried to do test in your branch and I'm getting this warnings:

W (715) i2c: This driver is an old driver, please migrate your application code to adapt driver/i2c_master.h

And then I get this error and it restarts. The stack trace is the following:

I (750) main_task: Calling app_main()
I (760) epdiy: using resolution 300x832
I (760) gpio: GPIO[45]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (770) epdiy: pclk freq: 15000000 Hz
I (780) epdiy: line width: 21us, 315 cylces
I (780) epdiy: LCD init done.
I (780) epd: Space used for waveform LUT: 64K

assert failed: 0x4037d5c7
0x4037d5c7: prvInitialiseNewTask at /home/martin/esp/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:1088 (discriminator 1)

Backtrace: 0x4037564a:0x3fc98df0 0x4037c065:0x3fc98e10 0x4038175d:0x3fc98e30 0x4037d5c7:0x3fc98e70 0x4037e904:0x3fc98ea0 0x42007dfe:0x3fc98ee0 0x42007add:0x3fc98f30 0x420079ac:0x3fc98f50 0x420079cf:0x3fc98f90 0x4201a883:0x3fc98fb0
0x4037564a: panic_abort at /home/martin/esp/esp-idf/components/esp_system/panic.c:463
0x4037c065: esp_system_abort at /home/martin/esp/esp-idf/components/esp_system/port/esp_system_chip.c:92
0x4038175d: __assert_func at /home/martin/esp/esp-idf/components/newlib/assert.c:39
0x4037d5c7: prvInitialiseNewTask at /home/martin/esp/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:1088 (discriminator 1)
0x4037e904: xTaskCreatePinnedToCore at /home/martin/esp/esp-idf/components/freertos/esp_additions/freertos_tasks_c_additions.h:268
0x42007dfe: epd_renderer_init at /home/martin/esp/projects/epdiy/src/render.c:326
0x42007add: epd_init at /home/martin/esp/projects/epdiy/src/epdiy.c:563
0x420079ac: idf_setup at /home/martin/esp/projects/epdiy/examples/dragon/main/main.c:42
0x420079cf: app_main at /home/martin/esp/projects/epdiy/examples/dragon/main/main.c:49
0x4201a883: main_task at /home/martin/esp/esp-idf/components/freertos/app_startup.c:208

where it hangs:

/* This is used as an array index so must ensure it's not too large. */
configASSERT( uxPriority < configMAX_PRIORITIES );

It seems that whatever task is doing after epd_lcd_init() "LCD init done" is failing in this assert @vroland what it could be?

Commenting that assert in esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c it works perfectly. So there must be something we are missing if it works in certain configurations and not in others. And this should be solved before merging #349

huming2207 commented 2 weeks ago

Hi @martinberlin

Which demo project did you try to compile? I tried the greyscale and screen_diag and it works fine for me.

I think maybe you need to try re-installing ESP-IDF? I doubt it might be somehow you set the configMAX_PRIORITIES to a wrong value somehow (e.g. using some IDE's refactor feature like CLion, it may refactored the value in ESP-IDF by accident)? My configMAX_PRIORITIES is 25, shown as below:

Jackson

martinberlin commented 2 weeks ago

Hello Jackson, just checked this file that is located in esp-idf/components/freertos/config/include/freertos and as expected I also have 25 as Max priorities.

I doubt it might be somehow you set the configMAX_PRIORITIES to a wrong value somehow

I'm using idf in the command line to build and flash the devices. I really doubt this value that is a constant would be changed somewhere, will try to debug it today. The example I tried is: examples/dragon Can you try with that one and see if we can reproduce this?

UPDATE: For me also grayscale & demo example works without any additional change. Now I did a fullclean / flashed again dragon and it worked out.

huming2207 commented 2 weeks ago

The example I tried is: examples/dragon Can you try with that one and see if we can reproduce this?

Sure, will do.

But I still think you might have some kinda courrpted ESP-IDF copy. Otherwise CI won't even pass me.

martinberlin commented 2 weeks ago

Yes it might be. We will need to add some notes to use fullclean after update of idf to new versions. Or even just completely delete the build directory. Otherwise the users will hit the same mistake

huming2207 commented 2 weeks ago

Yea, I think for your case, try removing the whole ~/esp and ~/.espressif directory and reinstall it, and then remove the build directory in your project (or idf.py fullclean) and rebuild.

martinberlin commented 2 weeks ago

Latest update about this. Debugging after this line and printing the values:

I (725) epd: LUT: 64K uxP: 25 MAX_PRIO: 25

hence the assert:

configASSERT( uxPriority < configMAX_PRIORITIES );

Does trigger and stops execution. Sorry before it seems I was testing with this line commented. @huming2207 we need to find out why uxPriority is 25 for this examples. I'm also going to clean completely IDF and install it again, but this is not the usual procedure. Supposedly you can simply checkout an upgraded release, run the install.sh shell command and after doing the export that sets python & IDF in your environment you should be ready to build. Also this seems to be failing only in epdiy projects after the upgrade. I tried other idf programs in the examples folder and they run just fine without triggering this. For examples/get-started/hello-world

Right after BOOT:
uxP: 24 MAX_PRIO: 25
I (286) sleep: Configure to isolate all GPIO pins in sleep state
I (293) sleep: Enable automatic switching of GPIO sleep configuration
uxP: 1 MAX_PRIO: 25

uxP: 0 MAX_PRIO: 25

I (306) main_task: Started on CPU0

huming2207 commented 2 weeks ago

@martinberlin Hmmm I don't know what's happening in your environment. Maybe also try removing your sdkconfig, or even re-clone a new copy of EPDIY and try compiling it out.

I just tested the dragon example and it works fine:

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x9 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce2820,len:0x156c
load:0x403c8700,len:0x4
load:0x403c8704,len:0xe3c
load:0x403cb700,len:0x2f9c
entry 0x403c892c
I (27) boot: ESP-IDF v5.3 2nd stage bootloader
I (27) boot: compile time Aug 27 2024 21:52:12
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.2
I (34) qio_mode: Enabling default flash chip QIO
I (39) boot.esp32s3: Boot SPI Speed : 80MHz
I (44) boot.esp32s3: SPI Mode       : QIO
I (48) boot.esp32s3: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00177000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=83264h (537188) map
I (186) esp_image: segment 1: paddr=0009328c vaddr=3fc93500 size=024c0h (  9408) load
I (188) esp_image: segment 2: paddr=00095754 vaddr=40374000 size=0a8c4h ( 43204) load
I (200) esp_image: segment 3: paddr=000a0020 vaddr=42000020 size=1b300h (111360) map
I (217) esp_image: segment 4: paddr=000bb328 vaddr=4037e8c4 size=04c0ch ( 19468) load
I (227) boot: Loaded app from partition at offset 0x10000
I (227) boot: Disabling RNG early entropy source...
I (239) octal_psram: vendor id    : 0x0d (AP)
I (239) octal_psram: dev id       : 0x02 (generation 3)
I (239) octal_psram: density      : 0x03 (64 Mbit)
I (244) octal_psram: good-die     : 0x01 (Pass)
I (249) octal_psram: Latency      : 0x01 (Fixed)
I (255) octal_psram: VCC          : 0x01 (3V)
I (260) octal_psram: SRF          : 0x01 (Fast Refresh)
I (266) octal_psram: BurstType    : 0x01 (Hybrid Wrap)
I (271) octal_psram: BurstLen     : 0x01 (32 Byte)
I (277) octal_psram: Readlatency  : 0x02 (10 cycles@Fixed)
I (283) octal_psram: DriveStrength: 0x00 (1/1)
I (289) MSPI Timing: PSRAM timing tuning index: 5
I (294) esp_psram: Found 8MB PSRAM device
I (298) esp_psram: Speed: 80MHz
I (302) cpu_start: Multicore app
I (596) esp_psram: SPI SRAM memory test OK
I (605) cpu_start: Pro cpu start user code
I (605) cpu_start: cpu freq: 240000000 Hz
I (605) app_init: Application information:
I (608) app_init: Project name:     dragon_example
I (613) app_init: App version:      2.0.0-17-gc42defb-dirty
I (620) app_init: Compile time:     Aug 27 2024 21:52:08
I (626) app_init: ELF file SHA256:  fe91eb305668ae04...
I (632) app_init: ESP-IDF:          v5.3
I (636) efuse_init: Min chip rev:     v0.0
I (641) efuse_init: Max chip rev:     v0.99
I (646) efuse_init: Chip rev:         v0.2
I (651) heap_init: Initializing. RAM available for dynamic allocation:
I (658) heap_init: At 3FC964B0 len 00053260 (332 KiB): RAM
I (664) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (670) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (676) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
I (683) esp_psram: Adding pool of 8192K of PSRAM memory to heap allocator
I (690) spi_flash: detected chip: gd
I (694) spi_flash: flash io: qio
W (698) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
W (711) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h`
I (722) sleep: Configure to isolate all GPIO pins in sleep state
I (729) sleep: Enable automatic switching of GPIO sleep configuration
I (736) main_task: Started on CPU0
I (746) esp_psram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (746) main_task: Calling app_main()
I (756) epdiy: using resolution 256x768
I (756) gpio: GPIO[45]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (766) epdiy: pclk freq: 20000000 Hz
I (776) epdiy: line width: 14us, 280 cylces
I (776) epdiy: LCD init done.
I (776) epd: Space used for waveform LUT: 64K
I (1886) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (2246) epdiy: diff: 25ms, draw: 351ms, buffer update: 12ms, total: 388ms
I (12326) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (12686) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (13696) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (14056) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (24136) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (24496) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (25506) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (25866) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (35946) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (36306) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (37316) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (37676) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (47756) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (48116) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (49126) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (49486) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (59566) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (59926) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (60936) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (61296) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (71376) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (71736) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (72746) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (73106) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (83186) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (83546) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (84556) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (84916) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (94996) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (95356) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (96366) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (96726) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms
I (106806) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (107166) epdiy: diff: 25ms, draw: 350ms, buffer update: 13ms, total: 388ms
I (108176) epdiy: Using optimized vector implementation on the ESP32-S3, only 1k of 65536 LUT in use!
I (108536) epdiy: diff: 25ms, draw: 350ms, buffer update: 12ms, total: 387ms

The App version: 2.0.0-17-gc42defb-dirty called "dirty" because I modified the code to let it use ED060XC3 waveform.

martinberlin commented 2 weeks ago

Hmmm I don't know what's happening in your environment.

I tried the ultimate step: Wiped out completely esp-idf. Installed it with

 git clone --recursive https://github.com/espressif/esp-idf.git --branch release/v5.3

Installed it and added it in the export source as usual. And I also deleted sdkconfig, so theoretically using s3 as target it should read the default configs of sdkconfig.defaults.esp32s3 it still does not work and fails in the same point. But sure it might be my environment and this is a super easy fix, you just need to add a +1 in the MAX_PRIORITIES assert.

martinberlin commented 1 week ago

Closing here since #349 is merged

vroland / epdiy

Weird behaviour on ESP-IDF v5.3 #345