Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] OTA Subscribe failure to /jobs/notify-next #72

Closed
txf- opened this issue Feb 2, 2024 · 3 comments
Closed

[BUG] OTA Subscribe failure to /jobs/notify-next #72

txf- opened this issue Feb 2, 2024 · 3 comments

Comments

@txf-
Copy link

txf- commented Feb 2, 2024 •
edited

Describe the bug
Please provide a clear and concise description explaining the bug.

System information

  • Hardware board:ESP32_DevKitC_v4
  • IDE used: VSCode
  • Operating System: Linux
  • Code version: v202212.00-32-gb8cd609
  • Project/Demo: [ ota_over_mqtt_demo]
    -ESP-IDF: 5.0-release

Expected behavior
For OTA to get the job and start fetching segments

Screenshots or console output

I (1171) ota_over_mqtt_demo: OTA over MQTT demo, Application version 0.0.0
I (1171) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (1171) AWS_OTA: otaPal_GetPlatformImageState
I (1191) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (1191) esp_ota_ops: [0] aflags/seq:0x2/0x1, pflags/seq:0xffffffff/0x0
I (1201) AWS_OTA: Current State=[RequestingJob], Event=[Start], New state=[RequestingJob]
I (1221) wifi:wifi driver task: 3ffd8760, prio:23, stack:6656, core=0
I (1221) system_api: Base MAC address is not set
I (1221) system_api: read default base MAC address from EFUSE
I (1241) wifi:wifi firmware version: 8809d51
I (1241) wifi:wifi certification version: v7.0
I (1241) wifi:config NVS flash: enabled
I (1241) wifi:config nano formating: disabled
I (1251) wifi:Init data frame dynamic rx buffer num: 32
I (1251) wifi:Init static rx mgmt buffer num: 5
I (1261) wifi:Init management short buffer num: 32
I (1261) wifi:Init dynamic tx buffer num: 32
I (1261) wifi:Init static rx buffer size: 1600
I (1271) wifi:Init static rx buffer num: 10
I (1271) wifi:Init dynamic rx buffer num: 32
I (1281) wifi_init: rx ba win: 6
I (1281) wifi_init: tcpip mbox: 32
I (1281) wifi_init: udp mbox: 6
I (1291) wifi_init: tcp mbox: 6
I (1291) wifi_init: tcp tx win: 5760
I (1301) wifi_init: tcp rx win: 5760
I (1301) wifi_init: tcp mss: 1440
I (1301) wifi_init: WiFi IRAM OP enabled
I (1311) wifi_init: WiFi RX IRAM OP enabled
I (1311) wifi_prov_scheme_ble: BT memory released
I (1321) app_wifi: Already provisioned, starting Wi-Fi STA
I (1331) wifi_prov_scheme_ble: BTDM memory released
I (1331) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
I (1411) wifi:mode : sta (4c:11:ae:ef:ef:10)
I (1411) wifi:enable tsf
I (2191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (3191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (3821) wifi:new:<5,0>, old:<1,0>, ap:<255,255>, sta:<5,0>, prof:1
I (3831) wifi:state: init -> auth (b0)
I (3831) wifi:state: auth -> init (8a0)
I (3831) wifi:new:<5,0>, old:<5,0>, ap:<255,255>, sta:<5,0>, prof:1
I (3831) core_mqtt_agent_manager: WiFi disconnected.
I (3841) app_wifi: Disconnected. Connecting to the AP again...
I (4191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (5191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (6191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (6261) core_mqtt_agent_manager: WiFi disconnected.
I (6261) app_wifi: Disconnected. Connecting to the AP again...
I (7191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (8191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (8671) wifi:new:<5,0>, old:<5,0>, ap:<255,255>, sta:<5,0>, prof:1
I (8671) wifi:state: init -> auth (b0)
I (8671) wifi:state: auth -> assoc (0)
I (8681) wifi:state: assoc -> run (10)
I (8691) wifi:connected with [SSID], aid = 4, channel 5, BW20, bssid = c8:c7:c2:cd:ca:c9
I (8691) wifi:security: WPA2-PSK, phy: bgn, rssi: -30
I (8701) wifi:pm start, type: 1

I (8701) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (8711) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (8711) wifi:<ba-add>idx:0 (ifx:0, d8:47:32:5d:9a:99), tid:0, ssn:0, winSize:64
I (9191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (9711) core_mqtt_agent_manager: WiFi connected.
I (9711) app_wifi: Connected with IP Address:192.168.0.164
I (9711) esp_netif_handlers: sta ip: 192.168.0.164, mask: 255.255.255.0, gw: 192.168.0.1
I (9721) main_task: Returned from app_main()
I (9761) wifi:<ba-add>idx:1 (ifx:0, d8:47:32:5d:9a:99), tid:1, ssn:0, winSize:64
I (10191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (11191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (11471) coreMQTT: MQTT connection established with the broker.
I (11471) core_mqtt_agent_manager: Session present: 0

I (11471) ota_over_mqtt_demo: coreMQTT-Agent connected. Resuming OTA agent.
I (11481) core_mqtt_agent_manager: coreMQTT-Agent connected.
E (11641) coreMQTT: Call to receiveSingleIteration failed. Status=MQTTRecvFailed
E (11641) coreMQTT: MQTT operation failed with status MQTTRecvFailed

I (11641) ota_over_mqtt_demo: coreMQTT-Agent disconnected. Suspending OTA agent.
I (11651) core_mqtt_agent_manager: coreMQTT-Agent disconnected.
I (11651) core_mqtt_agent_manager: TLS connection was disconnected.
W (12191) AWS_OTA: OTA Timer handle NULL for Timerid=0, can't stop.
W (12191) AWS_OTA: OTA Timer handle NULL for Timerid=1, can't stop.
I (13631) coreMQTT: MQTT connection established with the broker.
I (13631) core_mqtt_agent_manager: Session present: 0

E (13631) ota_over_mqtt_demo: Failed to SUBSCRIBE to topic with error = 4.
I (13631) ota_over_mqtt_demo: coreMQTT-Agent connected. Resuming OTA agent.
E (13641) AWS_OTA: Failed to subscribe to MQTT topic: subscribe returned error: OtaMqttStatus_t=OtaMqttSubscribeFailed, topic=$aws/things/[ENDPOINT]-ats.iot.eu-west-1.amazonaws.com/jobs/notify-next
I (13641) core_mqtt_agent_manager: coreMQTT-Agent connected.
I (13661) AWS_OTA: Current State=[RequestingJob], Event=[RequestJobDocument], New state=[WaitingForJob]
I (13681) AWS_OTA: OTA Agent is suspended.
I (13681) AWS_OTA: Current State=[Suspended], Event=[Suspend], New state=[Suspended]
I (14191) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (15191) AWS_OTA: otaPal_GetPlatformImageState
I (15191) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (15191) esp_ota_ops: [0] aflags/seq:0x2/0x1, pflags/seq:0xffffffff/0x0
I (15191) AWS_OTA: Current State=[RequestingJob], Event=[Resume], New state=[RequestingJob]
I (15201) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
I (16211) ota_over_mqtt_demo:  Received: 0   Queued: 0   Processed: 0   Dropped: 0
E (16391) coreMQTT: Call to receiveSingleIteration failed. Status=MQTTRecvFailed
E (16391) coreMQTT: MQTT operation failed with status MQTTRecvFailed

I (16391) ota_over_mqtt_demo: coreMQTT-Agent disconnected. Suspending OTA agent.
I (16401) core_mqtt_agent_manager: coreMQTT-Agent disconnected.
I (16401) core_mqtt_agent_manager: TLS connection was disconnected.
W (17211) AWS_OTA: OTA Timer handle NULL for Timerid=1, can't stop.
I (19771) coreMQTT: MQTT connection established with the broker.
I (19771) core_mqtt_agent_manager: Session present: 1

Steps to reproduce bug
Basically I'm just running the demo as-is (but only with the ota demo active, I reduced the number of local buffers and the number of segments requested. I have used this exactly as-is in the past with no issues.

Additional context
The code then just loops between losing connection to the broker and failing to subscribe.
@txf- txf- changed the title [BUG] OTA Subscribe failure [BUG] OTA Subscribe failure to /jobs/notify-next Feb 2, 2024
@paulbartell
Copy link
Member

@txf- Thanks for the report. I will attempt to reproduce the problem.

@txf-
Copy link
Author

txf- commented Feb 5, 2024 •
edited

@txf- Thanks for the report. I will attempt to reproduce the problem.

Hi, There is no need to investigate. I have since determined that this was caused by incorrect permissions set in AWS. It works as-is

@paulbartell
Copy link
Member

@txf- Thanks for letting me know.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@txf- @paulbartell