iot_usbh_modem运行后esp32s3可以和4g模块通信成功，但是获取不到ip？ (AEGHB-798) #400
Description
Answers checklist.
- I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
- I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
- I have searched the issue tracker for a similar issue and not found a similar issue.
General issue report
我的环境是vscode，esp-idf relase5.3版本，iot_usbh_modem, version: 0.2.1。硬件是ESP32-S3-DevKitC-1+移远EC800M-CN。我的问题和#341很像。但是我这个模块ec800m是确定支持ppp协议的。这个模块在电脑上也验证可以使用数据流量，但是运行起来前面几个步骤通过AT指令的log可以看到都能通信成功而且返回成功，但是到这一步modem_board: Modem state STAGE_WAIT_IP, Start就没法成功获取ip,加了一些打印，一直打dhcp_coarse_tmr()。请问可能是什么原因？如何排查？下面是完整的开机到异常的log
--- WARNING: GDB cannot open serial ports accessed as COMx
--- Using \.\COM18 instead...
--- esp-idf-monitor 1.4.0 on \.\COM18 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x28 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce2820,len:0x1918
load:0x403c8700,len:0x4
load:0x403c8704,len:0xe5c
load:0x403cb700,len:0x303c
entry 0x403c893c
I (27) boot: ESP-IDF GIT-NOTFOUND 2nd stage bootloader
I (27) boot: compile time Sep 3 2024 11:38:03
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.2
I (34) qio_mode: Enabling default flash chip QIO
I (40) boot.esp32s3: Boot SPI Speed : 80MHz
I (44) boot.esp32s3: SPI Mode : QIO
I (49) boot.esp32s3: SPI Flash Size : 8MB
I (54) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (63) boot: ## Label Usage Type ST Offset Length
I (70) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (78) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (85) boot: 2 factory factory app 00 00 00010000 00100000
I (92) boot: 3 storage Unknown data 01 82 00110000 00100000
I (100) boot: End of partition table
I (104) esp_image: segment 0: paddr=00010020 vaddr=3c0b0020 size=3454ch (214348) map
I (145) esp_image: segment 1: paddr=00044574 vaddr=3fc9e200 size=05238h ( 21048) load
I (149) esp_image: segment 2: paddr=000497b4 vaddr=40374000 size=06864h ( 26724) load
I (156) esp_image: segment 3: paddr=00050020 vaddr=42000020 size=a9494h (693396) map
I (265) esp_image: segment 4: paddr=000f94bc vaddr=4037a864 size=138a8h ( 80040) load
I (291) boot: Loaded app from partition at offset 0x10000
I (291) boot: Disabling RNG early entropy source...
I (303) octal_psram: vendor id : 0x0d (AP)
I (303) octal_psram: dev id : 0x02 (generation 3)
I (303) octal_psram: density : 0x03 (64 Mbit)
I (308) octal_psram: good-die : 0x01 (Pass)
I (313) octal_psram: Latency : 0x01 (Fixed)
I (318) octal_psram: VCC : 0x01 (3V)
I (323) octal_psram: SRF : 0x01 (Fast Refresh)
I (329) octal_psram: BurstType : 0x01 (Hybrid Wrap)
I (335) octal_psram: BurstLen : 0x01 (32 Byte)
I (340) octal_psram: Readlatency : 0x02 (10 cycles@Fixed)
I (347) octal_psram: DriveStrength: 0x00 (1/1)
D (352) MSPI Timing: test nums: 1, test result: [id][good/bad][good_times]:
D (359) MSPI Timing: [0][good][1]
D (362) MSPI Timing: [1][good][1]
D (366) MSPI Timing: [2][bad][0]
D (369) MSPI Timing: [3][good][1]
D (373) MSPI Timing: [4][good][1]
D (376) MSPI Timing: [5][good][1]
D (380) MSPI Timing: [6][good][1]
D (383) MSPI Timing: [7][bad][0]
D (386) MSPI Timing: [8][bad][0]
D (390) MSPI Timing: [9][good][1]
D (393) MSPI Timing: [10][good][1]
D (397) MSPI Timing: [11][good][1]
D (400) MSPI Timing: [12][good][1]
D (404) MSPI Timing: [13][good][1]
D (407) MSPI Timing: tuning success, best point is index 4
I (413) MSPI Timing: PSRAM timing tuning index: 4
I (418) esp_psram: Found 8MB PSRAM device
I (423) esp_psram: Speed: 80MHz
I (427) cpu_start: Multicore app
D (431) cpu_start: Pro cpu up
D (434) cpu_start: Starting app cpu, entry point is 0x40375a84
0x40375a84: apb_backup_dma_lock at D:/yang/esp/v5.3/esp-idf/components/esp_system/port/soc/esp32s3/apb_backup_dma.c:17
D (0) cpu_start: App cpu up
I (846) esp_psram: SPI SRAM memory test OK
D (855) clk: RTC_SLOW_CLK calibration value: 3558835
D (860) cpu_start: calling init function: 0x42003b48 on core: 0
0x42003b48: esp_sleep_config_gpio_isolate at D:/yang/esp/v5.3/esp-idf/components/esp_hw_support/sleep_gpio.c:70
D (860) cpu_start: calling init function: 0x4200405c on core: 0
0x4200405c: memprot_ll_iram0_reset_monitor_intrclr at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/memprot_ll.h:505
I (861) cpu_start: Pro cpu start user code
I (866) cpu_start: cpu freq: 240000000 Hz
D (870) cpu_start: calling init function: 0x42003a70 on core: 0
0x42003a70: rtc_isr_register at D:/yang/esp/v5.3/esp-idf/components/esp_hw_support/rtc_module.c:105
I (876) app_init: Application information:
I (881) app_init: Project name: usb_cdc_4g_module
I (887) app_init: App version: 1
I (891) app_init: Compile time: Sep 3 2024 15:45:20
I (897) app_init: ELF file SHA256: cdecd9ae1...
Warning: checksum mismatch between flashed and built applications. Checksum of built application is 858225fbd1626db11aaf916627c0dcc174d92c693e617c950d8f59e872938606
I (902) app_init: ESP-IDF: GIT-NOTFOUND
D (908) cpu_start: calling init function: 0x42003b58 on core: 0
0x42003b58: esp_sleep_config_gpio_isolate at D:/yang/esp/v5.3/esp-idf/components/esp_hw_support/sleep_gpio.c:74 (discriminator 1)
I (914) efuse_init: Min chip rev: v0.0
I (919) efuse_init: Max chip rev: v0.99
I (923) efuse_init: Chip rev: v0.2
D (928) cpu_start: calling init function: 0x420058c8 on core: 0
0x420058c8: esp_mprot_set_prot at D:/yang/esp/v5.3/esp-idf/components/esp_hw_support/port/esp32s3/esp_memprot.c:1156
D (934) memory_layout: Checking 7 reserved memory ranges:
D (940) memory_layout: Reserved memory range 0x3c000000 - 0x3e000000
D (946) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9e200
D (953) memory_layout: Reserved memory range 0x3fc9e200 - 0x3fca6ea0
D (959) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (965) memory_layout: Reserved memory range 0x40374000 - 0x4038e200
0x40374000: _WindowOverflow4 at D:/yang/esp/v5.3/esp-idf/components/xtensa/xtensa_vectors.S:2027
D (972) memory_layout: Reserved memory range 0x600fe000 - 0x600fe100
D (978) memory_layout: Reserved memory range 0x600fffe8 - 0x60100000
D (985) memory_layout: Building list of available memory regions:
D (991) memory_layout: Available memory region 0x3fca6ea0 - 0x3fcb0000
D (997) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
D (1004) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
D (1011) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
D (1017) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710
D (1024) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34
D (1031) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
D (1037) memory_layout: Available memory region 0x600fe100 - 0x600fffe8
I (1044) heap_init: Initializing. RAM available for dynamic allocation:
D (1051) heap_init: New heap initialised at 0x3fca6ea0
I (1057) heap_init: At 3FCA6EA0 len 00042870 (266 KiB): RAM
I (1063) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
D (1069) heap_init: New heap initialised at 0x3fcf0000
I (1074) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (1081) heap_init: New heap initialised at 0x600fe100
I (1086) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
D (1092) cpu_start: calling init function: 0x42008d50 on core: 0
0x42008d50: cache_ll_l1_get_bus at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/cache_ll.h:540
(inlined by) s_psram_mapping at D:/yang/esp/v5.3/esp-idf/components/esp_psram/esp_psram.c:250
D (1098) cpu_start: calling init function: 0x420086d0 on core: 0
0x420086d0: esp_vfs_link at D:/yang/esp/v5.3/esp-idf/components/vfs/vfs.c:682
D (1104) cpu_start: calling init function: 0x4200bd34 on core: 0
0x4200bd34: std at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp-elf/src/newlib/newlib/libc/stdio/findfp.c:92 (discriminator 1)
I (1110) esp_psram: Adding pool of 8192K of PSRAM memory to heap allocator
D (1118) cpu_start: calling init function: 0x420040a4 on core: 0
0x420040a4: memprot_ll_get_pif_constraint_lock at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/memprot_ll.h:707
D (1124) intr_alloc: Connected src 39 to int 1 (cpu 0)
D (1129) cpu_start: calling init function: 0x420040b0 on core: 0
0x420040b0: memprot_ll_get_pif_constraint_lock at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/memprot_ll.h:710
D (1135) cpu_start: calling init function: 0x42009bb0 on core: 0
0x42009bb0: esp_mmu_map at D:/yang/esp/v5.3/esp-idf/components/esp_mm/esp_mmu_map.c:449 (discriminator 1)
D (1141) cpu_start: calling init function: 0x4200a620 on core: 0
0x4200a620: add_entry at D:/yang/esp/v5.3/esp-idf/components/esp_system/task_wdt/task_wdt.c:180
D (1147) cpu_start: calling init function: 0x4200a9fc on core: 0
0x4200a9fc: esp_task_wdt_init at D:/yang/esp/v5.3/esp-idf/components/esp_system/task_wdt/task_wdt.c:521 (discriminator 1)
D (1153) cpu_start: calling init function: 0x42008750 on core: 0
0x42008750: esp_vfs_unlink at D:/yang/esp/v5.3/esp-idf/components/vfs/vfs.c:703 (discriminator 3)
D (1160) cpu_start: calling init function: 0x42008ad4 on core: 0
0x42008ad4: s_test_psram at D:/yang/esp/v5.3/esp-idf/components/esp_psram/esp_psram.c:465 (discriminator 1)
D (1166) cpu_start: calling init function: 0x420040f0 on core: 0
0x420040f0: memprot_ll_set_rtcfast_split_line at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/memprot_ll.h:771
D (1172) spi_flash: trying chip: issi
D (1175) spi_flash: trying chip: gd
D (1179) spi_flash: trying chip: mxic
D (1183) spi_flash: trying chip: winbond
D (1187) spi_flash: trying chip: boya
D (1190) spi_flash: trying chip: th
D (1194) spi_flash: trying chip: mxic (opi)
D (1198) spi_flash: trying chip: generic
I (1202) spi_flash: detected chip: generic
I (1207) spi_flash: flash io: qio
D (1211) chip_generic: set_io_mode: status before 0x200
W (1216) spi_flash: Detected size(16384k) larger than the size in the binary image header(8192k). Using the size in the binary image header.
D (1230) cpu_start: calling init function: 0x4209af38 on core: 0
D (1236) cpu_start: calling init function: 0x4207f0b4
D (1241) cpu_start: calling init function: 0x4203880c
D (1246) cpu_start: calling init function: 0x4037d21c
0x4037d21c: vTaskGenericNotifyGiveFromISR at D:/yang/esp/v5.3/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:6212
D (1251) cpu_start: calling init function: 0x420051e4
0x420051e4: esp_mprot_is_conf_locked_any at D:/yang/esp/v5.3/esp-idf/components/esp_hw_support/port/esp32s3/esp_memprot.c:680 (discriminator 1)
D (1256) cpu_start: calling init function: 0x420044e4
0x420044e4: memprot_ll_set_dram0_split_line at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/memprot_ll.h:1303
D (1261) cpu_start: calling init function: 0x4206c624 on core: 0
D (1267) intr_alloc: Connected src 59 to int 2 (cpu 0)
D (1273) cpu_start: calling init function: 0x420067c8 on core: 0
0x420067c8: uart_tcgetattr at D:/yang/esp/v5.3/esp-idf/components/esp_driver_uart/src/uart_vfs.c:803
I (1279) sleep: Configure to isolate all GPIO pins in sleep state
I (1286) sleep: Enable automatic switching of GPIO sleep configuration
D (1293) cpu_start: calling init function: 0x420040bc on core: 0
0x420040bc: memprot_ll_get_pif_constraint_lock at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/memprot_ll.h:710
D (1299) cpu_start: calling init function: 0x4200a434 on core: 0
0x4200a434: esp_flash_init_default_chip at D:/yang/esp/v5.3/esp-idf/components/spi_flash/esp_flash_spi_init.c:380
D (1305) cpu_start: calling init function: 0x420040c8 on core: 0
0x420040c8: memprot_ll_set_rtcfast_split_line at D:/yang/esp/v5.3/esp-idf/components/hal/esp32s3/include/hal/memprot_ll.h:740
D (1311) intr_alloc: Connected src 79 to int 3 (cpu 0)
D (1316) app_start: Starting scheduler on CPU0
D (1321) intr_alloc: Connected src 57 to int 5 (cpu 0)
D (1321) intr_alloc: Connected src 80 to int 0 (cpu 1)
D (1326) app_start: Starting scheduler on CPU1
D (1331) intr_alloc: Connected src 58 to int 1 (cpu 1)
I (1321) main_task: Started on CPU0
D (1341) heap_init: New heap initialised at 0x3fce9710
I (1345) esp_psram: Reserving pool of 32K of internal memory for DMA/internal allocations
D (1354) esp_psram: Allocating block of size 32768 bytes
I (1360) main_task: Calling app_main()
I (1364) led_indicator: LED Indicator Version: 0.3.0
I (1370) gpio: GPIO[15]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1379) led_indicator: blink_lists is null, use default blink list
W (1386) led_indicator: ./managed_components/espressif__led_indicator/src/led_indicator.c:280 (_led_indicator_create_com):LED indicator does not have the hal_indicator_set_brightness function
I (1404) led_indicator: Indicator create successfully. type:GPIO mode, hardware_data:0xf, is_active_level_high:1, blink_lists:default
I (1416) led_indicator: LED Indicator Version: 0.3.0
I (1422) gpio: GPIO[17]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1432) led_indicator: blink_lists is null, use default blink list
W (1438) led_indicator: ./managed_components/espressif__led_indicator/src/led_indicator.c:280 (_led_indicator_create_com):LED indicator does not have the hal_indicator_set_brightness function
I (1456) led_indicator: Indicator create successfully. type:GPIO mode, hardware_data:0x11, is_active_level_high:1, blink_lists:default
I (1469) led_indicator: LED Indicator Version: 0.3.0
I (1475) gpio: GPIO[16]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1484) led_indicator: blink_lists is null, use default blink list
W (1491) led_indicator: ./managed_components/espressif__led_indicator/src/led_indicator.c:280 (_led_indicator_create_com):LED indicator does not have the hal_indicator_set_brightness function
I (1509) led_indicator: Indicator create successfully. type:GPIO mode, hardware_data:0x10, is_active_level_high:1, blink_lists:default
netif: netmask of interface set to 255.0.0.0
netif: GW address of interface set to 127.0.0.1
netif_set_ipaddr: netif address being changed
netif: added interface lo IP addr 127.0.0.1 netmask 255.0.0.0 gw 127.0.0.1
dns_init: initializing
D (1543) esp_netif_lwip: LwIP stack has been initialized
D (1548) esp_netif_lwip: esp-netif has been successfully initialized
D (1555) event: running task for loop 0x3fcb4acc
D (1559) event: created task for loop 0x3fcb4acc
D (1564) event: created event loop 0x3fcb4acc
I (1568) 4g_main: ====================================
I (1574) 4g_main: ESP 4G Cat.1 Wi-Fi Router
I (1580) 4g_main: ====================================
I (1585) modem_board: iot_usbh_modem, version: 0.2.1
I (1591) modem_board: Force reset modem board....
I (1596) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1606) modem_board: Resetting modem using io=13, level=0
I (1812) modem_board: Waiting for modem initialize ready
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (6812) event: created event loop 0x3fcb8e0c
I (6812) USB_HCDC: iot_usbh_cdc, version: 0.2.2
I (6812) IOT_USBH: iot_usbh, version: 0.2.1
D (6815) intr_alloc: Connected src 38 to int 8 (cpu 0)
I (6850) IOT_USBH: USB Port=1 init succeed, fifo strategy=0
I (6850) IOT_USBH: USB Processing Start
I (6850) IOT_USBH: usb port start succeed
I (6850) IOT_USBH: Waiting USB Connection
I (6854) USB_HCDC: usbh cdc driver install succeed
I (6859) IOT_USBH: Port power: ON Succeed
I (6864) USB_HCDC: Waiting CDC Device Connection
I (6850) USB_HCDC: CDC task start
D (6878) IOT_USBH: urb alloced
D (6881) IOT_USBH: urb alloced
D (6884) IOT_USBH: urb alloced
D (6888) IOT_USBH: urb alloced
D (6891) IOT_USBH: urb alloced
D (6894) IOT_USBH: urb alloced
D (6897) IOT_USBH: urb alloced
D (6900) IOT_USBH: urb alloced
D (6903) IOT_USBH: urb alloced
D (6906) IOT_USBH: urb alloced
dhcp_coarse_tmr()
I (8539) IOT_USBH: line 131 PORT_EVENT_CONNECTION
dhcp_coarse_tmr()
I (8639) IOT_USBH: Resetting Port
I (8699) IOT_USBH: Port reset succeed
I (8699) IOT_USBH: Getting Port Speed
I (8699) IOT_USBH: USB Speed: full-speed
I (8701) IOT_USBH: Pipe init succeed, addr: 00
D (8706) IOT_USBH: urb alloced
I (8710) IOT_USBH: Set Device Addr = 1
D (8714) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (8720) IOT_USBH: Set Device Addr Done
D (8724) IOT_USBH: urb free
D (8727) IOT_USBH: urb alloced
I (8730) IOT_USBH: get device desc
D (8735) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (8740) IOT_USBH: get device desc, actual_num_bytes:26
*** Device descriptor ***
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0x2
bDeviceSubClass 0x2
bDeviceProtocol 0x0
bMaxPacketSize0 64
idVendor 0x2ecc
idProduct 0x3004
bcdDevice 0.00
iManufacturer 1
iProduct 2
iSerialNumber 3
bNumConfigurations 1
D (8769) IOT_USBH: urb free
D (8772) IOT_USBH: urb alloced
I (8775) IOT_USBH: get short config desc
D (8781) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (8786) IOT_USBH: get config desc, actual_num_bytes:16
I (8792) IOT_USBH: get full config desc
D (8797) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (8802) IOT_USBH: get full config desc, actual_num_bytes:75
*** Configuration descriptor ***
bLength 9
bDescriptorType 2
wTotalLength 67
bNumInterfaces 2
bConfigurationValue 1
iConfiguration 4
bmAttributes 0xc0
bMaxPower 0mA
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 1
bInterfaceClass 0x2
bInterfaceSubClass 0x2
bInterfaceProtocol 0x0
iInterface 5
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 0x3 INT
wMaxPacketSize 10
bInterval 1
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 0xa
bInterfaceSubClass 0x0
bInterfaceProtocol 0x0
iInterface 6
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x2 EP 2 OUT
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
D (8901) IOT_USBH: urb free
D (8904) IOT_USBH: urb alloced
I (8907) IOT_USBH: Set Device Configuration = 1
D (8914) IOT_USBH: Got unexpected pipe_handle or event
W (8918) IOT_USBH: line 166 Pipe: default PIPE_EVENT_ERROR_XFER
E (8925) IOT_USBH: ./managed_components/espressif__iot_usbh/iot_usbh.c:930 (_usbh_set_device_config):urb event error
D (8936) IOT_USBH: pipe state = 1
W (8939) IOT_USBH: line 135 PORT_EVENT_DISCONNECTION
D (9045) IOT_USBH: urb dequeue handle = 0x3c0f0f40
W (9045) IOT_USBH: pipe=0x3fcc7efc clear failed
D (9045) IOT_USBH: urb free
E (9047) IOT_USBH: ./managed_components/espressif__iot_usbh/iot_usbh.c:1017 (_usbh_processing_task):Set device configuration failed
W (9059) IOT_USBH: Resetting USB Driver
W (9064) IOT_USBH: Resetting default pipe
D (9069) IOT_USBH: pipe state = 1
D (9172) IOT_USBH: urb dequeue handle = 0x0
W (9172) IOT_USBH: pipe=0x3fcc7efc clear failed
I (9172) IOT_USBH: iot_usbh_pipe_deinit: pipe state = 1
I (9176) IOT_USBH: Pipe deinit succeed, addr: 00
I (9182) IOT_USBH: hcd recovering
I (9186) IOT_USBH: Port power: ON Succeed
I (9290) IOT_USBH: Waiting USB Connection
dhcp_coarse_tmr()
dhcp_coarse_tmr()
I (10554) IOT_USBH: line 131 PORT_EVENT_CONNECTION
I (10654) IOT_USBH: Resetting Port
I (10714) IOT_USBH: Port reset succeed
I (10714) IOT_USBH: Getting Port Speed
I (10714) IOT_USBH: USB Speed: full-speed
I (10717) IOT_USBH: Pipe init succeed, addr: 00
D (10722) IOT_USBH: urb alloced
I (10725) IOT_USBH: Set Device Addr = 1
D (10730) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (10735) IOT_USBH: Set Device Addr Done
D (10740) IOT_USBH: urb free
D (10743) IOT_USBH: urb alloced
I (10746) IOT_USBH: get device desc
D (10750) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (10756) IOT_USBH: get device desc, actual_num_bytes:26
*** Device descriptor ***
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0xef
bDeviceSubClass 0x2
bDeviceProtocol 0x1
bMaxPacketSize0 64
idVendor 0x2c7c
idProduct 0x6002
bcdDevice 3.10
iManufacturer 1
iProduct 2
iSerialNumber 3
bNumConfigurations 1
D (10786) IOT_USBH: urb free
D (10789) IOT_USBH: urb alloced
I (10792) IOT_USBH: get short config desc
D (10797) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (10802) IOT_USBH: get config desc, actual_num_bytes:16
I (10808) IOT_USBH: get full config desc
D (10813) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (10819) IOT_USBH: get full config desc, actual_num_bytes:266
*** Configuration descriptor ***
bLength 9
bDescriptorType 2
wTotalLength 258
bNumInterfaces 6
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xe0
bMaxPower 500mA
*** Interface Association Descriptor ***
bLength 8
bDescriptorType 11
bFirstInterface 0
bInterfaceCount 2
bFunctionClass 0x2
bFunctionSubClass 0x6
bFunctionProtocol 0x0
iFunction 5
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 1
bInterfaceClass 0x2
bInterfaceSubClass 0x6
bInterfaceProtocol 0x0
iInterface 5
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x87 EP 7 IN
bmAttributes 0x3 INT
wMaxPacketSize 64
bInterval 16
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 0
bNumEndpoints 0
bInterfaceClass 0xa
bInterfaceSubClass 0x0
bInterfaceProtocol 0x0
iInterface 5
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 1
bNumEndpoints 2
bInterfaceClass 0xa
bInterfaceSubClass 0x0
bInterfaceProtocol 0x0
iInterface 0
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 0x2 BULK
wMaxPacketSize 512
bInterval 0
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0xc EP 12 OUT
bmAttributes 0x2 BULK
wMaxPacketSize 512
bInterval 0
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 2
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 0xff
bInterfaceSubClass 0x0
bInterfaceProtocol 0x0
iInterface 8
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x82 EP 2 IN
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0xb EP 11 OUT
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 3
bAlternateSetting 0
bNumEndpoints 3
bInterfaceClass 0xff
bInterfaceSubClass 0x0
bInterfaceProtocol 0x0
iInterface 11
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x89 EP 9 IN
bmAttributes 0x3 INT
wMaxPacketSize 64
bInterval 16
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x86 EP 6 IN
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0xf EP 15 OUT
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 4
bAlternateSetting 0
bNumEndpoints 3
bInterfaceClass 0xff
bInterfaceSubClass 0x0
bInterfaceProtocol 0x0
iInterface 11
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x88 EP 8 IN
bmAttributes 0x3 INT
wMaxPacketSize 64
bInterval 16
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0xa EP 10 OUT
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Interface descriptor ***
bLength 9
bDescriptorType 4
bInterfaceNumber 32
bAlternateSetting 0
bNumEndpoints 3
bInterfaceClass 0xff
bInterfaceSubClass 0x0
bInterfaceProtocol 0x0
iInterface 11
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x85 EP 5 IN
bmAttributes 0x3 INT
wMaxPacketSize 64
bInterval 16
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0x84 EP 4 IN
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
*** Endpoint descriptor ***
bLength 7
bDescriptorType 5
bEndpointAddress 0xd EP 13 OUT
bmAttributes 0x2 BULK
wMaxPacketSize 64
bInterval 0
D (11180) IOT_USBH: urb free
D (11183) IOT_USBH: urb alloced
I (11186) IOT_USBH: Set Device Configuration = 1
D (11192) IOT_USBH: line 162 Pipe: default PIPE_EVENT_URB_DONE
I (11197) IOT_USBH: Set Device Configuration Done
D (11203) IOT_USBH: urb free
D (11206) event: no handlers have been registered for event MODEM_BOARD_EVENT:0 posted to loop 0x3fcb4acc
D (11206) USB_HCDC: Creating bulk in pipe itf = 0, ep = 0x81,
I (11221) IOT_USBH: Pipe init succeed, addr: 81
D (11226) USB_HCDC: Creating bulk out pipe itf = 0, ep = 0x0A
I (11232) IOT_USBH: Pipe init succeed, addr: 0A
I (11238) USB_HCDC: CDC Device Connected
I (11242) esp-modem: --------- Modem PreDefined Info ------------------
I (11249) esp-modem: Model: EC600NCNLC-N06
I (11254) esp-modem: Modem itf: IN Addr:0x81, OUT Addr:0x0A
I (11260) esp-modem: ----------------------------------------------------
I (11268) gpio: GPIO[12]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (11277) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (11287) esp_netif_lwip: check: remote, if=0x3fcb7cf4 fn=0x420a26cc
D (11293) esp_netif_objects: esp_netif_add_to_list_unsafe netif added successfully (total netifs: 1)
netif: netmask of interface set to 255.255.255.255
netif: added interface pp IP addr 0.0.0.0 netmask 255.255.255.255 gw 0.0.0.0
D (11314) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3c0f0fa4
D (11322) esp-netif_lwip-ppp: Phase Dead
D (11326) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (11332) USB_HCDC: rx0 flush -0 = 0
D (11332) modem_board: Handling bits = 0080, stage = 1, retry = 0
I (11342) modem_board: DTE reconnect, reconnecting ...
dhcp_coarse_tmr()
I (12348) modem_board: reconnect after 5s...
dhcp_coarse_tmr()
I (13348) modem_board: reconnect after 4s...
dhcp_coarse_tmr()
I (14348) modem_board: reconnect after 3s...
dhcp_coarse_tmr()
I (15348) modem_board: reconnect after 2s...
dhcp_coarse_tmr()
I (16348) modem_board: reconnect after 1s...
I (16348) modem_board: Modem state STAGE_SYNC, Start
D (16358) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:AT
D (16358) USB_HCDC: cdc write itf: 0, buf = 0x3c0b9e14, len = 3
D (16364) USB_HCDC: cdc read itf: 0, buf = 0x3fcb8124, len = 6, read = 6
D (16368) esp-modem: debug_data: 0x3fcb8124 0d 0a 4f 4b 0d 0a |..OK..|
D (16377) esp_modem_dce: esp_modem_dce_generic_command(35): Command:AT
succeeded
D (16385) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:ATE0
D (16392) USB_HCDC: cdc write itf: 0, buf = 0x3c0b9e20, len = 5
D (16401) USB_HCDC: cdc read itf: 0, buf = 0x3fcb8124, len = 6, read = 6
D (16405) esp-modem: debug_data: 0x3fcb8124 0d 0a 4f 4b 0d 0a |..OK..|
D (16415) esp_modem_dce: esp_modem_dce_generic_command(35): Command:ATE0
succeeded
I (16423) modem_board: Network Auto reconnecting ...
I (16428) modem_board: Modem state STAGE_SYNC, Success!
D (16428) event: running post MODEM_BOARD_EVENT:7 with handler 0x4200bf08 and context 0x3fcc8be0 on loop 0x3fcb4acc
0x4200bf08: __fp_lock_all at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp-elf/src/newlib/newlib/libc/stdio/findfp.c:302
W (16445) 4g_main: Modem Board Event: Network disconnected
D (16534) modem_board: Handling bits = 0100, stage = 3, retry = 0
I (16534) modem_board: Modem state STAGE_CHECK_SIM, Start
D (16535) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:AT+CPIN?
dhcp_coarse_tmr()
D (16543) USB_HCDC: cdc write itf: 0, buf = 0x3c0b9e74, len = 9
D (16554) USB_HCDC: cdc read itf: 0, buf = 0x3fcb8124, len = 22, read = 22
D (16558) esp-modem: debug_data: 0x3fcb8124 0d 0a 2b 43 50 49 4e 3a 20 52 45 41 44 59 0d 0a |..+CPIN: READY..|
D (16568) esp-modem: debug_data: 0x3fcb8134 0d 0a 4f 4b 0d 0a |..OK..|
D (16578) esp_modem_dce: esp_modem_dce_generic_command(35): Command:AT+CPIN?
succeeded
I (16586) modem_board: SIM Card Ready
I (16590) modem_board: Modem state STAGE_CHECK_SIM, Success!
D (16590) event: running post MODEM_BOARD_EVENT:2 with handler 0x4200bf08 and context 0x3fcc8be0 on loop 0x3fcb4acc
0x4200bf08: __fp_lock_all at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp-elf/src/newlib/newlib/libc/stdio/findfp.c:302
I (16607) 4g_main: Modem Board Event: SIM Card Connected
D (16696) modem_board: Handling bits = 0100, stage = 4, retry = 0
I (16696) modem_board: Modem state STAGE_CHECK_SIGNAL, Start
D (16697) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:AT+CSQ
D (16705) USB_HCDC: cdc write itf: 0, buf = 0x3c0b9ebc, len = 7
D (16714) USB_HCDC: cdc read itf: 0, buf = 0x3fcb8124, len = 21, read = 21
D (16718) esp-modem: debug_data: 0x3fcb8124 0d 0a 2b 43 53 51 3a 20 32 36 2c 39 39 0d 0a 0d |..+CSQ: 26,99...|
D (16728) esp-modem: debug_data: 0x3fcb8134 0a 4f 4b 0d 0a |.OK..|
D (16738) esp_modem_dce: esp_modem_dce_generic_command(35): Command:AT+CSQ
succeeded
I (16746) modem_board: Signal quality: rssi=26, ber=99
I (16752) modem_board: Modem state STAGE_CHECK_SIGNAL, Success!
D (16858) modem_board: Handling bits = 0100, stage = 5, retry = 0
I (16858) modem_board: Modem state STAGE_CHECK_REGIST, Start
D (16859) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:AT+COPS?
D (16867) USB_HCDC: cdc write itf: 0, buf = 0x3c0b9e4c, len = 9
D (16877) USB_HCDC: cdc read itf: 0, buf = 0x3fcb8124, len = 30, read = 30
D (16880) esp-modem: debug_data: 0x3fcb8124 0d 0a 2b 43 4f 50 53 3a 20 30 2c 32 2c 22 34 36 |..+COPS: 0,2,"46|
D (16891) esp-modem: debug_data: 0x3fcb8134 30 31 31 22 2c 37 0d 0a 0d 0a 4f 4b 0d 0a |011",7....OK..|
D (16901) esp_modem_dce: esp_modem_dce_generic_command(35): Command:AT+COPS?
succeeded
I (16909) modem_board: Network registed, Operator: "46011"
I (16915) modem_board: Modem state STAGE_CHECK_REGIST, Success!
D (17022) modem_board: Handling bits = 0100, stage = 6, retry = 0
I (17022) modem_board: Modem state STAGE_START_PPP, Start
D (17023) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:AT+CGDCONT=1,"IP","CTNET"
D (17032) USB_HCDC: cdc write itf: 0, buf = 0x3fcc8604, len = 26
D (17043) USB_HCDC: cdc read itf: 0, buf = 0x3fcb8124, len = 6, read = 6
D (17045) esp-modem: debug_data: 0x3fcb8124 0d 0a 4f 4b 0d 0a |..OK..|
D (17055) esp_modem_dce: esp_modem_dce_generic_command(35): Command:AT+CGDCONT=1,"IP","CTNET"
succeeded
D (17064) esp_modem_dce: esp_modem_switch_to_data_mode
D (17070) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:ATD99**1#
D (17078) USB_HCDC: cdc write itf: 0, buf = 0x3c0b9ecc, len = 12
D (17087) USB_HCDC: cdc read itf: 0, buf = 0x3fcb8124, len = 11, read = 11
D (17091) esp-modem: debug_data: 0x3fcb8124 0d 0a 43 4f 4e 4e 45 43 54 0d 0a |..CONNECT..|
D (17101) esp_modem_dce: esp_modem_dce_generic_command(35): Command:ATD99**1#
succeeded
I (17110) modem_board: Modem state STAGE_START_PPP, Success!
D (17110) event: running post ESP_MODEM_EVENT:0 with handler 0x420365d4 and context 0x3fcc8a5c on loop 0x3fcb8e0c
D (17126) esp_netif_handlers: esp_netif action has started with netif0x3fcc8ee8 from event_id=0
D (17135) esp_netif_lwip: check: remote, if=0x3fcc8ee8 fn=0x420a21a8
D (17141) esp_netif_lwip: esp_netif_start_api 0x3fcc8ee8
D (17147) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3c0f0fa4
D (17155) esp-netif_lwip-ppp: Phase Start
D (17159) event: running post NETIF_PPP_STATUS:259 with handler 0x42017db0 and context 0x3fcc8b44 on loop 0x3fcb4acc
0x42017db0: insert_free_block at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:357
(inlined by) block_insert at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:388
(inlined by) tlsf_add_pool at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:907
D (17159) esp-netif_lwip-ppp: Phase Establish
D (17174) event: running post NETIF_PPP_STATUS:262 with handler 0x42017db0 and context 0x3fcc8b44 on loop 0x3fcb4acc
0x42017db0: insert_free_block at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:357
(inlined by) block_insert at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:388
(inlined by) tlsf_add_pool at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:907
D (17174) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
D (17191) esp_netif_lwip: check: local, if=0x3fcc8ee8 fn=0x420a2bb4
D (17197) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc8ee8
D (17204) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (17209) event: running post ESP_MODEM_EVENT:0 with handler 0x42014e98 and context 0x3fcc8b78 on loop 0x3fcb8e0c
0x42014e98: _svfiprintf_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp-elf/src/newlib/newlib/libc/stdio/svfiprintf.c:1391 (discriminator 3)
D (17216) modem_board: Handling bits = 0100, stage = 7, retry = 0
W (17220) modem_board: Modem event! 0
I (17226) modem_board: Modem state STAGE_WAIT_IP, Start
W (17236) modem_board: test STAGE_WAIT_IP start!
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (23191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (29191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (35191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (41191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (47191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (53191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (59191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (65191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (71191) USB_HCDC: cdc write itf: 0, buf = 0x3c0f2828, len = 45
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
D (77191) esp-netif_lwip-ppp: Phase Disconnect
D (77191) event: running post NETIF_PPP_STATUS:268 with handler 0x42017db0 and context 0x3fcc8b44 on loop 0x3fcb4acc
0x42017db0: insert_free_block at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:357
(inlined by) block_insert at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:388
(inlined by) tlsf_add_pool at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:907
D (77191) esp-netif_lwip-ppp: Phase Dead
I (77199) esp-netif_lwip-ppp: Connection lost
D (77199) event: running post NETIF_PPP_STATUS:256 with handler 0x42017db0 and context 0x3fcc8b44 on loop 0x3fcb4acc
0x42017db0: insert_free_block at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:357
(inlined by) block_insert at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:388
(inlined by) tlsf_add_pool at D:/yang/esp/v5.3/esp-idf/components/heap/tlsf/tlsf.c:907
D (77214) event: running post IP_EVENT:7 with handler 0x42036770 and context 0x3fcc8b10 on loop 0x3fcb4acc
D (77224) esp_netif_handlers: esp_netif action disconnected with netif0x3fcc8ee8 from event_id=7
D (77233) esp_netif_lwip: check: remote, if=0x3fcc8ee8 fn=0x420a2984
D (77239) esp_netif_lwip: esp_netif_down_api esp_netif:0x3fcc8ee8
W (77242) modem_board: con_bits 256,MODEM_DESTROY_BIT 1
netif: netmask of interface pp set to 0.0.0.0
W (77252) modem_board: con_bits 256,PPP_NET_CONNECT_BIT 16
D (77255) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fcc8f70
W (77263) modem_board: Modem Got IP timeout, retry from start!
D (77269) esp_netif_lwip: check: local, if=0x3fcc8ee8 fn=0x420a2bb4
D (77276) modem_board: Handling bits = 0100, stage = 7, retry = 5
D (77281) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc8ee8
E (77289) modem_board: Modem state STAGE_WAIT_IP, retry 5, timeout !
D (77295) esp_netif_lwip: call api in lwip: ret=0x0, give sem
W (77302) modem_board: Retry From Start !
D (77307) event: running post IP_EVENT:7 with handler 0x42014e98 and context 0x3fcc8bac on loop 0x3fcb4acc
0x42014e98: _svfiprintf_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp-elf/src/newlib/newlib/libc/stdio/svfiprintf.c:1391 (discriminator 3)
I (77322) modem_board: IP event! 7
I (77326) modem_board: Modem Disconnect from PPP Server
I (77312) modem_board: Modem state STAGE_SYNC, Start
D (77347) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:AT
W (77347) esp-modem-dte: Not support sending command in ppp mode, please exit ppp mode first
response timeoutem_dce: esp_modem_dce_generic_command(26): Command:AT
I (77373) modem_board: Current timeouts: 1 and errors: 0
W (77373) modem_board: Try to exit ppp mode........
D (77374) esp_modem_dce: esp_modem_dce_generic_command(20): Sending command:+++
D (77382) USB_HCDC: cdc write itf: 0, buf = 0x3c0b9ee4, len = 3
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()