subscribing in Assert tracker v2

[Mustafa]

Hello,

I'm trying to send messages from the cloud (AWS-IoT ) to the device, so I modified the device so that it subscribes to a new topic and when I send messages from could, it seems that the device doesn't listen frequently to the cloud. sometimes it receives a message, sometimes not. and when I sent multi messages very fast, the device receive all messages after a random delay. 

I tried to check the code if there is any configuration I can use to force the device to listen to Cloud always. but without luck. This behavior is in Active and Passive mode as well. 

My question is: How can the device receive messages instantly from the cloud without delay. 

Thanks in advance.

[Markus Tacker (he/him)]

Hei Mustafa,

this might be due to the device going into PSM, or if you are on NB-IoT the NAT timing out. You can experiment with lowering the MQTT keepalive time (CONFIG_MQTT_KEEPALIVE). However this increases energy consumption.

[Mustafa]

Thank you Markus for your tips. I"m actually using LTE-m.
I've realized that the cloud doesn't receive any message from the device side when I modify CONFIG_MQTT_KEEPALIVE to more than 130 sec. The device behaves normally and logs output confirm that message has been published, but from the cloud-side, no message is received. Any hints for this problem. 

[Markus Tacker (he/him)]

Not really sure what is causing this with the limited information at hand.

If the device is not disconnected from the broker when it sends PINGREQs after keep alive > 130 secs, it indicates that the NAT rule and TLS session are at least alive.
However some networks even drop TCP packets silently.

It would be great if you could provide more details:

1. What SIM are you using?
2. Which network?
3. Please provide logs from the application,
4. and ideally a modem trace.

[Mustafa]

Hello Markus,

I use iBasis sim in the Netherlands 

the log file and modem trace are here below. Thanks

[00:00:00.658,325] <inf> event_manager: MODEM_EVT_LTE_CONNECTING
[00:00:02.131,439] <inf> event_manager: MODEM_EVT_LTE_DISCONNECTED
[00:00:02.138,977] <inf> event_manager: MODEM_EVT_LTE_CELL_UPDATE
[00:00:03.256,195] <inf> event_manager: MODEM_EVT_LTE_CONNECTED
[00:00:03.266,052] <inf> event_manager: MODEM_EVT_LTE_PSM_UPDATE
[00:00:03.283,081] <dbg> cloud_module.state_set: State transition STATE_LTE_DISCONNECTED --> STATE_LTE_CONNECTED
[00:00:03.294,158] <dbg> cloud_module.connect_cloud: Connecting to cloud
[00:00:03.301,635] <wrn> cloud_module: Cloud connection establishment in progress
[00:00:03.310,485] <wrn> cloud_module: New connection attempt in 32 seconds if not successful
[00:00:03.320,190] <dbg> aws_iot_integration.aws_iot_event_handler: AWS_IOT_EVT_CONNECTING
[00:00:03.329,284] <dbg> cloud_module.cloud_wrap_event_handler: CLOUD_WRAP_EVT_CONNECTING
[00:00:03.338,378] <inf> event_manager: CLOUD_EVT_CONNECTING
[00:00:06.242,431] <dbg> aws_iot_integration.aws_iot_event_handler: AWS_IOT_EVT_CONNECTED
[00:00:06.415,985] <dbg> aws_iot_integration.aws_iot_event_handler: AWS_IOT_EVT_READY
[00:00:06.428,894] <dbg> cloud_module.cloud_wrap_event_handler: CLOUD_WRAP_EVT_CONNECTED
[00:00:06.438,568] <inf> event_manager: CLOUD_EVT_CONNECTED
[00:00:06.446,502] <dbg> cloud_module.sub_state_set: Sub state transition SUB_STATE_CLOUD_DISCONNECTED --> SUB_STATE_CLOUD_CONNECTED
[00:00:06.592,346] <inf> event_manager: DATA_EVT_DATE_TIME_OBTAINED
[00:00:06.611,938] <inf> event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, GNSS, MOD_STAT)
[00:00:06.642,974] <inf> event_manager: GPS_EVT_ACTIVE
[00:00:06.649,078] <dbg> gps_module.sub_state_set: Sub state transition SUB_STATE_IDLE --> SUB_STATE_SEARCH
[00:00:06.660,400] <dbg> gps_module.gps_event_handler: GPS_EVT_SEARCH_STARTED
[00:00:06.668,457] <dbg> gps_module.gps_event_handler: GPS_EVT_AGPS_DATA_NEEDED
[00:00:06.676,666] <inf> event_manager: GPS_EVT_AGPS_NEEDED
[00:00:06.683,532] <dbg> sensor_module.environmental_data_get: No external sensors, submitting dummy sensor data
[00:00:06.697,967] <inf> event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED
[00:00:06.706,390] <inf> agps: SUPL is initialized
[00:00:06.803,039] <inf> event_manager: MODEM_EVT_MODEM_STATIC_DATA_READY
[00:00:06.897,521] <inf> agps: Starting SUPL session
[00:00:06.934,448] <inf> event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY
[00:00:06.945,373] <dbg> cloud_codec_ringbuffer.cloud_codec_populate_modem_dynamic_buffer: Entry: 1 of 2 in dynamic modem buffer filled
[00:00:07.071,136] <inf> event_manager: MODEM_EVT_BATTERY_DATA_READY
[00:00:07.204,376] <dbg> cloud_codec_ringbuffer.cloud_codec_populate_bat_buffer: Entry: 1 of 2 in battery buffer filled
[00:00:07.646,820] <dbg> gps_module.gps_event_handler: GPS_EVT_OPERATION_BLOCKED
[00:00:09.066,253] <inf> agps: SUPL session finished successfully
[00:00:21.420,227] <dbg> gps_module.gps_event_handler: GPS_EVT_OPERATION_UNBLOCKED
[00:01:00.363,952] <inf> event_manager: APP_EVT_ACTIVITY_DETECTION_ENABLE
[00:01:21.706,359] <inf> event_manager: DATA_EVT_DATA_READY
[00:01:21.780,334] <inf> event_manager: DATA_EVT_DATA_SEND
[00:01:21.787,261] <dbg> cloud_codec.cloud_codec_encode_batch_data: No data to encode, JSON string empty...
[00:01:21.834,259] <wrn> cloud_module:  Data sent, data pointer: 0x200201f8
[00:01:21.912,475] <inf> event_manager: CLOUD_EVT_DATA_ACK
[00:01:25.534,332] <dbg> gps_module.gps_event_handler: GPS_EVT_SEARCH_TIMEOUT
[00:01:25.542,358] <inf> event_manager: GPS_EVT_TIMEOUT
[00:01:25.548,614] <inf> event_manager: GPS_EVT_INACTIVE
[00:01:25.554,901] <dbg> gps_module.sub_state_set: Sub state transition SUB_STATE_SEARCH --> SUB_STATE_IDLE
[00:01:25.565,704] <inf> event_manager: DATA_EVT_DATA_READY
[00:01:25.572,723] <dbg> cloud_codec.cloud_codec_encode_data: No data to encode, JSON string empty...
[00:10:00.363,952] <inf> event_manager: APP_EVT_DATA_GET_ALL
[00:10:00.370,910] <inf> event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, GNSS)
[00:10:00.441,284] <inf> event_manager: GPS_EVT_ACTIVE
[00:10:00.447,418] <dbg> gps_module.sub_state_set: Sub state transition SUB_STATE_IDLE --> SUB_STATE_SEARCH
[00:10:00.458,312] <dbg> sensor_module.environmental_data_get: No external sensors, submitting dummy sensor data
[00:10:00.489,593] <inf> event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED
[00:10:00.545,013] <inf> event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_NOT_READY
[00:10:00.599,121] <inf> event_manager: MODEM_EVT_BATTERY_DATA_READY
[00:10:00.606,811] <dbg> cloud_codec_ringbuffer.cloud_codec_populate_bat_buffer: Entry: 2 of 2 in battery buffer filled
[00:11:04.505,828] <dbg> gps_module.gps_event_handler: GPS_EVT_SEARCH_TIMEOUT
[00:11:04.513,885] <inf> event_manager: GPS_EVT_TIMEOUT
[00:11:04.520,141] <inf> event_manager: GPS_EVT_INACTIVE
[00:11:04.526,458] <dbg> gps_module.sub_state_set: Sub state transition SUB_STATE_SEARCH --> SUB_STATE_IDLE
[00:11:04.537,261] <inf> event_manager: DATA_EVT_DATA_READY
[00:11:04.561,706] <inf> event_manager: DATA_EVT_DATA_SEND
[00:11:04.568,664] <dbg> cloud_codec.cloud_codec_encode_batch_data: No data to encode, JSON string empty...
[00:11:04.615,417] <wrn> cloud_module:  Data sent, data pointer: 0x2001fc98
[00:11:04.665,466] <inf> event_manager: CLOUD_EVT_DATA_ACK
[00:11:05.086,456] <inf> event_manager: MODEM_EVT_LTE_CELL_UPDATE
[00:11:32.287,109] <inf> event_manager: MODEM_EVT_LTE_CELL_UPDATE

trace-2021-09-23T05-57-18.559Z.rar

[Markus Tacker (he/him)]

Hei, thanks for the trance. It was in parts corrupted, maybe due to UART issues, but I'll forward it internally for some analysis.

[Markus Tacker (he/him)]

Which modem firmware version are you running?

[Mustafa]

it is version 1.3.0

[Markus Tacker (he/him)]

Thanks!