Asset_tracker_v2 disconnect from AWS when shadow data is more than 2k

[Dmitry Pogodin]

Hello,

I'm using nRF SDK v1.6.0 with nRF9160 development board. I did minimum changes to Asset_Tracker_v2 application (enable debug log, set up for my aws account and to use my shadow).

After that, immediately after connecting to the cloud and requesting shadow data, application disconnect from the cloud with error code -128.

Here is a debug log:

[00:00:06.359,619] <dbg> cloud_module.connect_cloud: Connecting to cloud
[00:00:06.366,760] <wrn> cloud_module: Cloud connection establishment in progress
[00:00:06.374,908] <wrn> cloud_module: New connection attempt in 32 seconds if not successful
[00:00:06.384,155] <dbg> cloud_module.cloud_wrap_event_handler: CLOUD_WRAP_EVT_CONNECTING
[00:00:06.392,791] <inf> event_manager: CLOUD_EVT_CONNECTING
[00:00:06.553,192] <dbg> aws_iot.broker_init: IPv4 Address found 16.170.78.147
%CESQ: 62,3,23,3
[00:00:09.872,772] <dbg> aws_iot.connect_client: Using send socket timeout of 60 seconds
[00:00:09.881,225] <dbg> aws_iot.aws_e[00:00:10.073,486] <dbg> aws_iot.mqtt_evt_handler: MQTT client connected!
[00:00:10.080,596] <dbg> aws_iot.topic_subscribe: Subscribing to application topic: $aws/things/---/shadow/get/accepted
[00:00:10.094,696] <dbg> aws_iot.topic_subscribe: Subscribing to AWS shadow topic: $aws/things/---/shadow/update/delta
%CESQ: 61,3,17,2
[00:00:10.270,751] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_SUBACK: id = 2641 result = 0
[00:00:10.489,746] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_SUBACK: id = 3103 result = 0
[00:00:10.498,199] <dbg> aws_iot.0 aws_iot.device_shadow_document_request: Device shadow document requested
[00:00:10.518,676] <dbg> cloud_module.cloud_wrap_event_handler: CLOUD_WRAP_EVT_CONNECTED
[00:00:10.527,252] <inf> event_manager: CLOUD_EVT_CONNECTED
[00:00:10.533,721] <dbg> cloud_module.sub_state_set: Sub state transition SUB_STATE_CLOUD_DISCONNECTED --> SUB_STATE_CLOUD_CONNECTED
[00:00:10.754,211] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = -128
[00:00:10.762,420] <dbg> cloud_modulevent_handler: CLOUD_WRAP_EVT_DISCONNECTED
[00:00:10.771,270] <inf> event_manager: CLOUD_EVT_DISCONNECTED
[00:00:10.777,893] <dbg> aws_iot.aws_iot_cloud_poll: The cloud socket is already closed.
[00:00:10.786,346] <dbg> cloud_module.sub_state_set: Sub state transition SUB_STATE_CLOUD_CONNECTED --> SUB_STATE_CLOUD_DISCONNECTED
[00:00:10.798,706] <dbg> cloud_module.connect_check_work_fn: Cloud connection timeout occurred
[00:00:10.807,769] <inf> event_manager: CLOUD_EVT_CONNECTION_TIMEOUT

Here is my changes in prj.conf:

...

# # AWS IoT
# ## Mandatory application specific configurations for AWS_IOT.
CONFIG_AWS_IOT=y
CONFIG_AWS_IOT_TOPIC_UPDATE_DELTA_SUBSCRIBE=y
# CONFIG_AWS_IOT_TOPIC_GET_REJECTED_SUBSCRIBE=y
CONFIG_AWS_IOT_AUTO_DEVICE_SHADOW_REQUEST=y
CONFIG_AWS_IOT_MQTT_RX_TX_BUFFER_LEN=2048
CONFIG_AWS_IOT_MQTT_PAYLOAD_BUFFER_LEN=2048
CONFIG_AWS_IOT_APP_SUBSCRIPTION_LIST_COUNT=1
CONFIG_AWS_IOT_CLIENT_ID_APP=y
# CONFIG_AWS_FOTA=y

# ## AWS IoT options that must be configured.
CONFIG_AWS_IOT_SEC_TAG=42
CONFIG_AWS_IOT_BROKER_HOST_NAME="---.amazonaws.com"
CONFIG_AWS_IOT_CLIENT_ID_STATIC="---"
CONFIG_CLOUD_CLIENT_ID="---"
CONFIG_CLOUD_CLIENT_ID_USE_CUSTOM=y

....

# nRF Cloud
CONFIG_NRF_CLOUD=n
CONFIG_AGPS=n
CONFIG_AGPS_SRC_NRF_CLOUD=n
CONFIG_NRF_CLOUD_AGPS=n
## Because PGPS consumes a lot of data its disabled by default.
CONFIG_NRF_CLOUD_PGPS=n
CONFIG_NRF_CLOUD_CONNECTION_POLL_THREAD=n
CONFIG_NRF_CLOUD_SEND_TIMEOUT=n
CONFIG_GPS_MODULE_NMEA=n

....

CONFIG_CLOUD_CODEC_LOG_LEVEL_DBG=y
CONFIG_CLOUD_MODULE_LOG_LEVEL_DBG=y
CONFIG_AWS_IOT_LOG_LEVEL_DBG=y
CONFIG_MQTT_LOG_LEVEL_DBG=y
CONFIG_BOOT_DELAY=3000

And changes in aws_iot_integration.c:

#define CFG_TOPIC AWS "%s/shadow/get/accepted"
#define CFG_TOPIC_LEN (AWS_LEN + AWS_CLOUD_CLIENT_ID_LEN + 20)

This problem is not related to the cloud settings as reducing shadow data size eliminate this issue. It's all about some buffer or another limit on application side.

So far I was able to trace the problem down to mqtt_client_tls_read function() from mqtt_transport_socket_tls.c file in which zsock_recv() call return 0, when shadow data was sent from AWS.

I've tried all different CONFIG_xxx_ LOG_LEVEL_DBG settings, but wasn't able to see any further information, why zsock_recv() may silently skip incoming data.

[Charlie]

Could be related, did you test with a bigger message size?

Best regards,

Charlie

[Dmitry Pogodin]

I can't. It's a define in header file for pre-compiled modem library.

[Charlie]

MQTT messages can be divided into several TCP packages. NRF_MODEM_TLS_MAX_MESSAGE_SIZ decides max size per message, and you can try to adjust the following parameters to adjust the max size of one MQTT message:

CONFIG_AWS_IOT_MQTT_RX_TX_BUFFER_LEN=2048
CONFIG_AWS_IOT_MQTT_PAYLOAD_BUFFER_LEN=2048

Best regards,

Charlie

[Dmitry Pogodin]

I've tried setting those two parameters for 2048 and 1024 - no visible change. Disconnect right after requested shadow data arrived.

Can it be so that AWS cloud use predefined, non negotiable TLS message size? And therefore there is no other way to fix the problem as to increase or better allow user to configure MAX TLS message size in Nordic's modem library?

PS: any way I think it will be nice to have a warning when modem/TLS library decide to reject incoming message. Also I think that have a runtime check for the two above mentioned parameters that they should be less than MAX TLS (if TLS connection is selected) can be good as well.

[Charlie]

Why don't your increase them since your shadow data is more than 2k? 2048 maybe still not be enough.

Best regards,

Charlie

[Dmitry Pogodin]

Because NS pre-compiled modem library has NRF_MODEM_TLS_MAX_MESSAGE_SIZE set to 2048 and I have no control on that parameter. However, of course, I've tried setting CONFIG_AWS_IOT_MQTT_RX_TX_BUFFER_LEN and CONFIG_AWS_IOT_MQTT_PAYLOAD_BUFFER_LEN for up to 8k with no effect.

[Charlie]

NRF_MODEM_TLS_MAX_MESSAGE_SIZE  doesn't affect this issue since it only decides the TCP package max size, and one MQTT message will be divided into several TCP packages if it is very bigger than NRF_MODEM_TLS_MAX_MESSAGE_SIZE.

How did you modify the Asset_Tracker_v2 application to increase shadow data is more than 2k? I will try to set up a similar experimental environment to recreate this issue.

Best regards,

Charlie

[Dmitry Pogodin]

Just manually write some JSON data on AWS IoT Core console.

[Dmitry Pogodin]

And one more thing - I'm pretty sure that CONFIG_AWS_IOT_MQTT_RX_TX_BUFFER_LEN and CONFIG_AWS_IOT_MQTT_PAYLOAD_BUFFER_LEN not related to the problem as it's zsock_recv() function which returns 0.