AWS does not recover from disconnect (IDFGH-13132) (CA-340)

[MarkMendelsohn]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

ESP-IDF v5.1.2-89-g5c61c89308-dirty 2nd stage bootloader

Espressif SoC revision.

Chip is ESP32-S3 (QFN56) (revision v0.1)

Operating System used.

macOS

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-S3-DevKitC-1

Power Supply used.

USB

What is the expected behavior?

Recover when AWS or Wifi connection is lost

What is the actual behavior?

Looks like AWS tried to recover but the 0x004C event occurred again right after the recovery just completed and then was not tried again.

Steps to reproduce.

Every couple of days AWS seems to disconnect

Debug Logs.

I (263244) coreMQTT: Ack packet deserialized with result: MQTTSuccess.
I (263244) coreMQTT: State record updated. New state=MQTTPublishDone.
I (263244) AWS_OTA: PUBACK received for packet id 68.
I (263254) AWS_OTA: Sent PUBLISH packet to broker $aws/things/dev-johndoe/shadow/update to broker.
I (263264) coreMQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess.
I (263274) coreMQTT: State record updated. New state=MQTTPublishDone.
I (263274) coreMQTT: Invoking subscription callback of matching topic filter: TopicFilter=$aws/things/dev-johndoe/shadow/update/documents, TopicName=$aws/things/dev-johndoe/shadow/update/documents
update_docs
I (263314) coreMQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess.
I (263324) coreMQTT: State record updated. New state=MQTTPublishDone.
I (263324) coreMQTT: Invoking subscription callback of matching topic filter: TopicFilter=$aws/things/dev-johndoe/shadow/update/accepted, TopicName=$aws/things/dev-johndoe/shadow/update/accepted
update_acc
-processLoopWithTimeout
-processLoopWithTimeout
datetime 1718730362
timestamp 1718730362
save nvs_open 0
nvs_get_blob 0 16
nvs_set_blob 0
E (282964) CLOUD: done sending
save nvs_open 0
nvs_get_blob 0 16
E (283014) esp-tls-mbedtls: read error :-0x004C:
E (283014) esp-tls-mbedtls: read error :-0x004C:
E (283254) esp-tls-mbedtls: read error :-0x004C:
E (283294) esp-tls-mbedtls: read error :-0x004C:
W (283304) AWS_OTA: Publish failed. Retrying connection after 317 ms backoff.
nvs_set_blob 0
E (283614) esp-tls-mbedtls: read error :-0x004C:
W (283614) AWS_OTA: Publish failed. Retrying connection after 450 ms backoff.
E (284064) esp-tls-mbedtls: read error :-0x004C:
W (284064) AWS_OTA: Publish failed. Retrying connection after 1472 ms backoff.
-processLoopWithTimeout
E (285534) esp-tls-mbedtls: read error :-0x004C:
E (285534) AWS_OTA: Publish failed, all attempts exhausted.
E (285544) AWS_OTA: Failed to send PUBLISH packet to broker with error = 4.
E (285554) AWS_OTA: MQTT_ProcessLoop returned with status = Invalid MQTT Status code.
I (285564) AWS_OTA: Disconnecting the MQTT connection with a380i996o62146-ats.iot.us-east-2.amazonaws.com.
I (285574) coreMQTT: Disconnected from the broker.
W (285574) AWS_OTA: OTA Timer handle NULL for Timerid=0, can't stop.
W (285584) AWS_OTA: OTA Timer handle NULL for Timerid=1, can't stop.
I (285594) AWS_OTA: OTA Agent is suspended.
I (285594) AWS_OTA: Establishing a TLS session to a380i996o62146-ats.iot.us-east-2.amazonaws.com:8883.
I (285594) AWS_OTA: Current State=[Suspended], Event=[Suspend], New state=[Suspended]
I (287004) AWS_OTA: Creating an MQTT connection to a380i996o62146-ats.iot.us-east-2.amazonaws.com.
I (287234) coreMQTT: MQTT connection established with the broker.
I (287234) AWS_OTA: MQTT connection successfully established with broker.
I (287244) AWS_OTA: otaPal_GetPlatformImageState
I (287244) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (287254) esp_ota_ops: [0] aflags/seq:0x2/0x1, pflags/seq:0xffffffff/0x0
I (287264) AWS_OTA: Current State=[RequestingJob], Event=[Resume], New state=[RequestingJob]
custom_mqtt_subscriptions: dev-johndoe $aws/things/
shadow_topic_str_delete_acc: dev-johndoe /shadow
shadow_topic_str_delete_acc: $aws/things/dev-johndoe/shadow/delete/accepted
E (287284) coreMQTT: Failed to register callback: Record for topic filter already exists: TopicFilter=$aws/things/dev-johndoe/shadow/delete/accepted
I (287304) AWS_OTA: SUBSCRIBE topic $aws/things/dev-johndoe/shadow/delete/accepted to broker.
E (287324) coreMQTT: Failed to register callback: Record for topic filter already exists: TopicFilter=$aws/things/dev-johndoe/shadow/delete/rejected
I (288144) AWS_OTA: SUBSCRIBE topic $aws/things/dev-johndoe/shadow/update/rejected to broker.
I (288144) AWS_OTA: Received SUBACK.
E (288154) coreMQTT: Failed to register callback: Record for topic filter already exists: TopicFilter=$aws/things/dev-johndoe/shadow/update/delta
I (288364) AWS_OTA: Received SUBACK.
I (288374) AWS_OTA: SUBSCRIBE topic $aws/things/dev-johndoe/shadow/update/delta to broker.
E (288374) coreMQTT: Failed to register callback: Record for topic filter already exists: TopicFilter=$aws/things/dev-johndoe/shadow/update/documents
I (288384) AWS_OTA: SUBSCRIBE topic $aws/things/dev-johndoe/shadow/update/documents to broker.
I (288394) AWS_OTA: Received SUBACK.
I (288404) AWS_OTA: Sent PUBLISH packet to broker $aws/things/dev-johndoe/shadow/get to broker.
-custom_mqtt_subscriptions: is_up true
I (288414) AWS_OTA: SUBSCRIBE topic $aws/things/dev-johndoe/jobs/notify-next to broker.
E (288424) coreMQTT: Failed to register callback: Record for topic filter already exists: TopicFilter=$aws/things/+/jobs/#
W (288444) AWS_OTA: Failed to register a callback to subscription manager with error = 3.
I (288454) AWS_OTA: Subscribed to MQTT topic: $aws/things/dev-johndoe/jobs/notify-next
I (288634) coreMQTT: Ack packet deserialized with result: MQTTSuccess.
I (288634) coreMQTT: State record updated. New state=MQTTPublishDone.
I (288644) AWS_OTA: PUBACK received for packet id 81.
I (288654) coreMQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess.
I (288674) coreMQTT: State record updated. New state=MQTTPublishDone.
I (288674) coreMQTT: Invoking subscription callback of matching topic filter: TopicFilter=$aws/things/dev-johndoe/shadow/get/accepted, TopicName=$aws/things/dev-johndoe/shadow/get/accepted
get_acc
auto
45
24
I (288844) AWS_OTA: Sent PUBLISH packet to broker $aws/things/dev-johndoe/jobs/$next/get to broker.
I (288854) AWS_OTA: Current State=[WaitingForJob], Event=[RequestJobDocument], New state=[WaitingForJob]
I (288844) AWS_OTA: Received SUBACK.
I (288884) AWS_OTA: Received SUBACK.
I (288894) AWS_OTA: Received SUBACK.
I (288894) coreMQTT: Ack packet deserialized with result: MQTTSuccess.
I (288904) coreMQTT: State record updated. New state=MQTTPublishDone.
I (288904) AWS_OTA: PUBACK received for packet id 83.
prvSensorTask msg 7 
I (288924) flow_cntrl.c: exiting auto monitoring loop in monitor_task_event_source()
prvWifiTask msg 7
-processLoopWithTimeout
I (289914) coreMQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess.
I (289914) coreMQTT: State record updated. New state=MQTTPublishDone. 
I (289914) coreMQTT: Invoking subscription callback of matching topic filter: TopicFilter=$aws/things/+/jobs/#, TopicName=$aws/things/dev-johndoe/jobs/$next/get/accepted
I (289934) AWS_OTA: No active job available in received job document: OtaJobParseErr_t=OtaJobParseErrNoActiveJobs
I (289944) AWS_OTA: otaPal_GetPlatformImageState
I (289944) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (289954) esp_ota_ops: [0] aflags/seq:0x2/0x1, pflags/seq:0xffffffff/0x0
I (289964) AWS_OTA: Current State=[WaitingForJob], Event=[ReceivedJobDocument], New state=[CreatingFile]
W (290074) AWS_OTA: PINGRESP should not be handled by the application callback when using MQTT_ProcessLoop.
I (290074) AWS_OTA: Sent PUBLISH packet to broker $aws/things/dev-johndoe/shadow/update to broker.
I (290174) coreMQTT: Ack packet deserialized with result: MQTTSuccess.
I (290174) coreMQTT: State record updated. New state=MQTTPublishDone.
I (290174) AWS_OTA: PUBACK received for packet id 84.
I (290184) coreMQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess.
I (290194) coreMQTT: State record updated. New state=MQTTPublishDone.
I (290204) coreMQTT: Invoking subscription callback of matching topic filter: TopicFilter=$aws/things/dev-johndoe/shadow/update/documents, TopicName=$aws/things/dev-johndoe/shadow/update/documents
update_docs
I (290234) coreMQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess.
I (290244) coreMQTT: State record updated. New state=MQTTPublishDone.
I (290254) coreMQTT: Invoking subscription callback of matching topic filter: TopicFilter=$aws/things/dev-johndoe/shadow/update/accepted, TopicName=$aws/things/dev-johndoe/shadow/update/accepted
update_acc
E (296014) esp-tls-mbedtls: read error :-0x004C:
E (296014) esp-tls-mbedtls: read error :-0x004C:
E (296014) esp-tls-mbedtls: read error :-0x004C:

More Information.

No response