after issue esp32 software reset the library gets stucks

[sushant-ht]

Hi,

I am using this code to link esp32 with 7600 and send data to MQTT, but I have noticed 1 issue, on power the code works fine, but if it gets reset by software reset or esp32 reset itself for any error that the code get hangs in the below-mentioned loop,

` do {
ESP_LOGI(TAG, "Trying to initialize modem on GPIO TX: %d / RX: %d", config.tx_io_num, config.rx_io_num);

    /* create dce object */
    #if CONFIG_EXAMPLE_MODEM_DEVICE_SIM800
        dce = sim800_init(dte);
    #elif CONFIG_EXAMPLE_MODEM_DEVICE_BG96
        dce = bg96_init(dte);
    #elif CONFIG_EXAMPLE_MODEM_DEVICE_SIM7600
        dce = sim7600_init(dte);
    #else
        #error "Unsupported DCE"
    #endif
    vTaskDelay(500 / portTICK_PERIOD_MS);
} while (dce == NULL);`

following is log after reset

�[0;32mI (29066) pppos_example: GOT ip event!!!�[0m
�[0;32mI (29076) system_api: Base MAC address is not set�[0m
�[0;32mI (29076) system_api: read default base MAC address from EFUSE�[0m
�[0;32mI (29086) pppos_example: MQTT other event id: 7�[0m
�[0;32mI (30226) pppos_example: MQTT_EVENT_CONNECTED�[0m
�[0;32mI (30226) pppos_example: sent subscribe successful, msg_id=59904�[0m
�[0;32mI (30576) pppos_example: MQTT_EVENT_SUBSCRIBED, msg_id=59904�[0m
�[0;32mI (30576) pppos_example: sent publish successful, msg_id=0�[0m
�[0;32mI (30926) pppos_example: MQTT_EVENT_DATA�[0m
TOPIC=/topic/esp-pppos

DATA=esp32-pppos
�[0;32mI (32476) pppos_example: rssi: 0, ber: 0�[0m
�[0;32mI (33576) pppos_example: rssi: 0, ber: 0�[0m
�[0;32mI (34676) pppos_example: rssi: 0, ber: 0�[0m
�[0;32mI (35776) pppos_example: rssi: 0, ber: 0�[0m
�[0;32mI (36876) pppos_example: rssi: 0, ber: 0�[0m
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:6984
load:0x40078000,len:13852
load:0x40080400,len:4548
entry 0x400806ec
�[0;32mI (29) boot: ESP-IDF v4.2 2nd stage bootloader�[0m
�[0;32mI (29) boot: compile time 16:43:57�[0m
�[0;32mI (29) boot: chip revision: 1�[0m
�[0;32mI (32) boot_comm: chip revision: 1, min. bootloader chip revision: 0�[0m
�[0;32mI (39) boot.esp32: SPI Speed : 40MHz�[0m
�[0;32mI (43) boot.esp32: SPI Mode : DIO�[0m
�[0;32mI (48) boot.esp32: SPI Flash Size : 4MB�[0m
�[0;32mI (52) boot: Enabling RNG early entropy source...�[0m
�[0;32mI (58) boot: Partition Table:�[0m
�[0;32mI (61) boot: ## Label Usage Type ST Offset Length�[0m
�[0;32mI (69) boot: 0 nvs WiFi data 01 02 00009000 00006000�[0m
�[0;32mI (76) boot: 1 phy_init RF data 01 01 0000f000 00001000�[0m
�[0;32mI (84) boot: 2 factory factory app 00 00 00010000 00100000�[0m
�[0;32mI (91) boot: End of partition table�[0m
�[0;32mI (95) boot_comm: chip revision: 1, min. application chip revision: 0�[0m
�[0;32mI (102) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x19360 (103264) map�[0m
�[0;32mI (150) esp_image: segment 1: paddr=0x00029388 vaddr=0x3ffb0000 size=0x02114 ( 8468) load�[0m
�[0;32mI (154) esp_image: segment 2: paddr=0x0002b4a4 vaddr=0x40080000 size=0x00400 ( 1024) load�[0m
�[0;32mI (158) esp_image: segment 3: paddr=0x0002b8ac vaddr=0x40080400 size=0x0476c ( 18284) load�[0m
�[0;32mI (174) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x63810 (407568) map�[0m
�[0;32mI (329) esp_image: segment 5: paddr=0x00093838 vaddr=0x40084b6c size=0x06b6c ( 27500) load�[0m
�[0;32mI (348) boot: Loaded app from partition at offset 0x10000�[0m
�[0;32mI (348) boot: Disabling RNG early entropy source...�[0m
�[0;32mI (348) cpu_start: Pro cpu up.�[0m
�[0;32mI (352) cpu_start: Application information:�[0m
�[0;32mI (356) cpu_start: Project name: pppos_client�[0m
�[0;32mI (362) cpu_start: App version: 1�[0m
�[0;32mI (366) cpu_start: Compile time: Aug 11 2021 17:01:58�[0m
�[0;32mI (372) cpu_start: ELF file SHA256: af7ac3fa0b39003a...�[0m
�[0;32mI (378) cpu_start: ESP-IDF: v4.2-dirty�[0m
�[0;32mI (384) cpu_start: Starting app cpu, entry point is 0x40081268�[0m
�[0;32mI (376) cpu_start: App cpu up.�[0m
�[0;32mI (394) heap_init: Initializing. RAM available for dynamic allocation:�[0m
�[0;32mI (401) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM�[0m
�[0;32mI (407) heap_init: At 3FFB39B0 len 0002C650 (177 KiB): DRAM�[0m
�[0;32mI (413) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM�[0m
�[0;32mI (420) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM�[0m
�[0;32mI (426) heap_init: At 4008B6D8 len 00014928 (82 KiB): IRAM�[0m
�[0;32mI (432) cpu_start: Pro cpu start user code�[0m
�[0;32mI (451) spi_flash: detected chip: generic�[0m
�[0;32mI (451) spi_flash: flash io: dio�[0m
�[0;32mI (452) cpu_start: Starting scheduler on PRO CPU.�[0m
�[0;32mI (0) cpu_start: Starting scheduler on APP CPU.�[0m
�[0;32mI (26056) uart: queue free spaces: 30�[0m
�[0;32mI (26056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (27556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (27556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (27556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (28056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (29556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (29556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (29556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (30056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (31556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (31556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (31556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (32056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (33556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (33556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (33556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (34056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (35556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (35556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (35556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (36056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (37556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (37556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (37556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (38056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (39556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (39556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (39556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (40056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (41556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (41556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (41556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (42056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (43556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (43556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (43556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (44056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (45556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (45556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (45556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (46056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (47556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (47556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (47556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (48056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (49556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (49556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (49556) bg96: bg96_init(539): sync failed�[0m
�[0;32mI (50056) pppos_example: Trying to initialize modem on GPIO TX: 26 / RX: 25�[0m
�[0;31mE (51556) esp-modem: esp_modem_dte_send_cmd(417): process command timeout�[0m
�[0;31mE (51556) dce_service: esp_modem_dce_sync(67): send command failed�[0m
�[0;31mE (51556) bg96: bg96_init(539): sync failed�[0m

Can you help some way resolve this, when I send SMS it is received, so i don't think it is a communication error between esp32 & sim7600, actually i thought earlier may be sim7600 is getting in sleep mode but that is not the case, somewhere pppos library is getting stuck,

�[0;33mW (434356) pppos_example: Unknow line received:
0m
�[0;31mE (434406) esp-modem: esp_dte_handle_line(138): handle line failed�[0m
�[0;33mW (434406) pppos_example: Unknow line received: +CMTI: "SM",15

is there a way to debug ? and find the root of the problem?