Assistance Needed for Setting Up Azure Communication via NRF9160 Modem on NB-IoT Network using STM32 as a host

[Amol_Chor]

Hi everyone,

I’m currently working on setting up Azure communication using the latest SLM version for PPP (Point-to-Point Protocol) support. Here’s the configuration I’m working with:

• Host MCU: STM32U585 running FreeRTOS, STM32-X-CUBE-CELLULAR, and LWIP (Lightweight IP open-source TCP/IP stack).
• Modem: NRF9160 Serial Lte Modem application (version 2.6.1) on NB-IoT network.
• Alternative Modem: Quctel modem (supports LTE network).

I have successfully established Azure communication with the Quctel modem using the STM32-X-CUBE-CELLULAR, and LWIP stack. However, I am facing challenges while trying to achieve the same with the NRF9160 modem over the NB-IoT network.

I have logs available from the Quctel modem that show successful Azure communication, but replicating this with the NRF9160 modem has been difficult.

here is the snippet from Quctel modem which showing 'Network is up with IP 10.65.175.125'

<INF>    17763 [CellularSe] client ppp_notify_phase_cb: PPP_PHASE_DEAD
>
<INF>    17763 [CellularSe] ppposif_client_dead
>
<L  >    17763 [CellularSe] ppp_connect[0]: holdoff=0
>
<L  >    17763 [CellularSe] ppp phase changed[0]: phase=3
>
<L  >    18003 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80ddf44
>
<L  >    18003 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    18003 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    18003 [TCP/IP    ] sys_timeout: 0x2007dde4 abs_time=19003 handler=dns_tmr arg=0x80ddf44
>
<INF>    18263 [CellularSe] client ppp_notify_phase_cb: PPP_PHASE_INITIALIZE
>
<L  >    18263 [CellularSe] pppos_connect: unit 0: connecting
>
<L  >    18263 [CellularSe] ppp_start[0]
>
<L  >    18263 [CellularSe] ppp phase changed[0]: phase=6
>
<INF>    18763 [CellularSe] client ppp_notify_phase_cb: 6
>
<L  >    18763 [CellularSe] pppos_send_config[0]: out_accm=FF FF FF FF
>
<L  >    18763 [CellularSe] ppp_send_config[0]
>
<L  >    18763 [CellularSe] pppos_recv_config[0]: in_accm=FF FF FF FF
>
<L  >    18763 [CellularSe] ppp_recv_config[0]
>
<L  >    18763 [CellularSe] ppp: auth protocols:
>
<L  >    18763 [CellularSe]  PAP=0
>
<L  >    18763 [CellularSe]
>
<L  >    18763 [CellularSe] pbuf_alloc(length=24)
>
<L  >    18763 [CellularSe] pbuf_alloc(length=24) == 0x2007da3c
>
<L  >    18763 [CellularSe] pbuf_alloc(length=0)
>
<L  >    18763 [CellularSe] pbuf_alloc(length=0) == 0x2007d82c
>
<L  >    18767 [CellularSe] pbuf_free(0x2007d82c)
>
<L  >    18767 [CellularSe] pbuf_free: deallocating 0x2007d82c
>
<L  >    18767 [CellularSe] pppos_write[0]: len=24
>
<L  >    18767 [CellularSe] pbuf_free(0x2007da3c)
>
<L  >    18767 [CellularSe] pbuf_free: deallocating 0x2007da3c
>
<L  >    18767 [CellularSe] sys_timeout: 0x2007ddd0 abs_time=24767 handler=(fsm_timeout) arg=0x2007f47c
>
<L  >    18767 [CellularSe] ppp_start[0]: finished
>
<L  >    18769 [PPPosifClt] pbuf_alloc(length=1)
>
<L  >    18769 [PPPosifClt] pbuf_alloc(length=1) == 0x2007da3c
>
<L  >    18769 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18769 [PPPosifClt] pppos_input[0]: got 1 bytes
>
<L  >    18769 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18769 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    18769 [PPPosifClt] pbuf_alloc(length=2)
>
<L  >    18769 [PPPosifClt] pbuf_alloc(length=2) == 0x2007da3c
>
<L  >    18769 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18769 [PPPosifClt] pppos_input[0]: got 2 bytes
>
<L  >    18770 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18770 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3)
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3) == 0x2007da3c
>
<L  >    18770 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18770 [PPPosifClt] pppos_input[0]: got 3 bytes
>
<L  >    18770 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18770 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3)
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3) == 0x2007da3c
>
<L  >    18770 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18770 [PPPosifClt] pppos_input[0]: got 3 bytes
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=0)
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=0) == 0x2007d82c
>
<L  >    18770 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18770 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3)
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3) == 0x2007da3c
>
<L  >    18770 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18770 [PPPosifClt] pppos_input[0]: got 3 bytes
>
<L  >    18770 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18770 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3)
>
<L  >    18770 [PPPosifClt] pbuf_alloc(length=3) == 0x2007da3c
>
<L  >    18770 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18771 [PPPosifClt] pppos_input[0]: got 3 bytes
>
<L  >    18771 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18771 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    18771 [PPPosifClt] pbuf_alloc(length=3)
>
<L  >    18771 [PPPosifClt] pbuf_alloc(length=3) == 0x2007da3c
>
<L  >    18771 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18771 [PPPosifClt] pppos_input[0]: got 3 bytes
>
<L  >    18771 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18771 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    18771 [PPPosifClt] pbuf_alloc(length=3)
>
<L  >    18771 [PPPosifClt] pbuf_alloc(length=3) == 0x2007da3c
>
<L  >    18771 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    18771 [PPPosifClt] pppos_input[0]: got 3 bytes
>
<L  >    18771 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    18771 [PPPosifClt]
>
<L  >    18786 [PPPosifClt] pbuf_free(0x2007d40c)
>
<L  >    18787 [P
>
<INF>    19287 [PPPosifClt] client ppp_notify_phase_cb: 7
>
<L  >    19287 [PPPosifClt] ppp phase changed[0]: phase=9
>
<INF>    19787 [PPPosifClt] client ppp_notify_phase_cb: PPP_PHASE_NETWORK
>
<INF>    19787 [PPPosifClt] ppposif_client_network
>
<L  >    19787 [PPPosifClt] pbuf_alloc(length=32)
>
<L  >    19787 [PPPosifClt] pbuf_alloc(length=32) == 0x2007d61c
>
<L  >    19787 [PPPosifClt] pbuf_alloc(length=0)
>
<L  >    19787 [PPPosifClt] pbuf_alloc(length=0) == 0x2007d40c
>
<L  >    19790 [PPPosifClt] pbuf_free(0x2007d40c)
>
<L  >    19790 [PPPosifClt] pbuf_free: deallocating 0x2007d40c
>
<L  >    19790 [PPPosifClt] pppos_write[0]: len=32
>
<L  >    19790 [PPPosifClt] pbuf_free(0x2007d61c)
>
<L  >    19790 [PPPosifClt] pbuf_free: deallocating 0x2007d61c
>
<L  >    19790 [PPPosifClt] sys_timeout: 0x2007ddd0 abs_time=25790 handler=(fsm_timeout) arg=0x2008063c
>
<L  >    19790 [PPPosifClt] pbuf_free(0x2007d82c)
>
<L  >    19790 [PPPosifClt] pbuf_free: deallocating 0x2007d82c
>
<L  >    19790 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    19790 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    19790 [PPPosifClt] pbuf_alloc(length=22)
>
<L  >    19790 [PPPosifClt] pbuf_alloc(length=22) == 0x2007da3c
>
<L  >    19790 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    19790 [PPPosifClt] pppos_input[0]: got 22 bytes
>
<L  >    19790 [PPPosifClt] pbuf_alloc(length=0)
>
<L  >    19790 [PPPosifClt] pbuf_alloc(length=0) == 0x2007d82c
>
<L  >    19791 [PPPosifClt] pbuf_remove_header: old 0x2007d83c new 0x2007d83e (2)
>
<L  >    19791 [PPPosifClt] pbuf_free(0x2007d82c)
>
<L  >    19791 [PPPosifClt] pbuf_free: deallocating 0x2007d82c
>
<L  >    19791 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    19791 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    19806 [TCP/IP    ] sct calling h=dns_tmr t=803 arg=0x80ddf44
>
<L  >    19806 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    19806 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    19806 [TCP/IP    ] sys_timeout: 0x2007dde4 abs_time=20003 handler=dns_tmr arg=0x80ddf44
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=1)
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=1) == 0x2007da3c
>
<L  >    19807 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    19807 [PPPosifClt] pppos_input[0]: got 1 bytes
>
<L  >    19807 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    19807 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=2)
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=2) == 0x2007da3c
>
<L  >    19807 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    19807 [PPPosifClt] pppos_input[0]: got 2 bytes
>
<L  >    19807 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    19807 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=3)
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=3) == 0x2007da3c
>
<L  >    19807 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    19807 [PPPosifClt] pppos_input[0]: got 3 bytes
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=0)
>
<L  >    19807 [PPPosifClt] pbuf_alloc(length=0) == 0x2007d82c
>
<L  >    19807 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    19808 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    19808 [PPPosifClt] pbuf_alloc(length=4)
>
<L  >    19808 [PPPosifClt] pbuf_alloc(length=4) == 0x2007da3c
>
<L  >    19808 [PPPosifClt] tcpip_inpkt: PACKET 0x2007da3c/0x2004475c
>
<L  >    19808 [PPPosifClt] pppos_input[0]: got 4 bytes
>
<L  >    19808 [PPPosifClt] pbuf_remove_header: old 0x2007d83c new 0x2007d83e (2)
>
<L  >    19808 [PPPosifClt] pbuf_alloc(length=14)
>
<L  >    19808 [PPPosifClt] pbuf_alloc(length=14) == 0x2007d61c
>
<L  >    19808 [PPPosifClt] pbuf_alloc(length=0)
>
<L  >    19808 [PPPosifClt] pbuf_alloc(length=0) == 0x2007d40c
>
<L  >    19809 [PPPosifClt] pbuf_free(0x2007d40c)
>
<L  >    19809 [PPPosifClt] pbuf_free: deallocating 0x2007d40c
>
<L  >    19809 [PPPosifClt] pppos_write[0]: len=14
>
<L  >    19810 [PPPosifClt] pbuf_free(0x2007d61c)
>
<L  >    19810 [PPPosifClt] pbuf_free: deallocating 0x2007d61c
>
<L  >    19810 [PPPosifClt] pbuf_free(0x2007d82c)
>
<L  >    19810 [PPPosifClt] pbuf_free: dealloc
>
<L  >    19813 [PPPosifClt] pbuf_free(0x2007d40c)
>
<INF>    20323 [PPPosifClt] client ppp_notify_phase_cb: PPP_PHASE_RUNNING
>
<INF>    20323 [PPPosifClt] CST: CST_notif_callback (Data Cache event=0)
>
<INF>    20323 [PPPosifClt] CST: CST_send_message: data cache 0
>
<L  >    20323 [PPPosifClt] pbuf_free(0x2007d82c)
>
<L  >    20323 [PPPosifClt] pbuf_free: deallocating 0x2007d82c
>
<L  >    20323 [PPPosifClt] pbuf_free(0x2007da3c)
>
<L  >    20323 [PPPosifClt] pbuf_free: deallocating 0x2007da3c
>
<L  >    20323 [TCP/IP    ] sct calling h=dns_tmr t=320 arg=0x80ddf44
>
<L  >    20323 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    20323 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    20323 [TCP/IP    ] sys_timeout: 0x2007dde4 abs_time=21003 handler=dns_tmr arg=0x80ddf44
>
<INF>    20323 [CellularSe] CST: CST_notif_callback (Data Cache event=0)
>
<INF>    20323 [CellularSe] CST: CST_send_message: data cache 0
>
<INF>    20323 [CellularSe] CST: AUTOM TASK: CST_PPP_CONFIG_ON_GOING_STATE - PPP_OPENED_EVENT
>
<INF>    20323 [CellularSe] CST: New State: MODEM_DATA_READY_STATE
>
<INF>    20323 [CellularSe] CST: modem state : CA_MODEM_STATE_DATAREADY
>
<INF>    20323 [CellularSe] CST: CST_notif_callback (Data Cache event=0)
>
<INF>    20323 [CellularSe] CST: CST_send_message: data cache 0
>
<INF>    20323 [CellularSe] CST: CST_send_message: NO_EVENT
>
<INF>    20323 [CellularSe] CST: CST_notif_callback (Data Cache event=2)
>
<INF>    20323 [CellularSe] CellularApp: Modem ready to transmit data
>
<L  >    20324 [CellularSe] sys_timeout: 0x2007ddd0 abs_time=24086 handler=sntp_request arg=0
>
<INF>    20324 [CellularSe] CST: CST_notif_callback (Data Cache event=0)
>
<INF>    20324 [CellularSe] CST: CST_send_message: data cache 0
>
<INF>    20324 [CellularSe] CST: CST_notif_callback (Data Cache event=1)
>
<INF>    20324 [CellularSe] CST: CST_send_message: data cache 1
>
<INF>    20324 [CellularSe] Network is up with IP 10.65.175.125
>
<INF>    20324 [CellularSe] CST: rt_state_ppp = DC_SERVICE_UNAVAIL. Nothing to do
>
<INF>    20324 [CellularSe] CST: autom_event = no event
>
<INF>    20324 [CellularSe] CST: rt_state_ppp = DC_SERVICE_UNAVAIL. Nothing to do
>
<INF>    20324 [CellularSe] CST: autom_event = no event
>
<INF>    20324 [CellularSe] CST: autom_event = no event
>
<INF>    20324 [CellularSe] CST: rt_state_ppp = DC_SERVICE_UNAVAIL. Nothing to do
>
<INF>    20324 [CellularSe] CST: autom_event = no event
>
<INF>    20324 [CellularSe] CST: autom_event = no event

the same setup with the NRF9160 modem, I made the necessary changes for AT commands and added the supported AT commands in the STM32U585 X-CUBE-CELLULAR driver.
While network registration completes successfully on both modems.

Using the NRF9160 as a modem for STM32U585, the PPP from the LWIP stack fails to obtain an IP address for the STM32U585 host when attempting internet connectivity

here is the snippet of logs when PPP starts on HOST STM32U585

<INF>    70841 [CellularSe] client ppp_notify_phase_cb: PPP_PHASE_DEAD
>
<INF>    70841 [CellularSe] ppposif_client_dead
>
<L  >    70841 [CellularSe] ppp_connect[0]: holdoff=0
>
<L  >    70841 [CellularSe] ppp phase changed[0]: phase=3
>
<L  >    71012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    71012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    71012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    71012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=72012 handler=dns_tmr arg=0x80e5ebc
>
<INF>    71341 [CellularSe] client ppp_notify_phase_cb: PPP_PHASE_INITIALIZE
>
<L  >    71341 [CellularSe] pppos_connect: unit 0: connecting
>
<L  >    71341 [CellularSe] ppp_start[0]
>
<L  >    71341 [CellularSe] ppp phase changed[0]: phase=6
>
<INF>    71841 [CellularSe] client ppp_notify_phase_cb: 6
>
<L  >    71841 [CellularSe] pppos_send_config[0]: out_accm=FF FF FF FF
>
<L  >    71841 [CellularSe] ppp_send_config[0]
>
<L  >    71841 [CellularSe] pppos_recv_config[0]: in_accm=FF FF FF FF
>
<L  >    71841 [CellularSe] ppp_recv_config[0]
>
<L  >    71841 [CellularSe] ppp: auth protocols:
>
<L  >    71841 [CellularSe]  PAP=0
>
<L  >    71841 [CellularSe]
>
<L  >    71841 [CellularSe] pbuf_alloc(length=24)
>
<L  >    71841 [CellularSe] pbuf_alloc(length=24) == 0x200831b0
>
<L  >    71841 [CellularSe] pbuf_alloc(length=0)
>
<L  >    71841 [CellularSe] pbuf_alloc(length=0) == 0x20082fa0
>
<L  >    71845 [CellularSe] pbuf_free(0x20082fa0)
>
<L  >    71845 [CellularSe] pbuf_free: deallocating 0x20082fa0
>
<L  >    71845 [CellularSe] pppos_write[0]: len=24
>
<L  >    71845 [CellularSe] pbuf_free(0x200831b0)
>
<L  >    71845 [CellularSe] pbuf_free: deallocating 0x200831b0
>
<L  >    71845 [CellularSe] sys_timeout: 0x20083544 abs_time=77845 handler=(fsm_timeout) arg=0x20084bf0
>
<L  >    71845 [CellularSe] ppp_start[0]: finished
>
<INF>    71862 [CellularSe] CST: CST_notif_callback (Data Cache event=2)
>
<INF>    71862 [CellularSe] CST: CST_notif_callback (Data Cache event=0)
>
<INF>    71863 [CellularSe] CST: CST_send_message: data cache 0
>
<INF>    71863 [CellularSe] CST: CST_notif_callback (Data Cache event=1)
>
<INF>    71863 [CellularSe] CST: CST_send_message: data cache 1
>
<INF>    71863 [CellularSe] CST: New State: CST_PPP_CONFIG_ON_GOING_STATE
>
<INF>    71863 [CellularSe] CST: rt_state_ppp = DC_SERVICE_UNAVAIL. Nothing to do
>
<INF>    71863 [CellularSe] CST: autom_event = no event
>
<INF>    71863 [CellularSe] CST: autom_event = no event
>
<L  >    72012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    72012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    72012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    72012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=73012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    73012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    73012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    73012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    73012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=74012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    74012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    74012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    74012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    74012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=75012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    75012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    75012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    75012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    75012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=76012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    76012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    76012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    76012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    76012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=77012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    77012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    77012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    77012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    77012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=78012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    77845 [TCP/IP    ] sct calling h=(fsm_timeout) t=0 arg=0x20084bf0
>
<L  >    77845 [TCP/IP    ] pbuf_alloc(length=24)
>
<L  >    77845 [TCP/IP    ] pbuf_alloc(length=24) == 0x200831b0
>
<L  >    77845 [TCP/IP    ] pbuf_alloc(length=0)
>
<L  >    77845 [TCP/IP    ] pbuf_alloc(length=0) == 0x20082fa0
>
<L  >    77849 [TCP/IP    ] pbuf_free(0x20082fa0)
>
<L  >    77849 [TCP/IP    ] pbuf_free: deallocating 0x20082fa0
>
<L  >    77849 [TCP/IP    ] pppos_write[0]: len=24
>
<L  >    77849 [TCP/IP    ] pbuf_free(0x200831b0)
>
<L  >    77849 [TCP/IP    ] pbuf_free: deallocating 0x200831b0
>
<L  >    77849 [TCP/IP    ] sys_timeout: 0x20083544 abs_time=83849 handler=(fsm_timeout) arg=0x20084bf0
>
<L  >    78012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    78012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    78012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    78012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=79012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    79012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    79012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    79012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    79012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=80012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    80012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    80012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    80012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    80012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=81012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    81012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    81012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    81012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    81012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=82012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    82012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    82012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    82012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    82012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=83012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    83012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    83012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    83012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    83012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=84012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    83849 [TCP/IP    ] sct calling h=(fsm_timeout) t=0 arg=0x20084bf0
>
<L  >    83849 [TCP/IP    ] pbuf_alloc(length=24)
>
<L  >    83849 [TCP/IP    ] pbuf_alloc(length=24) == 0x200831b0
>
<L  >    83849 [TCP/IP    ] pbuf_alloc(length=0)
>
<L  >    83849 [TCP/IP    ] pbuf_alloc(length=0) == 0x20082fa0
>
<L  >    83853 [TCP/IP    ] pbuf_free(0x20082fa0)
>
<L  >    83853 [TCP/IP    ] pbuf_free: deallocating 0x20082fa0
>
<L  >    83853 [TCP/IP    ] pppos_write[0]: len=24
>
<L  >    83853 [TCP/IP    ] pbuf_free(0x200831b0)
>
<L  >    83853 [TCP/IP    ] pbuf_free: deallocating 0x200831b0
>
<L  >    83853 [TCP/IP    ] sys_timeout: 0x20083544 abs_time=89853 handler=(fsm_timeout) arg=0x20084bf0
>
<L  >    84012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    84012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    84012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    84012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=85012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    85012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    85012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    85012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    85012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=86012 handler=dns_tmr arg=0x80e5ebc
>
<L  >    85841 [Tmr Svc   ] ppp_close[0]: kill_link -> lcp_close
>
<L  >    85841 [Tmr Svc   ] ppp phase changed[0]: phase=11
>
<L  >    86012 [TCP/IP    ] sct calling h=dns_tmr t=0 arg=0x80e5ebc
>
<L  >    86012 [TCP/IP    ] tcpip: dns_tmr()
>
<L  >    86012 [TCP/IP    ] dns_tmr: dns_check_entries
>
<L  >    86012 [TCP/IP    ] sys_timeout: 0x20083558 abs_time=87012 handler=dns_tmr arg=0x80e5ebc
>
<INF>    86341 [Tmr Svc   ] client ppp_notify_phase_cb: 11
>
<L  >    86341 [Tmr Svc   ] pbuf_alloc(length=20)
>
<L  >    86341 [Tmr Svc   ] pbuf_alloc(length=20) == 0x200831b0
>
<L  >    86341 [Tmr Svc   ] pbuf_alloc(length=0)
>
<L  >    86341 [Tmr Svc   ] pbuf_alloc(length=0) == 0x20082fa0
>
<L  >    86343 [Tmr Svc   ] pbuf_free(0x20082fa0)
>
<L  >    86343 [Tmr Svc   ] pbuf_free: deallocating 0x20082fa0
>
<L  >    86343 [Tmr Svc   ] pppos_write[0]: len=20
>
<L  >    86343 [Tmr Svc   ] pbuf_free(0x200831b0)
>
<L  >    86343 [Tmr Svc   ] pbuf_free: deallocating 0x200831b0
>
<L  >    86343 [Tmr Svc   ] sys_timeout: 0x20083544 abs_time=92343 handler=(fsm_timeout) arg=0x20084bf0
>
<INF>    86343 [Tmr Svc   ] ppposif_config_timeout_timer_callback
>
<INF>    86344 [Tmr Svc   ] CST: CST_notif_callback (Data Cache event=0)
>
<INF>    86344 [Tmr Svc   ] CST: CST_send_message: data cache 0
>
<INF>    86344 [CellularSe] CST: CST_notif_callback (Data Cache event=0)
>
<INF>    86344 [CellularSe] CST: CST_send_message: data cache 0
>
<INF>    86344 [CellularSe] CST: AUTOM TASK: CST_PPP_CONFIG_ON_GOING_STATE - PPP_CLOSED_EVENT

Can anyone provide guidance or share their experience in configuring the NRF9160 modem for Azure communication over the NB-IoT network? Any advice, configuration tips, or insights would be greatly appreciated.

Thank you!

[Michal]

Are you able to check and provide the logs from nRF9160 directly as well? It is hard for our experts to debug without knowing what happens on the nRF9160.

For example via RTT.

Also, which modem FW version are you using on nRF9160?

Best regards,

Michal

[Amol_Chor]

Michal said:

Also, which modem FW version are you using on nRF9160?

I am using SLM 2.6.1  on nrf9160.

modem firmware 1.3.6

[Michal]

Thank you for the information.

Still, I will need the logs from nRF9160 to be able to proceed further.

Best regards,

Michal

[Amol_Chor]

Here is the logs from nrf9160 side which is used in combination with out stm32u585

[00:00:00.253,875] <err> spi_nor: Device id 00 00 00 does not match config 9d 60 17
*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***
[00:00:00.266,784] <inf> at_cmd_custom: Custom AT commands enabled with 2 entries.
[00:00:00.274,963] <dbg> slm: main: RR: 0x00000000
[00:00:00.286,987] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.292,755] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.298,065] <inf> fs_nvs: data wra: 0, 0
[00:00:00.540,740] <inf> slm: lib_modem init: 0
[00:00:00.552,398] <inf> mcuboot_util: Image index: 0, Swap type: none
[00:00:00.559,417] <inf> slm: Serial LTE Modem
[00:00:00.658,142] <dbg> slm_ppp: slm_ppp_init: PPP initialized.
[00:00:00.664,642] <inf> slm_uart_handler: UART baud: 115200 d/p/s-bits: 3/0/1 HWFC: 1
[00:00:00.673,248] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      52 65 61 64 79 0d 0a                             |Ready..
[00:00:00.689,605] <inf> slm_at_host: at_host init done
[00:00:01.077,026] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.084,716] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.092,285] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.099,639] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[[00:00:01.107,330] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.114,929] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.122,558] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.129,882] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.107,269] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.144,653] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.152,282] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.159,881] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.167,236] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.144,592] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.181,976] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.189,605] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.197,235] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.204,559] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.181,945] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.219,329] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.226,959] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.234,558] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.241,912] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.219,268] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.256,683] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.264,282] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.271,911] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.279,266] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.256,622] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.294,036] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.301,635] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.309,265] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.316,589] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.293,975] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.331,359] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.338,989] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.346,618] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.353,942] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.331,329] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.368,713] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.376,342] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.383,972] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.391,296] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.368,682] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.406,066] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.413,696] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.421,295] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.428,649] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.406,005] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.443,420] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.451,049] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.458,648] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.466,003] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.443,359] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.480,773] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.488,403] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.496,002] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.503,356] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.480,712] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.518,096] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.525,726] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.533,355] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.540,679] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.518,066] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.555,450] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.563,049] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.570,678] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.578,002] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.555,389] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.592,773] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.600,402] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.608,001] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.615,325] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.592,712] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.630,096] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.637,725] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.645,324] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.652,648] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.630,065] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.667,419] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.675,048] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.682,647] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.690,002] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.667,358] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.704,742] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.712,371] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.720,001] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.727,325] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.704,711] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.742,095] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.749,694] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.757,324] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.764,648] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.742,034] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.779,418] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.787,017] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.794,647] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.801,971] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.779,357] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.816,711] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.824,340] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.831,970] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.839,294] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.816,680] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.854,064] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.861,663] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.869,293] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.876,617] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.854,003] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.891,387] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.899,017] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.906,646] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.913,970] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.891,357] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.928,741] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.936,340] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.943,969] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.951,293] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.928,680] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:01.966,064] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:01.973,693] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:01.981,292] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:01.988,647] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:01.966,033] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.003,417] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.011,016] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.018,646] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.025,970] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.003,356] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.040,740] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.048,370] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.055,969] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.063,323] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.040,679] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.078,094] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.085,693] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.093,322] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.100,646] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.078,033] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.115,417] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.123,046] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.130,645] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.138,000] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.115,386] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.152,770] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.160,369] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.167,999] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.175,323] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.152,709] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.190,093] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.197,723] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.205,322] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.212,646] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.190,032] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.227,416] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.235,046] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.242,645] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.249,969] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.227,355] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.264,739] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.272,369] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.279,968] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.287,292] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.264,678] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.302,062] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.309,692] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.317,291] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.324,615] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.302,001] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.339,385] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.347,015] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.354,614] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.361,938] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.339,355] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.376,708] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.384,307] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.391,937] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.399,261] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.376,647] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.414,031] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.421,630] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.429,229] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.436,584] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.413,970] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.451,324] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.458,953] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.466,552] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.473,876] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.451,263] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.488,647] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.496,246] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.503,875] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.511,199] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.488,586] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.525,970] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.533,569] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.541,198] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.548,522] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.525,909] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.563,293] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.570,892] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.578,521] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.585,845] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.563,232] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.600,585] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.608,215] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.615,814] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.623,168] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.600,555] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.637,908] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.645,538] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.653,137] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.660,491] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.637,878] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.675,231] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.682,861] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.690,460] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.697,784] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.675,201] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.712,554] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.720,184] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.727,783] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.735,107] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.712,493] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.749,877] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.757,476] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.765,106] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.772,430] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.749,816] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.787,200] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.794,799] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.802,398] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.809,722] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.787,139] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.824,493] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.832,122] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.839,721] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.847,045] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.824,432] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.861,816] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.869,415] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.877,044] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.884,368] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.861,755] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.899,108] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.906,738] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.914,337] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.921,661] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.899,078] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.936,401] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.944,000] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.951,599] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.958,923] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.936,340] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:02.973,663] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:02.981,262] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:02.988,861] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:02.996,154] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:02.973,602] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.010,894] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.018,493] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.026,092] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.033,416] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.010,833] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.048,156] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.055,755] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.063,354] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.070,678] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.048,095] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.085,449] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.093,048] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.100,646] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.107,971] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.085,388] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.122,741] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.130,340] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.137,969] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.145,294] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.122,680] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.160,034] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.167,663] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.175,262] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.182,586] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.160,003] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.197,357] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.204,956] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.212,554] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.219,879] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.197,296] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.234,649] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.242,248] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.249,847] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.257,171] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.234,588] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.271,911] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.279,541] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.287,139] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.294,464] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.271,881] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.309,204] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.316,833] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.324,432] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.331,756] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.309,173] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.346,527] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.354,125] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.361,755] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.369,079] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.346,466] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.383,850] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.391,448] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.399,078] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.406,402] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.383,789] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.421,173] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.428,771] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.436,401] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.443,725] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.421,112] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.458,465] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.466,064] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.473,693] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.481,018] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.458,404] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.495,788] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.503,387] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.511,016] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.518,341] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.495,727] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.533,081] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.540,679] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.548,309] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.555,633] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.533,020] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.570,373] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.578,002] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.585,601] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.592,926] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.570,343] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.607,666] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.615,295] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.622,894] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.630,218] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.607,635] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.644,958] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.652,587] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.660,186] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.667,541] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.644,927] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.682,281] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.689,910] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.697,509] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.704,833] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.682,220] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.719,604] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.727,203] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.734,832] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.742,156] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.719,543] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.756,896] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.764,495] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.772,125] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.779,449] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.756,835] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.794,189] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.801,788] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.809,387] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.816,741] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.794,128] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.831,481] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.839,080] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.846,679] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.854,003] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.831,420] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.868,774] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.876,373] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.883,972] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.891,296] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.868,713] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.906,036] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.913,635] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.921,264] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.928,588] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.905,975] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.943,328] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.950,927] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.958,526] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:03.965,850] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.943,267] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:03.980,621] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:03.988,220] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:03.995,819] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.003,143] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:03.980,560] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.017,883] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.025,512] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.033,111] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.040,435] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.017,852] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.055,206] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.062,805] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.070,404] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.077,728] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.055,145] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.092,498] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.100,097] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.107,727] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.115,051] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.092,437] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.129,791] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.137,420] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.145,019] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.152,343] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.129,760] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.167,114] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.174,713] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.182,312] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.189,636] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.167,053] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.204,406] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.212,036] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.219,635] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.226,959] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.204,376] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.241,729] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.249,359] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.256,958] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.264,282] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.241,668] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.279,052] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.286,651] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.294,281] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.301,605] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.278,991] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.316,375] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.323,974] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.331,573] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.338,897] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.316,314] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.353,637] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.361,267] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.368,865] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.376,190] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.353,607] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.390,930] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.398,529] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.406,158] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.413,482] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.390,869] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.428,222] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.435,821] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.443,420] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.450,744] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.428,161] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.465,515] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.473,114] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.480,712] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.488,037] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.465,454] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.502,807] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.510,406] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.518,005] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.525,329] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.502,746] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.540,069] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.547,698] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.555,297] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.562,622] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.540,039] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.577,362] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.584,960] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.592,559] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.599,884] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.577,301] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.614,624] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.622,192] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.629,791] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.637,115] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.614,562] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.651,855] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.659,454] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.667,053] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.674,377] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.651,794] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.689,086] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.696,685] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.704,284] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.711,608] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.689,056] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.726,348] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.733,947] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.741,546] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.748,840] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.726,287] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.763,580] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.771,179] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.778,778] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.786,102] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.763,519] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.800,842] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.808,441] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.816,040] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.823,364] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.800,781] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.838,104] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.845,703] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.853,302] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.860,626] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.838,043] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.875,335] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.882,934] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.890,533] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.897,857] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.875,305] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.912,597] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.920,196] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.927,795] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.935,119] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.912,536] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.949,859] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.957,489] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:04.965,087] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:04.972,412] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.949,829] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:04.987,182] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:04.994,781] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.002,410] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.009,735] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:04.987,121] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.024,505] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.032,104] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.039,703] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.047,027] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.024,444] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.061,798] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.069,396] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.077,026] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.084,350] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.061,737] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.099,121] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.106,719] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.114,349] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.121,673] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.099,060] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.136,413] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.144,042] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.151,641] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.158,966] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.136,383] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.173,736] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.181,335] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.188,964] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.196,289] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.173,675] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.211,029] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.218,658] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.226,257] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.233,581] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.210,998] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.248,352] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.255,950] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.263,580] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.270,904] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.248,291] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.285,644] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.293,273] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.300,872] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.308,197] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.285,614] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.322,967] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.330,566] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.338,195] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.345,520] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.322,906] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.360,260] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.367,889] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.375,488] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.382,812] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.360,198] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.397,552] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.405,181] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.412,780] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.420,104] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.397,521] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.434,875] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.442,474] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.450,103] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.457,427] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.434,814] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.472,167] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.479,797] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.487,396] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.494,720] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.472,137] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.509,460] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.517,089] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.524,688] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.532,012] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.509,429] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.546,783] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.554,382] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.561,981] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.569,305] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.546,722] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.584,075] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.591,674] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.599,273] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.606,628] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.584,014] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.621,368] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.628,997] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.636,596] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.643,920] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.621,307] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.658,660] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.666,290] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.673,889] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.681,213] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.658,630] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.695,953] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.703,582] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.711,181] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.718,505] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.695,922] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.733,276] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.740,875] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.748,474] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.755,798] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.733,215] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.770,568] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.778,167] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.785,766] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.793,090] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.770,507] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.807,861] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.815,460] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.823,089] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.830,413] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.807,800] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.845,153] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.852,752] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.860,351] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.867,675] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.845,092] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.882,415] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.890,045] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.897,644] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.904,968] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.882,385] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.919,708] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.927,307] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.934,936] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.942,260] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.919,647] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.957,000] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:05.964,630] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:05.972,229] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:05.979,553] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.956,970] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:05.994,293] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.001,922] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.009,521] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.016,845] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:05.994,262] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.031,616] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.039,215] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.046,813] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.054,138] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.031,555] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.068,878] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.076,507] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.084,106] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.091,430] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.068,847] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.106,170] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.113,800] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.121,398] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.128,723] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.106,140] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.143,463] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.151,062] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.158,691] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.166,015] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.143,402] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.180,755] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.188,385] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.195,983] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.203,308] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.180,725] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.218,048] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.225,677] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.233,276] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.240,600] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.218,017] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.255,371] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.262,969] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.270,599] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.277,923] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.255,310] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.292,694] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.300,292] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.307,922] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.315,246] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.292,633] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.330,017] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.337,615] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.345,214] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.352,569] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.329,956] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.367,309] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.374,908] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.382,537] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.389,862] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.367,248] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.404,632] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.412,231] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.419,830] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.427,185] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.404,571] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.441,925] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.449,554] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.457,153] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.464,477] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.441,864] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.479,248] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.486,846] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.494,445] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.501,800] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.479,187] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[[00:00:06.516,540] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
[00:00:06.524,169] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (8)
[00:00:06.531,768] <dbg> slm_uart_handler: uart_callback: UART_RX_DISABLED
[00:00:06.539,093] <dbg> slm_uart_handler: uart_callback: UART_RX_STOPPED (4)
00:00:06.516,479] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[00:00:06.553,802] <dbg> slm_uart_handler: rx_recovery: UART RX enabled
[00:00:06.561,157] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  31                      |AT+CFUN= 1
[00:00:06.576,629] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:06.625,946] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:06.636,810] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:06.653,198] <dbg> slm_at_host: cmd_send: RX
                                      41 54                                            |AT
[00:00:06.668,853] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:06.685,241] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 52                             |AT+CGMR
[00:00:06.700,927] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6d 66 77 5f 6e 72  66 39 31 36 30 5f 31 2e |..mfw_nr f9160_1.
                                      33 2e 36 0d 0a 0d 0a 4f  4b 0d 0a                |3.6....O K..
[00:00:06.727,111] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 4d 45 45 3d  31                      |AT+CMEE= 1
[00:00:06.742,797] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:06.759,246] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 50 53 4d 53  3d 30                   |AT+CPSMS =0
[00:00:06.774,932] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:06.791,290] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  30                      |AT+CFUN= 0
[00:00:06.806,823] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=0" to the modem.
[00:00:07.061,676] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:07.078,125] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 53 59 53 54  45 4d 4d 4f 44 45 3d 31 |AT%XSYST EMMODE=1
                                      2c 31 2c 31 2c 30                                |,1,1,0
[00:00:07.111,694] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:07.128,082] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  31                      |AT+CFUN= 1
[00:00:07.143,524] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:07.188,049] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:07.198,760] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:17.101,318] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  31                      |AT+CFUN= 1
[00:00:17.116,790] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:17.128,662] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:17.139,465] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:17.155,975] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:17.171,936] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:26.086,303] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 50 49 4e 3f                          |AT+CPIN?
[00:00:26.102,111] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 50 49 4e 3a  20 52 45 41 44 59 0d 0a |..+CPIN:  READY..
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:29.076,599] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 52                             |AT+CGMR
[00:00:29.092,498] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6d 66 77 5f 6e 72  66 39 31 36 30 5f 31 2e |..mfw_nr f9160_1.
                                      33 2e 36 0d 0a 0d 0a 4f  4b 0d 0a                |3.6....O K..
[00:00:29.118,743] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 50 49 4e 3f                          |AT+CPIN?
[00:00:29.134,490] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 50 49 4e 3a  20 52 45 41 44 59 0d 0a |..+CPIN:  READY..
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:29.160,766] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 44 43 4f  4e 54 3f                |AT+CGDCO NT?
[00:00:29.176,666] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 47 44 43 4f  4e 54 3a 20 30 2c 22 22 |..+CGDCO NT: 0,""
                                      2c 22 22 2c 22 22 2c 30  2c 30 0d 0a 0d 0a 4f 4b |,"","",0 ,0....OK
                                      0d 0a                                            |..
[00:00:29.212,646] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 49 4d 49                             |AT+CIMI
[00:00:29.228,485] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 32 34 30 34 32 32  36 30 33 32 36 30 30 32 |..240422 60326002
                                      39 0d 0a 0d 0a 4f 4b 0d  0a                      |9....OK. .
[00:00:29.254,760] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:29.270,690] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:29.306,671] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 44 43 4f  4e 54 3d 31 2c 22 49 50 |AT+CGDCO NT=1,"IP
                                      22 2c 22 65 6d 65 72 73  6f 6e 2e 72 74 72 2e 63 |","emers on.rtr.c
                                      78 6e 22                                         |xn"
[00:00:29.342,071] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:29.358,551] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  31                      |AT+CFUN= 1
[00:00:29.373,992] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:29.385,772] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:29.396,636] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:29.413,024] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:29.428,924] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:29.464,965] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 52                             |AT+CGMR
[00:00:29.480,834] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6d 66 77 5f 6e 72  66 39 31 36 30 5f 31 2e |..mfw_nr f9160_1.
                                      33 2e 36 0d 0a 0d 0a 4f  4b 0d 0a                |3.6....O K..
[00:00:29.507,019] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 50 49 4e 3f                          |AT+CPIN?
[00:00:29.522,857] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 50 49 4e 3a  20 52 45 41 44 59 0d 0a |..+CPIN:  READY..
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:29.549,163] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 44 43 4f  4e 54 3f                |AT+CGDCO NT?
[00:00:29.564,971] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 47 44 43 4f  4e 54 3a 20 30 2c 22 22 |..+CGDCO NT: 0,""
                                      2c 22 22 2c 22 22 2c 30  2c 30 0d 0a 2b 43 47 44 |,"","",0 ,0..+CGD
                                      43 4f 4e 54 3a 20 31 2c  22 49 50 22 2c 22 65 6d |CONT: 1, "IP","em
                                      65 72 73 6f 6e 2e 72 74  72 2e 63 78 6e 22 2c 22 |erson.rt r.cxn","
                                      22 2c 30 2c 30 0d 0a 0d  0a 4f 4b 0d 0a          |",0,0... .OK..
[00:00:29.620,544] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 45 52 45 47  3d 32                   |AT+CEREG =2
[00:00:29.636,230] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:29.652,679] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 53 4e 3d  31                      |AT+CGSN= 1
[00:00:29.668,487] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 47 53 4e 3a  20 22 33 35 38 34 34 37 |..+CGSN:  "358447
                                      31 37 37 34 38 31 30 38  33 22 0d 0a 0d 0a 4f 4b |17748108 3"....OK
                                      0d 0a                                            |..
[00:00:29.704,528] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 49                             |AT+CGMI
[00:00:29.720,458] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4e 6f 72 64 69 63  20 53 65 6d 69 63 6f 6e |..Nordic  Semicon
                                      64 75 63 74 6f 72 20 41  53 41 0d 0a 0d 0a 4f 4b |ductor A SA....OK
                                      0d 0a                                            |..
[00:00:29.756,439] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 4d                             |AT+CGMM
[00:00:29.772,216] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6e 52 46 39 31 36  30 2d 53 49 43 41 0d 0a |..nRF916 0-SICA..
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:29.798,400] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 52                             |AT+CGMR
[00:00:29.814,117] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6d 66 77 5f 6e 72  66 39 31 36 30 5f 31 2e |..mfw_nr f9160_1.
                                      33 2e 36 0d 0a 0d 0a 4f  4b 0d 0a                |3.6....O K..
[00:00:29.840,423] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 53 4e                             |AT+CGSN
[00:00:29.856,292] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 33 35 38 34 34 37  31 37 37 34 38 31 30 38 |..358447 17748108
                                      33 0d 0a 0d 0a 4f 4b 0d  0a                      |3....OK. .
[00:00:29.882,446] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:29.898,468] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:29.934,478] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 49 4d 49                             |AT+CIMI
[00:00:29.950,286] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 32 34 30 34 32 32  36 30 33 32 36 30 30 32 |..240422 60326002
                                      39 0d 0a 0d 0a 4f 4b 0d  0a                      |9....OK. .
[00:00:29.976,531] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  30                      |AT+CFUN= 0
[00:00:29.992,034] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=0" to the modem.
[00:00:33.089,721] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:33.106,048] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 53 59 53 54  45 4d 4d 4f 44 45 3d 31 |AT%XSYST EMMODE=1
                                      2c 31 2c 31 2c 30                                |,1,1,0
[00:00:33.139,678] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:33.156,036] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  31                      |AT+CFUN= 1
[00:00:33.171,478] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:33.217,376] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:33.228,179] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:33.244,659] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a                                            |..
[00:00:33.261,047] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      2b 43 45 52 45 47 3a 20  30 0d 0a                |+CEREG:  0..
[00:00:33.277,465] <dbg> slm_ppp: pdp_ctx_event_handler: Default PDN connection event 5 received.
[00:00:43.128,631] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  31                      |AT+CFUN= 1
[00:00:43.144,042] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:43.155,700] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:43.166,381] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:43.182,830] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:43.198,730] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:43.234,741] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 52                             |AT+CGMR
[00:00:43.250,457] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6d 66 77 5f 6e 72  66 39 31 36 30 5f 31 2e |..mfw_nr f9160_1.
                                      33 2e 36 0d 0a 0d 0a 4f  4b 0d 0a                |3.6....O K..
[00:00:43.276,611] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 50 49 4e 3f                          |AT+CPIN?
[00:00:43.292,327] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 50 49 4e 3a  20 52 45 41 44 59 0d 0a |..+CPIN:  READY..
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:43.318,511] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 44 43 4f  4e 54 3f                |AT+CGDCO NT?
[00:00:43.334,259] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 47 44 43 4f  4e 54 3a 20 30 2c 22 22 |..+CGDCO NT: 0,""
                                      2c 22 22 2c 22 22 2c 30  2c 30 0d 0a 0d 0a 4f 4b |,"","",0 ,0....OK
                                      0d 0a                                            |..
[00:00:43.370,269] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 49 4d 49                             |AT+CIMI
[00:00:43.386,077] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 32 34 30 34 32 32  36 30 33 32 36 30 30 32 |..240422 60326002
                                      39 0d 0a 0d 0a 4f 4b 0d  0a                      |9....OK. .
[00:00:43.412,322] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:43.428,222] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:43.464,202] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 44 43 4f  4e 54 3d 31 2c 22 49 50 |AT+CGDCO NT=1,"IP
                                      22 2c 22 65 6d 65 72 73  6f 6e 2e 72 74 72 2e 63 |","emers on.rtr.c
                                      78 6e 22                                         |xn"
[00:00:43.499,572] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:43.515,960] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 46 55 4e 3d  31                      |AT+CFUN= 1
[00:00:43.531,433] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:43.543,060] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:43.554,107] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:43.570,465] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:43.586,303] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:43.622,344] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 52                             |AT+CGMR
[00:00:43.638,183] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6d 66 77 5f 6e 72  66 39 31 36 30 5f 31 2e |..mfw_nr f9160_1.
                                      33 2e 36 0d 0a 0d 0a 4f  4b 0d 0a                |3.6....O K..
[00:00:43.664,367] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 50 49 4e 3f                          |AT+CPIN?
[00:00:43.680,053] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 50 49 4e 3a  20 52 45 41 44 59 0d 0a |..+CPIN:  READY..
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:43.706,268] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 44 43 4f  4e 54 3f                |AT+CGDCO NT?
[00:00:43.722,229] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 47 44 43 4f  4e 54 3a 20 30 2c 22 22 |..+CGDCO NT: 0,""
                                      2c 22 22 2c 22 22 2c 30  2c 30 0d 0a 2b 43 47 44 |,"","",0 ,0..+CGD
                                      43 4f 4e 54 3a 20 31 2c  22 49 50 22 2c 22 65 6d |CONT: 1, "IP","em
                                      65 72 73 6f 6e 2e 72 74  72 2e 63 78 6e 22 2c 22 |erson.rt r.cxn","
                                      22 2c 30 2c 30 0d 0a 0d  0a 4f 4b 0d 0a          |",0,0... .OK..
[00:00:43.777,832] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 53 4e 3d  31                      |AT+CGSN= 1
[00:00:43.793,762] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 47 53 4e 3a  20 22 33 35 38 34 34 37 |..+CGSN:  "358447
                                      31 37 37 34 38 31 30 38  33 22 0d 0a 0d 0a 4f 4b |17748108 3"....OK
                                      0d 0a                                            |..
[00:00:43.829,650] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 49                             |AT+CGMI
[00:00:43.845,428] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4e 6f 72 64 69 63  20 53 65 6d 69 63 6f 6e |..Nordic  Semicon
                                      64 75 63 74 6f 72 20 41  53 41 0d 0a 0d 0a 4f 4b |ductor A SA....OK
                                      0d 0a                                            |..
[00:00:43.881,408] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 4d                             |AT+CGMM
[00:00:43.897,216] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6e 52 46 39 31 36  30 2d 53 49 43 41 0d 0a |..nRF916 0-SICA..
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:43.923,400] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 4d 52                             |AT+CGMR
[00:00:43.939,117] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 6d 66 77 5f 6e 72  66 39 31 36 30 5f 31 2e |..mfw_nr f9160_1.
                                      33 2e 36 0d 0a 0d 0a 4f  4b 0d 0a                |3.6....O K..
[00:00:43.965,423] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 53 4e                             |AT+CGSN
[00:00:43.981,262] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 33 35 38 34 34 37  31 37 37 34 38 31 30 38 |..358447 17748108
                                      33 0d 0a 0d 0a 4f 4b 0d  0a                      |3....OK. .
[00:00:44.007,446] <dbg> slm_at_host: cmd_send: RX
                                      41 54 25 58 49 43 43 49  44                      |AT%XICCI D
[00:00:44.023,498] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 25 58 49 43 43 49  44 3a 20 38 39 34 36 34 |..%XICCI D: 89464
                                      32 30 38 34 34 36 30 33  32 36 30 30 32 39 35 0d |20844603 2600295.
                                      0a 0d 0a 4f 4b 0d 0a                             |...OK..
[00:00:44.059,417] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 49 4d 49                             |AT+CIMI
[00:00:44.075,256] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 32 34 30 34 32 32  36 30 33 32 36 30 30 32 |..240422 60326002
                                      39 0d 0a 0d 0a 4f 4b 0d  0a                      |9....OK. .
[00:00:44.101,470] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 4f 50 53 3f                          |AT+COPS?
[00:00:44.117,187] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 4f 50 53 3a  20 30 0d 0a 0d 0a 4f 4b |..+COPS:  0....OK
                                      0d 0a                                            |..
[00:00:44.143,402] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 4f 50 53 3d  30                      |AT+COPS= 0
[00:00:44.159,393] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:44.175,781] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 45 52 45 47  3f                      |AT+CEREG ?
[00:00:44.191,619] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 45 52 45 47  3a 20 30 2c 32 2c 22 43 |..+CEREG : 0,2,"C
                                      30 38 37 22 2c 22 30 30  30 34 36 31 39 32 22 2c |087","00 046192",
                                      39 0d 0a 0d 0a 4f 4b 0d  0a                      |9....OK. .
[00:00:44.227,722] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 4f 50 53 3f                          |AT+COPS?
[00:00:44.243,530] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 4f 50 53 3a  20 30 0d 0a 0d 0a 4f 4b |..+COPS:  0....OK
                                      0d 0a                                            |..
[00:00:44.269,714] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 41 54 54  3d 31                   |AT+CGATT =1
[00:00:44.285,583] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:44.301,940] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 53 51                                |AT+CSQ
[00:00:44.317,687] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 53 51 3a 20  39 39 2c 39 39 0d 0a 0d |..+CSQ:  99,99...
                                      0a 4f 4b 0d 0a                                   |.OK..
[00:00:44.450,805] <inf> slm_ppp: Connection up. Starting PPP.
[00:00:44.458,068] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a                                            |..
[00:00:44.474,456] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      2b 43 4e 45 43 5f 45 53  4d 3a 20 35 30 2c 30 0d |+CNEC_ES M: 50,0.
                                      0a                                               |.
[00:00:44.500,579] <dbg> slm_ppp: pdp_ctx_event_handler: Default PDN connection event 0 received.
[00:00:44.512,054] <dbg> slm_ppp: ppp_start: MTU set to 1500.
[00:00:44.519,714] <inf> slm_ppp: PPP started.
[00:00:45.632,537] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 53 51                                |AT+CSQ
[00:00:45.648,376] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 53 51 3a 20  39 39 2c 39 39 0d 0a 0d |..+CSQ:  99,99...
                                      0a 4f 4b 0d 0a                                   |.OK..
[00:00:45.674,591] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 45 52 45 47  3f                      |AT+CEREG ?
[00:00:45.690,399] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 45 52 45 47  3a 20 30 2c 35 2c 22 43 |..+CEREG : 0,5,"C
                                      30 38 37 22 2c 22 30 30  30 34 36 31 39 32 22 2c |087","00 046192",
                                      39 0d 0a 0d 0a 4f 4b 0d  0a                      |9....OK. .
[00:00:45.726,531] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 4f 50 53 3f                          |AT+COPS?
[00:00:45.742,370] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 4f 50 53 3a  20 30 2c 32 2c 22 34 30 |..+COPS:  0,2,"40
                                      35 38 36 34 22 2c 39 0d  0a 0d 0a 4f 4b 0d 0a    |5864",9. ...OK..
[00:00:45.768,585] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 45 52 45 47  3f                      |AT+CEREG ?
[00:00:45.784,393] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 45 52 45 47  3a 20 30 2c 35 2c 22 43 |..+CEREG : 0,5,"C
                                      30 38 37 22 2c 22 30 30  30 34 36 31 39 32 22 2c |087","00 046192",
                                      39 0d 0a 0d 0a 4f 4b 0d  0a                      |9....OK. .
[00:00:45.820,373] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 4f 50 53 3f                          |AT+COPS?
[00:00:45.836,120] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 4f 50 53 3a  20 30 2c 32 2c 22 34 30 |..+COPS:  0,2,"40
                                      35 38 36 34 22 2c 39 0d  0a 0d 0a 4f 4b 0d 0a    |5864",9. ...OK..
[00:00:45.862,365] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 41 54 54  3f                      |AT+CGATT ?
[00:00:45.878,173] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 2b 43 47 41 54 54  3a 20 31 0d 0a 0d 0a 4f |..+CGATT : 1....O
                                      4b 0d 0a                                         |K..
[00:00:45.904,418] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 45 52 45  50 3d 31 2c 30          |AT+CGERE P=1,0
[00:00:45.919,891] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1,0" to the modem.
[00:00:45.930,908] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..
[00:00:45.947,265] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 47 50 41 44  44 52 3d 31             |AT+CGPAD DR=1
[00:00:45.963,226] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a 4f 4b 0d 0a                                |..OK..

[Michal]

Thank you, we are looking into it internally.

Best regards,

Michal

[Amol_Chor]

Thanks for your reply !!

We are able to establish the PPP communication in our board.

here we are using SLM (2.6.1) without CMUX configuration.

A separate UART assign to for PPP communication, the STM32U585 able to communicate with NRF9160 using PPP configuration and STM32U585 got the IP address as well.

Now the scenario is, we are trying to connect Azure cloud after getting the IP address but there is socket connect failed.

here is the logs for STM32U585 

[INF] Starting bootloader
[WRN] This device was provisioned with dummy keys. This device is NOT SECURE
[INF] Primary image: magic=good, swap_type=0x3, copy_done=0x1, image_ok=0x1
[INF] Scratch: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
[INF] Boot source: none
[INF] Swap type: none
[INF] Primary image: magic=good, swap_type=0x1, copy_done=0x3, image_ok=0x1
[INF] Scratch: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
[INF] Boot source: primary slot
[INF] Swap type: none
[INF] Bootloader chainload address offset: 0x3a000
[INF] Jumping to the first image slot
[WRN] This device was provisioned with dummy keys. This device is NOT SECURE
[Sec Thread] Secure image initializing!
TF-M isolation level is: 0x00000002
TF-M FP mode: Software
Booting TFM v1.5.0


<INF>        0 [None      ] HW Init Complete.
>
<INF>        9 [Init      ]
===== X-Cube-Cellular version : X-CUBE-CELLULAR-7.1.0 =====
>
<INF>    30010 [AzureTask ] ------------------------------------------------------------------------------
>
<INF>    30010 [AzureTask ] ADU
>
<INF>    30010 [AzureTask ] Version: 1.0
>
<INF>    30010 [AzureTask ] ------------------------------------------------------------------------------
>
<INF>    30010 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
>
<ERR>    30010 [AzureTask ] Failed to connect to nimazureiothub.azure-devices.net with error -1.
>
<WRN>    30010 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [261]ms.
>
<INF>    30272 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
>
<ERR>    30272 [AzureTask ] Failed to connect to nimazureiothub.azure-devices.net with error -1.
>
<WRN>    30272 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [390]ms.
>
<INF>    30662 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
>
<ERR>    31432 [AzureTask ] Failed to connect to nimazureiothub.azure-devices.net with error -1.
>
<WRN>    31432 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1455]ms.
>
<INF>    32060 [CellularSe] CellularApp: Modem ready to transmit data
>
<INF>    32060 [CellularSe] Network is up with IP 10.82.2.189
>
<INF>    32887 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
>
<ERR>    46009 [AzureTask ] Failed to connect to nimazureiothub.azure-devices.net with error -1.
>
<WRN>    46009 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1257]ms.
>

 

another logs for STM32U585

<INF>        0 [None      ] HW Init Complete.
<INF>        9 [Init      ]
===== X-Cube-Cellular version : X-CUBE-CELLULAR-7.1.0 =====
<INF>       11 [AzureTask ] ------------------------------------------------------------------------------
<INF>       11 [AzureTask ] ADU
<INF>       11 [AzureTask ] Version: 1.0
<INF>       11 [AzureTask ] ------------------------------------------------------------------------------
<INF>       11 [AzureTask ] Demo completed successfully.
<INF>       11 [AzureTask ] Short delay before starting the next iteration....
<INF>     5011 [AzureTask ] Demo completed successfully.
<INF>     5011 [AzureTask ] Short delay before starting the next iteration....
<INF>    10011 [AzureTask ] Demo completed successfully.
<INF>    10011 [AzureTask ] Short delay before starting the next iteration....
<INF>    15011 [AzureTask ] Demo completed successfully.
<INF>    15011 [AzureTask ] Short delay before starting the next iteration....
<INF>    20011 [AzureTask ] Demo completed successfully.
<INF>    20011 [AzureTask ] Short delay before starting the next iteration....
<INF>    25011 [AzureTask ] Demo completed successfully.
<INF>    25011 [AzureTask ] Short delay before starting the next iteration....
<INF>    30011 [AzureTask ] Demo completed successfully.
<INF>    30011 [AzureTask ] Short delay before starting the next iteration....
<INF>    35011 [AzureTask ] Demo completed successfully.
<INF>    35011 [AzureTask ] Short delay before starting the next iteration....
<INF>    40011 [AzureTask ] Demo completed successfully.
<INF>    40011 [AzureTask ] Short delay before starting the next iteration....
<INF>    45011 [AzureTask ] Demo completed successfully.
<INF>    45011 [AzureTask ] Short delay before starting the next iteration....
<INF>    50011 [AzureTask ] Demo completed successfully.
<INF>    50011 [AzureTask ] Short delay before starting the next iteration....
<INF>    55011 [AzureTask ] Demo completed successfully.
<INF>    55011 [AzureTask ] Short delay before starting the next iteration....
<INF>    60011 [AzureTask ] Demo completed successfully.
<INF>    60011 [AzureTask ] Short delay before starting the next iteration....
<INF>    65011 [AzureTask ] Demo completed successfully.
<INF>    65011 [AzureTask ] Short delay before starting the next iteration....
<INF>    70011 [AzureTask ] Demo completed successfully.
<INF>    70011 [AzureTask ] Short delay before starting the next iteration....
<INF>    75011 [AzureTask ] Demo completed successfully.
<INF>    75011 [AzureTask ] Short delay before starting the next iteration....
<INF>    80011 [AzureTask ] Demo completed successfully.
<INF>    80011 [AzureTask ] Short delay before starting the next iteration....
<INF>    85011 [AzureTask ] Demo completed successfully.
<INF>    85011 [AzureTask ] Short delay before starting the next iteration....
<INF>    90011 [AzureTask ] Demo completed successfully.
<INF>    90011 [AzureTask ] Short delay before starting the next iteration....
<INF>    95011 [AzureTask ] Demo completed successfully.
<INF>    95011 [AzureTask ] Short delay before starting the next iteration....
<INF>   100011 [AzureTask ] Demo completed successfully.
<INF>   100011 [AzureTask ] Short delay before starting the next iteration....
<INF>   105011 [AzureTask ] Demo completed successfully.
<INF>   105011 [AzureTask ] Short delay before starting the next iteration....
<INF>   110011 [AzureTask ] Demo completed successfully.
<INF>   110011 [AzureTask ] Short delay before starting the next iteration....
<INF>   115011 [AzureTask ] Demo completed successfully.
<INF>   115011 [AzureTask ] Short delay before starting the next iteration....
<INF>   120011 [AzureTask ] Demo completed successfully.
<INF>   120011 [AzureTask ] Short delay before starting the next iteration....
<INF>   125011 [AzureTask ] Demo completed successfully.
<INF>   125011 [AzureTask ] Short delay before starting the next iteration....
<INF>   130011 [AzureTask ] Demo completed successfully.
<INF>   130011 [AzureTask ] Short delay before starting the next iteration....
<INF>   135011 [AzureTask ] Demo completed successfully.
<INF>   135011 [AzureTask ] Short delay before starting the next iteration....
<INF>   140011 [AzureTask ] Demo completed successfully.
<INF>   140011 [AzureTask ] Short delay before starting the next iteration....
<INF>   145011 [AzureTask ] Demo completed successfully.
<INF>   145011 [AzureTask ] Short delay before starting the next iteration....
<INF>   150011 [AzureTask ] Demo completed successfully.
<INF>   150011 [AzureTask ] Short delay before starting the next iteration....
<INF>   155011 [AzureTask ] Demo completed successfully.
<INF>   155011 [AzureTask ] Short delay before starting the next iteration....
<INF>   160011 [AzureTask ] Demo completed successfully.
<INF>   160011 [AzureTask ] Short delay before starting the next iteration....
<INF>   165011 [AzureTask ] Demo completed successfully.
<INF>   165011 [AzureTask ] Short delay before starting the next iteration....
<INF>   170011 [AzureTask ] Demo completed successfully.
<INF>   170011 [AzureTask ] Short delay before starting the next iteration....
<INF>   175011 [AzureTask ] Demo completed successfully.
<INF>   175011 [AzureTask ] Short delay before starting the next iteration....
<INF>   180011 [AzureTask ] Demo completed successfully.
<INF>   180011 [AzureTask ] Short delay before starting the next iteration....
<INF>   185011 [AzureTask ] Demo completed successfully.
<INF>   185011 [AzureTask ] Short delay before starting the next iteration....
<INF>   190011 [AzureTask ] Demo completed successfully.
<INF>   190011 [AzureTask ] Short delay before starting the next iteration....
<INF>   195011 [AzureTask ] Demo completed successfully.
<INF>   195011 [AzureTask ] Short delay before starting the next iteration....
<INF>   200011 [AzureTask ] Demo completed successfully.
<INF>   200011 [AzureTask ] Short delay before starting the next iteration....
<INF>   205011 [AzureTask ] Demo completed successfully.
<INF>   205011 [AzureTask ] Short delay before starting the next iteration....
<INF>   210011 [AzureTask ] Demo completed successfully.
<INF>   210011 [AzureTask ] Short delay before starting the next iteration....
<INF>   215011 [AzureTask ] Demo completed successfully.
<INF>   215011 [AzureTask ] Short delay before starting the next iteration....
<INF>   217800 [CellularSe] CellularApp: Modem ready to transmit data
<INF>   217800 [CellularSe] Network is up with IP 10.65.157.41
<INF>   220011 [AzureTask ] Demo completed successfully.
<INF>   220011 [AzureTask ] Short delay before starting the next iteration....
<INF>   221617 [PPPosifClt] The current Unix epoch time is 1719324012
<INF>   221617 [PPPosifClt] IST Date & Time: 2024-06-25 07:30:12 PM
<INF>   225011 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   230896 [AzureTask ] Successfully initialized mbedTLS.
<INF>   235972 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   235972 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   235972 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   235982 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [447]ms.
<INF>   236429 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   239233 [AzureTask ] Successfully initialized mbedTLS.
<INF>   244308 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   244308 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   244308 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   244318 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [451]ms.
<INF>   244769 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   244769 [AzureTask ] Failed to open socket.
<WRN>   244769 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [214]ms.
<INF>   244983 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   244983 [AzureTask ] Failed to open socket.
<WRN>   244983 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1533]ms.
<INF>   246516 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   246516 [AzureTask ] Failed to open socket.
<WRN>   246516 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2206]ms.
<INF>   248722 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   248722 [AzureTask ] Failed to open socket.
<WRN>   248722 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2534]ms.
<INF>   251256 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   251256 [AzureTask ] Failed to open socket.
<WRN>   251256 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2833]ms.
<INF>   254089 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   255978 [AzureTask ] Successfully initialized mbedTLS.
<INF>   261053 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   261053 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   261053 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   261063 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [4084]ms.
<INF>   265147 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   267727 [AzureTask ] Successfully initialized mbedTLS.
<INF>   272802 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   272802 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   272802 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   272812 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [4410]ms.
<INF>   277222 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   277222 [AzureTask ] Failed to open socket.
<WRN>   277222 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [3551]ms.
<INF>   280773 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   283116 [AzureTask ] Successfully initialized mbedTLS.
<INF>   288190 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   288190 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   288190 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   288200 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [4091]ms.
<INF>   292291 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   294665 [AzureTask ] Successfully initialized mbedTLS.
<INF>   299740 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   299740 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   299740 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   299750 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [3368]ms.
<INF>   303118 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   303118 [AzureTask ] Failed to open socket.
<WRN>   303118 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2198]ms.
<INF>   305316 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   305316 [AzureTask ] Failed to open socket.
<WRN>   305316 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1322]ms.
<INF>   306638 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   306638 [AzureTask ] Failed to open socket.
<WRN>   306638 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2704]ms.
<INF>   308772 [PPPosifClt] The current Unix epoch time is 1719324099
<INF>   308772 [PPPosifClt] IST Date & Time: 2024-06-25 07:31:39 PM
<INF>   309342 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   311257 [AzureTask ] Successfully initialized mbedTLS.
<INF>   316331 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   316331 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   316331 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   316341 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [3767]ms.
<INF>   320108 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   320108 [AzureTask ] Failed to open socket.
<WRN>   320108 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [3513]ms.
<INF>   323621 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   323621 [AzureTask ] Failed to open socket.
<WRN>   323621 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [4926]ms.
<INF>   328547 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   328547 [AzureTask ] Failed to open socket.
<WRN>   328547 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [3000]ms.
<INF>   331547 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   331547 [AzureTask ] Failed to open socket.
<WRN>   331547 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [51]ms.
<INF>   331598 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   331598 [AzureTask ] Failed to open socket.
<WRN>   331598 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1790]ms.
<INF>   333388 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   336687 [AzureTask ] Successfully initialized mbedTLS.
<INF>   341762 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   341762 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   341762 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   341773 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [1868]ms.
<INF>   343641 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   344602 [AzureTask ] Successfully initialized mbedTLS.
<INF>   349676 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   349676 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   349676 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   349686 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [3725]ms.
<INF>   353411 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   353411 [AzureTask ] Failed to open socket.
<WRN>   353411 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [3756]ms.
<INF>   357167 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   357167 [AzureTask ] Failed to open socket.
<WRN>   357167 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2680]ms.
<INF>   359847 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   361398 [AzureTask ] Successfully initialized mbedTLS.
<INF>   366472 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   366472 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   366472 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   366482 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [1323]ms.
<INF>   367805 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   369162 [AzureTask ] Successfully initialized mbedTLS.
<INF>   374236 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   374236 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   374236 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   374247 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [1575]ms.
<INF>   375822 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   375822 [AzureTask ] Failed to open socket.
<WRN>   375822 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [355]ms.
<INF>   376177 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   376177 [AzureTask ] Failed to open socket.
<WRN>   376177 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1540]ms.
<INF>   377717 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   377717 [AzureTask ] Failed to open socket.
<WRN>   377717 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1945]ms.
<INF>   379662 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   379662 [AzureTask ] Failed to open socket.
<WRN>   379662 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [3621]ms.
<INF>   383283 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   387032 [AzureTask ] Successfully initialized mbedTLS.
<INF>   392107 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   392107 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   392107 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   392117 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [3973]ms.
<INF>   396090 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<INF>   396693 [PPPosifClt] The current Unix epoch time is 1719324186
<INF>   396693 [PPPosifClt] IST Date & Time: 2024-06-25 07:33:06 PM
<DBG>   397784 [AzureTask ] Successfully initialized mbedTLS.
<INF>   402858 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   402858 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   402858 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   402868 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [523]ms.
<INF>   403391 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   403391 [AzureTask ] Failed to open socket.
<WRN>   403391 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2075]ms.
<INF>   405466 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   405466 [AzureTask ] Failed to open socket.
<WRN>   405466 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1464]ms.
<INF>   406930 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   406930 [AzureTask ] Failed to open socket.
<WRN>   406930 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2470]ms.
<INF>   409400 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   412439 [AzureTask ] Successfully initialized mbedTLS.
<INF>   417513 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   417513 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   417513 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   417523 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [581]ms.
<INF>   418104 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   418104 [AzureTask ] Failed to open socket.
<WRN>   418104 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [842]ms.
<INF>   418946 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   418946 [AzureTask ] Failed to open socket.
<WRN>   418946 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [2823]ms.
<INF>   421769 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   423722 [AzureTask ] Successfully initialized mbedTLS.
<INF>   428796 [AzureTask ] SOCKETS_ERROR_NONE 11   ####
<ERR>   428796 [AzureTask ] Failed to perform TLS handshake: lMbedtlsError[-29312]= SSL - The connection indicated an EOF : <No-Low-Level-Code>.
<ERR>   428796 [AzureTask ] Failed to do TLS handshake 4.
<WRN>   428806 [AzureTask ] Connection to the IoT Hub failed [4]. Retrying connection with backoff and jitter [3401]ms.
<INF>   432207 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   432207 [AzureTask ] Failed to open socket.
<WRN>   432207 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [1172]ms.
<INF>   433379 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<ERR>   433379 [AzureTask ] Failed to open socket.
<WRN>   433379 [AzureTask ] Connection to the IoT Hub failed [6]. Retrying connection with backoff and jitter [4136]ms.
<INF>   437515 [AzureTask ] Creating a TLS connection to nimazureiothub.azure-devices.net:8883.
<DBG>   443035 [AzureTask ] Successfully initialized mbedTLS.
>

another logs when we try to download file over PPP using http

Resetting device.[INF] Starting bootloader
[WRN] This device was provisioned with dummy keys. This device is NOT SECURE
[INF] Primary image: magic=good, swap_type=0x3, copy_done=0x1, image_ok=0x1
[INF] Scratch: magic=bad, swap_type=0x4, copy_done=0x2, image_ok=0x2
[INF] Boot source: none
[INF] Swap type: none
[INF] Primary image: magic=good, swap_type=0x1, copy_done=0x3, image_ok=0x1
[INF] Scratch: magic=bad, swap_type=0x4, copy_done=0x2, image_ok=0x2
[INF] Boot source: primary slot
[INF] Swap type: none
[INF] Bootloader chainload address offset: 0x3a000
[INF] Jumping to the first image slot
[WRN] This device was provisioned with dummy keys. This device is NOT SECURE
[Sec Thread] Secure image initializing!
TF-M isolation level is: 0x00000002
TF-M FP mode: Software
Booting TFM v1.5.0


<INF>        0 [None      ] HW Init Complete.
>
<INF>        4 [Init      ]
===== X-Cube-Cellular version : X-CUBE-CELLULAR-7.1.0 =====
>
<INF>        6 [AzureDemoT] ------------------------------------------------------------------------------
>
<INF>        6 [AzureDemoT] ADU SAMPLE
>
<INF>        6 [AzureDemoT] Version: 1.0
>
<INF>        6 [AzureDemoT] ------------------------------------------------------------------------------
>
<INF>        6 [AzureDemoT] HTTP Demo completed successfully.
>
<INF>        6 [AzureDemoT] Short delay before starting the next iteration....
>
<INF>     3006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>     5006 [AzureDemoT] HTTP Demo completed successfully.
>
<INF>     5006 [AzureDemoT] Short delay before starting the next iteration....
>
<INF>     6006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>     9006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    10006 [AzureDemoT] HTTP Demo completed successfully.
>
<INF>    10006 [AzureDemoT] Short delay before starting the next iteration....
>
<INF>    12006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    15006 [AzureDemoT] HTTP Demo completed successfully.
>
<INF>    15006 [AzureDemoT] Short delay before starting the next iteration....
>
<INF>    15006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    18006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    19876 [CellularSe] CellularApp: Modem ready to transmit data
>
<INF>    19876 [CellularSe] Network is up with IP 10.65.169.23
>
<INF>    20006 [AzureDemoT] HTTP Demo completed successfully.
>
<INF>    20006 [AzureDemoT] Short delay before starting the next iteration....
>
<INF>    21006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    24006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    24250 [PPPosifClt] The current Unix epoch time is 1719484874
>
<INF>    24250 [PPPosifClt] IST Date & Time: 2024-06-27 04:11:14 PM
>
<INF>    25006 [AzureDemoT] Connecting socket to nimdeviceupdate--nimdeviceupdate.b.nlu.dl.adu.microsoft.com
>
<INF>    27006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    30006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    31237 [AzureDemoT]  xStatus: 0
>
<INF>    32538 [AzureDemoT] [HTTP] Size Request Success 200
>
<INF>    32538 [AzureDemoT] [ADU] HTTP Range Request was successful: size 0 bytes
>
<INF>    32538 [AzureDemoT] [ADU] Send HTTP request.
>
<INF>    32538 [AzureDemoT] RTC Date & Time: 2024-06-27 04:11:22
>
<INF>    32538 [AzureDemoT] UTC Timestamp: 1722053482
>
<INF>    32538 [AzureDemoT] RTC Date & Time: 2024-06-27 04:11:22
>
<INF>    32538 [AzureDemoT] UTC Timestamp: 1722053482
>
<INF>    33006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    36006 [Heartbeat ] vHeartbeatTask I am Alive.
>
<INF>    37569 [AzureDemoT] SOCKETS_ERROR_NONE 11   ####
>
<ERR>    37569 [AzureDemoT] Response not received: Zero returned from transport recv: totalReceived=0
>

here is NRF9160 logs 

[00:00:00.253,967] <err> spi_nor: Device id 00 00 00 does not match config c2 28 17
*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***
[00:00:00.266,784] <inf> at_cmd_custom: Custom AT commands enabled with 2 entries.
[00:00:00.274,963] <dbg> slm: main: RR: 0x00000000
[00:00:00.286,682] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.292,449] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.297,760] <inf> fs_nvs: data wra: 0, 0
[00:00:00.540,618] <inf> slm: lib_modem init: 0
[00:00:00.552,246] <inf> mcuboot_util: Image index: 0, Swap type: none
[00:00:00.559,234] <inf> slm: Serial LTE Modem
[00:00:00.657,806] <dbg> slm_ppp: slm_ppp_init: PPP initialized.
[00:00:00.664,306] <inf> slm_uart_handler: UART baud: 115200 d/p/s-bits: 3/0/1 HWFC: 0
Ready
[00:00:00.672,882] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      52 65 61 64 79 0d 0a                             |Ready..
[00:00:00.690,460] <inf> slm_at_host: at_host init done
[00:00:00.705,291] <inf> slm: lte auto connect
[00:00:00.717,468] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CFUN=1" to the modem.
[00:00:00.764,556] <dbg> slm_util: slm_util_at_cmd_no_intercept: Forwarding "AT+CGEREP=1" to the modem.
[00:00:11.214,111] <inf> slm_ppp: Connection up. Starting PPP.

[00:00:11.221,313] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      0d 0a                                            |..
+CNEC_ESM: 50,0
[00:00:11.237,792] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      2b 43 4e 45 43 5f 45 53  4d 3a 20 35 30 2c 30 0d |+CNEC_ES M: 50,0.
                                      0a                                               |.
[00:00:11.265,319] <dbg> slm_ppp: pdp_ctx_event_handler: Default PDN connection event 0 received.
[00:00:11.275,360] <dbg> slm_ppp: ppp_start: MTU set to 1500.
[00:00:11.283,172] <inf> slm_ppp: PPP started.
[00:00:32.403,198] <inf> slm_ppp: Peer connected.
[00:00:33.769,378] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:33.885,498] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:33.901,489] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:33.917,938] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:34.892,730] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:34.902,587] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:36.829,833] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:36.871,520] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:39.836,456] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:39.846,374] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:40.830,444] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:40.840,362] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:41.785,400] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:41.820,068] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:43.799,530] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:43.809,417] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:00:48.001,098] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:48.736,999] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:49.729,125] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:51.707,000] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:54.674,407] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:55.660,430] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:56.652,404] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:00:58.632,415] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:01:01.609,069] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:01.619,140] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:02.588,073] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:04.580,200] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:01:04.590,087] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:01:04.600,006] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:05.556,823] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:01:07.547,546] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:01:07.557,403] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:08.521,423] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:09.513,671] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:10.505,767] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:01:11.501,068] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.
[00:01:11.510,925] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 58 bytes to modem socket.
[00:01:12.486,694] <dbg> slm_ppp: ppp_data_passing_thread: Forwarded 78 bytes to modem socket.

Is there any configuration that need to take care for PPP stability?

[Amol_Chor]

Michal 

Is there any information regarding this scenario? 

[Michal]

Hello,

Sorry for the delays. I had people look into it internally.and we will need some more logs. Here are more testing instructions:

Are you able to try to use LTE-M on the nRF9160, to see whether the issue may be about the use of NB-IoT by chance?

Then, about the debug logs, both modem traces and enabling of the following Kconfig options could help in seeing what's going on:

• CONFIG_NET_L2_PPP_LOG_LEVEL_DBG
• CONFIG_MODEM_MODULES_LOG_LEVEL_DBG

Best regards,

Michal