I have a project with a nRF9160 and using its LTE modem to connect to a LWM2M server, based on the eclipse Leshan. I am using the lwm2m_rd_client.
I have noticed some problems when the server has restarted. If the server restarts the connection seems to be quietly lost (from the client's perspective). When the LWM2M lifetime times out, my client will try to update the registration, but will never get an ack from the server/modem. Even though the server is back up, the client has to go through all the retransmit attempts, without any replies. When the last retransmit also eventually fails, a Registration Update Timeout error is triggered, then forcing a completely new registration. This new registration succeeds.
Is this the expected behaviour?
What I would expect is to get some error from the modem back, either immediately when the server restarts, or when we try to do the update registration. For example, is this not a time were we could get a COAP_TYPE_RESET and therefore get a faster complete re-registration?
It seems like the update uses the socket function send and the registration uses the socket function connect. Is there some issue in the send implementation, or maybe rather how the modem replies to sends to a socket that has lost its peer connection (which is what I am assuming happens when the server restarts)?
Or do you suspect that my server is not responding correctly to the update request?
I have attached an excerpt from a log here, I have added some more prints in lwm2m_engine than just the ordinary ones. So just prior to this log start I have restarted my LWM2M server, but there are no notice of that in the logs. And then a little later, at the start of this log, we will try to do a update registration because the lifetime is about to time out. I have also decreased the coap retransmit try times, to 1 instead of the normal 4, to see the resolution more quickly.
[00:00:28.609,100] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:28.609,100] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:28.609,161] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:28.609,191] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2147483647 [00:00:29.109,344] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:29.109,375] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:29.109,436] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:29.109,436] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2147483647 [00:00:29.609,619] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:29.609,619] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:29.609,954] <dbg> net_lwm2m_engine: lwm2m_engine_get: path:1/0/1, buf:0x200310c4, buflen:4 [00:00:29.610,046] <dbg> net_lwm2m_rd_client: sm_send_registration: registration sent [MY_SERVER_IP_ADDR] [00:00:29.610,076] <wrn> net_lwm2m_engine: socket_loop, timeout: 393 [00:00:29.610,137] <inf> net_lwm2m_engine: Poll rc: 1 [00:00:29.610,168] <inf> net_lwm2m_engine: sock_fds[0].revents: 4 [00:00:29.610,382] <inf> net_lwm2m_engine: msg->type: 0 [00:00:29.610,382] <inf> net_lwm2m_engine: msg->message_timeout_cb: 0x51465 [00:00:29.619,323] <inf> net_lwm2m_engine: socket_send_message returned: 0 [00:00:29.619,354] <wrn> net_lwm2m_engine: socket_loop, timeout: 383 [00:00:29.619,354] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 10445 [00:00:29.709,594] <inf> lte_helpers: RRC mode: Connected [00:00:30.002,807] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:30.002,838] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:30.002,868] <wrn> net_lwm2m_engine: socket_loop, timeout: 107 [00:00:30.002,868] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 10062 [00:00:30.064,636] <inf> battery_monitor: Charge complete [00:00:30.110,076] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:30.110,076] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:30.110,137] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:30.110,137] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 9954 [00:00:30.610,321] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:30.610,351] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:30.610,412] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:30.610,412] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 9454 [00:00:31.110,595] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:31.110,626] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:31.110,656] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:31.110,687] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 8954 [00:00:31.610,839] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:31.610,839] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:31.610,900] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:31.610,900] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 8454 [00:00:32.111,083] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:32.111,083] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:32.111,114] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:32.111,145] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 7953 [00:00:32.611,328] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:32.611,358] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:32.611,419] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:32.611,419] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 7453 [00:00:33.111,602] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:33.111,602] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:33.111,663] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:33.111,663] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 6953 [00:00:33.611,846] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:33.611,846] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:33.611,877] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:33.611,907] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 6453 [00:00:34.112,091] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:34.112,121] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:34.112,182] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:34.112,182] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 5952 [00:00:34.612,365] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:34.612,365] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:34.612,426] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:34.612,426] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 5452 [00:00:35.112,609] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:35.112,609] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:35.112,640] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:35.112,670] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 4952 [00:00:35.167,816] <inf> lte_helpers: RRC mode: Idle [00:00:35.613,037] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:35.613,067] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:35.613,128] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:35.613,128] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 4451 [00:00:36.113,311] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:36.113,311] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:36.113,372] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:36.113,372] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 3951 [00:00:36.613,555] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:36.613,555] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:36.613,586] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:36.613,616] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 3451 [00:00:37.113,800] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:37.113,830] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:37.113,891] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:37.113,891] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2951 [00:00:37.614,074] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:37.614,074] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:37.614,135] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:37.614,135] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2450 [00:00:38.114,318] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:38.114,318] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:38.114,379] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:38.114,379] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 1950 [00:00:38.614,562] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:38.614,593] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:38.614,654] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:38.614,654] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 1450 [00:00:39.114,837] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:39.114,837] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:39.114,898] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:39.114,898] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 950 [00:00:39.615,081] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:39.615,081] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:39.615,112] <wrn> net_lwm2m_engine: socket_loop, timeout: 387 [00:00:39.615,142] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 449 [00:00:40.002,349] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:40.002,380] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:40.002,410] <wrn> net_lwm2m_engine: socket_loop, timeout: 113 [00:00:40.002,410] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 62 [00:00:40.064,605] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:40.064,605] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:40.064,636] <wrn> net_lwm2m_engine: socket_loop, timeout: 51 [00:00:40.064,697] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 0 [00:00:40.064,849] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:40.064,880] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:40.064,910] <wrn> net_lwm2m_engine: socket_loop, timeout: 51 [00:00:40.064,941] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 0 [00:00:40.065,063] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:40.065,093] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:40.065,124] <wrn> net_lwm2m_engine: socket_loop, timeout: 50 [00:00:40.065,124] <inf> net_lwm2m_engine: p->retries: 1 [00:00:40.065,155] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2147483647 [00:00:40.065,216] <inf> net_lwm2m_engine: Poll rc: 1 [00:00:40.065,216] <inf> net_lwm2m_engine: sock_fds[0].revents: 4 [00:00:40.065,246] <inf> net_lwm2m_engine: msg->type: 0 [00:00:40.065,246] <inf> net_lwm2m_engine: msg->message_timeout_cb: 0x51465 [00:00:40.065,338] <inf> battery_monitor: Charge complete [00:00:40.074,157] <inf> net_lwm2m_engine: socket_send_message returned: 0 [00:00:40.074,188] <wrn> net_lwm2m_engine: socket_loop, timeout: 41 [00:00:40.074,188] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 20900 [00:00:40.115,386] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:40.115,386] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:40.115,447] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:40.115,447] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 20859 [00:00:40.159,027] <inf> lte_helpers: RRC mode: Connected [00:00:40.615,234] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:40.615,264] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:40.615,325] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:40.615,325] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 20359 [00:00:41.115,509] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:41.115,509] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:41.115,570] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:41.115,570] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 19859 [00:00:41.615,753] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:41.615,753] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:41.615,814] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:41.615,814] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 19359 [00:00:42.115,997] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:42.116,027] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:42.116,088] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:42.116,088] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 18858 [00:00:42.616,271] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:42.616,271] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:42.616,333] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:42.616,333] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 18358 [00:00:43.116,516] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:43.116,516] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:43.116,577] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:43.116,577] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 17858 [00:00:43.616,760] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:43.616,790] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:43.616,851] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:43.616,851] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 17358 [00:00:44.117,034] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:44.117,034] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:44.117,095] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:44.117,095] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 16857 [00:00:44.617,279] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:44.617,279] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:44.617,309] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:44.617,340] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 16357 [00:00:45.117,523] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:45.117,553] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:45.117,614] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:45.117,614] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 15857 [00:00:45.617,797] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:45.617,797] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:45.617,858] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:45.617,858] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 15357 [00:00:45.800,292] <inf> lte_helpers: RRC mode: Idle [00:00:46.117,492] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:46.117,553] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:46.117,614] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:46.117,614] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 14857 [00:00:46.617,797] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:46.617,828] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:46.617,858] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:46.617,889] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 14357 [00:00:47.118,041] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:47.118,041] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:47.118,103] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:47.118,103] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 13856 [00:00:47.618,286] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:47.618,286] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:47.618,316] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:47.618,347] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 13356 [00:00:48.118,530] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:48.118,560] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:48.118,621] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:48.118,621] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 12856 [00:00:48.618,804] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:48.618,804] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:48.618,865] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:48.618,865] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 12356 [00:00:49.119,049] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:49.119,049] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:49.119,110] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:49.119,110] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 11855 [00:00:49.619,293] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:49.619,323] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:49.619,354] <wrn> net_lwm2m_engine: socket_loop, timeout: 383 [00:00:49.619,384] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 11355 [00:00:50.002,563] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:50.002,563] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:50.002,593] <wrn> net_lwm2m_engine: socket_loop, timeout: 117 [00:00:50.002,624] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 10972 [00:00:50.065,704] <inf> battery_monitor: Charge complete [00:00:50.119,781] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:50.119,812] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:50.119,873] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:50.119,873] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 10855 [00:00:50.620,056] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:50.620,086] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:50.620,147] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:50.620,147] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 10354 [00:00:51.120,330] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:51.120,330] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:51.120,391] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:51.120,391] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 9854 [00:00:51.620,574] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:51.620,574] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:51.620,605] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:51.620,635] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 9354 [00:00:52.120,819] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:52.120,849] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:52.120,910] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:52.120,910] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 8854 [00:00:52.621,093] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:52.621,093] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:52.621,154] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:52.621,154] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 8353 [00:00:53.121,337] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:53.121,337] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:53.121,398] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:53.121,398] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 7853 [00:00:53.621,582] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:53.621,612] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:53.621,673] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:53.621,673] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 7353 [00:00:54.121,856] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:54.121,856] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:54.121,917] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:54.121,917] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 6853 [00:00:54.622,100] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:54.622,100] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:54.622,161] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:54.622,161] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 6352 [00:00:55.122,344] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:55.122,375] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:55.122,436] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:55.122,436] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 5852 [00:00:55.622,619] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:55.622,619] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:55.622,680] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:55.622,680] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 5352 [00:00:56.122,863] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:56.122,863] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:56.122,924] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:56.122,924] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 4852 [00:00:56.623,107] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:56.623,138] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:56.623,168] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:56.623,199] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 4351 [00:00:57.123,352] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:57.123,352] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:57.123,413] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:57.123,413] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 3851 [00:00:57.623,596] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:57.623,596] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:57.623,657] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:57.623,657] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 3351 [00:00:58.123,840] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:58.123,870] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:58.123,931] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:58.123,931] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2851 [00:00:58.624,114] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:58.624,114] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:58.624,176] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:58.624,176] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2350 [00:00:59.124,359] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:59.124,359] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:59.124,420] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:00:59.124,420] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 1850 [00:00:59.624,603] <inf> net_lwm2m_engine: Poll rc: 0 [00:00:59.624,633] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:00:59.624,664] <wrn> net_lwm2m_engine: socket_loop, timeout: 378 [00:00:59.624,694] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 1350 [00:01:00.002,868] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:00.002,868] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:00.002,899] <wrn> net_lwm2m_engine: socket_loop, timeout: 122 [00:01:00.002,929] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 972 [00:01:00.066,040] <inf> battery_monitor: Charge complete [00:01:00.125,091] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:00.125,122] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:00.125,183] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:01:00.125,183] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 849 [00:01:00.625,366] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:00.625,396] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:00.625,457] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:01:00.625,457] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 349 [00:01:00.974,670] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:00.974,670] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:00.974,700] <wrn> net_lwm2m_engine: socket_loop, timeout: 151 [00:01:00.974,731] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 0 [00:01:00.974,792] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:00.974,822] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:00.974,853] <wrn> net_lwm2m_engine: socket_loop, timeout: 151 [00:01:00.974,884] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 0 [00:01:00.974,945] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:00.974,975] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:00.974,975] <wrn> net_lwm2m_engine: socket_loop, timeout: 151 [00:01:00.975,006] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 0 [00:01:00.975,067] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:00.975,097] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:00.975,097] <wrn> net_lwm2m_engine: socket_loop, timeout: 150 [00:01:00.975,128] <inf> net_lwm2m_engine: p->retries: 0 [00:01:00.975,128] <inf> net_lwm2m_engine: message_timeout_cb: 0x51465 [00:01:00.975,158] <wrn> net_lwm2m_rd_client: Registration Update Timeout [00:01:00.975,219] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 2147483647 [00:01:01.125,427] <inf> net_lwm2m_engine: Poll rc: 0 [00:01:01.125,427] <inf> net_lwm2m_engine: sock_fds[0].revents: 0 [00:01:01.132,537] <dbg> net_lwm2m_engine: lwm2m_engine_get: path:0/0/1, buf:0x2003109f, buflen:1 [00:01:01.132,629] <dbg> net_lwm2m_engine: lwm2m_engine_get: path:0/0/10, buf:0x20031116, buflen:2 [00:01:01.132,690] <inf> net_lwm2m_rd_client: RD Client started with endpoint '352656109477326' with client lifetime 30 [00:01:01.132,781] <dbg> net_lwm2m_engine: lwm2m_parse_peerinfo: Parse url: coaps://MY_SERVER_IP_ADDR:MY_PORT [00:01:01.219,970] <inf> lte_helpers: RRC mode: Connected [00:01:01.916,564] <dbg> net_lwm2m_engine: lwm2m_engine_get: path:1/0/1, buf:0x200310c4, buflen:4 [00:01:01.918,304] <dbg> net_lwm2m_rd_client: sm_send_registration: registration sent [MY_SERVER_IP_ADDR] [00:01:01.918,334] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:01:01.918,395] <inf> net_lwm2m_engine: Poll rc: 1 [00:01:01.918,395] <inf> net_lwm2m_engine: sock_fds[0].revents: 4 [00:01:01.918,609] <inf> net_lwm2m_engine: msg->type: 0 [00:01:01.918,640] <inf> net_lwm2m_engine: msg->message_timeout_cb: 0x51419 [00:01:01.919,891] <inf> net_lwm2m_engine: socket_send_message returned: 0 [00:01:01.919,921] <wrn> net_lwm2m_engine: socket_loop, timeout: 500 [00:01:01.919,952] <wrn> net_lwm2m_engine: socket_loop, next_retransmit: 12479 [00:01:02.074,615] <inf> net_lwm2m_engine: Poll rc: 1 [00:01:02.074,645] <inf> net_lwm2m_engine: sock_fds[0].revents: 1 [00:01:02.074,829] <dbg> net_lwm2m_engine: lwm2m_udp_receive: checking for reply from [MY_SERVER_IP_ADDR] [00:01:02.074,859] <dbg> net_lwm2m_rd_client: do_registration_reply_cb: Registration callback (code:2.1) [00:01:02.074,890] <inf> asset_tracker: Registration complete [00:01:02.074,920] <inf> net_lwm2m_rd_client: Registration Done (EP='zwoUPMuLdD') [00:01:02.075,012] <dbg> net_lwm2m_engine: lwm2m_udp_receive: reply 0x2001d214 handled and removed
I am using code based on NCS 1.8.0, and using modem v1.3.1.
Regards,
Andreas Pettersson
