I am currently using the nRF9160 SLM firmware to send data over MQTT via datamode.
After connecting to the MQTT broker, I enter data mode using the following command: "AT#XMQTTPUB=\"topic",\"\",1,0","
I then send 16384 bytes of data to the nRF9160, which is followed by the default character terminator "+++" to trigger the send over the network.
All of these steps are successful in sending data to the MQTT broker, and I can confirm via quality of service 1 that the data is being sent. My issue is that during the client_write_msg() there is a significant delay that occurs during the sending process. This delay ranges from 5-15 seconds.
Here is a log depicting this delay:
[00:01:56.259,338] <inf> slm_at_host: Enter datamode [00:01:57.913,848] <inf> slm_at_host: Raw send: size_send: 16384, data 0x20034538 [00:01:57.922,363] <dbg> net_mqtt: mqtt_publish: (sysworkq): [CID 0x20018228]:[State 0x06]: >> Topic size 0x00000019, Data size 0x00004000 [00:01:57.935,882] <dbg> net_mqtt_enc: pack_utf8_str: (sysworkq): >> str_size:0000001b cur:0x2001b9e2, end:0x2001c9dd [00:01:57.947,387] <dbg> net_mqtt_enc: pack_uint16: (sysworkq): >> val:0019 cur:0x2001b9e2, end:0x2001c9dd [00:01:57.957,885] <dbg> net_mqtt_enc: pack_uint16: (sysworkq): >> val:000e cur:0x2001b9fd, end:0x2001c9dd [00:01:57.968,414] <dbg> net_mqtt_enc: mqtt_encode_fixed_header: (sysworkq): << msg type:0x32 length:0x0000401d [00:01:57.979,400] <dbg> net_mqtt_enc: packet_length_encode: (sysworkq): >> length:0x0000401d cur:(nil), end:(nil) [00:01:57.990,600] <dbg> net_mqtt_enc: mqtt_encode_fixed_header: (sysworkq): Fixed header length = 04 [00:01:58.000,732] <dbg> net_mqtt_enc: pack_uint8: (sysworkq): >> val:32 cur:0x2001b9de, end:0x2001c9dd [00:01:58.011,016] <dbg> net_mqtt_enc: packet_length_encode: (sysworkq): >> length:0x0000401d cur:0x2001b9df, end:0x2001c9dd [00:01:58.023,162] <dbg> net_mqtt: client_write_msg: (sysworkq): [0x20018228]: Transport writing message. [00:01:58.033,660] <inf> nrf_modem: send() fd 0x0, len 33, flags 0x0 (blocking) [00:01:58.050,933] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_OK [00:01:58.059,082] <inf> nrf_modem: send() fd 0x0, 33 bytes sent [00:01:58.066,589] <inf> nrf_modem: send() fd 0x0, len 2048, flags 0x0 (blocking) [00:01:58.078,369] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_OK [00:01:58.086,517] <inf> nrf_modem: send() fd 0x0, 2048 bytes sent [00:01:58.094,207] <inf> nrf_modem: send() fd 0x0, len 2048, flags 0x0 (blocking) [00:01:58.109,588] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_OK [00:01:58.117,736] <inf> nrf_modem: send() fd 0x0, 2048 bytes sent [00:01:58.125,396] <inf> nrf_modem: send() fd 0x0, len 2048, flags 0x0 (blocking) [00:01:58.136,932] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_OK [00:01:58.145,080] <inf> nrf_modem: send() fd 0x0, 2048 bytes sent [00:01:58.152,862] <inf> nrf_modem: send() fd 0x0, len 2048, flags 0x0 (blocking) [00:01:58.164,916] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl on [00:01:58.265,045] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_SSL_WANT_WRITE [00:02:02.754,425] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl off [00:02:02.763,214] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl on [00:02:02.863,342] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_SSL_WANT_WRITE [00:02:08.126,556] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl off [00:02:08.135,589] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl on [00:02:08.235,748] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_SSL_WANT_WRITE [00:02:08.521,606] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl off [00:02:08.530,548] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl on [00:02:08.630,706] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_SSL_WANT_WRITE [00:02:08.730,834] <inf> nrf_modem: RPC_IP_STATUS_NTF fd 0xff, RPC flow ctrl off [00:02:08.739,715] <inf> nrf_modem: RPC_IP_SEND_RES fd 0x0, result RPC_IP_ERR_OK [00:02:08.747,863] <inf> nrf_modem: send() fd 0x0, 2048 bytes sent
There is a ~4 second delay from [00:01:58.265,045] to [00:02:02.754,425], and following this is ~6 second delay from [00:02:02.863,342] to [00:02:08.126,556].
Looking at the log messages, it seems as though there is not enough space in the buffer to send the data and it is waiting until there is free space. What can I change to prevent this delay from occurring?
Here are my relevant configurations:
## SLM Configuration CONFIG_SLM_DATAMODE_URC=y CONFIG_SLM_DATAMODE_BUF_SIZE=16384 CONFIG_SLM_UART_RX_BUF_SIZE=4096 CONFIG_SLM_UART_RX_BUF_COUNT=8 CONFIG_SLM_DATAMODE_TERMINATOR="+++" CONFIG_SLM_MQTTC_MESSAGE_BUFFER_LEN=4096 ## nRF Modem Configuration CONFIG_NRF_MODEM_LIB_SHMEM_TX_SIZE=32768 CONFIG_NRF_MODEM_LIB_SHMEM_RX_SIZE=32768 CONFIG_NRF_MODEM_LIB_SENDMSG_BUF_SIZE=2048 CONFIG_AT_MONITOR_HEAP_SIZE=4096 CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=8192
Please let me know if there's any additional information I can add to aid this.