simple_cmux_client reconnection Story in esp-idf-v4.4.2 vs esp-idf-v5.0 (IDFGH-8899)

espressif / esp-protocols

Collection of ESP-IDF components related to networking protocols

165 stars 115 forks source link

Waiting for the device to reconnect.............. ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x15 (USB_UART_CHIP_RESET),boot:0x2d (SPI_FAST_FLASH_BOOT) Saved PC:0x420955f2 0x420955f2: esp_pm_impl_waiti at /home/franz/esp-idf-v4.4.2/components/esp_pm/pm_impl.c:839 SPIWP:0xee mode:DIO, clock div:1 load:0x3fce3808,len:0x1654 load:0x403c9700,len:0xbb8 load:0x403cc700,len:0x2f88 entry 0x403c9954 I (24) boot: ESP-IDF v4.4.2-dirty 2nd stage bootloader I (25) boot: compile time 15:26:16 I (25) boot: chip revision: 0 I (27) boot.esp32s3: Boot SPI Speed : 80MHz I (32) boot.esp32s3: SPI Mode : DIO I (36) boot.esp32s3: SPI Flash Size : 8MB I (41) boot: Enabling RNG early entropy source... I (46) boot: Partition Table: I (50) boot: ## Label Usage Type ST Offset Length I (57) boot: 0 nvs WiFi data 01 02 00009000 00004000 I (65) boot: 1 otadata OTA data 01 00 0000d000 00002000 I (72) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (80) boot: 3 factory factory app 00 00 00010000 00177000 I (87) boot: 4 ota_0 OTA app 00 10 00190000 00177000 I (95) boot: 5 ota_1 OTA app 00 11 00310000 00177000 I (102) boot: End of partition table I (106) boot: Defaulting to factory image I (111) esp_image: segment 0: paddr=00010020 vaddr=3c0a0020 size=2f148h (192840) map I (154) esp_image: segment 1: paddr=0003f170 vaddr=3fc92260 size=00ea8h ( 3752) load I (155) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=9abf8h (633848) map I (274) esp_image: segment 3: paddr=000dac20 vaddr=3fc93108 size=01a6ch ( 6764) load I (275) esp_image: segment 4: paddr=000dc694 vaddr=40374000 size=0e25ch ( 57948) load I (292) esp_image: segment 5: paddr=000ea8f8 vaddr=50000000 size=00010h ( 16) load I (298) boot: Loaded app from partition at offset 0x10000 I (298) boot: Disabling RNG early entropy source... I (312) cpu_start: Pro cpu up. I (312) cpu_start: Starting app cpu, entry point is 0x4037533c 0x4037533c: call_start_cpu1 at /home/franz/esp-idf-v4.4.2/components/esp_system/port/cpu_start.c:160 I (0) cpu_start: App cpu up. I (326) cpu_start: Pro cpu start user code I (326) cpu_start: cpu freq: 160000000 I (327) cpu_start: Application information: I (329) cpu_start: Project name: simple_cmux_client I (335) cpu_start: App version: v0.6-74-gfb07226-dirty I (341) cpu_start: Compile time: Dec 6 2022 15:27:45 I (347) cpu_start: ELF file SHA256: 78ca619e905db129... I (353) cpu_start: ESP-IDF: v4.4.2-dirty I (359) heap_init: Initializing. RAM available for dynamic allocation: I (366) heap_init: At 3FC97C90 len 00048370 (288 KiB): D/IRAM I (372) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM I (379) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM I (385) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM I (392) spi_flash: detected chip: gd I (396) spi_flash: flash io: dio W (400) spi_flash: Detected size(16384k) larger than the size in the binary image header(8192k). Using the size in the binary image header. I (415) sleep: Configure to isolate all GPIO pins in sleep state I (420) sleep: Enable automatic switching of GPIO sleep configuration I (427) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. I (447) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (447) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2457) modem_pwkey: status = 1 I (2457) uart: queue free spaces: 30 W (2957) cmux_example: sync no Success after 0 try I (3057) cmux_example: sync Success after 1 try I (3157) cmux_example: set_flow_control OK I (3257) cmux_example: sync Success after 0 try Modem IMSI number:901288005681920 set_network_mode OK set_preferred_mode OK Modem has correctly entered mode CMUX_MANUAL_MODE Modem has correctly entered mode CMUX_MANUAL_DATA Operator name:vodafone.de I (11747) esp-netif_lwip-ppp: Connected I (11747) esp-netif_lwip-ppp: Name Server1: 217.14.160.130 I (11747) esp-netif_lwip-ppp: Name Server2: 217.14.164.35 I (11757) cmux_example: IP : 100.82.79.92 I (11757) cmux_example: Netmask : 255.255.255.255 I (11767) cmux_example: Gateway : 10.64.64.64 Got IP address I (11767) system_api: Base MAC address is not set I (11777) system_api: read default base MAC address from EFUSE TOPIC:/topic/esp-modem DATA:Hello modem Data received Modem IMSI number:901288005681920 I (25267) esp-netif_lwip-ppp: User interrupt I (25267) esp_modem_netif: PPP state changed event 5 Modem has correctly entered mode CMUX_MANUAL_COMMAND hang_up OK Modem IMEI number:865456057017046 Modem has correctly entered mode CMUX_MANUAL_DATA Operator name:vodafone.de I (32337) esp-netif_lwip-ppp: Connected I (32337) esp-netif_lwip-ppp: Name Server1: 217.14.160.130 I (32337) esp-netif_lwip-ppp: Name Server2: 217.14.164.35 I (32347) cmux_example: IP : 100.82.79.92 I (32347) cmux_example: Netmask : 255.255.255.255 I (32357) cmux_example: Gateway : 10.64.64.64 Got IP address TOPIC:/topic/esp-modem DATA:Hello modem Data received Modem IMSI number:901288005681920

Waiting for the device to reconnect.......... ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x15 (USB_UART_CHIP_RESET),boot:0x2d (SPI_FAST_FLASH_BOOT) Saved PC:0x40378d0e 0x40378d0e: esp_cpu_wait_for_intr at /home/franz/esp-idf-v5.0/components/esp_hw_support/cpu.c:110 SPIWP:0xee mode:DIO, clock div:1 load:0x3fce3810,len:0x1684 load:0x403c9700,len:0xbe8 load:0x403cc700,len:0x2e98 entry 0x403c9904 I (24) boot: ESP-IDF v5.0-dirty 2nd stage bootloader I (25) boot: compile time 15:14:31 I (25) boot: chip revision: v0.1 I (27) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (34) boot.esp32s3: Boot SPI Speed : 80MHz I (39) boot.esp32s3: SPI Mode : DIO I (43) boot.esp32s3: SPI Flash Size : 8MB I (48) boot: Enabling RNG early entropy source... I (54) boot: Partition Table: I (57) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00004000 I (72) boot: 1 otadata OTA data 01 00 0000d000 00002000 I (79) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (87) boot: 3 factory factory app 00 00 00010000 00177000 I (94) boot: 4 ota_0 OTA app 00 10 00190000 00177000 I (102) boot: 5 ota_1 OTA app 00 11 00310000 00177000 I (109) boot: End of partition table I (114) boot: Defaulting to factory image I (118) boot_comm: chip revision: 1, min. application chip revision: 0 I (125) esp_image: segment 0: paddr=00010020 vaddr=3c0a0020 size=37160h (225632) map I (174) esp_image: segment 1: paddr=00047188 vaddr=3fc92c00 size=02cf0h ( 11504) load I (177) esp_image: segment 2: paddr=00049e80 vaddr=40374000 size=06198h ( 24984) load I (186) esp_image: segment 3: paddr=00050020 vaddr=42000020 size=9ce0ch (642572) map I (304) esp_image: segment 4: paddr=000ece34 vaddr=4037a198 size=089f8h ( 35320) load I (312) esp_image: segment 5: paddr=000f5834 vaddr=50000000 size=00010h ( 16) load I (319) boot: Loaded app from partition at offset 0x10000 I (319) boot: Disabling RNG early entropy source... I (333) cpu_start: Pro cpu up. I (333) cpu_start: Starting app cpu, entry point is 0x40375414 0x40375414: call_start_cpu1 at /home/franz/esp-idf-v5.0/components/esp_system/port/cpu_start.c:142 I (0) cpu_start: App cpu up. I (347) cpu_start: Pro cpu start user code I (347) cpu_start: cpu freq: 160000000 Hz I (347) cpu_start: Application information: I (350) cpu_start: Project name: simple_cmux_client I (356) cpu_start: App version: v0.6-78-gda13529 I (362) cpu_start: Compile time: Dec 6 2022 15:14:49 I (368) cpu_start: ELF file SHA256: bfee4966b95e4ceb... I (374) cpu_start: ESP-IDF: v5.0-dirty I (379) heap_init: Initializing. RAM available for dynamic allocation: I (386) heap_init: At 3FC98A18 len 00050CF8 (323 KiB): D/IRAM I (393) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM I (400) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM I (406) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM I (413) spi_flash: detected chip: gd I (416) spi_flash: flash io: dio W (420) spi_flash: Detected size(16384k) larger than the size in the binary image header(8192k). Using the size in the binary image header. I (436) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. I (454) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (454) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2464) modem_pwkey: status = 1 I (2464) uart: queue free spaces: 30 W (2964) cmux_example: sync no Success after 0 try I (3064) cmux_example: sync Success after 1 try I (3164) cmux_example: set_flow_control OK I (3264) cmux_example: sync Success after 0 try Modem IMSI number:901288005681920 set_network_mode OK set_preferred_mode OK Modem has correctly entered mode CMUX_MANUAL_MODE Modem has correctly entered mode CMUX_MANUAL_DATA Operator name:vodafone.de I (11754) esp-netif_lwip-ppp: Connected I (11754) esp_modem_netif: PPP state changed event 0 I (11754) cmux_example: IP : 36.151.206.63 I (11754) cmux_example: Netmask : 255.255.255.255 I (11764) cmux_example: Gateway : 10.64.64.64 Got IP address I (11774) system_api: Base MAC address is not set I (11774) system_api: read default base MAC address from EFUSE TOPIC:/topic/esp-modem DATA:Hello modem Data received Modem IMSI number:901288005681920 Modem has correctly entered mode CMUX_MANUAL_COMMAND hang_up OK Modem IMEI number:865456057017046 E (14954) esp-netif_lwip-ppp: esp_netif_start_ppp: PPP connection cannot be started Modem has correctly entered mode CMUX_MANUAL_DATA Operator name:vodafone.de I (18924) esp-netif_lwip-ppp: User interrupt I (18924) esp_modem_netif: PPP state changed event 5 E (74964) cmux_example: Cannot get IP within specified timeout... exiting I (74964) esp-netif_lwip-ppp: User interrupt

I (0) cpu_start: App cpu up. I (347) cpu_start: Pro cpu start user code I (347) cpu_start: cpu freq: 160000000 Hz I (347) cpu_start: Application information: I (350) cpu_start: Project name: simple_cmux_client I (356) cpu_start: App version: v0.6-79-g830bd09 I (362) cpu_start: Compile time: Dec 12 2022 07:31:53 I (368) cpu_start: ELF file SHA256: 0d0132016691dbd8... I (374) cpu_start: ESP-IDF: v5.0-dirty I (379) heap_init: Initializing. RAM available for dynamic allocation: I (386) heap_init: At 3FC98A18 len 00050CF8 (323 KiB): D/IRAM I (393) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM I (400) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM I (406) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM I (413) spi_flash: detected chip: gd I (416) spi_flash: flash io: dio W (420) spi_flash: Detected size(16384k) larger than the size in the binary image header(8192k). Using the size in the binary image header. I (436) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. I (454) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (454) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2464) modem_pwkey: status = 1 I (2464) uart: queue free spaces: 30 W (2964) cmux_example: sync no Success after 0 try I (3064) cmux_example: sync Success after 1 try I (3164) cmux_example: set_flow_control OK I (3264) cmux_example: sync Success after 0 try Modem IMSI number:901288005681920 set_network_mode OK set_preferred_mode OK Modem has correctly entered mode CMUX_MANUAL_MODE Modem has correctly entered mode CMUX_MANUAL_DATA Operator name:vodafone.de I (11754) esp-netif_lwip-ppp: Connected I (11754) cmux_example: IP : 36.151.206.63 I (11754) cmux_example: Netmask : 255.255.255.255 I (11764) cmux_example: Gateway : 10.64.64.64 Got IP address I (11764) system_api: Base MAC address is not set I (11774) system_api: read default base MAC address from EFUSE TOPIC:/topic/esp-modem DATA:Hello modem Data received Modem IMSI number:901288005681920 I (26054) esp-netif_lwip-ppp: User interrupt I (26054) esp_modem_netif: PPP state changed event 5 Modem has correctly entered mode CMUX_MANUAL_COMMAND hang_up OK Modem IMEI number:865456057017046 Modem has correctly entered mode CMUX_MANUAL_DATA Operator name:vodafone.de I (33124) esp-netif_lwip-ppp: Connected E (87074) cmux_example: Cannot get IP within specified timeout... exiting I (99074) esp-netif_lwip-ppp: User interrupt I (99074) esp_modem_netif: PPP state changed event 5 E (134044) esp_netif_lwip: ip lost timer: failed to post lost ip event (103)

....... ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x15 (USB_UART_CHIP_RESET),boot:0x2d (SPI_FAST_FLASH_BOOT) Saved PC:0x40378d72 0x40378d72: esp_cpu_wait_for_intr at /home/franz/esp-idf-v5.0/components/esp_hw_support/cpu.c:110 SPIWP:0xee mode:DIO, clock div:1 load:0x3fce3810,len:0x1684 load:0x403c9700,len:0xbe8 load:0x403cc700,len:0x2e98 entry 0x403c9904 I (24) boot: ESP-IDF v5.0-dirty 2nd stage bootloader I (25) boot: compile time 07:55:33 I (25) boot: chip revision: v0.1 I (27) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (34) boot.esp32s3: Boot SPI Speed : 80MHz I (39) boot.esp32s3: SPI Mode : DIO I (43) boot.esp32s3: SPI Flash Size : 8MB I (48) boot: Enabling RNG early entropy source... I (54) boot: Partition Table: I (57) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00004000 I (72) boot: 1 otadata OTA data 01 00 0000d000 00002000 I (79) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (87) boot: 3 factory factory app 00 00 00010000 00177000 I (94) boot: 4 ota_0 OTA app 00 10 00190000 00177000 I (102) boot: 5 ota_1 OTA app 00 11 00310000 00177000 I (109) boot: End of partition table I (114) boot: Defaulting to factory image I (118) boot_comm: chip revision: 1, min. application chip revision: 0 I (125) esp_image: segment 0: paddr=00010020 vaddr=3c0b0020 size=3d308h (250632) map I (179) esp_image: segment 1: paddr=0004d330 vaddr=3fc92e00 size=02ce8h ( 11496) load I (182) esp_image: segment 2: paddr=00050020 vaddr=42000020 size=a15d0h (660944) map I (303) esp_image: segment 3: paddr=000f15f8 vaddr=3fc95ae8 size=001e0h ( 480) load I (304) esp_image: segment 4: paddr=000f17e0 vaddr=40374000 size=0ed14h ( 60692) load I (322) esp_image: segment 5: paddr=001004fc vaddr=50000000 size=00010h ( 16) load I (329) boot: Loaded app from partition at offset 0x10000 I (329) boot: Disabling RNG early entropy source... I (343) cpu_start: Pro cpu up. I (343) cpu_start: Starting app cpu, entry point is 0x40375444 0x40375444: call_start_cpu1 at /home/franz/esp-idf-v5.0/components/esp_system/port/cpu_start.c:142 I (0) cpu_start: App cpu up. V CACHE_ERR: illegal error intr clr & ena mask is: 0x3f V CACHE_ERR: coreD (135 a1c)c eclssk :e rRrTC_oSLrOW _CiLKn ctalrib ractilonr &v aelnuae :m a39s40k36 5i:0 m x1f V CACHE_ERR: illegal error intr clr & ena mask is: 0x3f V CACHE_ERR: core 0 access error intr clr & ena mask is: 0x1f I (369) cpu_start: Pro cpu start user code I (372) cpu_start: cpu freq: 160000000 Hz I (377) cpu_start: Application information: I (382) cpu_start: Project name: simple_cmux_client I (388) cpu_start: App version: v0.6-80-gd893916-dirty I (394) cpu_start: Compile time: Dec 12 2022 07:57:09 I (400) cpu_start: ELF file SHA256: 1663cd6e388fdd34... I (406) cpu_start: ESP-IDF: v5.0-dirty V (411) memory_layout: reserved range is 0x3c0ed2f8 - 0x3c0ed318 D (417) memory_layout: Checking 5 reserved memory ranges: D (423) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc92e00 D (429) memory_layout: Reserved memory range 0x3fc92e00 - 0x3fc98e88 D (436) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000 D (442) memory_layout: Reserved memory range 0x40374000 - 0x40382e00 0x40374000: _WindowOverflow4 at /home/franz/esp-idf-v5.0/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742 D (448) memory_layout: Reserved memory range 0x600fe000 - 0x600fe010 D (455) memory_layout: Building list of available memory regions: V (461) memory_layout: Examining memory region 0x40374000 - 0x40378000 0x40374000: _WindowOverflow4 at /home/franz/esp-idf-v5.0/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742 0x40378000: is_page_mapped_in_cache at /home/franz/esp-idf-v5.0/components/spi_flash/flash_mmap.c:464 V (468) memory_layout: Region 0x40374000 - 0x40378000 inside of reserved 0x40374000 - 0x40382e00 0x40374000: _WindowOverflow4 at /home/franz/esp-idf-v5.0/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742 0x40378000: is_page_mapped_in_cache at /home/franz/esp-idf-v5.0/components/spi_flash/flash_mmap.c:464 0x40374000: _WindowOverflow4 at /home/franz/esp-idf-v5.0/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742 V (476) memory_layout: Examining memory region 0x3fc88000 - 0x3fc90000 V (483) memory_layout: Region 0x3fc88000 - 0x3fc90000 inside of reserved 0x3fc84000 - 0x3fc92e00 V (492) memory_layout: Examining memory region 0x3fc90000 - 0x3fca0000 V (499) memory_layout: Start of region 0x3fc90000 - 0x3fca0000 overlaps reserved 0x3fc84000 - 0x3fc92e00 V (508) memory_layout: Start of region 0x3fc92e00 - 0x3fca0000 overlaps reserved 0x3fc92e00 - 0x3fc98e88 D (518) memory_layout: Available memory region 0x3fc98e88 - 0x3fca0000 V (524) memory_layout: Examining memory region 0x3fca0000 - 0x3fcb0000 D (531) memory_layout: Available memory region 0x3fca0000 - 0x3fcb0000 V (537) memory_layout: Examining memory region 0x3fcb0000 - 0x3fcc0000 D (544) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000 V (551) memory_layout: Examining memory region 0x3fcc0000 - 0x3fcd0000 D (557) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000 V (564) memory_layout: Examining memory region 0x3fcd0000 - 0x3fce0000 D (570) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000 V (577) memory_layout: Examining memory region 0x3fce0000 - 0x3fce9710 D (584) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710 V (590) memory_layout: Examining memory region 0x3fce9710 - 0x3fcf0000 V (597) memory_layout: End of region 0x3fce9710 - 0x3fcf0000 overlaps reserved 0x3fceee34 - 0x3fcf0000 D (606) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34 V (613) memory_layout: Examining memory region 0x3fcf0000 - 0x3fcf8000 D (619) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000 V (626) memory_layout: Examining memory region 0x600fe000 - 0x60100000 V (633) memory_layout: Start of region 0x600fe000 - 0x60100000 overlaps reserved 0x600fe000 - 0x600fe010 D (642) memory_layout: Available memory region 0x600fe010 - 0x60100000 I (649) heap_init: Initializing. RAM available for dynamic allocation: D (656) heap_init: New heap initialised at 0x3fc98e88 I (661) heap_init: At 3FC98E88 len 00050888 (322 KiB): D/IRAM I (667) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM D (674) heap_init: New heap initialised at 0x3fcf0000 I (679) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM D (685) heap_init: New heap initialised at 0x600fe010 I (691) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM V (697) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (703) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E D (711) intr_alloc: Connected src 39 to int 2 (cpu 0) V (717) memspi: raw_chip_id: 1840C8 V (720) memspi: chip_id: C84018 V (724) memspi: raw_chip_id: 1840C8 V (727) memspi: chip_id: C84018 D (731) spi_flash: trying chip: issi D (734) spi_flash: trying chip: gd I (738) spi_flash: detected chip: gd I (742) spi_flash: flash io: dio W (746) spi_flash: Detected size(16384k) larger than the size in the binary image header(8192k). Using the size in the binary image header. D (759) cpu_start: calling init function: 0x4207cac4 0x4207cac4: _GLOBAL__sub_I__ZNSt12ctype_bynameIwEC2ERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEj at cxx11-wlocale-inst.cc:? D (764) cpu_start: calling init function: 0x420787f0 0x420787f0: _GLOBAL__sub_I__ZNSt12ctype_bynameIcEC2ERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEj at cxx11-locale-inst.cc:? D (769) cpu_start: calling init function: 0x420706f8 0x420706f8: _GLOBAL__sub_I__ZNSt12ctype_bynameIwEC2ERKSsj at wlocale-inst.cc:? D (774) cpu_start: calling init function: 0x420695f0 0x420695f0: _GLOBAL__sub_I__ZNSt12ctype_bynameIcEC2ERKSsj at locale-inst.cc:? D (779) cpu_start: calling init function: 0x42061850 0x42061850: _GLOBAL__sub_I___cxa_get_globals_fast at eh_globals.cc:? D (784) cpu_start: calling init function: 0x42061678 0x42061678: _GLOBAL__sub_I__ZN9__gnu_cxx9__freeresEv at eh_alloc.cc:? D (789) cpu_start: calling init function: 0x42038ff0 0x42038ff0: esp_ds_conn_lock at /home/franz/esp-idf-v5.0/components/mbedtls/port/esp_ds/esp_rsa_sign_alt.c:47 D (794) cpu_start: calling init function: 0x42020d6c 0x42020d6c: esp_ipc_init at /home/franz/esp-idf-v5.0/components/esp_system/esp_ipc.c:115 D (799) cpu_start: calling init function: 0x42010f48 0x42010f48: _GLOBAL__sub_I__ZN3idf5event21PLATFORM_MAX_DELAY_MSE at /home/franz/esp-idf-v5.0/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:224 V (804) pthread: pthread_once: call init_routine 0x3fc93694 V (809) pthread: pthread_once: call init_routine 0x3fc9368c D (816) cpu_start: calling init function: 0x42010054 0x42010054: _GLOBAL__sub_I__ZN3idf5event18ESPEventAPIDefaultC2Ev at /home/franz/esp-idf-v5.0/examples/cxx/experimental/experimental_cpp_component/esp_event_api.cpp:113 D (820) cpu_start: calling init function: 0x4200c7ec 0x4200c7ec: _GLOBAL__sub_I__ZN10MqttClientC2ERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/simple_cmux_client/simple_mqtt_client.cpp:105 D (824) cpu_start: calling init function: 0x4200b4ec 0x4200b4ec: _GLOBAL__sub_I__Z19set_mode_and_reportRSt10unique_ptrIN9esp_modem3DCEESt14default_deleteIS1_EENS0_10modem_modeE at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/simple_cmux_client/simple_cmux_client_main.cpp:377 D (829) cpu_start: calling init function: 0x42003e60 0x42003e60: esp_reset_reason_init at /home/franz/esp-idf-v5.0/components/esp_system/port/soc/esp32s3/reset_reason.c:67 D (834) cpu_start: calling init function: 0x42002d80 0x42002d80: esp_init_app_elf_sha256 at /home/franz/esp-idf-v5.0/components/esp_app_format/esp_app_desc.c:69 D (839) cpu_start: calling init function: 0x420085b4 on core: 0 0x420085b4: __esp_system_init_fn_esp_timer_startup_init at /home/franz/esp-idf-v5.0/components/esp_timer/src/esp_timer.c:464 V (845) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (851) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC02 D (860) intr_alloc: Connected src 59 to int 3 (cpu 0) D (865) cpu_start: calling init function: 0x42003af0 on core: 0 0x42003af0: __esp_system_init_fn_init_components0 at /home/franz/esp-idf-v5.0/components/esp_system/startup.c:477 D (871) cpu_start: Setting C++ exception workarounds. V (876) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (882) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E D (890) intr_alloc: Connected src 79 to int 9 (cpu 0) I (895) cpu_start: Starting scheduler on PRO CPU. V (901) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (901) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x402 D (901) intr_alloc: Connected src 57 to int 12 (cpu 0) V (901) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args V (911) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E D (911) intr_alloc: Connected src 80 to int 2 (cpu 1) I (921) cpu_start: Starting scheduler on APP CPU. V (921) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args V (931) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x402 D (941) intr_alloc: Connected src 58 to int 3 (cpu 1) D (941) heap_init: New heap initialised at 0x3fce9710 V (951) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (961) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE D (961) intr_alloc: Connected src 52 to int 13 (cpu 0) I (971) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (981) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2991) modem_pwkey: status = 1 D (2991) event: running task for loop 0x3fce9f34 D (2991) event: created task for loop 0x3fce9f34 D (2991) event: created event loop 0x3fce9f34 D (2991) esp_netif_lwip: LwIP stack has been initialized D (3001) esp_netif_lwip: esp-netif has been successfully initialized I (3001) uart: queue free spaces: 30 V (3011) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (3011) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE D (3021) intr_alloc: Connected src 28 to int 17 (cpu 0) D (3031) esp_netif_objects: esp_netif_add_to_list 0x3fcee2a0 D (3031) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1) D (3041) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3fc99614 D (3051) esp-netif_lwip-ppp: Phase Dead V (3051) command_lib: sync V (3061) command_lib: generic_command_common V (3061) command_lib: generic_command D (3061) command_lib: generic_command command AT W (3571) cmux_example: sync no Success after 0 try V (3571) command_lib: sync V (3571) command_lib: generic_command_common V (3571) command_lib: generic_command D (3571) command_lib: generic_command command AT D (3631) command_lib: Response: AT OK I (3631) cmux_example: sync Success after 1 try V (3631) command_lib: set_flow_control V (3631) command_lib: generic_command_common V (3631) command_lib: generic_command D (3641) command_lib: generic_command command AT+IFC=2, 2 D (3731) command_lib: Response: AT+IFC=2, 2 OK I (3731) cmux_example: set_flow_control OK V (3731) command_lib: sync V (3731) command_lib: generic_command_common V (3731) command_lib: generic_command D (3741) command_lib: generic_command command AT D (3831) command_lib: Response: AT OK I (3831) cmux_example: sync Success after 0 try V (3831) command_lib: get_imsi V (3831) command_lib: generic_get_string V (3831) command_lib: generic_get_string V (3931) command_lib: Token: {AT+CIMI} V (3931) command_lib: Token: {901288005681920} } (3931) command_lib: Token: { V (3931) command_lib: Token: {OK} Modem IMSI number:901288005681920 V (3941) command_lib: set_network_mode V (3941) command_lib: generic_command_common V (3941) command_lib: generic_command D (3951) command_lib: generic_command command AT+CNMP=38 D (4031) command_lib: Response: AT+CNMP=38 OK set_network_mode OK V (4031) command_lib: set_preferred_mode V (4031) command_lib: generic_command_common V (4031) command_lib: generic_command D (4041) command_lib: generic_command command AT+CMNB=1 D (4131) command_lib: Response: AT+CMNB=1 OK set_preferred_mode OK V (6131) command_lib: set_cmux V (6131) command_lib: generic_command_common V (6131) command_lib: generic_command D (6131) command_lib: generic_command command AT+CMUX=0 D (6131) command_lib: Response: DST: 0 *PSUTTZ: 22/12/12,07:06:14","+04",0 AT+CMUX=0 OK V (6241) CMUX Received: 0x3fcee060 f9 03 73 01 d7 f9 |..s...| D (6241) CMUX: Payload frame: dlci:00 type:73 payload:0 available:2 V (6251) CMUX Received: 0x3fcee060 f9 07 73 01 15 f9 |..s...| D (6251) CMUX: Payload frame: dlci:01 type:73 payload:0 available:2 V (6261) CMUX Received: 0x3fcee060 f9 0b 73 01 92 f9 |..s...| D (6271) CMUX: Payload frame: dlci:02 type:73 payload:0 available:2 Modem has correctly entered mode CMUX_MANUAL_MODE V (6281) command_lib: set_echo V (6281) command_lib: generic_command_common V (6281) command_lib: generic_command D (6291) command_lib: generic_command command ATE0 V (6291) Send: 0x3fcf4ea4 f9 05 ef 0b |....| V (6301) Send: 0x3fcf5148 41 54 45 30 0d |ATE0.| V (6301) CMUX Received: 0x3fcee060 f9 05 ff 0b 41 54 45 30 0d ae f9 f9 05 ff 0d 0d |....ATE0........| V (6321) CMUX Received: 0x3fcee070 0a 4f 4b 0d 0a 4a f9 |.OK..J.| D (6331) CMUX: Payload frame: dlci:01 type:ff payload:5 available:19 D (6331) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8 D (6341) command_lib: Response: OK V (6321) Send: 0x3fcf4ea8 bb f9 |..| V (6351) command_lib: set_pdp_context V (6351) command_lib: generic_command_common V (6361) command_lib: generic_command D (6361) command_lib: generic_command command AT+CGDCONT=1,"IP","nbiot.global-m2m.net" V (6371) Send: 0x3fcf4e24 f9 05 ef 53 |...S| V (6381) Send: 0x3fcee8dc 41 54 2b 43 47 44 43 4f 4e 54 3d 31 2c 22 49 50 |AT+CGDCONT=1,"IP| V (6381) CMUX Received: 0x3fcee060 f9 05 ff 0d 0d 0a 4f 4b 0d 0a 4a f9 |......OK..J.| D (6391) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8 V (6401) Send: 0x3fcee8ec 22 2c 22 6e 62 69 6f 74 2e 67 6c 6f 62 61 6c 2d |","nbiot.global-| V (6411) Send: 0x3fcee8fc 6d 32 6d 2e 6e 65 74 22 0d |m2m.net".| D (6411) command_lib: Response: OK V (6421) Send: 0x3fcf4e28 d9 f9 |..| V (6431) command_lib: set_data_mode V (6431) command_lib: generic_command D (6441) command_lib: generic_command command ATD*99## V (6441) Send: 0x3fcf4ed4 f9 05 ef 13 |....| V (6451) Send: 0x3fcf5158 41 54 44 2a 39 39 23 23 0d |ATD*99##.| V (6451) CMUX Received: 0x3fcee060 f9 01 ef 0b e3 07 07 8d 01 79 f9 f9 05 ff 2b 0d |.........y....+.| V (6471) CMUX Received: 0x3fcee070 0a 43 4f 4e 4e 45 43 54 20 31 35 30 30 30 30 30 |.CONNECT 1500000| V (6481) CMUX Received: 0x3fcee080 30 30 0d 0a 96 f9 |00....| D (6491) CMUX: Payload frame: dlci:00 type:ef payload:5 available:34 D (6491) CMUX: Payload frame: dlci:01 type:ff payload:21 available:23 D (6501) command_lib: Response: CONNECT 150000000 V (6471) Send: 0x3fcf4ed8 a9 f9 |..| D (6511) esp_netif_handlers: esp_netif action has started with netif0x3fcee2a0 from event_id=0 D (6521) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fc99614 D (6531) esp-netif_lwip-ppp: Phase Start D (6531) esp-netif_lwip-ppp: Phase Establish D (6541) esp_netif_lwip: check: remote, if=0x3fcee2a0 fn=0x42023bcc 0x42023bcc: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v5.0/components/esp_netif/lwip/esp_netif_lwip.c:272 D (6541) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcee2a0 V (6551) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcee2a0 D (6551) esp_netif_lwip: call api in lwip: ret=0x0, give sem Modem has correctly entered mode CMUX_MANUAL_DATA V (6561) command_lib: get_operator_name V (6571) command_lib: generic_get_string V (6571) Send: 0x3fcf5024 f9 09 ef 13 |....| V (6581) Send: 0x3fcf5204 41 54 2b 43 4f 50 53 3f 0d |AT+COPS?.| V (6581) CMUX Received: 0x3fcee060 f9 09 ff 49 0d 0a 2b 43 4f 50 53 3a 20 30 2c 30 |...I..+COPS: 0,0| V (6601) CMUX Received: 0x3fcee070 2c 22 76 6f 64 61 66 6f 6e 65 2e 64 65 22 2c 37 |,"vodafone.de",7| V (6611) CMUX Received: 0x3fcee080 0d 0a 0d 0a 4f 4b 0d 0a ba f9 |....OK....| D (6621) CMUX: Payload frame: dlci:02 type:ff payload:36 available:38 } (6621) command_lib: Token: { V (6631) command_lib: Token: {+COPS: 0,0,"vodafone.de",7} } (6631) command_lib: Token: { V (6631) command_lib: Token: {OK} V (6601) Send: 0x3fcf5028 2e f9 |..| Operator name:vodafone.de V (12541) Send: 0x3fcebfc4 f9 05 ef 5b |...[| V (12541) Send: 0x3fc9a8ac 7e ff 7d 23 c0 21 7d 21 7d 21 7d 20 7d 34 7d 22 |~.}#.!}!}!} }4}"| V (12541) Send: 0x3fc9a8bc 7d 26 7d 20 7d 20 7d 20 7d 20 7d 25 7d 26 81 a8 |}&} } } } }%}&..| V (12551) CMUX Received: 0x3fcee060 f9 05 ff 6d 7e ff 7d 23 c0 21 7d 21 7d 20 7d 20 |...m~.}#.!}!} } | V (12551) Send: 0x3fc9a8cc d6 87 7d 27 7d 22 7d 28 7d 22 b0 87 7e |..}'}"}(}"..~| V (12571) CMUX Received: 0x3fcee070 7d 39 7d 22 7d 26 7d 20 7d 20 7d 20 7d 20 7d 23 |}9}"}&} } } } }#| V (12571) Send: 0x3fcebfc8 d7 f9 |..| V (12581) CMUX Received: 0x3fcee080 7d 25 c2 23 7d 25 7d 25 7d 26 44 3c 7d 2e d5 7d |}%.#}%}%}&D<}..}| V (12601) CMUX Received: 0x3fcee090 27 7d 22 7d 28 7d 22 f4 fa 7e 02 f9 f9 05 ff 5b |'}"}(}"..~.....[| D (12611) CMUX: Payload frame: dlci:01 type:ff payload:54 available:60 V (12611) Send: 0x3fcebf24 f9 05 ef 33 |...3| V (12621) CMUX Received: 0x3fcee060 7e ff 7d 23 c0 21 7d 22 7d 21 7d 20 7d 34 7d 22 |~.}#.!}"}!} }4}"| V (12621) Send: 0x3fc9b4ac 7e ff 7d 23 c0 21 7d 24 7d 20 7d 20 7d 29 7d 23 |~.}#.!}$} } })}#| V (12631) CMUX Received: 0x3fcee070 7d 26 7d 20 7d 20 7d 20 7d 20 7d 25 7d 26 81 a8 |}&} } } } }%}&..| V (12641) Send: 0x3fc9b4bc 7d 25 c2 23 7d 25 f8 60 7e |}%.#}%.`~| V (12661) CMUX Received: 0x3fcee080 d6 87 7d 27 7d 22 7d 28 7d 22 5b ee 7e c2 f9 |..}'}"}(}"[.~..| V (12661) Send: 0x3fcebf28 91 f9 |..| D (12671) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47 V (12681) CMUX Received: 0x3fcee060 f9 05 ff 5f 7e ff 7d 23 c0 21 7d 21 7d 21 7d 20 |..._~.}#.!}!}!} | V (12691) CMUX Received: 0x3fcee070 7d 34 7d 22 7d 26 7d 20 7d 20 7d 20 7d 20 7d 25 |}4}"}&} } } } }%| V (12701) CMUX Received: 0x3fcee080 7d 26 44 3c 7d 2e d5 7d 27 7d 22 7d 28 7d 22 7d |}&D<}..}'}"}(}"}| V (12711) CMUX Received: 0x3fcee090 31 e5 7e c5 f9 |1.~..| D (12721) CMUX: Payload frame: dlci:01 type:ff payload:47 available:49 V (12731) Send: 0x3fcebf24 f9 05 ef 5d |...]| V (12731) Send: 0x3fc9b4ac 7e ff 7d 23 c0 21 7d 22 7d 21 7d 20 7d 34 7d 22 |~.}#.!}"}!} }4}"| V (12731) CMUX Received: 0x3fcee060 f9 05 ff 31 7e ff 7d 23 c0 21 7d 2b 7d 22 7d 20 |...1~.}#.!}+}"} | V (12741) Send: 0x3fc9b4bc 7d 26 7d 20 7d 20 7d 20 7d 20 7d 25 7d 26 44 3c |}&} } } } }%}&D<| V (12761) Send: 0x3fc9b4cc 7d 2e d5 7d 27 7d 22 7d 28 7d 22 fa 8c 7e |}..}'}"}(}"..~| V (12761) CMUX Received: 0x3fcee070 7d 28 44 3c 7d 2e d5 7d 29 7d 2e 7e 67 f9 |}(D<}..})}.~g.| V (12771) Send: 0x3fcebf28 33 f9 |3.| D (12791) CMUX: Payload frame: dlci:01 type:ff payload:24 available:26 D (12791) esp-netif_lwip-ppp: Phase Authenticate D (12801) esp-netif_lwip-ppp: Phase Network V (12801) Send: 0x3fcebe44 f9 05 ef 49 |...I| V (12811) Send: 0x3fc9baac 7e ff 03 80 21 01 01 00 1c 02 06 00 2d 0f 01 03 |~...!.......-...| V (12811) CMUX Received: 0x3fcee060 f9 05 ff 15 7e 80 21 01 00 00 04 67 c3 7e 58 f9 |....~.!....g.~X.| V (12821) Send: 0x3fc9babc 06 00 00 00 00 81 06 00 00 00 00 83 06 00 00 00 |................| V (12841) CMUX Received: 0x3fcee070 f9 05 ff 21 7e 80 21 04 01 00 0a 02 06 00 2d 0f |...!~.!.......-.| V (12841) Send: 0x3fc9bacc 00 55 15 7e |.U.~| V (12851) CMUX Received: 0x3fcee080 01 f8 30 7e 7b f9 |..0~{.| V (12851) Send: 0x3fcebe48 28 f9 |(.| D (12871) CMUX: Payload frame: dlci:01 type:ff payload:10 available:34 V (12881) Send: 0x3fcebf24 f9 05 ef 25 |...%| D (12881) CMUX: Payload frame: dlci:01 type:ff payload:16 available:18 V (12881) Send: 0x3fc9b4ac 7e ff 03 80 21 03 00 00 0a 03 06 00 00 00 00 a0 |~...!...........| V (12901) CMUX Received: 0x3fcee060 f9 05 ff 15 7e 80 21 01 01 00 04 bb 99 7e 58 f9 |....~.!......~X.| V (12901) Send: 0x3fc9b4bc 3d 7e |=~| D (12911) CMUX: Payload frame: dlci:01 type:ff payload:10 available:12 V (12921) Send: 0x3fcebf28 69 f9 |i.| V (12931) Send: 0x3fcebf34 f9 05 ef 3d |...=| V (12941) CMUX Received: 0x3fcee060 f9 05 ff 39 7e 80 21 03 02 00 16 03 06 64 52 4f |...9~.!......dRO| V (12941) Send: 0x3fc9aeac 7e ff 03 80 21 01 02 00 16 03 06 00 00 00 00 81 |~...!...........| V (12951) CMUX Received: 0x3fcee070 5c 81 06 d9 0e a0 82 83 06 d9 0e a4 23 12 73 7e |\...........#.s~| V (12961) Send: 0x3fc9aebc 06 00 00 00 00 83 06 00 00 00 00 da 82 7e |.............~| V (12981) CMUX Received: 0x3fcee080 69 f9 |i.| V (12981) Send: 0x3fcebf38 7b f9 |{.| D (12991) CMUX: Payload frame: dlci:01 type:ff payload:28 available:30 V (12991) Send: 0x3fcebf24 f9 05 ef 19 |....| V (13011) Send: 0x3fc9aeac 7e ff 03 80 21 02 01 00 04 cd 92 7e |~...!......~| V (13011) Send: 0x3fcebf28 44 f9 |D.| V (13021) Send: 0x3fcebf34 f9 05 ef 3d |...=| V (13031) CMUX Received: 0x3fcee060 f9 05 ff 39 7e 80 21 02 03 00 16 03 06 64 52 4f |...9~.!......dRO| V (13031) Send: 0x3fc9baac 7e ff 03 80 21 01 03 00 16 03 06 64 52 4f 5c 81 |~...!......dRO\.| V (13041) CMUX Received: 0x3fcee070 5c 81 06 d9 0e a0 82 83 06 d9 0e a4 23 23 ed 7e |\...........##.~| V (13051) Send: 0x3fc9babc 06 d9 0e a0 82 83 06 d9 0e a4 23 b5 8e 7e |..........#..~| V (13071) CMUX Received: 0x3fcee080 69 f9 |i.| V (13071) Send: 0x3fcebf38 7b f9 |{.| D (13081) CMUX: Payload frame: dlci:01 type:ff payload:28 available:30 D (13091) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fcee324 D (13101) esp_netif_lwip: if0x3fcee2a0 ip changed=1 D (13101) event: running post IP_EVENT:6 with handler 0x4202238c and context 0x3fcee700 on loop 0x3fce9f34 0x4202238c: esp_netif_action_connected at /home/franz/esp-idf-v5.0/components/esp_netif/esp_netif_handlers.c:36 I (13101) esp-netif_lwip-ppp: Connected D (13111) esp_netif_handlers: esp_netif action connected with netif0x3fcee2a0 from event_id=6 D (13111) esp-netif_lwip-ppp: Phase Running D (13121) esp_netif_lwip: check: remote, if=0x3fcee2a0 fn=0x42023374 0x42023374: esp_netif_up_api at /home/franz/esp-idf-v5.0/components/esp_netif/lwip/esp_netif_lwip.c:1458 D (13131) esp_netif_lwip: esp_netif_up_api esp_netif:0x3fcee2a0 D (13141) esp_netif_lwip: check: local, if=0x3fcee2a0 fn=0x42023bcc 0x42023bcc: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v5.0/components/esp_netif/lwip/esp_netif_lwip.c:272 D (13151) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcee2a0 V (13151) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcee2a0 D (13161) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (13161) event: running post IP_EVENT:6 with handler 0x4209b37c and context 0x3fcee764 on loop 0x3fce9f34 0x4209b37c: idf::event::ESPEventReg::event_handler_hook(void*, char const*, long, void*) at /home/franz/esp-idf-v5.0/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56 D (13171) event: running post NETIF_PPP_STATUS:0 with handler 0x42012504 and context 0x3fcee6bc on loop 0x3fce9f34 0x42012504: esp_modem::Netif::on_ppp_changed(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/esp_modem/src/esp_modem_netif.cpp:22 I (13181) cmux_example: IP : 36.151.206.63 I (13191) cmux_example: Netmask : 255.255.255.255 I (13201) cmux_example: Gateway : 10.64.64.64 Got IP address I (13201) system_api: Base MAC address is not set I (13211) system_api: read default base MAC address from EFUSE D (13211) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit D (13221) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit D (13231) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit D (13241) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit D (13241) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit D (13251) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit D (13261) mqtt_client: MQTT client_id=ESP32_2a0AC4 D (13261) event: created event loop 0x3fceec7c D (13271) mqtt_client: Core selection disabled D (13271) event: running post MQTT_EVENTS:7 with handler 0x4200c65c and context 0x3fceedb4 on loop 0x3fceec7c 0x4200c65c: MqttClientHandle::mqtt_event_handler(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/simple_cmux_client/simple_mqtt_client.cpp:44 D (13281) event: no handlers have been registered for event MQTT_EVENTS:7 posted to loop 0x3fce9f34 D (13281) esp-tls: host:test.mosquitto.org: strlen 18 V (13301) Send: 0x3fcebe24 f9 05 ef 8b |....| V (13301) Send: 0x3fc9c3c0 7e 21 45 00 00 40 00 00 00 00 ff 11 8e 6d 64 52 |~!E..@.......mdR| V (13311) Send: 0x3fc9c3d0 4f 5c d9 0e a0 82 dd e6 00 35 00 2c a0 ba 64 57 |O\.......5.,..dW| V (13321) Send: 0x3fc9c3e0 01 00 00 01 00 00 00 00 00 00 04 74 65 73 74 09 |...........test.| V (13331) Send: 0x3fc9c3f0 6d 6f 73 71 75 69 74 74 6f 03 6f 72 67 00 00 01 |mosquitto.org...| V (13341) Send: 0x3fc9c400 00 01 62 65 7e |..be~| V (13351) Send: 0x3fcebe28 5b f9 |[.| V (13871) CMUX Received: 0x3fcee060 f9 05 ff ab 7e 21 45 00 00 50 d3 04 40 00 39 11 |....~!E..P..@.9.| V (13871) CMUX Received: 0x3fcee070 41 59 d9 0e a0 82 64 52 4f 5c 00 35 dd e6 00 3c |AY....dRO\.5...<| V (13881) CMUX Received: 0x3fcee080 a6 02 64 57 81 80 00 01 00 01 00 00 00 00 04 74 |..dW...........t| V (13891) CMUX Received: 0x3fcee090 65 73 74 09 6d 6f 73 71 75 69 74 74 6f 03 6f 72 |est.mosquitto.or| D (13901) CMUX: Payload frame: dlci:01 type:ff payload:85 available:60 V (13911) CMUX Received: 0x3fcee0a0 67 00 00 01 00 01 c0 0c 00 01 00 01 00 00 01 2c |g..............,| V (13921) CMUX Received: 0x3fcee0b0 00 04 5b 79 5d 5e 64 e8 7e 76 f9 |..[y]^d.~v.| D (13921) CMUX: Payload frame: dlci:01 type:ff payload:25 available:27 D (13931) esp-tls: [sock=54] Resolved IPv4 address: 91.121.93.94 D (13941) esp-tls: [sock=54] Connecting to server. HOST: test.mosquitto.org, Port: 1883 V (13951) Send: 0x3fcebeb4 f9 05 ef 63 |...c| V (13951) Send: 0x3fc9c4f0 7e 21 45 00 00 2c 00 01 00 00 ff 06 4f 45 64 52 |~!E..,......OEdR| V (13961) Send: 0x3fc9c500 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 28 00 00 |O\[y]^...[S".(..| V (13971) Send: 0x3fc9c510 00 00 60 02 16 70 1c f7 00 00 02 04 05 a0 56 d5 |..`..p........V.| V (13981) Send: 0x3fc9c520 7e |~| V (13991) Send: 0x3fcebeb8 fd f9 |..| V (14141) CMUX Received: 0x3fcee060 f9 05 ff 63 7e 21 45 00 00 2c 00 00 40 00 2d 06 |...c~!E..,..@.-.| V (14141) CMUX Received: 0x3fcee070 e1 46 5b 79 5d 5e 64 52 4f 5c 07 5b de a7 c0 f7 |.F[y]^dRO\.[....| V (14151) CMUX Received: 0x3fcee080 01 63 53 22 bf 29 60 12 fa f0 76 aa 00 00 02 04 |.cS".)`...v.....| V (14161) CMUX Received: 0x3fcee090 05 00 e9 a5 7e e8 f9 |....~..| D (14171) CMUX: Payload frame: dlci:01 type:ff payload:49 available:51 V (14171) Send: 0x3fcebe24 f9 05 ef 5b |...[| V (14181) Send: 0x3fc9d18c 7e 21 45 00 00 28 00 02 00 00 ff 06 4f 48 64 52 |~!E..(......OHdR| V (14191) Send: 0x3fc9d19c 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 29 c0 f7 |O\[y]^...[S".)..| V (14201) Send: 0x3fc9d1ac 01 64 50 10 16 70 72 34 00 00 78 95 7e |.dP..pr4..x.~| V (14211) Send: 0x3fcebe28 d7 f9 |..| D (14211) mqtt_client: Transport connected to mqtt://test.mosquitto.org:1883 D (14221) mqtt_client: Sending MQTT CONNECT message, type: 1, id: 0000 V (14231) Send: 0x3fcebec4 f9 05 ef 8f |....| V (14231) Send: 0x3fc9c9ec 7e 21 45 00 00 42 00 03 00 00 ff 06 4f 2d 64 52 |~!E..B......O-dR| V (14241) Send: 0x3fc9c9fc 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 29 c0 f7 |O\[y]^...[S".)..| V (14251) Send: 0x3fc9ca0c 01 64 50 18 16 70 4e 0e 00 00 10 18 00 04 4d 51 |.dP..pN.......MQ| V (14261) Send: 0x3fc9ca1c 54 54 04 02 00 78 00 0c 45 53 50 33 32 5f 32 61 |TT...x..ESP32_2a| V (14271) Send: 0x3fc9ca2c 30 41 43 34 c0 b9 7e |0AC4..~| V (14281) Send: 0x3fcebec8 5c f9 |\.| V (14561) CMUX Received: 0x3fcee060 f9 05 ff 5b 7e 21 45 00 00 28 d8 2c 40 00 2d 06 |...[~!E..(.,@.-.| V (14561) CMUX Received: 0x3fcee070 09 1e 5b 79 5d 5e 64 52 4f 5c 07 5b de a7 c0 f7 |..[y]^dRO\.[....| V (14571) CMUX Received: 0x3fcee080 01 64 53 22 bf 43 50 10 fa d6 8d b3 00 00 6f 0e |.dS".CP.......o.| V (14581) CMUX Received: 0x3fcee090 7e c2 f9 |~..| D (14591) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47 V (14621) CMUX Received: 0x3fcee060 f9 05 ff 63 7e 21 45 00 00 2c d8 2d 40 00 2d 06 |...c~!E..,.-@.-.| V (14621) CMUX Received: 0x3fcee070 09 19 5b 79 5d 5e 64 52 4f 5c 07 5b de a7 c0 f7 |..[y]^dRO\.[....| V (14621) CMUX Received: 0x3fcee080 01 64 53 22 bf 43 50 18 fa d6 6d a5 00 00 20 02 |.dS".CP...m... .| V (14631) CMUX Received: 0x3fcee090 00 00 d6 5c 7e e8 f9 |...\~..| D (14641) CMUX: Payload frame: dlci:01 type:ff payload:49 available:51 D (14651) mqtt_client: mqtt_message_receive: first byte: 0x20 D (14661) mqtt_client: mqtt_message_receive: read "remaining length" byte: 0x2 D (14661) mqtt_client: mqtt_message_receive: total message length: 4 (already read: 2) D (14671) mqtt_client: mqtt_message_receive: read_len=2 D (14681) mqtt_client: mqtt_message_receive: transport_read():4 4 D (14681) mqtt_client: Connected D (14681) event: running post MQTT_EVENTS:1 with handler 0x4200c65c and context 0x3fceedb4 on loop 0x3fceec7c 0x4200c65c: MqttClientHandle::mqtt_event_handler(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/simple_cmux_client/simple_mqtt_client.cpp:44 D (14691) event: running post MQTT_EVENTS:1 with handler 0x4209b37c and context 0x3fceee00 on loop 0x3fce9f34 0x4209b37c: idf::event::ESPEventReg::event_handler_hook(void*, char const*, long, void*) at /home/franz/esp-idf-v5.0/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56 D (14701) mqtt_client: mqtt_enqueue id: 50276, type=8 successful V (14711) Send: 0x3fcebe64 f9 05 ef 5b |...[| V (14721) Send: 0x3fc9c5cc 7e 21 45 00 00 28 00 04 00 00 ff 06 4f 46 64 52 |~!E..(......OFdR| V (14731) Send: 0x3fc9c5dc 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 43 c0 f7 |O\[y]^...[S".C..| V (14741) Send: 0x3fc9c5ec 01 68 50 10 16 6c 72 1a 00 00 29 2c 7e |.hP..lr...),~| V (14741) Send: 0x3fcebe68 d7 f9 |..| D (14721) outbox: ENQUEUE msgid=50276, msg_type=8, len=23, size=23 V (14761) Send: 0x3fcebec4 f9 05 ef 8b |....| V (14771) Send: 0x3fc9cae0 7e 21 45 00 00 3f 00 05 00 00 ff 06 4f 2e 64 52 |~!E..?......O.dR| V (14781) Send: 0x3fc9caf0 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 43 c0 f7 |O\[y]^...[S".C..| V (14781) Send: 0x3fc9cb00 01 68 50 18 16 6c 7d 5e 14 00 00 82 15 c4 64 00 |.hP..l}^......d.| V (14791) Send: 0x3fc9cb10 10 2f 74 6f 70 69 63 2f 65 73 70 2d 6d 6f 64 65 |./topic/esp-mode| V (14801) Send: 0x3fc9cb20 6d 00 b1 e8 7e |m...~| V (14811) Send: 0x3fcebec8 5b f9 |[.| D (14821) mqtt_client: Sent subscribe topic=/topic/esp-modem, id: 50276, type=8 successful V (15111) CMUX Received: 0x3fcee060 f9 05 ff 65 7e 21 45 00 00 2d d8 2e 40 00 2d 06 |...e~!E..-..@.-.| V (15111) CMUX Received: 0x3fcee070 09 17 5b 79 5d 5e 64 52 4f 5c 07 5b de a7 c0 f7 |..[y]^dRO\.[....| V (15121) CMUX Received: 0x3fcee080 01 68 53 22 bf 5a 50 18 fa bf 39 3a 00 00 90 03 |.hS".ZP...9:....| V (15131) CMUX Received: 0x3fcee090 c4 64 00 dd 54 7e 0c f9 |.d..T~..| D (15141) CMUX: Payload frame: dlci:01 type:ff payload:50 available:52 V (15151) Send: 0x3fcebe44 f9 05 ef 99 |....| V (15161) Send: 0x3fc9dc54 7e 21 45 00 00 47 00 06 00 00 ff 06 4f 25 64 52 |~!E..G......O%dR| V (15161) Send: 0x3fc9dc64 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 5a c0 f7 |O\[y]^...[S".Z..| V (15171) Send: 0x3fc9dc74 01 6d 50 18 16 67 31 8b 00 00 30 1d 00 10 2f 74 |.mP..g1...0.../t| V (15181) Send: 0x3fc9dc84 6f 70 69 63 2f 65 73 70 2d 6d 6f 64 65 6d 48 65 |opic/esp-modemHe| V (15191) Send: 0x3fc9dc94 6c 6c 6f 20 6d 6f 64 65 6d 2a e2 7e |llo modem*.~| V (15201) Send: 0x3fcebe48 a4 f9 |..| D (15211) mqtt_client: mqtt_message_receive: first byte: 0x90 D (15211) mqtt_client: mqtt_message_receive: read "remaining length" byte: 0x3 D (15221) mqtt_client: mqtt_message_receive: total message length: 5 (already read: 2) D (15231) mqtt_client: mqtt_message_receive: read_len=3 D (15231) mqtt_client: mqtt_message_receive: transport_read():5 5 D (15241) mqtt_client: msg_type=9, msg_id=50276 D (15241) mqtt_client: pending_id=50276, pending_msg_count = 1 D (15251) outbox: DELETED msgid=50276, msg_type=8, remain size=0 D (15261) mqtt_client: deliver_suback, message_length_read=5, message_length=5 D (15261) event: running post MQTT_EVENTS:3 with handler 0x4200c65c and context 0x3fceedb4 on loop 0x3fceec7c 0x4200c65c: MqttClientHandle::mqtt_event_handler(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/simple_cmux_client/simple_mqtt_client.cpp:44 D (15271) event: no handlers have been registered for event MQTT_EVENTS:3 posted to loop 0x3fce9f34 V (15421) CMUX Received: 0x3fcee060 f9 05 ff 99 7e 21 45 00 00 47 d8 2f 40 00 2d 06 |....~!E..G./@.-.| V (15421) CMUX Received: 0x3fcee070 08 fc 5b 79 5d 5e 64 52 4f 5c 07 5b de a7 c0 f7 |..[y]^dRO\.[....| V (15431) CMUX Received: 0x3fcee080 01 6d 53 22 bf 79 50 18 fa a0 4d 32 00 00 30 1d |.mS".yP...M2..0.| V (15441) CMUX Received: 0x3fcee090 00 10 2f 74 6f 70 69 63 2f 65 73 70 2d 6d 6f 64 |../topic/esp-mod| D (15441) CMUX: Payload frame: dlci:01 type:ff payload:76 available:60 V (15451) CMUX Received: 0x3fcee0a0 65 6d 48 65 6c 6c 6f 20 6d 6f 64 65 6d 59 68 7e |emHello modemYh~| V (15461) CMUX Received: 0x3fcee0b0 b1 f9 |..| D (15471) CMUX: Payload frame: dlci:01 type:ff payload:16 available:18 D (15481) mqtt_client: mqtt_message_receive: first byte: 0x30 D (15481) mqtt_client: mqtt_message_receive: read "remaining length" byte: 0x1d D (15491) mqtt_client: mqtt_message_receive: total message length: 31 (already read: 2) D (15501) mqtt_client: mqtt_message_receive: read_len=29 D (15501) mqtt_client: mqtt_message_receive: transport_read():31 31 V (15511) Send: 0x3fcebe64 f9 05 ef 5b |...[| D (15511) mqtt_client: msg_type=3, msg_id=0 D (15521) mqtt_client: deliver_publish, message_length_read=31, message_length=31 V (15521) Send: 0x3fc9c4c4 7e 21 45 00 00 28 00 07 00 00 ff 06 4f 43 64 52 |~!E..(......OCdR| D (15531) mqtt_client: deliver_publish: msg_topic_len=16 D (15541) mqtt_client: Get data len= 11, topic len=16, total_data: 11 offset: 0 V (15541) Send: 0x3fc9c4d4 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 79 c0 f7 |O\[y]^...[S".y..| D (15551) event: running post MQTT_EVENTS:6 with handler 0x4200c65c and context 0x3fceedb4 on loop 0x3fceec7c 0x4200c65c: MqttClientHandle::mqtt_event_handler(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/simple_cmux_client/simple_mqtt_client.cpp:44 V (15561) Send: 0x3fc9c4e4 01 8c 50 10 16 48 71 e4 00 00 ed e9 7e |..P..Hq.....~| D (15571) event: running post MQTT_EVENTS:6 with handler 0x4209b37c and context 0x3fcf3404 on loop 0x3fce9f34 0x4209b37c: idf::event::ESPEventReg::event_handler_hook(void*, char const*, long, void*) at /home/franz/esp-idf-v5.0/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56 V (15581) Send: 0x3fcebe68 d7 f9 |..| D (15591) event: running post MQTT_EVENTS:6 with handler 0x4209b37c and context 0x3fcf7e80 on loop 0x3fce9f34 0x4209b37c: idf::event::ESPEventReg::event_handler_hook(void*, char const*, long, void*) at /home/franz/esp-idf-v5.0/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56 TOPIC:/topic/esp-modem DATA:Hello modem Data received V (15611) Send: 0x3fcebec4 f9 05 ef 5f |..._| V (15621) Send: 0x3fc9cbb8 7e 21 45 00 00 2a 00 08 00 00 ff 06 4f 40 64 52 |~!E..*......O@dR| V (15631) Send: 0x3fc9cbc8 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 79 c0 f7 |O\[y]^...[S".y..| V (15631) Send: 0x3fc9cbd8 01 8c 50 18 16 48 91 d9 00 00 e0 00 1e 87 7e |..P..H........~| V (15641) Send: 0x3fcebec8 d0 f9 |..| V (15951) CMUX Received: 0x3fcee060 f9 05 ff 5b 7e 21 45 00 00 28 d8 30 40 00 2d 06 |...[~!E..(.0@.-.| V (15951) CMUX Received: 0x3fcee070 09 1a 5b 79 5d 5e 64 52 4f 5c 07 5b de a7 c0 f7 |..[y]^dRO\.[....| V (15961) CMUX Received: 0x3fcee080 01 8c 53 22 bf 7b 50 11 fa 9e 8d 8a 00 00 1f 28 |..S".{P........(| V (15971) CMUX Received: 0x3fcee090 7e c2 f9 |~..| D (15971) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47 V (15981) Send: 0x3fcebe24 f9 05 ef 5b |...[| V (15991) Send: 0x3fc9c464 7e 21 45 00 00 28 00 09 00 00 ff 06 4f 41 64 52 |~!E..(......OAdR| V (16001) Send: 0x3fc9c474 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 7b c0 f7 |O\[y]^...[S".{..| V (16011) Send: 0x3fc9c484 01 8d 50 10 16 47 71 e2 00 00 42 ae 7e |..P..Gq...B.~| V (16011) Send: 0x3fcebe28 d7 f9 |..| V (16021) Send: 0x3fcebe44 f9 05 ef 5b |...[| V (16031) Send: 0x3fc9c4c4 7e 21 45 00 00 28 00 0a 00 00 ff 06 4f 40 64 52 |~!E..(......O@dR| V (16041) Send: 0x3fc9c4d4 4f 5c 5b 79 5d 5e de a7 07 5b 53 22 bf 7b c0 f7 |O\[y]^...[S".{..| V (16051) Send: 0x3fc9c4e4 01 8d 50 11 16 47 71 e1 00 00 89 30 7e |..P..Gq....0~| V (16061) Send: 0x3fcebe48 d7 f9 |..| D (16061) event: deleted loop 0x3fceec7c V (16071) command_lib: get_imsi V (16071) command_lib: generic_get_string V (16081) command_lib: generic_get_string V (16081) Send: 0x3fcf5074 f9 09 ef 11 |....| V (16091) Send: 0x3fcf5228 41 54 2b 43 49 4d 49 0d |AT+CIMI.| V (16101) Send: 0x3fcf5078 cd f9 |..| V (16081) CMUX Received: 0x3fcee060 f9 09 ff 33 0d 0a 39 30 31 32 38 38 30 30 35 36 |...3..9012880056| V (16111) CMUX Received: 0x3fcee070 38 31 39 32 30 0d 0a 0d 0a 4f 4b 0d 0a 03 f9 |81920....OK....| D (16121) CMUX: Payload frame: dlci:02 type:ff payload:25 available:27 } (16131) command_lib: Token: { V (16131) command_lib: Token: {901288005681920} } (16141) command_lib: Token: { V (16141) command_lib: Token: {OK} Modem IMSI number:901288005681920 D (16151) esp_netif_handlers: esp_netif action stopped with netif0x3fcee2a0 from event_id=0 D (16151) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3fc99614 V (16161) CMUX Received: 0x3fcee060 f9 05 ff 5b 7e 21 45 00 00 28 00 00 40 00 2d 06 |...[~!E..(..@.-.| D (16171) esp-netif_lwip-ppp: Phase Terminate D (16181) esp-netif_lwip-ppp: Phase Network V (16181) CMUX Received: 0x3fcee070 e1 4a 5b 79 5d 5e 64 52 4f 5c 07 5b de a7 c0 f7 |.J[y]^dRO\.[....| D (16181) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fcee324 V (16201) CMUX Received: 0x3fcee080 01 8d 53 22 bf 7c 50 10 fa 9e 8d 89 00 00 fc 3c |..S".|P........<| D (16201) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fcee2a0 V (16211) CMUX Received: 0x3fcee090 7e c2 f9 |~..| D (16211) esp_netif_lwip: if0x3fcee2a0 start ip lost tmr: interval=120 D (16231) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47 D (16231) esp-netif_lwip-ppp: Phase Establish V (16241) Send: 0x3fcebf64 f9 05 ef 3b |...;| V (16251) CMUX Received: 0x3fcee060 f9 05 ff 25 7e ff 7d 23 c0 21 7d 26 7d 22 7d 20 |...%~.}#.!}&}"} | V (16251) Send: 0x3fc9a8ac 7e ff 7d 23 c0 21 7d 25 7d 22 7d 20 7d 30 55 73 |~.}#.!}%}"} }0Us| V (16271) CMUX Received: 0x3fcee070 7d 24 94 7d 2d 7e 7c f9 |}$.}-~|.| V (16271) Send: 0x3fc9a8bc 65 72 20 72 65 71 75 65 73 74 53 33 7e |er requestS3~| D (16281) CMUX: Payload frame: dlci:01 type:ff payload:18 available:20 V (16281) Send: 0x3fcebf68 9f f9 |..| D (16301) esp_netif_lwip: check: remote, if=0x3fcee2a0 fn=0x42023bcc 0x42023bcc: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v5.0/components/esp_netif/lwip/esp_netif_lwip.c:272 D (16301) esp-netif_lwip-ppp: Phase Disconnect D (16311) esp-netif_lwip-ppp: Phase Dead I (16311) esp-netif_lwip-ppp: User interrupt D (16321) event: running post NETIF_PPP_STATUS:5 with handler 0x42012504 and context 0x3fcee6bc on loop 0x3fce9f34 0x42012504: esp_modem::Netif::on_ppp_changed(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/esp_modem/src/esp_modem_netif.cpp:22 D (16321) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcee2a0 I (16331) esp_modem_netif: PPP state changed event 5 V (16331) esp_netif_objects: esp_netif_next_unsafe 0x0 V (16341) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcee2a0 V (16351) esp_netif_objects: esp_netif_next_unsafe 0x3fcee2a0 D (16361) esp_netif_lwip: call api in lwip: ret=0x0, give sem V (17251) CMUX Received: 0x3fcee060 f9 01 ef 0b e3 07 07 87 01 79 f9 f9 05 ff 1d 0d |.........y......| V (17251) CMUX Received: 0x3fcee070 0a 4e 4f 20 43 41 52 52 49 45 52 0d 0a 56 f9 f9 |.NO CARRIER..V..| V (17261) CMUX Received: 0x3fcee080 01 ef 0b e3 07 07 8d 01 79 f9 |........y.| D (17271) CMUX: Payload frame: dlci:00 type:ef payload:5 available:38 D (17271) CMUX: Payload frame: dlci:01 type:ff payload:14 available:27 D (17281) esp-modem: debug_data: 0x3fcee06f 0d 0a 4e 4f 20 43 41 52 52 49 45 52 0d 0a |..NO CARRIER..| D (17291) CMUX: Payload frame: dlci:00 type:ef payload:5 available:7 Modem has correctly entered mode CMUX_MANUAL_COMMAND V (17801) command_lib: hang_up V (17801) command_lib: generic_command_common V (17801) command_lib: generic_command D (17801) command_lib: generic_command command ATH V (17801) Send: 0x3fcf4f84 f9 09 ef 09 |....| V (17811) Send: 0x3fcf5228 41 54 48 0d |ATH.| V (17801) CMUX Received: 0x3fcee060 f9 09 ff 0d 0d 0a 4f 4b 0d 0a cd f9 |......OK....| D (17831) CMUX: Payload frame: dlci:02 type:ff payload:6 available:8 D (17831) command_lib: Response: OK V (17831) Send: 0x3fcf4f88 df f9 |..| hang_up OK V (18341) command_lib: get_imei V (18341) command_lib: generic_get_string V (18341) command_lib: generic_get_string V (18341) Send: 0x3fcf5074 f9 09 ef 11 |....| V (18341) Send: 0x3fcf5228 41 54 2b 43 47 53 4e 0d |AT+CGSN.| V (18341) CMUX Received: 0x3fcee060 f9 09 ff 33 0d 0a 38 36 35 34 35 36 30 35 37 30 |...3..8654560570| V (18361) Send: 0x3fcf5078 cd f9 |..| V (18371) CMUX Received: 0x3fcee070 31 37 30 34 36 0d 0a 0d 0a 4f 4b 0d 0a 03 f9 |17046....OK....| D (18381) CMUX: Payload frame: dlci:02 type:ff payload:25 available:27 } (18381) command_lib: Token: { V (18391) command_lib: Token: {865456057017046} } (18391) command_lib: Token: { V (18401) command_lib: Token: {OK} Modem IMEI number:865456057017046 V (18401) command_lib: set_echo V (18411) command_lib: generic_command_common V (18411) command_lib: generic_command D (18411) command_lib: generic_command command ATE0 V (18421) Send: 0x3fcf4ea4 f9 09 ef 0b |....| V (18431) Send: 0x3fcf5148 41 54 45 30 0d |ATE0.| V (18421) CMUX Received: 0x3fcee060 f9 09 ff 0d 0d 0a 4f 4b 0d 0a cd f9 |......OK....| V (18441) Send: 0x3fcf4ea8 3c f9 |<.| D (18451) CMUX: Payload frame: dlci:02 type:ff payload:6 available:8 D (18461) command_lib: Response: OK V (18461) command_lib: set_pdp_context V (18471) command_lib: generic_command_common V (18471) command_lib: generic_command D (18471) command_lib: generic_command command AT+CGDCONT=1,"IP","nbiot.global-m2m.net" V (18481) Send: 0x3fcf4e24 f9 09 ef 53 |...S| V (18491) Send: 0x3fceea74 41 54 2b 43 47 44 43 4f 4e 54 3d 31 2c 22 49 50 |AT+CGDCONT=1,"IP| V (18491) CMUX Received: 0x3fcee060 f9 09 ff 0d 0d 0a 4f 4b 0d 0a cd f9 |......OK....| D (18511) CMUX: Payload frame: dlci:02 type:ff payload:6 available:8 D (18511) command_lib: Response: OK V (18511) Send: 0x3fceea84 22 2c 22 6e 62 69 6f 74 2e 67 6c 6f 62 61 6c 2d |","nbiot.global-| V (18531) Send: 0x3fceea94 6d 32 6d 2e 6e 65 74 22 0d |m2m.net".| V (18531) Send: 0x3fcf4e28 5e f9 |^.| V (18541) command_lib: set_data_mode V (18551) command_lib: generic_command D (18551) command_lib: generic_command command ATD*99## V (18561) Send: 0x3fcf4ed4 f9 09 ef 13 |....| V (18561) Send: 0x3fcf5158 41 54 44 2a 39 39 23 23 0d |ATD*99##.| V (18561) CMUX Received: 0x3fcee060 f9 01 ef 0b e3 07 0b 8d 01 79 f9 f9 09 ff 2b 0d |.........y....+.| V (18581) Send: 0x3fcf4ed8 2e f9 |..| V (18591) CMUX Received: 0x3fcee070 0a 43 4f 4e 4e 45 43 54 20 31 35 30 30 30 30 30 |.CONNECT 1500000| V (18601) CMUX Received: 0x3fcee080 30 30 0d 0a 11 f9 |00....| D (18611) CMUX: Payload frame: dlci:00 type:ef payload:5 available:34 D (18611) CMUX: Payload frame: dlci:02 type:ff payload:21 available:23 D (18621) command_lib: Response: CONNECT 150000000 D (18631) esp_netif_handlers: esp_netif action has started with netif0x3fcee2a0 from event_id=0 D (18631) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fc99614 D (18641) esp-netif_lwip-ppp: Phase Start D (18651) esp-netif_lwip-ppp: Phase Establish D (18651) esp_netif_lwip: check: remote, if=0x3fcee2a0 fn=0x42023bcc 0x42023bcc: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v5.0/components/esp_netif/lwip/esp_netif_lwip.c:272 D (18661) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcee2a0 V (18661) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcee2a0 D (18671) esp_netif_lwip: call api in lwip: ret=0x0, give sem Modem has correctly entered mode CMUX_MANUAL_DATA V (18681) command_lib: get_operator_name V (18681) command_lib: generic_get_string V (18691) Send: 0x3fcf5024 f9 05 ef 13 |....| V (18701) Send: 0x3fcf5204 41 54 2b 43 4f 50 53 3f 0d |AT+COPS?.| V (18691) CMUX Received: 0x3fcee060 f9 05 ff 49 0d 0a 2b 43 4f 50 53 3a 20 30 2c 30 |...I..+COPS: 0,0| V (18711) Send: 0x3fcf5028 a9 f9 |..| V (18721) CMUX Received: 0x3fcee070 2c 22 76 6f 64 61 66 6f 6e 65 2e 64 65 22 2c 37 |,"vodafone.de",7| V (18731) CMUX Received: 0x3fcee080 0d 0a 0d 0a 4f 4b 0d 0a 3d f9 |....OK..=.| D (18741) CMUX: Payload frame: dlci:01 type:ff payload:36 available:38 } (18751) command_lib: Token: { V (18751) command_lib: Token: {+COPS: 0,0,"vodafone.de",7} } (18751) command_lib: Token: { V (18761) command_lib: Token: {OK} Operator name:vodafone.de V (24651) Send: 0x3fcebfc4 f9 09 ef 5b |...[| V (24651) Send: 0x3fc9a8ac 7e ff 7d 23 c0 21 7d 21 7d 23 7d 20 7d 34 7d 22 |~.}#.!}!}#} }4}"| V (24651) Send: 0x3fc9a8bc 7d 26 7d 20 7d 20 7d 20 7d 20 7d 25 7d 26 a9 a7 |}&} } } } }%}&..| V (24661) CMUX Received: 0x3fcee060 f9 09 ff 6b 7e ff 7d 23 c0 21 7d 21 7d 23 7d 20 |...k~.}#.!}!}#} | V (24661) Send: 0x3fc9a8cc 70 6a 7d 27 7d 22 7d 28 7d 22 21 e4 7e |pj}'}"}(}"!.~| V (24681) CMUX Received: 0x3fcee070 7d 39 7d 22 7d 26 7d 20 7d 20 7d 20 7d 20 7d 23 |}9}"}&} } } } }#| V (24681) Send: 0x3fcebfc8 50 f9 |P.| V (24691) CMUX Received: 0x3fcee080 7d 25 c2 23 7d 25 7d 25 7d 26 44 3c 3e 23 7d 27 |}%.#}%}%}&D<>#}'| V (24711) CMUX Received: 0x3fcee090 7d 22 7d 28 7d 22 d6 74 7e 61 f9 f9 09 ff 5b 7e |}"}(}".t~a....[~| D (24721) CMUX: Payload frame: dlci:02 type:ff payload:53 available:60 V (24721) Send: 0x3fcebf24 f9 09 ef 33 |...3| D (24731) CMUX: Payload frame: dlci:02 type:ff payload:45 available:1 V (24731) Send: 0x3fc9b4ac 7e ff 7d 23 c0 21 7d 24 7d 23 7d 20 7d 29 7d 23 |~.}#.!}$}#} })}#| V (24741) CMUX Received: 0x3fcee0a0 ff 7d 23 c0 21 7d 22 7d 23 7d 20 7d 34 7d 22 7d |.}#.!}"}#} }4}"}| V (24751) Send: 0x3fc9b4bc 7d 25 c2 23 7d 25 28 ea 7e |}%.#}%(.~| V (24761) CMUX Received: 0x3fcee0b0 26 7d 20 7d 20 7d 20 7d 20 7d 25 7d 26 a9 a7 70 |&} } } } }%}&..p| V (24761) Send: 0x3fcebf28 16 f9 |..| V (24781) CMUX Received: 0x3fcee0c0 6a 7d 27 7d 22 7d 28 7d 22 ca 8d 7e 45 f9 |j}'}"}(}"..~E.| D (24791) CMUX: Payload frame: dlci:02 type:ff payload:44 available:46 V (24801) CMUX Received: 0x3fcee060 f9 09 ff 5b 7e ff 7d 23 c0 21 7d 21 7d 24 7d 20 |...[~.}#.!}!}$} | V (24811) CMUX Received: 0x3fcee070 7d 34 7d 22 7d 26 7d 20 7d 20 7d 20 7d 20 7d 25 |}4}"}&} } } } }%| V (24821) CMUX Received: 0x3fcee080 7d 26 44 3c 3e 23 7d 27 7d 22 7d 28 7d 22 b0 48 |}&D<>#}'}"}(}".H| V (24831) CMUX Received: 0x3fcee090 7e 45 f9 |~E.| D (24831) CMUX: Payload frame: dlci:02 type:ff payload:45 available:47 V (24841) Send: 0x3fcebf24 f9 09 ef 5b |...[| V (24851) Send: 0x3fc9b4ac 7e ff 7d 23 c0 21 7d 22 7d 24 7d 20 7d 34 7d 22 |~.}#.!}"}$} }4}"| V (24851) CMUX Received: 0x3fcee060 f9 09 ff 2d 7e ff 7d 23 c0 21 7d 2b 7d 25 7d 20 |...-~.}#.!}+}%} | V (24861) Send: 0x3fc9b4bc 7d 26 7d 20 7d 20 7d 20 7d 20 7d 25 7d 26 44 3c |}&} } } } }%}&D<| V (24871) CMUX Received: 0x3fcee070 7d 28 44 3c 3e 23 7d 2a ed 7e f5 f9 |}(D<>#}*.~..| V (24881) Send: 0x3fc9b4cc 3e 23 7d 27 7d 22 7d 28 7d 22 5b 21 7e |>#}'}"}(}"[!~| D (24891) CMUX: Payload frame: dlci:02 type:ff payload:22 available:24 V (24891) Send: 0x3fcebf28 50 f9 |P.| D (24911) esp-netif_lwip-ppp: Phase Authenticate D (24911) esp-netif_lwip-ppp: Phase Network V (24921) Send: 0x3fcebe44 f9 09 ef 49 |...I| V (24921) Send: 0x3fc9c0ac 7e ff 03 80 21 01 04 00 1c 02 06 00 2d 0f 01 03 |~...!.......-...| V (24921) CMUX Received: 0x3fcee060 f9 09 ff 15 7e 80 21 01 02 00 04 df 76 7e df f9 |....~.!.....v~..| V (24931) Send: 0x3fc9c0bc 06 00 00 00 00 81 06 00 00 00 00 83 06 00 00 00 |................| V (24951) CMUX Received: 0x3fcee070 f9 09 ff 21 7e 80 21 04 04 00 0a 02 06 00 2d 0f |...!~.!.......-.| V (24951) Send: 0x3fc9c0cc 00 2c 06 7e |.,.~| V (24971) Send: 0x3fcebe48 af f9 |..| V (24971) CMUX Received: 0x3fcee080 01 e0 42 7e fc f9 |..B~..| D (24991) CMUX: Payload frame: dlci:02 type:ff payload:10 available:34 V (24991) Send: 0x3fcebf24 f9 09 ef 25 |...%| D (25001) CMUX: Payload frame: dlci:02 type:ff payload:16 available:18 V (25001) Send: 0x3fc9b4ac 7e ff 03 80 21 03 02 00 0a 03 06 00 00 00 00 5a |~...!..........Z| V (25011) CMUX Received: 0x3fcee060 f9 09 ff 15 7e 80 21 01 03 00 04 03 2c 7e df f9 |....~.!.....,~..| V (25011) Send: 0x3fc9b4bc a6 7e |.~| D (25031) CMUX: Payload frame: dlci:02 type:ff payload:10 available:12 V (25031) Send: 0x3fcebf28 ee f9 |..| V (25051) Send: 0x3fcebf34 f9 09 ef 3d |...=| V (25051) CMUX Received: 0x3fcee060 f9 09 ff 39 7e 80 21 03 05 00 16 03 06 64 52 4f |...9~.!......dRO| V (25051) Send: 0x3fc9aeac 7e ff 03 80 21 01 05 00 16 03 06 00 00 00 00 81 |~...!...........| V (25071) CMUX Received: 0x3fcee070 5c 81 06 d9 0e a0 82 83 06 d9 0e a4 23 16 f7 7e |\...........#..~| V (25071) Send: 0x3fc9aebc 06 00 00 00 00 83 06 00 00 00 00 de 06 7e |.............~| V (25091) CMUX Received: 0x3fcee080 ee f9 |..| V (25091) Send: 0x3fcebf38 fc f9 |..| D (25111) CMUX: Payload frame: dlci:02 type:ff payload:28 available:30 V (25111) Send: 0x3fcebf24 f9 09 ef 19 |....| V (25121) Send: 0x3fc9aeac 7e ff 03 80 21 02 03 00 04 75 27 7e |~...!....u'~| V (25131) Send: 0x3fcebf28 c3 f9 |..| V (25141) Send: 0x3fcebf34 f9 09 ef 3d |...=| V (25151) CMUX Received: 0x3fcee060 f9 09 ff 39 7e 80 21 02 06 00 16 03 06 64 52 4f |...9~.!......dRO| V (25151) Send: 0x3fc9baac 7e ff 03 80 21 01 06 00 16 03 06 64 52 4f 5c 81 |~...!......dRO\.| V (25161) CMUX Received: 0x3fcee070 5c 81 06 d9 0e a0 82 83 06 d9 0e a4 23 ff 07 7e |\...........#..~| V (25161) Send: 0x3fc9babc 06 d9 0e a0 82 83 06 d9 0e a4 23 69 64 7e |..........#id~| V (25181) CMUX Received: 0x3fcee080 ee f9 |..| V (25181) Send: 0x3fcebf38 fc f9 |..| D (25201) CMUX: Payload frame: dlci:02 type:ff payload:28 available:30 D (25211) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fcee324 D (25211) esp_netif_lwip: if0x3fcee2a0 ip unchanged I (25221) esp-netif_lwip-ppp: Connected D (25221) event: running post NETIF_PPP_STATUS:0 with handler 0x42012504 and context 0x3fcee6bc on loop 0x3fce9f34 0x42012504: esp_modem::Netif::on_ppp_changed(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/esp_modem/src/esp_modem_netif.cpp:22 D (25231) esp-netif_lwip-ppp: Phase Running E (78761) cmux_example: Cannot get IP within specified timeout... exiting D (78761) esp_netif_handlers: esp_netif action stopped with netif0x3fcee2a0 from event_id=0 D (78761) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3fc99614 D (78771) esp-netif_lwip-ppp: Phase Terminate D (78771) esp-netif_lwip-ppp: Phase Network D (78781) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fcee324 D (78781) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fcee2a0 D (78791) esp_netif_lwip: if0x3fcee2a0 start ip lost tmr: already started D (78801) esp-netif_lwip-ppp: Phase Establish V (78801) Send: 0x3fcebf64 f9 09 ef 3b |...;| V (78811) Send: 0x3fc9a8ac 7e ff 7d 23 c0 21 7d 25 7d 24 7d 20 7d 30 55 73 |~.}#.!}%}$} }0Us| V (78811) CMUX Received: 0x3fcee060 f9 09 ff 23 7e ff 7d 23 c0 21 7d 26 7d 24 7d 20 |...#~.}#.!}&}$} | V (78821) Send: 0x3fc9a8bc 65 72 20 72 65 71 75 65 73 74 be 8b 7e |er request..~| V (78841) CMUX Received: 0x3fcee070 7d 24 4d db 7e 1f f9 |}$M.~..| V (78841) Send: 0x3fcebf68 18 f9 |..| D (78851) CMUX: Payload frame: dlci:02 type:ff payload:17 available:19 D (78851) esp_netif_lwip: check: remote, if=0x3fcee2a0 fn=0x42023bcc 0x42023bcc: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v5.0/components/esp_netif/lwip/esp_netif_lwip.c:272 D (78861) esp-netif_lwip-ppp: Phase Disconnect D (78871) esp-netif_lwip-ppp: Phase Dead I (78871) esp-netif_lwip-ppp: User interrupt D (78881) event: running post NETIF_PPP_STATUS:5 with handler 0x42012504 and context 0x3fcee6bc on loop 0x3fce9f34 0x42012504: esp_modem::Netif::on_ppp_changed(void*, char const*, long, void*) at /home/franz/git/krone/pppos_client_sample/simple_cmux_client/build/../components/esp_modem/src/esp_modem_netif.cpp:22 I (78891) esp_modem_netif: PPP state changed event 5 D (78891) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcee2a0 V (78901) esp_netif_objects: esp_netif_next_unsafe 0x0 V (78911) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcee2a0 V (78911) esp_netif_objects: esp_netif_next_unsafe 0x3fcee2a0 D (78921) esp_netif_lwip: call api in lwip: ret=0x0, give sem V (78921) intr_alloc: esp_intr_free: Disabling int, killing handler D (78931) event: deleted loop 0x3fce9f34

Same with ESP-IDF 4.4.2

0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

 TOPIC:/topic/esp-modem
 DATA:Hello modem
Data received
V (27440) Send: 0x3fce27c0   f9 09 ef 5f                                       |..._|
V (27450) Send: 0x3fceb0e4   7e 21 45 00 00 2a 00 0f  00 00 ff 06 4f 39 64 52  |~!E..*......O9dR|
V (27460) Send: 0x3fceb0f4   4f 5c 5b 79 5d 5e c3 32  07 5b db 24 0e 10 c7 f8  |O\[y]^.2.[.$....|
V (27470) Send: 0x3fceb104   0c 55 50 18 16 48 c4 eb  00 00 e0 00 cf ac 7e     |.UP..H........~|
V (27480) Send: 0x3fce27c4   57 f9                                             |W.|
V (28010) CMUX Received: 0x3fce596c   f9 09 ff 5b 7e 21 45 00  00 28 2a c3 40 00 2d 06  |...[~!E..(*.@.-.|
V (28010) CMUX Received: 0x3fce597c   b6 87 5b 79 5d 5e 64 52  4f 5c 07 5b c3 32 c7 f8  |..[y]^dRO\.[.2..|
V (28020) CMUX Received: 0x3fce598c   0c 55 db 24 0e 12 50 11  fa 9e c0 9c 00 00 e7 2d  |.U.$..P........-|
V (28030) CMUX Received: 0x3fce599c   7e 45 f9                                          |~E.|
D (28040) CMUX: Payload frame: dlci:02 type:ff payload:45 available:47
V (28040) Send: 0x3fce2720   f9 09 ef 5b                                       |...[|
V (28050) Send: 0x3fcebccc   7e 21 45 00 00 28 00 10  00 00 ff 06 4f 3a 64 52  |~!E..(......O:dR|
V (28060) Send: 0x3fcebcdc   4f 5c 5b 79 5d 5e c3 32  07 5b db 24 0e 12 c7 f8  |O\[y]^.2.[.$....|
V (28070) Send: 0x3fcebcec   0c 56 50 10 16 47 a4 f4  00 00 c6 ac 7e           |.VP..G......~|
V (28080) Send: 0x3fce2724   50 f9                                             |P.|
V (28090) Send: 0x3fce2740   f9 09 ef 5b                                       |...[|
V (28090) Send: 0x3fceab7c   7e 21 45 00 00 28 00 11  00 00 ff 06 4f 39 64 52  |~!E..(......O9dR|
V (28100) Send: 0x3fceab8c   4f 5c 5b 79 5d 5e c3 32  07 5b db 24 0e 12 c7 f8  |O\[y]^.2.[.$....|
V (28110) Send: 0x3fceab9c   0c 56 50 11 16 47 a4 f3  00 00 6d b1 7e           |.VP..G....m.~|
V (28120) Send: 0x3fce2744   50 f9                                             |P.|
D (28130) event: deleted loop 0x3fce8184
V (28130) command_lib: get_imsi
V (28130) command_lib: generic_get_string
V (28140) command_lib: generic_get_string
V (28140) Send: 0x3fcf51f0   f9 05 ef 11                                       |....|
V (28150) Send: 0x3fcf53f8   41 54 2b 43 49 4d 49 0d                           |AT+CIMI.|
V (28150) CMUX Received: 0x3fce596c   f9 05 ff 33 0d 0a 39 30  31 32 38 38 30 30 35 36  |...3..9012880056|
V (28170) CMUX Received: 0x3fce597c   38 31 39 32 30 0d 0a 0d  0a 4f 4b 0d 0a 84 f9     |81920....OK....|
D (28180) CMUX: Payload frame: dlci:01 type:ff payload:25 available:27
} (28180) command_lib: Token: {

V (28190) command_lib: Token: {901288005681920}

} (28190) command_lib: Token: {

V (28190) command_lib: Token: {OK}

V (28170) Send: 0x3fcf51f4   4a f9                                             |J.|
Modem IMSI number:901288005681920
V (28210) CMUX Received: 0x3fce596c   f9 09 ff 5b 7e 21 45 00  00 28 00 00 40 00 2d 06  |...[~!E..(..@.-.|
V (28220) CMUX Received: 0x3fce597c   e1 4a 5b 79 5d 5e 64 52  4f 5c 07 5b c3 32 c7 f8  |.J[y]^dRO\.[.2..|
V (28230) CMUX Received: 0x3fce598c   0c 56 db 24 0e 13 50 10  fa 9e c0 9b 00 00 de 0f  |.V.$..P.........|
V (28240) CMUX Received: 0x3fce599c   7e 45 f9                                          |~E.|
D (28250) CMUX: Payload frame: dlci:02 type:ff payload:45 available:47
D (28250) esp_netif_handlers: esp_netif action stopped with netif0x3fce5bac from event_id=0
D (28260) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3fce5edc
D (28270) esp-netif_lwip-ppp: Phase Terminate
D (28270) esp-netif_lwip-ppp: Phase Network
D (28280) esp-netif_lwip-ppp: Phase Establish
V (28280) Send: 0x3fce2860   f9 09 ef 3b                                       |...;|
V (28290) CMUX Received: 0x3fce596c   f9 09 ff 23 7e ff 7d 23  c0 21 7d 26 7d 24 7d 20  |...#~.}#.!}&}$} |
V (28290) Send: 0x3fce74a4   7e ff 7d 23 c0 21 7d 25  7d 24 7d 20 7d 30 55 73  |~.}#.!}%}$} }0Us|
V (28310) CMUX Received: 0x3fce597c   7d 24 4d db 7e 1f f9                              |}$M.~..|
V (28310) Send: 0x3fce74b4   65 72 20 72 65 71 75 65  73 74 be 8b 7e           |er request..~|
D (28320) CMUX: Payload frame: dlci:02 type:ff payload:17 available:19
V (28320) Send: 0x3fce2864   18 f9                                             |..|
D (28340) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (28340) esp-netif_lwip-ppp: Phase Disconnect
D (28350) esp-netif_lwip-ppp: Phase Dead
I (28350) esp-netif_lwip-ppp: User interrupt
D (28360) event: running post NETIF_PPP_STATUS:5 with handler 0x42010ff8 and context 0x3fce7270 on loop 0x3fce0814
0x42010ff8: esp_modem::Netif::on_ppp_changed(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/esp_modem/src/esp_modem_netif.cpp:22

D (28360) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
I (28370) esp_modem_netif: PPP state changed event 5
V (28380) esp_netif_objects: esp_netif_next_unsafe 0x0
V (28390) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
V (28390) esp_netif_objects: esp_netif_next_unsafe 0x3fce5bac
D (28400) esp_netif_lwip: call api in lwip: ret=0x0, give sem
V (29290) CMUX Received: 0x3fce596c   f9 01 ef 0b e3 07 0b 87  01 79 f9 f9 09 ff 1d 0d  |.........y......|
V (29290) CMUX Received: 0x3fce597c   0a 4e 4f 20 43 41 52 52  49 45 52 0d 0a d1 f9 f9  |.NO CARRIER.....|
V (29300) CMUX Received: 0x3fce598c   01 ef 0b e3 07 0b 8d 01  79 f9                    |........y.|
D (29310) CMUX: Payload frame: dlci:00 type:ef payload:5 available:38
D (29310) CMUX: Payload frame: dlci:02 type:ff payload:14 available:27
D (29320) esp-modem: debug_data: 0x3fce597b   0d 0a 4e 4f 20 43 41 52  52 49 45 52 0d 0a        |..NO CARRIER..|
D (29330) CMUX: Payload frame: dlci:00 type:ef payload:5 available:7
Modem has correctly entered mode CMUX_MANUAL_COMMAND
V (29840) command_lib: hang_up
V (29840) command_lib: generic_command_common
V (29840) command_lib: generic_command
D (29840) command_lib: generic_command command ATH

V (29840) Send: 0x3fcf5120   f9 05 ef 09                                       |....|
V (29850) Send: 0x3fcf53f8   41 54 48 0d                                       |ATH.|
V (29840) CMUX Received: 0x3fce596c   f9 05 ff 0d 0d 0a 4f 4b  0d 0a 4a f9              |......OK..J.|
D (29870) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8
D (29870) command_lib: Response: 
OK

V (29870) Send: 0x3fcf5124   58 f9                                             |X.|
hang_up OK
V (30380) command_lib: get_imei
V (30380) command_lib: generic_get_string
V (30380) command_lib: generic_get_string
V (30380) Send: 0x3fcf51f0   f9 05 ef 11                                       |....|
V (30380) Send: 0x3fcf53f8   41 54 2b 43 47 53 4e 0d                           |AT+CGSN.|
V (30380) CMUX Received: 0x3fce596c   f9 05 ff 33 0d 0a 38 36  35 34 35 36 30 35 37 30  |...3..8654560570|
V (30400) Send: 0x3fcf51f4   4a f9                                             |J.|
V (30410) CMUX Received: 0x3fce597c   31 37 30 34 36 0d 0a 0d  0a 4f 4b 0d 0a 84 f9     |17046....OK....|
D (30420) CMUX: Payload frame: dlci:01 type:ff payload:25 available:27
} (30420) command_lib: Token: {

V (30430) command_lib: Token: {865456057017046}

} (30430) command_lib: Token: {

V (30440) command_lib: Token: {OK}

Modem IMEI number:865456057017046
V (30440) command_lib: set_echo
V (30450) command_lib: generic_command_common
V (30450) command_lib: generic_command
D (30450) command_lib: generic_command command ATE0

V (30460) Send: 0x3fcf5050   f9 05 ef 0b                                       |....|
V (30470) Send: 0x3fcf5328   41 54 45 30 0d                                    |ATE0.|
V (30460) CMUX Received: 0x3fce596c   f9 05 ff 0d 0d 0a 4f 4b  0d 0a 4a f9              |......OK..J.|
V (30480) Send: 0x3fcf5054   bb f9                                             |..|
D (30490) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8
D (30500) command_lib: Response: 
OK

V (30500) command_lib: set_pdp_context
V (30510) command_lib: generic_command_common
V (30510) command_lib: generic_command
D (30510) command_lib: generic_command command AT+CGDCONT=1,"IP","nbiot.global-m2m.net"

V (30520) Send: 0x3fcf4fd0   f9 05 ef 53                                       |...S|
V (30530) Send: 0x3fce85bc   41 54 2b 43 47 44 43 4f  4e 54 3d 31 2c 22 49 50  |AT+CGDCONT=1,"IP|
V (30530) CMUX Received: 0x3fce596c   f9 05 ff 0d 0d 0a 4f 4b  0d 0a 4a f9              |......OK..J.|
D (30550) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8
D (30550) command_lib: Response: 
OK

V (30550) Send: 0x3fce85cc   22 2c 22 6e 62 69 6f 74  2e 67 6c 6f 62 61 6c 2d  |","nbiot.global-|
V (30570) Send: 0x3fce85dc   6d 32 6d 2e 6e 65 74 22  0d                       |m2m.net".|
V (30570) Send: 0x3fcf4fd4   d9 f9                                             |..|
V (30580) command_lib: set_data_mode
V (30590) command_lib: generic_command
D (30590) command_lib: generic_command command ATD*99##

V (30600) Send: 0x3fcf5080   f9 05 ef 13                                       |....|
V (30600) Send: 0x3fcf5338   41 54 44 2a 39 39 23 23  0d                       |ATD*99##.|
V (30600) CMUX Received: 0x3fce596c   f9 01 ef 0b e3 07 07 8d  01 79 f9 f9 05 ff 2b 0d  |.........y....+.|
V (30620) Send: 0x3fcf5084   a9 f9                                             |..|
V (30630) CMUX Received: 0x3fce597c   0a 43 4f 4e 4e 45 43 54  20 31 35 30 30 30 30 30  |.CONNECT 1500000|
V (30640) CMUX Received: 0x3fce598c   30 30 0d 0a 96 f9                                 |00....|
D (30650) CMUX: Payload frame: dlci:00 type:ef payload:5 available:34
D (30650) CMUX: Payload frame: dlci:01 type:ff payload:21 available:23
D (30660) command_lib: Response: 
CONNECT 150000000

D (30670) esp_netif_handlers: esp_netif action has started with netif0x3fce5bac from event_id=0
D (30670) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fce5edc
D (30680) esp-netif_lwip-ppp: Phase Start
D (30690) esp-netif_lwip-ppp: Phase Establish
D (30690) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (30700) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
V (30700) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
D (30710) esp_netif_lwip: call api in lwip: ret=0x0, give sem
Modem has correctly entered mode CMUX_MANUAL_DATA
V (30720) command_lib: get_operator_name
V (30720) command_lib: generic_get_string
V (30730) Send: 0x3fcf51a0   f9 09 ef 13                                       |....|
V (30740) Send: 0x3fcf53d4   41 54 2b 43 4f 50 53 3f  0d                       |AT+COPS?.|
V (30730) CMUX Received: 0x3fce596c   f9 09 ff 49 0d 0a 2b 43  4f 50 53 3a 20 30 2c 30  |...I..+COPS: 0,0|
V (30750) Send: 0x3fcf51a4   2e f9                                             |..|
V (30760) CMUX Received: 0x3fce597c   2c 22 76 6f 64 61 66 6f  6e 65 2e 64 65 22 2c 37  |,"vodafone.de",7|
V (30770) CMUX Received: 0x3fce598c   0d 0a 0d 0a 4f 4b 0d 0a  ba f9                    |....OK....|
D (30780) CMUX: Payload frame: dlci:02 type:ff payload:36 available:38
} (30790) command_lib: Token: {

V (30790) command_lib: Token: {+COPS: 0,0,"vodafone.de",7}

} (30790) command_lib: Token: {

V (30800) command_lib: Token: {OK}

Operator name:vodafone.de
V (36690) Send: 0x3fce28c0   f9 05 ef 5f                                       |..._|
V (36690) Send: 0x3fce7b7c   7e ff 7d 23 c0 21 7d 21  7d 25 7d 20 7d 34 7d 22  |~.}#.!}!}%} }4}"|
V (36690) Send: 0x3fce7b8c   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 7d 3b  |}&} } } } }%}&};|
V (36700) CMUX Received: 0x3fce596c   f9 05 ff 6b 7e ff 7d 23  c0 21 7d 21 7d 26 7d 20  |...k~.}#.!}!}&} |
V (36700) Send: 0x3fce7b9c   f8 3a 2f 7d 27 7d 22 7d  28 7d 22 33 7d 3d 7e     |.:/}'}"}(}"3}=~|
V (36720) CMUX Received: 0x3fce597c   7d 39 7d 22 7d 26 7d 20  7d 20 7d 20 7d 20 7d 23  |}9}"}&} } } } }#|
V (36720) Send: 0x3fce28c4   d0 f9                                             |..|
V (36730) CMUX Received: 0x3fce598c   7d 25 c2 23 7d 25 7d 25  7d 26 44 46 a6 6a 7d 27  |}%.#}%}%}&DF.j}'|
V (36750) CMUX Received: 0x3fce599c   7d 22 7d 28 7d 22 84 44  7e e6 f9 f9 05 ff 5d 7e  |}"}(}".D~.....]~|
D (36760) CMUX: Payload frame: dlci:01 type:ff payload:53 available:60
V (36760) Send: 0x3fce2820   f9 05 ef 35                                       |...5|
D (36770) CMUX: Payload frame: dlci:01 type:ff payload:46 available:1
V (36770) Send: 0x3fce8a50   7e ff 7d 23 c0 21 7d 24  7d 26 7d 20 7d 29 7d 23  |~.}#.!}$}&} })}#|
V (36780) CMUX Received: 0x3fce59ac   ff 7d 23 c0 21 7d 22 7d  25 7d 20 7d 34 7d 22 7d  |.}#.!}"}%} }4}"}|
V (36790) Send: 0x3fce8a60   7d 25 c2 23 7d 25 49 7d  5d 7e                    |}%.#}%I}]~|
V (36800) Send: 0x3fce2824   75 f9                                             |u.|
V (36810) CMUX Received: 0x3fce59bc   26 7d 20 7d 20 7d 20 7d  20 7d 25 7d 26 7d 3b f8  |&} } } } }%}&};.|
V (36820) CMUX Received: 0x3fce59cc   3a 2f 7d 27 7d 22 7d 28  7d 22 d8 74 7e 26 f9     |:/}'}"}(}".t~&.|
D (36830) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47
V (36840) CMUX Received: 0x3fce596c   f9 05 ff 5b 7e ff 7d 23  c0 21 7d 21 7d 27 7d 20  |...[~.}#.!}!}'} |
V (36850) CMUX Received: 0x3fce597c   7d 34 7d 22 7d 26 7d 20  7d 20 7d 20 7d 20 7d 25  |}4}"}&} } } } }%|
V (36860) CMUX Received: 0x3fce598c   7d 26 44 46 a6 6a 7d 27  7d 22 7d 28 7d 22 6d fb  |}&DF.j}'}"}(}"m.|
V (36870) CMUX Received: 0x3fce599c   7e c2 f9                                          |~..|
D (36870) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47
V (36880) Send: 0x3fce2820   f9 05 ef 5b                                       |...[|
V (36890) Send: 0x3fce8a50   7e ff 7d 23 c0 21 7d 22  7d 27 7d 20 7d 34 7d 22  |~.}#.!}"}'} }4}"|
V (36890) CMUX Received: 0x3fce596c   f9 05 ff 2b 7e ff 7d 23  c0 21 7d 2b 7d 28 7d 20  |...+~.}#.!}+}(} |
V (36900) Send: 0x3fce8a60   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 44 46  |}&} } } } }%}&DF|
V (36920) CMUX Received: 0x3fce597c   7d 28 44 46 a6 6a bf 38  7e 96 f9                 |}(DF.j.8~..|
V (36920) Send: 0x3fce8a70   a6 6a 7d 27 7d 22 7d 28  7d 22 86 92 7e           |.j}'}"}(}"..~|
D (36930) CMUX: Payload frame: dlci:01 type:ff payload:21 available:23
V (36930) Send: 0x3fce2824   d7 f9                                             |..|
D (36950) esp-netif_lwip-ppp: Phase Authenticate
D (36950) esp-netif_lwip-ppp: Phase Network
V (36960) Send: 0x3fce2740   f9 05 ef 49                                       |...I|
V (36960) Send: 0x3fce9638   7e ff 03 80 21 01 07 00  1c 02 06 00 2d 0f 01 03  |~...!.......-...|
V (36960) CMUX Received: 0x3fce596c   f9 05 ff 15 7e 80 21 01  04 00 04 06 a0 7e 58 f9  |....~.!......~X.|
V (36970) Send: 0x3fce9648   06 00 00 00 00 81 06 00  00 00 00 83 06 00 00 00  |................|
V (36990) CMUX Received: 0x3fce597c   f9 05 ff 21 7e 80 21 04  07 00 0a 02 06 00 2d 0f  |...!~.!.......-.|
V (36990) Send: 0x3fce9658   00 f4 f0 7e                                       |...~|
V (37010) CMUX Received: 0x3fce598c   01 e7 94 7e 7b f9                                 |...~{.|
V (37010) Send: 0x3fce2744   28 f9                                             |(.|
D (37020) CMUX: Payload frame: dlci:01 type:ff payload:10 available:34
V (37030) Send: 0x3fce2820   f9 05 ef 25                                       |...%|
D (37040) CMUX: Payload frame: dlci:01 type:ff payload:16 available:18
V (37040) Send: 0x3fce8a50   7e ff 03 80 21 03 04 00  0a 03 06 00 00 00 00 45  |~...!..........E|
V (37050) CMUX Received: 0x3fce596c   f9 05 ff 15 7e 80 21 01  05 00 04 da fa 7e 58 f9  |....~.!......~X.|
V (37060) Send: 0x3fce8a60   02 7e                                             |.~|
D (37070) CMUX: Payload frame: dlci:01 type:ff payload:10 available:12
V (37070) Send: 0x3fce2824   69 f9                                             |i.|
V (37090) Send: 0x3fce2830   f9 05 ef 3d                                       |...=|
V (37090) CMUX Received: 0x3fce596c   f9 05 ff 39 7e 80 21 03  08 00 16 03 06 64 52 4f  |...9~.!......dRO|
V (37090) Send: 0x3fce845c   7e ff 03 80 21 01 08 00  16 03 06 00 00 00 00 81  |~...!...........|
V (37110) CMUX Received: 0x3fce597c   5c 81 06 d9 0e a0 82 83  06 d9 0e a4 23 bb ae 7e  |\...........#..~|
V (37110) Send: 0x3fce846c   06 00 00 00 00 83 06 00  00 00 00 73 5f 7e        |...........s_~|
V (37130) CMUX Received: 0x3fce598c   69 f9                                             |i.|
V (37130) Send: 0x3fce2834   7b f9                                             |{.|
D (37150) CMUX: Payload frame: dlci:01 type:ff payload:28 available:30
V (37150) Send: 0x3fce2820   f9 05 ef 19                                       |....|
V (37160) Send: 0x3fce9c2c   7e ff 03 80 21 02 05 00  04 ac f1 7e              |~...!......~|
V (37170) Send: 0x3fce2824   44 f9                                             |D.|
V (37180) Send: 0x3fce2830   f9 05 ef 3d                                       |...=|
V (37190) CMUX Received: 0x3fce596c   f9 05 ff 39 7e 80 21 02  09 00 16 03 06 64 52 4f  |...9~.!......dRO|
V (37190) Send: 0x3fce8a50   7e ff 03 80 21 01 09 00  16 03 06 64 52 4f 5c 81  |~...!......dRO\.|
V (37200) Send: 0x3fce8a60   06 d9 0e a0 82 83 06 d9  0e a4 23 1c 53 7e        |..........#.S~|
V (37210) CMUX Received: 0x3fce597c   5c 81 06 d9 0e a0 82 83  06 d9 0e a4 23 8a 30 7e  |\...........#.0~|
V (37210) Send: 0x3fce2834   7b f9                                             |{.|
V (37230) CMUX Received: 0x3fce598c   69 f9                                             |i.|
D (37240) CMUX: Payload frame: dlci:01 type:ff payload:28 available:30
I (37250) esp-netif_lwip-ppp: Connected
I (37250) esp-netif_lwip-ppp: Name Server1: 217.14.160.130
I (37260) esp-netif_lwip-ppp: Name Server2: 217.14.164.35
D (37260) event: running post IP_EVENT:6 with handler 0x420220f4 and context 0x3fce72b4 on loop 0x3fce0814
0x420220f4: esp_netif_action_connected at /home/franz/esp-idf-v4.4.2/components/esp_netif/esp_netif_handlers.c:44

D (37260) esp-netif_lwip-ppp: Phase Running
D (37270) esp_netif_handlers: esp_netif action connected with netif0x3fce5bac from event_id=6
D (37280) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42022e80
0x42022e80: esp_netif_up_api at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:1256

D (37290) esp_netif_lwip: esp_netif_up_api esp_netif:0x3fce5bac
D (37300) esp_netif_lwip: check: local, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (37300) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
V (37310) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
D (37320) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (37320) event: running post IP_EVENT:6 with handler 0x42099aec and context 0x3fce7318 on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

I (37330) cmux_example: IP          : 100.82.79.92
I (37340) cmux_example: Netmask     : 255.255.255.255
I (37340) cmux_example: Gateway     : 10.64.64.64
Got IP address
D (37350) MQTT_CLIENT: MQTT client_id=ESP32_2a0AC4
D (37350) event: created event loop 0x3fce8288
D (37360) MQTT_CLIENT: Core selection disabled
D (37360) event: running post MQTT_EVENTS:7 with handler 0x42009be4 and context 0x3fce8cb8 on loop 0x3fce8288
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (37370) event: no handlers have been registered for event MQTT_EVENTS:7 posted to loop 0x3fce0814
D (37370) esp-tls: host:test.mosquitto.org: strlen 18
D (37390) esp-tls: [sock=54] Resolved IPv4 address: 91.121.93.94
D (37390) esp-tls: [sock=54] Connecting to server. HOST: test.mosquitto.org, Port: 1883
V (37400) Send: 0x3fce27b0   f9 05 ef 63                                       |...c|
V (37410) Send: 0x3fceab7c   7e 21 45 00 00 2c 00 12  00 00 ff 06 4f 34 64 52  |~!E..,......O4dR|
V (37420) Send: 0x3fceab8c   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 03 00 00  |O\[y]^.3.[f.....|
V (37430) Send: 0x3fceab9c   00 00 60 02 16 70 c9 18  00 00 02 04 05 a0 e0 dc  |..`..p..........|
V (37430) Send: 0x3fceabac   7e                                                |~|
V (37440) Send: 0x3fce27b4   fd f9                                             |..|
V (38280) CMUX Received: 0x3fce596c   f9 05 ff 63 7e 21 45 00  00 2c 00 00 40 00 2d 06  |...c~!E..,..@.-.|
V (38290) CMUX Received: 0x3fce597c   e1 46 5b 79 5d 5e 64 52  4f 5c 07 5b c3 33 51 c5  |.F[y]^dRO\.[.3Q.|
V (38290) CMUX Received: 0x3fce598c   ac e0 66 9a 1b 04 60 12  fa f0 e6 80 00 00 02 04  |..f...`.........|
V (38300) CMUX Received: 0x3fce599c   05 00 8a 89 7e e8 f9                              |....~..|
D (38310) CMUX: Payload frame: dlci:01 type:ff payload:49 available:51
V (38320) Send: 0x3fce2720   f9 05 ef 5b                                       |...[|
V (38330) Send: 0x3fceb764   7e 21 45 00 00 28 00 13  00 00 ff 06 4f 37 64 52  |~!E..(......O7dR|
V (38340) Send: 0x3fceb774   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 04 51 c5  |O\[y]^.3.[f...Q.|
V (38340) Send: 0x3fceb784   ac e1 50 10 16 70 e2 0a  00 00 1a 57 7e           |..P..p.....W~|
V (38350) Send: 0x3fce2724   d7 f9                                             |..|
D (38360) MQTT_CLIENT: Transport connected to mqtt://test.mosquitto.org:1883
D (38370) MQTT_CLIENT: Sending MQTT CONNECT message, type: 1, id: 0000
V (38380) Send: 0x3fce27c0   f9 05 ef 8f                                       |....|
V (38380) Send: 0x3fceb0e4   7e 21 45 00 00 42 00 14  00 00 ff 06 4f 1c 64 52  |~!E..B......O.dR|
V (38390) Send: 0x3fceb0f4   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 04 51 c5  |O\[y]^.3.[f...Q.|
V (38400) Send: 0x3fceb104   ac e1 50 18 16 70 bd e4  00 00 10 18 00 04 4d 51  |..P..p........MQ|
V (38410) Send: 0x3fceb114   54 54 04 02 00 78 00 0c  45 53 50 33 32 5f 32 61  |TT...x..ESP32_2a|
V (38420) Send: 0x3fceb124   30 41 43 34 d7 cd 7e                              |0AC4..~|
V (38430) Send: 0x3fce27c4   5c f9                                             |\.|
V (38590) CMUX Received: 0x3fce596c   f9 05 ff 5b 7e 21 45 00  00 28 f0 93 40 00 2d 06  |...[~!E..(..@.-.|
V (38590) CMUX Received: 0x3fce597c   f0 b6 5b 79 5d 5e 64 52  4f 5c 07 5b c3 33 51 c5  |..[y]^dRO\.[.3Q.|
V (38600) CMUX Received: 0x3fce598c   ac e1 66 9a 1b 1e 50 10  fa d6 fd 89 00 00 61 de  |..f...P.......a.|
V (38610) CMUX Received: 0x3fce599c   7e c2 f9                                          |~..|
D (38620) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47
V (38620) CMUX Received: 0x3fce596c   f9 05 ff 63 7e 21 45 00  00 2c f0 94 40 00 2d 06  |...c~!E..,..@.-.|
V (38630) CMUX Received: 0x3fce597c   f0 b1 5b 79 5d 5e 64 52  4f 5c 07 5b c3 33 51 c5  |..[y]^dRO\.[.3Q.|
V (38640) CMUX Received: 0x3fce598c   ac e1 66 9a 1b 1e 50 18  fa d6 dd 7b 00 00 20 02  |..f...P....{.. .|
V (38650) CMUX Received: 0x3fce599c   00 00 13 28 7e e8 f9                              |...(~..|
D (38660) CMUX: Payload frame: dlci:01 type:ff payload:49 available:51
D (38670) MQTT_CLIENT: mqtt_message_receive: first byte: 0x20
D (38670) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
V (38680) Send: 0x3fce2760   f9 05 ef 5b                                       |...[|
D (38680) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
V (38690) Send: 0x3fceb764   7e 21 45 00 00 28 00 15  00 00 ff 06 4f 35 64 52  |~!E..(......O5dR|
V (38700) Send: 0x3fceb774   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 1e 51 c5  |O\[y]^.3.[f...Q.|
V (38710) Send: 0x3fceb784   ac e5 50 10 16 6c e1 f0  00 00 0b d9 7e           |..P..l......~|
V (38720) Send: 0x3fce2764   d7 f9                                             |..|
D (38730) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (38730) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (38740) MQTT_CLIENT: Connected
D (38740) event: running post MQTT_EVENTS:1 with handler 0x42009be4 and context 0x3fce8cb8 on loop 0x3fce8288
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (38750) event: running post MQTT_EVENTS:1 with handler 0x42099aec and context 0x3fce8d14 on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

D (38760) MQTT_CLIENT: mqtt_enqueue id: 5120, type=8 successful
D (38770) OUTBOX: ENQUEUE msgid=5120, msg_type=8, len=23, size=23
V (38780) Send: 0x3fce27c0   f9 05 ef 89                                       |....|
V (38780) Send: 0x3fceb0e4   7e 21 45 00 00 3f 00 16  00 00 ff 06 4f 1d 64 52  |~!E..?......O.dR|
V (38790) Send: 0x3fceb0f4   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 1e 51 c5  |O\[y]^.3.[f...Q.|
V (38800) Send: 0x3fceb104   ac e5 50 18 16 6c 9e 4f  00 00 82 15 14 00 00 10  |..P..l.O........|
V (38810) Send: 0x3fceb114   2f 74 6f 70 69 63 2f 65  73 70 2d 6d 6f 64 65 6d  |/topic/esp-modem|
V (38820) Send: 0x3fceb124   00 80 22 7e                                       |.."~|
V (38830) Send: 0x3fce27c4   b8 f9                                             |..|
D (38830) MQTT_CLIENT: Sent subscribe topic=/topic/esp-modem, id: 5120, type=8 successful
V (38960) CMUX Received: 0x3fce596c   f9 05 ff 65 7e 21 45 00  00 2d f0 95 40 00 2d 06  |...e~!E..-..@.-.|
V (38960) CMUX Received: 0x3fce597c   f0 af 5b 79 5d 5e 64 52  4f 5c 07 5b c3 33 51 c5  |..[y]^dRO\.[.3Q.|
V (38960) CMUX Received: 0x3fce598c   ac e5 66 9a 1b 35 50 18  fa bf 59 75 00 00 90 03  |..f..5P...Yu....|
V (38970) CMUX Received: 0x3fce599c   14 00 00 35 dc 7e 0c f9                           |...5.~..|
D (38980) CMUX: Payload frame: dlci:01 type:ff payload:50 available:52
V (38990) Send: 0x3fce2740   f9 05 ef 99                                       |....|
V (39000) Send: 0x3fcec234   7e 21 45 00 00 47 00 17  00 00 ff 06 4f 14 64 52  |~!E..G......O.dR|
V (39010) Send: 0x3fcec244   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 35 51 c5  |O\[y]^.3.[f..5Q.|
V (39020) Send: 0x3fcec254   ac ea 50 18 16 67 a1 61  00 00 30 1d 00 10 2f 74  |..P..g.a..0.../t|
V (39020) Send: 0x3fcec264   6f 70 69 63 2f 65 73 70  2d 6d 6f 64 65 6d 48 65  |opic/esp-modemHe|
V (39030) Send: 0x3fcec274   6c 6c 6f 20 6d 6f 64 65  6d ec 75 7e              |llo modem.u~|
V (39040) Send: 0x3fce2744   a4 f9                                             |..|
D (39050) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (39060) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (39060) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (39070) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (39080) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (39080) MQTT_CLIENT: msg_type=9, msg_id=5120
D (39090) MQTT_CLIENT: pending_id=5120, pending_msg_count = 1
D (39090) OUTBOX: DELETED msgid=5120, msg_type=8, remain size=0
D (39100) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (39100) event: running post MQTT_EVENTS:3 with handler 0x42009be4 and context 0x3fce8cb8 on loop 0x3fce8288
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (39110) event: no handlers have been registered for event MQTT_EVENTS:3 posted to loop 0x3fce0814
V (39410) CMUX Received: 0x3fce596c   f9 05 ff 99 7e 21 45 00  00 47 f0 96 40 00 2d 06  |....~!E..G..@.-.|
V (39410) CMUX Received: 0x3fce597c   f0 94 5b 79 5d 5e 64 52  4f 5c 07 5b c3 33 51 c5  |..[y]^dRO\.[.3Q.|
V (39410) CMUX Received: 0x3fce598c   ac ea 66 9a 1b 54 50 18  fa a0 bd 08 00 00 30 1d  |..f..TP.......0.|
V (39420) CMUX Received: 0x3fce599c   00 10 2f 74 6f 70 69 63  2f 65 73 70 2d 6d 6f 64  |../topic/esp-mod|
D (39430) CMUX: Payload frame: dlci:01 type:ff payload:76 available:60
V (39440) CMUX Received: 0x3fce59ac   65 6d 48 65 6c 6c 6f 20  6d 6f 64 65 6d 13 d8 7e  |emHello modem..~|
V (39450) CMUX Received: 0x3fce59bc   b1 f9                                             |..|
D (39460) CMUX: Payload frame: dlci:01 type:ff payload:16 available:18
D (39470) MQTT_CLIENT: mqtt_message_receive: first byte: 0x30
D (39470) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x1d
V (39480) Send: 0x3fce2760   f9 05 ef 5b                                       |...[|
D (39480) MQTT_CLIENT: mqtt_message_receive: total message length: 31 (already read: 2)
V (39490) Send: 0x3fceab7c   7e 21 45 00 00 28 00 18  00 00 ff 06 4f 32 64 52  |~!E..(......O2dR|
V (39500) Send: 0x3fceab8c   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 54 51 c5  |O\[y]^.3.[f..TQ.|
V (39510) Send: 0x3fceab9c   ad 09 50 10 16 48 e1 ba  00 00 c0 b2 7e           |..P..H......~|
V (39520) Send: 0x3fce2764   d7 f9                                             |..|
D (39530) MQTT_CLIENT: mqtt_message_receive: read_len=29
D (39530) MQTT_CLIENT: mqtt_message_receive: transport_read():31 31
D (39540) MQTT_CLIENT: msg_type=3, msg_id=0
D (39540) MQTT_CLIENT: deliver_publish, message_length_read=31, message_length=31
D (39550) MQTT_CLIENT: deliver_publish: msg_topic_len=16
D (39560) MQTT_CLIENT: Get data len= 11, topic len=16, total_data: 11 offset: 0
D (39560) event: running post MQTT_EVENTS:6 with handler 0x42009be4 and context 0x3fce8cb8 on loop 0x3fce8288
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (39570) event: running post MQTT_EVENTS:6 with handler 0x42099aec and context 0x3fce8d88 on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

D (39580) event: running post MQTT_EVENTS:6 with handler 0x42099aec and context 0x3fce8d48 on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

 TOPIC:/topic/esp-modem
 DATA:Hello modem
Data received
V (39600) Send: 0x3fce27c0   f9 05 ef 5f                                       |..._|
V (39610) Send: 0x3fceb0e4   7e 21 45 00 00 2a 00 19  00 00 ff 06 4f 2f 64 52  |~!E..*......O/dR|
V (39610) Send: 0x3fceb0f4   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 54 51 c5  |O\[y]^.3.[f..TQ.|
V (39620) Send: 0x3fceb104   ad 09 50 18 16 48 01 b0  00 00 e0 00 82 c7 7e     |..P..H........~|
V (39630) Send: 0x3fce27c4   d0 f9                                             |..|
V (39900) CMUX Received: 0x3fce596c   f9 05 ff 5b 7e 21 45 00  00 28 f0 97 40 00 2d 06  |...[~!E..(..@.-.|
V (39900) CMUX Received: 0x3fce597c   f0 b2 5b 79 5d 5e 64 52  4f 5c 07 5b c3 33 51 c5  |..[y]^dRO\.[.3Q.|
V (39910) CMUX Received: 0x3fce598c   ad 09 66 9a 1b 56 50 11  fa 9e fd 60 00 00 62 5d  |..f..VP....`..b]|
V (39910) CMUX Received: 0x3fce599c   7e c2 f9                                          |~..|
D (39920) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47
V (39930) Send: 0x3fce2720   f9 05 ef 5b                                       |...[|
V (39940) Send: 0x3fcebccc   7e 21 45 00 00 28 00 1a  00 00 ff 06 4f 30 64 52  |~!E..(......O0dR|
V (39950) Send: 0x3fcebcdc   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 56 51 c5  |O\[y]^.3.[f..VQ.|
V (39960) Send: 0x3fcebcec   ad 0a 50 10 16 47 e1 b8  00 00 d8 50 7e           |..P..G.....P~|
V (39960) Send: 0x3fce2724   d7 f9                                             |..|
V (39970) Send: 0x3fce2740   f9 05 ef 5b                                       |...[|
V (39980) Send: 0x3fceab7c   7e 21 45 00 00 28 00 1b  00 00 ff 06 4f 2f 64 52  |~!E..(......O/dR|
V (39990) Send: 0x3fceab8c   4f 5c 5b 79 5d 5e c3 33  07 5b 66 9a 1b 56 51 c5  |O\[y]^.3.[f..VQ.|
V (40000) Send: 0x3fceab9c   ad 0a 50 11 16 47 e1 b7  00 00 56 6d 7e           |..P..G....Vm~|
V (40010) Send: 0x3fce2744   d7 f9                                             |..|
D (40010) event: deleted loop 0x3fce8288
V (40020) command_lib: get_imsi
V (40020) command_lib: generic_get_string
V (40020) command_lib: generic_get_string
V (40030) Send: 0x3fcf51f0   f9 09 ef 11                                       |....|
V (40040) Send: 0x3fcf53f8   41 54 2b 43 49 4d 49 0d                           |AT+CIMI.|
V (40030) CMUX Received: 0x3fce596c   f9 09 ff 33 0d 0a 39 30  31 32 38 38 30 30 35 36  |...3..9012880056|
V (40050) Send: 0x3fcf51f4   cd f9                                             |..|
V (40060) CMUX Received: 0x3fce597c   38 31 39 32 30 0d 0a 0d  0a 4f 4b 0d 0a 03 f9     |81920....OK....|
D (40070) CMUX: Payload frame: dlci:02 type:ff payload:25 available:27
} (40080) command_lib: Token: {

V (40080) command_lib: Token: {901288005681920}

} (40090) command_lib: Token: {

V (40090) command_lib: Token: {OK}

Modem IMSI number:901288005681920
D (40100) esp_netif_handlers: esp_netif action stopped with netif0x3fce5bac from event_id=0
D (40100) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3fce5edc
V (40110) CMUX Received: 0x3fce596c   f9 05 ff 5b 7e 21 45 00  00 28 00 00 40 00 2d 06  |...[~!E..(..@.-.|
D (40120) esp-netif_lwip-ppp: Phase Terminate
D (40130) esp-netif_lwip-ppp: Phase Network
D (40130) esp-netif_lwip-ppp: Phase Establish
V (40130) CMUX Received: 0x3fce597c   e1 4a 5b 79 5d 5e 64 52  4f 5c 07 5b c3 33 51 c5  |.J[y]^dRO\.[.3Q.|
V (40130) Send: 0x3fce2860   f9 05 ef 3d                                       |...=|
V (40150) CMUX Received: 0x3fce598c   ad 0a 66 9a 1b 57 50 10  fa 9e fd 5f 00 00 92 4c  |..f..WP...._...L|
V (40150) Send: 0x3fce75a8   7e ff 7d 23 c0 21 7d 25  7d 26 7d 20 7d 30 55 73  |~.}#.!}%}&} }0Us|
V (40170) Send: 0x3fce75b8   65 72 20 72 65 71 75 65  73 74 ea 7d 3b 7e        |er request.};~|
V (40170) CMUX Received: 0x3fce599c   7e c2 f9                                          |~..|
V (40180) Send: 0x3fce2864   7b f9                                             |{.|
D (40190) CMUX: Payload frame: dlci:01 type:ff payload:45 available:47
D (40200) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (40210) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
V (40210) CMUX Received: 0x3fce596c   f9 05 ff 23 7e ff 7d 23  c0 21 7d 26 7d 26 7d 20  |...#~.}#.!}&}&} |
V (40210) esp_netif_objects: esp_netif_next_unsafe 0x0
V (40230) CMUX Received: 0x3fce597c   7d 24 f5 6e 7e 98 f9                              |}$.n~..|
V (40230) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
D (40240) CMUX: Payload frame: dlci:01 type:ff payload:17 available:19
V (40240) esp_netif_objects: esp_netif_next_unsafe 0x3fce5bac
D (40260) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (40260) esp-netif_lwip-ppp: Phase Disconnect
D (40270) esp-netif_lwip-ppp: Phase Dead
I (40270) esp-netif_lwip-ppp: User interrupt
D (40280) event: running post NETIF_PPP_STATUS:5 with handler 0x42010ff8 and context 0x3fce7270 on loop 0x3fce0814
0x42010ff8: esp_modem::Netif::on_ppp_changed(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/esp_modem/src/esp_modem_netif.cpp:22

I (40290) esp_modem_netif: PPP state changed event 5
V (41140) CMUX Received: 0x3fce596c   f9 01 ef 0b e3 07 07 87  01 79 f9 f9 05 ff 1d 0d  |.........y......|
V (41140) CMUX Received: 0x3fce597c   0a 4e 4f 20 43 41 52 52  49 45 52 0d 0a 56 f9 f9  |.NO CARRIER..V..|
V (41150) CMUX Received: 0x3fce598c   01 ef 0b e3 07 07 8d 01  79 f9                    |........y.|
D (41160) CMUX: Payload frame: dlci:00 type:ef payload:5 available:38
D (41170) CMUX: Payload frame: dlci:01 type:ff payload:14 available:27
D (41170) esp-modem: debug_data: 0x3fce597b   0d 0a 4e 4f 20 43 41 52  52 49 45 52 0d 0a        |..NO CARRIER..|
D (41180) CMUX: Payload frame: dlci:00 type:ef payload:5 available:7
Modem has correctly entered mode CMUX_MANUAL_COMMAND
V (41690) command_lib: hang_up
V (41690) command_lib: generic_command_common
V (41690) command_lib: generic_command
D (41690) command_lib: generic_command command ATH

V (41690) Send: 0x3fcf5120   f9 09 ef 09                                       |....|
V (41700) Send: 0x3fcf53f8   41 54 48 0d                                       |ATH.|
V (41690) CMUX Received: 0x3fce596c   f9 09 ff 0d 0d 0a 4f 4b  0d 0a cd f9              |......OK....|
D (41720) CMUX: Payload frame: dlci:02 type:ff payload:6 available:8
D (41720) command_lib: Response: 
OK

V (41720) Send: 0x3fcf5124   df f9                                             |..|
hang_up OK
V (42230) command_lib: get_imei
V (42230) command_lib: generic_get_string
V (42230) command_lib: generic_get_string
V (42230) Send: 0x3fcf51f0   f9 09 ef 11                                       |....|
V (42230) Send: 0x3fcf53f8   41 54 2b 43 47 53 4e 0d                           |AT+CGSN.|
V (42230) CMUX Received: 0x3fce596c   f9 09 ff 33 0d 0a 38 36  35 34 35 36 30 35 37 30  |...3..8654560570|
V (42250) Send: 0x3fcf51f4   cd f9                                             |..|
V (42260) CMUX Received: 0x3fce597c   31 37 30 34 36 0d 0a 0d  0a 4f 4b 0d 0a 03 f9     |17046....OK....|
D (42270) CMUX: Payload frame: dlci:02 type:ff payload:25 available:27
} (42270) command_lib: Token: {

V (42280) command_lib: Token: {865456057017046}

} (42280) command_lib: Token: {

V (42290) command_lib: Token: {OK}

Modem IMEI number:865456057017046
V (42290) command_lib: set_echo
V (42300) command_lib: generic_command_common
V (42300) command_lib: generic_command
D (42300) command_lib: generic_command command ATE0

V (42310) Send: 0x3fcf5050   f9 09 ef 0b                                       |....|
V (42320) Send: 0x3fcf5328   41 54 45 30 0d                                    |ATE0.|
V (42310) CMUX Received: 0x3fce596c   f9 09 ff 0d 0d 0a 4f 4b  0d 0a cd f9              |......OK....|
V (42330) Send: 0x3fcf5054   3c f9                                             |<.|
D (42340) CMUX: Payload frame: dlci:02 type:ff payload:6 available:8
D (42350) command_lib: Response: 
OK

V (42350) command_lib: set_pdp_context
V (42360) command_lib: generic_command_common
V (42360) command_lib: generic_command
D (42360) command_lib: generic_command command AT+CGDCONT=1,"IP","nbiot.global-m2m.net"

V (42370) Send: 0x3fcf4fd0   f9 09 ef 53                                       |...S|
V (42380) Send: 0x3fce848c   41 54 2b 43 47 44 43 4f  4e 54 3d 31 2c 22 49 50  |AT+CGDCONT=1,"IP|
V (42380) CMUX Received: 0x3fce596c   f9 09 ff 0d 0d 0a 4f 4b  0d 0a cd f9              |......OK....|
D (42400) CMUX: Payload frame: dlci:02 type:ff payload:6 available:8
D (42400) command_lib: Response: 
OK

V (42400) Send: 0x3fce849c   22 2c 22 6e 62 69 6f 74  2e 67 6c 6f 62 61 6c 2d  |","nbiot.global-|
V (42420) Send: 0x3fce84ac   6d 32 6d 2e 6e 65 74 22  0d                       |m2m.net".|
V (42420) Send: 0x3fcf4fd4   5e f9                                             |^.|
V (42430) command_lib: set_data_mode
V (42440) command_lib: generic_command
D (42440) command_lib: generic_command command ATD*99##

V (42450) Send: 0x3fcf5080   f9 09 ef 13                                       |....|
V (42450) Send: 0x3fcf5338   41 54 44 2a 39 39 23 23  0d                       |ATD*99##.|
V (42450) CMUX Received: 0x3fce596c   f9 01 ef 0b e3 07 0b 8d  01 79 f9 f9 09 ff 2b 0d  |.........y....+.|
V (42470) Send: 0x3fcf5084   2e f9                                             |..|
V (42480) CMUX Received: 0x3fce597c   0a 43 4f 4e 4e 45 43 54  20 31 35 30 30 30 30 30  |.CONNECT 1500000|
V (42490) CMUX Received: 0x3fce598c   30 30 0d 0a 11 f9                                 |00....|
D (42500) CMUX: Payload frame: dlci:00 type:ef payload:5 available:34
D (42500) CMUX: Payload frame: dlci:02 type:ff payload:21 available:23
D (42510) command_lib: Response: 
CONNECT 150000000

D (42520) esp_netif_handlers: esp_netif action has started with netif0x3fce5bac from event_id=0
D (42520) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fce5edc
D (42530) esp-netif_lwip-ppp: Phase Start
D (42540) esp-netif_lwip-ppp: Phase Establish
D (42540) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (42550) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
V (42550) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
D (42560) esp_netif_lwip: call api in lwip: ret=0x0, give sem
Modem has correctly entered mode CMUX_MANUAL_DATA
V (42570) command_lib: get_operator_name
V (42570) command_lib: generic_get_string
V (42580) Send: 0x3fcf51a0   f9 05 ef 13                                       |....|
V (42590) Send: 0x3fcf53d4   41 54 2b 43 4f 50 53 3f  0d                       |AT+COPS?.|
V (42580) CMUX Received: 0x3fce596c   f9 05 ff 49 0d 0a 2b 43  4f 50 53 3a 20 30 2c 30  |...I..+COPS: 0,0|
V (42600) Send: 0x3fcf51a4   a9 f9                                             |..|
V (42610) CMUX Received: 0x3fce597c   2c 22 76 6f 64 61 66 6f  6e 65 2e 64 65 22 2c 37  |,"vodafone.de",7|
V (42620) CMUX Received: 0x3fce598c   0d 0a 0d 0a 4f 4b 0d 0a  3d f9                    |....OK..=.|
D (42630) CMUX: Payload frame: dlci:01 type:ff payload:36 available:38
} (42640) command_lib: Token: {

V (42640) command_lib: Token: {+COPS: 0,0,"vodafone.de",7}

} (42640) command_lib: Token: {

V (42650) command_lib: Token: {OK}

Operator name:vodafone.de
V (48540) Send: 0x3fce28c0   f9 09 ef 5b                                       |...[|
V (48540) Send: 0x3fce7a78   7e ff 7d 23 c0 21 7d 21  7d 27 7d 20 7d 34 7d 22  |~.}#.!}!}'} }4}"|
V (48540) Send: 0x3fce7a88   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 d3 62  |}&} } } } }%}&.b|
V (48550) CMUX Received: 0x3fce596c   f9 09 ff 6b 7e ff 7d 23  c0 21 7d 21 7d 29 7d 20  |...k~.}#.!}!})} |
V (48550) Send: 0x3fce7a98   ff 34 7d 27 7d 22 7d 28  7d 22 c4 8a 7e           |.4}'}"}(}"..~|
V (48570) CMUX Received: 0x3fce597c   7d 39 7d 22 7d 26 7d 20  7d 20 7d 20 7d 20 7d 23  |}9}"}&} } } } }#|
V (48570) Send: 0x3fce28c4   50 f9                                             |P.|
V (48580) CMUX Received: 0x3fce598c   7d 25 c2 23 7d 25 7d 25  7d 26 44 46 d4 b4 7d 27  |}%.#}%}%}&DF..}'|
V (48600) CMUX Received: 0x3fce599c   7d 22 7d 28 7d 22 93 55  7e 61 f9 f9 09 ff 5b 7e  |}"}(}".U~a....[~|
D (48610) CMUX: Payload frame: dlci:02 type:ff payload:53 available:60
V (48610) Send: 0x3fce2820   f9 09 ef 33                                       |...3|
D (48620) CMUX: Payload frame: dlci:02 type:ff payload:45 available:1
V (48620) Send: 0x3fce8b80   7e ff 7d 23 c0 21 7d 24  7d 29 7d 20 7d 29 7d 23  |~.}#.!}$})} })}#|
V (48630) CMUX Received: 0x3fce59ac   ff 7d 23 c0 21 7d 22 7d  27 7d 20 7d 34 7d 22 7d  |.}#.!}"}'} }4}"}|
V (48640) Send: 0x3fce8b90   7d 25 c2 23 7d 25 fb cc  7e                       |}%.#}%..~|
V (48650) CMUX Received: 0x3fce59bc   26 7d 20 7d 20 7d 20 7d  20 7d 25 7d 26 d3 62 ff  |&} } } } }%}&.b.|
V (48650) Send: 0x3fce2824   16 f9                                             |..|
V (48670) CMUX Received: 0x3fce59cc   34 7d 27 7d 22 7d 28 7d  22 2f e3 7e 45 f9        |4}'}"}(}"/.~E.|
D (48680) CMUX: Payload frame: dlci:02 type:ff payload:44 available:46
V (48690) CMUX Received: 0x3fce596c   f9 09 ff 5b 7e ff 7d 23  c0 21 7d 21 7d 2a 7d 20  |...[~.}#.!}!}*} |
V (48700) CMUX Received: 0x3fce597c   7d 34 7d 22 7d 26 7d 20  7d 20 7d 20 7d 20 7d 25  |}4}"}&} } } } }%|
V (48710) CMUX Received: 0x3fce598c   7d 26 44 46 d4 b4 7d 27  7d 22 7d 28 7d 22 f6 dc  |}&DF..}'}"}(}"..|
V (48720) CMUX Received: 0x3fce599c   7e 45 f9                                          |~E.|
D (48720) CMUX: Payload frame: dlci:02 type:ff payload:45 available:47
V (48730) Send: 0x3fce2820   f9 09 ef 5d                                       |...]|
V (48740) Send: 0x3fce8b80   7e ff 7d 23 c0 21 7d 22  7d 2a 7d 20 7d 34 7d 22  |~.}#.!}"}*} }4}"|
V (48740) CMUX Received: 0x3fce596c   f9 09 ff 2b 7e ff 7d 23  c0 21 7d 2b 7d 2b 7d 20  |...+~.}#.!}+}+} |
V (48750) Send: 0x3fce8b90   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 44 46  |}&} } } } }%}&DF|
V (48760) CMUX Received: 0x3fce597c   7d 28 44 46 d4 b4 56 6c  7e 11 f9                 |}(DF..Vl~..|
V (48770) Send: 0x3fce8ba0   d4 b4 7d 27 7d 22 7d 28  7d 22 7d 3d b5 7e        |..}'}"}(}"}=.~|
D (48780) CMUX: Payload frame: dlci:02 type:ff payload:21 available:23
V (48780) Send: 0x3fce2824   b4 f9                                             |..|
D (48800) esp-netif_lwip-ppp: Phase Authenticate
D (48800) esp-netif_lwip-ppp: Phase Network
V (48810) Send: 0x3fce2740   f9 09 ef 49                                       |...I|
V (48810) Send: 0x3fce9768   7e ff 03 80 21 01 0a 00  1c 02 06 00 2d 0f 01 03  |~...!.......-...|
V (48810) CMUX Received: 0x3fce596c   f9 09 ff 15 7e 80 21 01  06 00 04 be 15 7e df f9  |....~.!......~..|
V (48820) Send: 0x3fce9778   06 00 00 00 00 81 06 00  00 00 00 83 06 00 00 00  |................|
V (48840) CMUX Received: 0x3fce597c   f9 09 ff 21 7e 80 21 04  0a 00 0a 02 06 00 2d 0f  |...!~.!.......-.|
V (48840) Send: 0x3fce9788   00 ef 61 7e                                       |..a~|
V (48860) Send: 0x3fce2744   af f9                                             |..|
V (48860) CMUX Received: 0x3fce598c   01 35 99 7e fc f9                                 |.5.~..|
D (48880) CMUX: Payload frame: dlci:02 type:ff payload:10 available:34
V (48880) Send: 0x3fce2820   f9 09 ef 25                                       |...%|
D (48890) CMUX: Payload frame: dlci:02 type:ff payload:16 available:18
V (48890) Send: 0x3fce8b80   7e ff 03 80 21 03 06 00  0a 03 06 00 00 00 00 bf  |~...!...........|
V (48900) CMUX Received: 0x3fce596c   f9 09 ff 15 7e 80 21 01  07 00 04 62 4f 7e df f9  |....~.!....bO~..|
V (48900) Send: 0x3fce8b90   99 7e                                             |.~|
D (48920) CMUX: Payload frame: dlci:02 type:ff payload:10 available:12
V (48920) Send: 0x3fce2824   ee f9                                             |..|
V (48940) Send: 0x3fce2830   f9 09 ef 3d                                       |...=|
V (48940) Send: 0x3fce858c   7e ff 03 80 21 01 0b 00  16 03 06 00 00 00 00 81  |~...!...........|
V (48940) CMUX Received: 0x3fce596c   f9 09 ff 39 7e 80 21 03  0b 00 16 03 06 64 52 4f  |...9~.!......dRO|
V (48950) Send: 0x3fce859c   06 00 00 00 00 83 06 00  00 00 00 c7 06 7e        |.............~|
V (48970) CMUX Received: 0x3fce597c   5c 81 06 d9 0e a0 82 83  06 d9 0e a4 23 0f f7 7e  |\...........#..~|
V (48970) Send: 0x3fce2834   fc f9                                             |..|
V (48990) Send: 0x3fce2820   f9 09 ef 19                                       |....|
V (48990) CMUX Received: 0x3fce598c   ee f9                                             |..|
V (49000) Send: 0x3fce9d5c   7e ff 03 80 21 02 07 00  04 14 44 7e              |~...!.....D~|
D (49010) CMUX: Payload frame: dlci:02 type:ff payload:28 available:30
V (49010) Send: 0x3fce2824   c3 f9                                             |..|
V (49030) Send: 0x3fce2830   f9 09 ef 3d                                       |...=|
V (49040) CMUX Received: 0x3fce596c   f9 09 ff 39 7e 80 21 02  0c 00 16 03 06 64 52 4f  |...9~.!......dRO|
V (49040) Send: 0x3fce8b80   7e ff 03 80 21 01 0c 00  16 03 06 64 52 4f 5c 81  |~...!......dRO\.|
V (49050) CMUX Received: 0x3fce597c   5c 81 06 d9 0e a0 82 83  06 d9 0e a4 23 56 da 7e  |\...........#V.~|
V (49050) Send: 0x3fce8b90   06 d9 0e a0 82 83 06 d9  0e a4 23 c0 b9 7e        |..........#..~|
V (49070) CMUX Received: 0x3fce598c   ee f9                                             |..|
V (49070) Send: 0x3fce2834   fc f9                                             |..|
D (49090) CMUX: Payload frame: dlci:02 type:ff payload:28 available:30
I (49100) esp-netif_lwip-ppp: Connected
I (49100) esp-netif_lwip-ppp: Name Server1: 217.14.160.130
I (49110) esp-netif_lwip-ppp: Name Server2: 217.14.164.35
D (49110) event: running post IP_EVENT:6 with handler 0x420220f4 and context 0x3fce72b4 on loop 0x3fce0814
0x420220f4: esp_netif_action_connected at /home/franz/esp-idf-v4.4.2/components/esp_netif/esp_netif_handlers.c:44

D (49120) esp-netif_lwip-ppp: Phase Running
D (49120) esp_netif_handlers: esp_netif action connected with netif0x3fce5bac from event_id=6
D (49130) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42022e80
0x42022e80: esp_netif_up_api at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:1256

D (49140) esp_netif_lwip: esp_netif_up_api esp_netif:0x3fce5bac
D (49150) esp_netif_lwip: check: local, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (49150) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
V (49160) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
D (49170) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (49170) event: running post IP_EVENT:6 with handler 0x42099aec and context 0x3fce7318 on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

I (49180) cmux_example: IP          : 100.82.79.92
I (49190) cmux_example: Netmask     : 255.255.255.255
I (49190) cmux_example: Gateway     : 10.64.64.64
Got IP address
D (49200) MQTT_CLIENT: MQTT client_id=ESP32_2a0AC4
D (49200) event: created event loop 0x3fce8184
D (49210) MQTT_CLIENT: Core selection disabled
D (49210) event: running post MQTT_EVENTS:7 with handler 0x42009be4 and context 0x3fce82bc on loop 0x3fce8184
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (49220) event: no handlers have been registered for event MQTT_EVENTS:7 posted to loop 0x3fce0814
D (49220) esp-tls: host:test.mosquitto.org: strlen 18
D (49240) esp-tls: [sock=54] Resolved IPv4 address: 91.121.93.94
D (49240) esp-tls: [sock=54] Connecting to server. HOST: test.mosquitto.org, Port: 1883
V (49250) Send: 0x3fce27b0   f9 09 ef 63                                       |...c|
V (49260) Send: 0x3fceab7c   7e 21 45 00 00 2c 00 1c  00 00 ff 06 4f 2a 64 52  |~!E..,......O*dR|
V (49270) Send: 0x3fceab8c   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 a8 00 00  |O\[y]^.4.[%.....|
V (49280) Send: 0x3fceab9c   00 00 60 02 16 70 41 81  00 00 02 04 05 a0 3c 04  |..`..pA.......<.|
V (49280) Send: 0x3fceabac   7e                                                |~|
V (49290) Send: 0x3fce27b4   7a f9                                             |z.|
V (49830) CMUX Received: 0x3fce596c   f9 09 ff 63 7e 21 45 00  00 2c 00 00 40 00 2d 06  |...c~!E..,..@.-.|
V (49830) CMUX Received: 0x3fce597c   e1 46 5b 79 5d 5e 64 52  4f 5c 07 5b c3 34 49 a3  |.F[y]^dRO\.[.4I.|
V (49830) CMUX Received: 0x3fce598c   4c 2e 25 8b e3 a9 60 12  fa f0 c7 bd 00 00 02 04  |L.%...`.........|
V (49840) CMUX Received: 0x3fce599c   05 00 f0 3b 7e 6f f9                              |...;~o.|
D (49850) CMUX: Payload frame: dlci:02 type:ff payload:49 available:51
V (49860) Send: 0x3fce2720   f9 09 ef 5b                                       |...[|
V (49870) Send: 0x3fceb764   7e 21 45 00 00 28 00 1d  00 00 ff 06 4f 2d 64 52  |~!E..(......O-dR|
V (49880) Send: 0x3fceb774   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 a9 49 a3  |O\[y]^.4.[%...I.|
V (49890) Send: 0x3fceb784   4c 2f 50 10 16 70 c3 47  00 00 bb eb 7e           |L/P..p.G....~|
V (49890) Send: 0x3fce2724   50 f9                                             |P.|
D (49900) MQTT_CLIENT: Transport connected to mqtt://test.mosquitto.org:1883
D (49910) MQTT_CLIENT: Sending MQTT CONNECT message, type: 1, id: 0000
V (49920) Send: 0x3fce27c0   f9 09 ef 8f                                       |....|
V (49920) Send: 0x3fceb0e4   7e 21 45 00 00 42 00 1e  00 00 ff 06 4f 12 64 52  |~!E..B......O.dR|
V (49930) Send: 0x3fceb0f4   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 a9 49 a3  |O\[y]^.4.[%...I.|
V (49940) Send: 0x3fceb104   4c 2f 50 18 16 70 9f 21  00 00 10 18 00 04 4d 51  |L/P..p.!......MQ|
V (49950) Send: 0x3fceb114   54 54 04 02 00 78 00 0c  45 53 50 33 32 5f 32 61  |TT...x..ESP32_2a|
V (49960) Send: 0x3fceb124   30 41 43 34 82 a6 7e                              |0AC4..~|
V (49970) Send: 0x3fce27c4   db f9                                             |..|
V (50090) CMUX Received: 0x3fce596c   f9 09 ff 5b 7e 21 45 00  00 28 dc c9 40 00 2d 06  |...[~!E..(..@.-.|
V (50090) CMUX Received: 0x3fce597c   04 81 5b 79 5d 5e 64 52  4f 5c 07 5b c3 34 49 a3  |..[y]^dRO\.[.4I.|
V (50100) CMUX Received: 0x3fce598c   4c 2f 25 8b e3 c3 50 10  fa d6 de c6 00 00 41 32  |L/%...P.......A2|
V (50110) CMUX Received: 0x3fce599c   7e 45 f9                                          |~E.|
D (50110) CMUX: Payload frame: dlci:02 type:ff payload:45 available:47
V (50120) CMUX Received: 0x3fce596c   f9 09 ff 63 7e 21 45 00  00 2c dc ca 40 00 2d 06  |...c~!E..,..@.-.|
V (50130) CMUX Received: 0x3fce597c   04 7c 5b 79 5d 5e 64 52  4f 5c 07 5b c3 34 49 a3  |.|[y]^dRO\.[.4I.|
V (50140) CMUX Received: 0x3fce598c   4c 2f 25 8b e3 c3 50 18  fa d6 be b8 00 00 20 02  |L/%...P....... .|
V (50150) CMUX Received: 0x3fce599c   00 00 9c 21 7e 6f f9                              |...!~o.|
D (50160) CMUX: Payload frame: dlci:02 type:ff payload:49 available:51
D (50170) MQTT_CLIENT: mqtt_message_receive: first byte: 0x20
D (50170) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (50180) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (50190) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (50190) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (50200) MQTT_CLIENT: Connected
D (50200) event: running post MQTT_EVENTS:1 with handler 0x42009be4 and context 0x3fce82bc on loop 0x3fce8184
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (50210) event: running post MQTT_EVENTS:1 with handler 0x42099aec and context 0x3fce8318 on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

D (50220) MQTT_CLIENT: mqtt_enqueue id: 27685, type=8 successful
D (50230) OUTBOX: ENQUEUE msgid=27685, msg_type=8, len=23, size=23
V (50230) Send: 0x3fce27c0   f9 09 ef 89                                       |....|
V (50240) Send: 0x3fceb0e4   7e 21 45 00 00 3f 00 1f  00 00 ff 06 4f 14 64 52  |~!E..?......O.dR|
V (50250) Send: 0x3fceb0f4   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 c3 49 a3  |O\[y]^.4.[%...I.|
V (50260) Send: 0x3fceb104   4c 33 50 18 16 6c 27 67  00 00 82 15 6c 25 00 10  |L3P..l'g....l%..|
V (50270) Send: 0x3fceb114   2f 74 6f 70 69 63 2f 65  73 70 2d 6d 6f 64 65 6d  |/topic/esp-modem|
V (50280) Send: 0x3fceb124   00 20 52 7e                                       |. R~|
V (50280) Send: 0x3fce27c4   3f f9                                             |?.|
D (50290) MQTT_CLIENT: Sent subscribe topic=/topic/esp-modem, id: 27685, type=8 successful
V (50530) CMUX Received: 0x3fce596c   f9 09 ff 65 7e 21 45 00  00 2d dc cb 40 00 2d 06  |...e~!E..-..@.-.|
V (50530) CMUX Received: 0x3fce597c   04 7a 5b 79 5d 5e 64 52  4f 5c 07 5b c3 34 49 a3  |.z[y]^dRO\.[.4I.|
V (50540) CMUX Received: 0x3fce598c   4c 33 25 8b e3 da 50 18  fa bf e2 8c 00 00 90 03  |L3%...P.........|
V (50550) CMUX Received: 0x3fce599c   6c 25 00 d0 fe 7e 8b f9                           |l%...~..|
D (50560) CMUX: Payload frame: dlci:02 type:ff payload:50 available:52
V (50570) Send: 0x3fce2740   f9 09 ef 99                                       |....|
V (50580) Send: 0x3fcec234   7e 21 45 00 00 47 00 20  00 00 ff 06 4f 0b 64 52  |~!E..G. ....O.dR|
V (50580) Send: 0x3fcec244   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 da 49 a3  |O\[y]^.4.[%...I.|
V (50590) Send: 0x3fcec254   4c 38 50 18 16 67 82 9e  00 00 30 1d 00 10 2f 74  |L8P..g....0.../t|
V (50600) Send: 0x3fcec264   6f 70 69 63 2f 65 73 70  2d 6d 6f 64 65 6d 48 65  |opic/esp-modemHe|
V (50610) Send: 0x3fcec274   6c 6c 6f 20 6d 6f 64 65  6d 19 76 7e              |llo modem.v~|
V (50620) Send: 0x3fce2744   23 f9                                             |#.|
D (50630) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (50630) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (50640) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (50650) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (50650) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (50660) MQTT_CLIENT: msg_type=9, msg_id=27685
D (50660) MQTT_CLIENT: pending_id=27685, pending_msg_count = 1
D (50670) OUTBOX: DELETED msgid=27685, msg_type=8, remain size=0
D (50680) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (50680) event: running post MQTT_EVENTS:3 with handler 0x42009be4 and context 0x3fce82bc on loop 0x3fce8184
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (50690) event: no handlers have been registered for event MQTT_EVENTS:3 posted to loop 0x3fce0814
V (50830) CMUX Received: 0x3fce596c   f9 09 ff 99 7e 21 45 00  00 47 dc cc 40 00 2d 06  |....~!E..G..@.-.|
V (50830) CMUX Received: 0x3fce597c   04 5f 5b 79 5d 5e 64 52  4f 5c 07 5b c3 34 49 a3  |._[y]^dRO\.[.4I.|
V (50840) CMUX Received: 0x3fce598c   4c 38 25 8b e3 f9 50 18  fa a0 9e 45 00 00 30 1d  |L8%...P....E..0.|
V (50850) CMUX Received: 0x3fce599c   00 10 2f 74 6f 70 69 63  2f 65 73 70 2d 6d 6f 64  |../topic/esp-mod|
D (50860) CMUX: Payload frame: dlci:02 type:ff payload:76 available:60
V (50870) CMUX Received: 0x3fce59ac   65 6d 48 65 6c 6c 6f 20  6d 6f 64 65 6d d9 98 7e  |emHello modem..~|
V (50880) CMUX Received: 0x3fce59bc   36 f9                                             |6.|
D (50890) CMUX: Payload frame: dlci:02 type:ff payload:16 available:18
D (50890) MQTT_CLIENT: mqtt_message_receive: first byte: 0x30
D (50900) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x1d
D (50900) MQTT_CLIENT: mqtt_message_receive: total message length: 31 (already read: 2)
D (50910) MQTT_CLIENT: mqtt_message_receive: read_len=29
D (50920) MQTT_CLIENT: mqtt_message_receive: transport_read():31 31
D (50920) MQTT_CLIENT: msg_type=3, msg_id=0
D (50930) MQTT_CLIENT: deliver_publish, message_length_read=31, message_length=31
D (50940) MQTT_CLIENT: deliver_publish: msg_topic_len=16
D (50940) MQTT_CLIENT: Get data len= 11, topic len=16, total_data: 11 offset: 0
D (50950) event: running post MQTT_EVENTS:6 with handler 0x42009be4 and context 0x3fce82bc on loop 0x3fce8184
0x42009be4: MqttClientHandle::mqtt_event_handler(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/simple_cmux_client/simple_mqtt_client.cpp:44

D (50960) event: running post MQTT_EVENTS:6 with handler 0x42099aec and context 0x3fce8d7c on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

D (50970) event: running post MQTT_EVENTS:6 with handler 0x42099aec and context 0x3fce834c on loop 0x3fce0814
0x42099aec: idf::event::ESPEventReg::event_handler_hook(void*, char const*, int, void*) at /home/franz/esp-idf-v4.4.2/examples/cxx/experimental/experimental_cpp_component/esp_event_cxx.cpp:56

 TOPIC:/topic/esp-modem
 DATA:Hello modem
Data received
V (50980) Send: 0x3fce27c0   f9 09 ef 5f                                       |..._|
V (50990) Send: 0x3fceb0e4   7e 21 45 00 00 2a 00 21  00 00 ff 06 4f 27 64 52  |~!E..*.!....O'dR|
V (51000) Send: 0x3fceb0f4   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 f9 49 a3  |O\[y]^.4.[%...I.|
V (51010) Send: 0x3fceb104   4c 57 50 18 16 48 e2 ec  00 00 e0 00 a0 e3 7e     |LWP..H........~|
V (51020) Send: 0x3fce27c4   57 f9                                             |W.|
V (51210) CMUX Received: 0x3fce596c   f9 09 ff 5d 7e 21 45 00  00 28 dc cd 40 00 2d 06  |...]~!E..(..@.-.|
V (51210) CMUX Received: 0x3fce597c   04 7d 5d 5b 79 5d 5e 64  52 4f 5c 07 5b c3 34 49  |.}][y]^dRO\.[.4I|
V (51220) CMUX Received: 0x3fce598c   a3 4c 57 25 8b e3 fb 50  11 fa 9e de 9d 00 00 b1  |.LW%...P........|
V (51230) CMUX Received: 0x3fce599c   97 7e a1 f9                                       |.~..|
D (51240) CMUX: Payload frame: dlci:02 type:ff payload:46 available:48
V (51250) Send: 0x3fce2720   f9 09 ef 5b                                       |...[|
V (51250) Send: 0x3fcebccc   7e 21 45 00 00 28 00 22  00 00 ff 06 4f 28 64 52  |~!E..(."....O(dR|
V (51260) Send: 0x3fcebcdc   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 fb 49 a3  |O\[y]^.4.[%...I.|
V (51270) Send: 0x3fcebcec   4c 58 50 10 16 47 c2 f5  00 00 00 2a 7e           |LXP..G.....*~|
V (51280) Send: 0x3fce2724   50 f9                                             |P.|
V (51290) Send: 0x3fce2740   f9 09 ef 5b                                       |...[|
V (51290) Send: 0x3fceab7c   7e 21 45 00 00 28 00 23  00 00 ff 06 4f 27 64 52  |~!E..(.#....O'dR|
V (51300) Send: 0x3fceab8c   4f 5c 5b 79 5d 5e c3 34  07 5b 25 8b e3 fb 49 a3  |O\[y]^.4.[%...I.|
V (51310) Send: 0x3fceab9c   4c 58 50 11 16 47 c2 f4  00 00 7a ec 7e           |LXP..G....z.~|
V (51320) Send: 0x3fce2744   50 f9                                             |P.|
D (51330) event: deleted loop 0x3fce8184
V (51330) command_lib: get_imsi
V (51340) command_lib: generic_get_string
V (51340) command_lib: generic_get_string
V (51340) Send: 0x3fcf51f0   f9 05 ef 11                                       |....|
V (51350) CMUX Received: 0x3fce596c   f9 05 ff 33 0d 0a 39 30  31 32 38 38 30 30 35 36  |...3..9012880056|
V (51360) Send: 0x3fcf53f8   41 54 2b 43 49 4d 49 0d                           |AT+CIMI.|
V (51370) Send: 0x3fcf51f4   4a f9                                             |J.|
V (51370) CMUX Received: 0x3fce597c   38 31 39 32 30 0d 0a 0d  0a 4f 4b 0d 0a 84 f9     |81920....OK....|
D (51390) CMUX: Payload frame: dlci:01 type:ff payload:25 available:27
} (51390) command_lib: Token: {

V (51400) command_lib: Token: {901288005681920}

} (51400) command_lib: Token: {

V (51400) command_lib: Token: {OK}

Modem IMSI number:901288005681920
D (51410) esp_netif_handlers: esp_netif action stopped with netif0x3fce5bac from event_id=0
D (51420) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3fce5edc
D (51430) esp-netif_lwip-ppp: Phase Terminate
D (51430) esp-netif_lwip-ppp: Phase Network
D (51440) esp-netif_lwip-ppp: Phase Establish
V (51440) Send: 0x3fce2860   f9 09 ef 3b                                       |...;|
V (51450) CMUX Received: 0x3fce596c   f9 09 ff 25 7e ff 7d 23  c0 21 7d 26 7d 28 7d 20  |...%~.}#.!}&}(} |
V (51450) Send: 0x3fce74a4   7e ff 7d 23 c0 21 7d 25  7d 28 7d 20 7d 30 55 73  |~.}#.!}%}(} }0Us|
V (51470) CMUX Received: 0x3fce597c   7d 24 ee 7d 5e 7e fb f9                           |}$.}^~..|
V (51470) Send: 0x3fce74b4   65 72 20 72 65 71 75 65  73 74 75 f2 7e           |er requestu.~|
D (51480) CMUX: Payload frame: dlci:02 type:ff payload:18 available:20
V (51480) Send: 0x3fce2864   18 f9                                             |..|
D (51500) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (51500) esp-netif_lwip-ppp: Phase Disconnect
D (51510) esp-netif_lwip-ppp: Phase Dead
I (51510) esp-netif_lwip-ppp: User interrupt
D (51520) event: running post NETIF_PPP_STATUS:5 with handler 0x42010ff8 and context 0x3fce7270 on loop 0x3fce0814
0x42010ff8: esp_modem::Netif::on_ppp_changed(void*, char const*, int, void*) at /home/franz/git/krone2/pppos_client_sample/simple_cmux_client/components/esp_modem/src/esp_modem_netif.cpp:22

D (51520) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
I (51530) esp_modem_netif: PPP state changed event 5
V (51530) esp_netif_objects: esp_netif_next_unsafe 0x0
V (51540) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
V (51550) esp_netif_objects: esp_netif_next_unsafe 0x3fce5bac
D (51560) esp_netif_lwip: call api in lwip: ret=0x0, give sem
V (52450) CMUX Received: 0x3fce596c   f9 01 ef 0b e3 07 0b 87  01 79 f9 f9 09 ff 1d 0d  |.........y......|
V (52450) CMUX Received: 0x3fce597c   0a 4e 4f 20 43 41 52 52  49 45 52 0d 0a d1 f9 f9  |.NO CARRIER.....|
V (52460) CMUX Received: 0x3fce598c   01 ef 0b e3 07 0b 8d 01  79 f9                    |........y.|
D (52470) CMUX: Payload frame: dlci:00 type:ef payload:5 available:38
D (52470) CMUX: Payload frame: dlci:02 type:ff payload:14 available:27
D (52480) esp-modem: debug_data: 0x3fce597b   0d 0a 4e 4f 20 43 41 52  52 49 45 52 0d 0a        |..NO CARRIER..|
D (52490) CMUX: Payload frame: dlci:00 type:ef payload:5 available:7
Modem has correctly entered mode CMUX_MANUAL_COMMAND
V (53000) command_lib: hang_up
V (53000) command_lib: generic_command_common
V (53000) command_lib: generic_command
D (53000) command_lib: generic_command command ATH

V (53000) Send: 0x3fcf5120   f9 05 ef 09                                       |....|
V (53010) Send: 0x3fcf53f8   41 54 48 0d                                       |ATH.|
V (53000) CMUX Received: 0x3fce596c   f9 05 ff 0d 0d 0a 4f 4b  0d 0a 4a f9              |......OK..J.|
D (53030) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8
D (53030) command_lib: Response: 
OK

V (53030) Send: 0x3fcf5124   58 f9                                             |X.|
hang_up OK
V (53540) command_lib: get_imei
V (53540) command_lib: generic_get_string
V (53540) command_lib: generic_get_string
V (53540) Send: 0x3fcf51f0   f9 05 ef 11                                       |....|
V (53540) Send: 0x3fcf53f8   41 54 2b 43 47 53 4e 0d                           |AT+CGSN.|
V (53540) CMUX Received: 0x3fce596c   f9 05 ff 33 0d 0a 38 36  35 34 35 36 30 35 37 30  |...3..8654560570|
V (53560) Send: 0x3fcf51f4   4a f9                                             |J.|
V (53570) CMUX Received: 0x3fce597c   31 37 30 34 36 0d 0a 0d  0a 4f 4b 0d 0a 84 f9     |17046....OK....|
D (53580) CMUX: Payload frame: dlci:01 type:ff payload:25 available:27
} (53580) command_lib: Token: {

V (53590) command_lib: Token: {865456057017046}

} (53590) command_lib: Token: {

V (53600) command_lib: Token: {OK}

Modem IMEI number:865456057017046
V (53600) command_lib: set_echo
V (53610) command_lib: generic_command_common
V (53610) command_lib: generic_command
D (53610) command_lib: generic_command command ATE0

V (53620) Send: 0x3fcf5050   f9 05 ef 0b                                       |....|
V (53630) Send: 0x3fcf5328   41 54 45 30 0d                                    |ATE0.|
V (53620) CMUX Received: 0x3fce596c   f9 05 ff 0d 0d 0a 4f 4b  0d 0a 4a f9              |......OK..J.|
V (53640) Send: 0x3fcf5054   bb f9                                             |..|
D (53650) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8
D (53660) command_lib: Response: 
OK

V (53660) command_lib: set_pdp_context
V (53670) command_lib: generic_command_common
V (53670) command_lib: generic_command
D (53670) command_lib: generic_command command AT+CGDCONT=1,"IP","nbiot.global-m2m.net"

V (53680) Send: 0x3fcf4fd0   f9 05 ef 53                                       |...S|
V (53690) Send: 0x3fce85bc   41 54 2b 43 47 44 43 4f  4e 54 3d 31 2c 22 49 50  |AT+CGDCONT=1,"IP|
V (53690) CMUX Received: 0x3fce596c   f9 05 ff 0d 0d 0a 4f 4b  0d 0a 4a f9              |......OK..J.|
D (53710) CMUX: Payload frame: dlci:01 type:ff payload:6 available:8
D (53710) command_lib: Response: 
OK

V (53710) Send: 0x3fce85cc   22 2c 22 6e 62 69 6f 74  2e 67 6c 6f 62 61 6c 2d  |","nbiot.global-|
V (53730) Send: 0x3fce85dc   6d 32 6d 2e 6e 65 74 22  0d                       |m2m.net".|
V (53730) Send: 0x3fcf4fd4   d9 f9                                             |..|
V (53740) command_lib: set_data_mode
V (53750) command_lib: generic_command
D (53750) command_lib: generic_command command ATD*99##

V (53760) Send: 0x3fcf5080   f9 05 ef 13                                       |....|
V (53760) Send: 0x3fcf5338   41 54 44 2a 39 39 23 23  0d                       |ATD*99##.|
V (53760) CMUX Received: 0x3fce596c   f9 01 ef 0b e3 07 07 8d  01 79 f9 f9 05 ff 2b 0d  |.........y....+.|
V (53780) Send: 0x3fcf5084   a9 f9                                             |..|
V (53790) CMUX Received: 0x3fce597c   0a 43 4f 4e 4e 45 43 54  20 31 35 30 30 30 30 30  |.CONNECT 1500000|
V (53800) CMUX Received: 0x3fce598c   30 30 0d 0a 96 f9                                 |00....|
D (53810) CMUX: Payload frame: dlci:00 type:ef payload:5 available:34
D (53810) CMUX: Payload frame: dlci:01 type:ff payload:21 available:23
D (53820) command_lib: Response: 
CONNECT 150000000

D (53820) esp_netif_handlers: esp_netif action has started with netif0x3fce5bac from event_id=0
D (53830) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fce5edc
D (53840) esp-netif_lwip-ppp: Phase Start
D (53850) esp-netif_lwip-ppp: Phase Establish
D (53850) esp_netif_lwip: check: remote, if=0x3fce5bac fn=0x42023618
0x42023618: esp_netif_update_default_netif_lwip at /home/franz/esp-idf-v4.4.2/components/esp_netif/lwip/esp_netif_lwip.c:188

D (53860) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fce5bac
V (53860) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fce5bac
D (53870) esp_netif_lwip: call api in lwip: ret=0x0, give sem
Modem has correctly entered mode CMUX_MANUAL_DATA
V (53880) command_lib: get_operator_name
V (53880) command_lib: generic_get_string
V (53890) Send: 0x3fcf51a0   f9 09 ef 13                                       |....|
V (53900) Send: 0x3fcf53d4   41 54 2b 43 4f 50 53 3f  0d                       |AT+COPS?.|
V (53890) CMUX Received: 0x3fce596c   f9 09 ff 49 0d 0a 2b 43  4f 50 53 3a 20 30 2c 30  |...I..+COPS: 0,0|
V (53910) Send: 0x3fcf51a4   2e f9                                             |..|
V (53920) CMUX Received: 0x3fce597c   2c 22 76 6f 64 61 66 6f  6e 65 2e 64 65 22 2c 37  |,"vodafone.de",7|
V (53930) CMUX Received: 0x3fce598c   0d 0a 0d 0a 4f 4b 0d 0a  ba f9                    |....OK....|
D (53940) CMUX: Payload frame: dlci:02 type:ff payload:36 available:38
} (53950) command_lib: Token: {

V (53950) command_lib: Token: {+COPS: 0,0,"vodafone.de",7}

} (53950) command_lib: Token: {

V (53960) command_lib: Token: {OK}

Operator name:vodafone.de

espressif / esp-protocols

simple_cmux_client reconnection Story in esp-idf-v4.4.2 vs esp-idf-v5.0 (IDFGH-8899) #188