espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.72k stars 7.3k forks source link

pppos_client example hit panic if PM_ENABLE && PM_DFS_INIT_AUTO (IDFGH-2732) #4801

Closed AxelLin closed 4 years ago

AxelLin commented 4 years ago

Module or chip used: ESP32-WROOM-32 IDF version: v4.2-dev-358-ga0644bf8ae6a Build System: CMake Compiler version: xtensa-esp32-elf-gcc (crosstool-NG esp-2019r2) 8.2.0 Operating System: Linux Power Supply: USB

Got below panic if build pppos-client with below settings: CONFIG_PM_ENABLE=y CONFIG_PM_DFS_INIT_AUTO=y

It's 100% reproducable.

I (29) boot: ESP-IDF v4.2-dev-358-ga0644bf8ae6a-dirt 2nd stage bootloader I (29) boot: compile time 13:26:56 I (30) boot: chip revision: 1 I (34) boot.esp32: SPI Speed : 40MHz I (38) boot.esp32: SPI Mode : DIO I (43) boot.esp32: SPI Flash Size : 4MB I (48) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (57) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (71) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (79) boot: 2 factory factory app 00 00 00010000 00100000 I (86) boot: End of partition table I (90) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x18fc0 (102336) map I (136) esp_image: segment 1: paddr=0x00028fe8 vaddr=0x3ffb0000 size=0x02264 ( 8804) load I (140) esp_image: segment 2: paddr=0x0002b254 vaddr=0x40080000 size=0x00404 ( 1028) load 0x40080000: _WindowOverflow4 at /home/axel/esp/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1789

I (143) esp_image: segment 3: paddr=0x0002b660 vaddr=0x40080404 size=0x049b8 ( 18872) load I (160) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x65934 (416052) map 0x400d0020: _stext at ??:?

I (311) esp_image: segment 5: paddr=0x0009595c vaddr=0x40084dbc size=0x068c8 ( 26824) load 0x40084dbc: xRingbufferSend at /home/axel/esp/esp-idf/components/esp_ringbuf/ringbuf.c:1015

I (330) boot: Loaded app from partition at offset 0x10000 I (330) boot: Disabling RNG early entropy source... I (330) cpu_start: Pro cpu up. I (334) cpu_start: Application information: I (339) cpu_start: Project name: pppos_client I (344) cpu_start: App version: v4.2-dev-358-ga0644bf8ae6a-dirt I (351) cpu_start: Compile time: Feb 19 2020 13:26:47 I (357) cpu_start: ELF file SHA256: b840e27d2aeddb77... I (363) cpu_start: ESP-IDF: v4.2-dev-358-ga0644bf8ae6a-dirt I (370) cpu_start: Starting app cpu, entry point is 0x4008135c 0x4008135c: call_start_cpu1 at /home/axel/esp/esp-idf/components/esp32/cpu_start.c:274

I (0) cpu_start: App cpu up. I (381) heap_init: Initializing. RAM available for dynamic allocation: I (388) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM I (394) heap_init: At 3FFB3DD8 len 0002C228 (176 KiB): DRAM I (400) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (406) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (413) heap_init: At 4008B684 len 0001497C (82 KiB): IRAM I (419) cpu_start: Pro cpu start user code I (437) spi_flash: detected chip: gd I (437) spi_flash: flash io: dio I (438) pm_esp32: Frequency switching config: CPU_MAX: 240, APB_MAX: 240, APB_MIN: 40, Light sleep: DISABLED I (445) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. ppp phase changed[1]: phase=0 I (31907) uart: queue free spaces: 30 E (32407) esp-modem: esp_modem_dte_send_cmd(221): process command timeout E (32407) dce_service: esp_modem_dce_sync(48): send command failed E (32407) bg96: bg96_init(461): sync failed Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled. Core 0 register dump: PC : 0x400d673a PS : 0x00060a30 A0 : 0x800d2a19 A1 : 0x3ffb5bd0 0x400d673a: app_main at /home/axel/esp/esp-idf/examples/protocols/pppos_client/build/../main/pppos_client_main.c:415

A2 : 0x00000000 A3 : 0x3ffbb150 A4 : 0x3ffb9b54 A5 : 0x00060023 A6 : 0x00000001 A7 : 0x00060023 A8 : 0x800d6738 A9 : 0x3ffb5ba0 A10 : 0x00000000 A11 : 0x3ffbd3dc A12 : 0x400d7900 A13 : 0x00000000 0x400d7900: bg96_deinit at /home/axel/esp/esp-idf/examples/protocols/pppos_client/build/../components/modem/src/bg96.c:429

A14 : 0x00000000 A15 : 0x0001c200 SAR : 0x00000004 EXCCAUSE: 0x0000001c EXCVADDR: 0x0000007c LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xfffffffd

ELF file SHA256: b840e27d2aeddb775f500e61b885d74c37917581d140dc15314e1aac7ab1d667

Backtrace: 0x400d6737:0x3ffb5bd0 0x400d2a16:0x3ffb5ce0 0x40088679:0x3ffb5d00 0x400d6737: app_main at /home/axel/esp/esp-idf/examples/protocols/pppos_client/build/../main/pppos_client_main.c:411

0x400d2a16: main_task at /home/axel/esp/esp-idf/components/esp32/cpu_start.c:563

0x40088679: vPortTaskWrapper at /home/axel/esp/esp-idf/components/freertos/xtensa/port.c:143

Rebooting... ets Jun 8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0030,len:4 load:0x3fff0034,len:7156 load:0x40078000,len:14352 load:0x40080400,len:4448 0x40080400: _init at ??:?

entry 0x400806f0

david-cermak commented 4 years ago

Hi @AxelLin

The issue is that the example uses the UART with the default clock mode, so the baudrate might not be stable when using PM_ENABLE as described in the docs here https://docs.espressif.com/projects/esp-idf/en/latest/api-reference/system/power_management.html#dynamic-frequency-scaling-and-peripheral-drivers

I'm going to update the example code to init the UART with .source_clk = UART_SCLK_REF_TICK, to fix this issue.

AxelLin commented 4 years ago

I tried change below line to .source_clk = UART_SCLK_REF_TICK, but still got the same issue. https://github.com/espressif/esp-idf/blob/master/examples/protocols/pppos_client/components/modem/src/esp_modem.c#L383

Any other changes required?

david-cermak commented 4 years ago

oh, yes, sorry I checked only against the PPP server (skipped the command mode). You would have to disable the rx interrupts after uart init, as well (add uart_disable_rx_intr(esp_dte->uart_port); to here )

please hold on, fix coming soon.

koobest commented 4 years ago

Hi, @AxelLin Can you try to swap the calling order of these two functions? uart_driver_install uart_param_config

https://github.com/espressif/esp-idf/blob/e36516372a84ff894bde80bc26f9307c1c9e9af0/examples/protocols/pppos_client/components/modem/src/esp_modem.c#L387

thanks!!

AxelLin commented 4 years ago

Hi @koobest , @david-cermak

It works if calling uart_param_config() before uart_driver_install(). BTW, I'm wondering if the uart_set_pin()/uart_set_hw_flow_ctrl() calls should be called before uart_driver_install() as well.

Thanks, Axel

AxelLin commented 4 years ago

Not sure if this is fixed or not, I sent the fix in below pull request: https://github.com/espressif/esp-idf/pull/4904

Alvin1Zhang commented 4 years ago

@AxelLin Thanks for the updates and contributing the PR.

Alvin1Zhang commented 4 years ago

@AxelLin Thanks for reporting the issue, we have a fix internally now under reviewing, will keep you posted. Thanks.

AxelLin commented 5 months ago

Hi @david-cermak The UART_SCLK_REF_TICK does not exist on ESP32S3. Which UART clock source should be used for ESP32S3 so it can work with PM_ENABLE && PM_DFS_INIT_AUTO?