search

Azure-Samples / iot-middleware-freertos-samples

This repo has samples for dev kits using the Azure IoT middleware for FreeRTOS
MIT License
76 stars 46 forks source link

ESPRESSIF ADU sample fails to deploy #394

Closed florianhumblot closed 3 months ago

florianhumblot commented 3 months ago

Please provide us with the following information:

This issue is for a: (mark with an x)

- [x] bug report -> please search issues before submitting
- [ ] feature request
- [ ] documentation issue or request
- [ ] regression (a behavior that used to work and stopped in a new release)

Minimal steps to reproduce

Any log messages given by the failure

Full log from first boot, through upgrade process and reboot SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd5820,len:0x1714 load:0x403cc710,len:0x968 load:0x403ce710,len:0x2f9c entry 0x403cc710 I (24) boot: ESP-IDF v5.1.3-416-gd23b7a0361 2nd stage bootloader I (24) boot: compile time Aug 20 2024 07:02:20 I (25) boot: chip revision: v0.4 I (29) boot.esp32c3: SPI Speed : 80MHz I (34) boot.esp32c3: SPI Mode : DIO I (38) boot.esp32c3: SPI Flash Size : 4MB I (43) boot: Enabling RNG early entropy source... I (48) boot: Partition Table: I (52) boot: ## Label Usage Type ST Offset Length I (59) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (67) boot: 1 otadata OTA data 01 00 0000f000 00002000 I (74) boot: 2 phy_init RF data 01 01 00011000 00001000 I (82) boot: 3 factory factory app 00 00 00020000 00100000 I (89) boot: 4 ota_0 OTA app 00 10 00120000 00100000 I (97) boot: 5 ota_1 OTA app 00 11 00220000 00100000 I (104) boot: End of partition table I (108) boot: Defaulting to factory image I (113) esp_image: segment 0: paddr=00020020 vaddr=3c0c0020 size=2e850h (190544) map I (152) esp_image: segment 1: paddr=0004e878 vaddr=3fc90e00 size=017a0h ( 6048) load I (154) esp_image: segment 2: paddr=00050020 vaddr=42000020 size=bd174h (774516) map I (284) esp_image: segment 3: paddr=0010d19c vaddr=3fc925a0 size=016f4h ( 5876) load I (285) esp_image: segment 4: paddr=0010e898 vaddr=40380000 size=10cc4h ( 68804) load I (308) boot: Loaded app from partition at offset 0x20000 I (308) boot: Disabling RNG early entropy source... I (320) cpu_start: Unicore app I (320) cpu_start: Pro cpu up. I (329) cpu_start: Pro cpu start user code I (329) cpu_start: cpu freq: 160000000 Hz I (329) cpu_start: Application information: I (332) cpu_start: Project name: azure_iot_freertos_esp32 I (338) cpu_start: App version: 1 I (343) cpu_start: Compile time: Aug 20 2024 07:05:45 I (349) cpu_start: ELF file SHA256: b380be4be47953c3... I (355) cpu_start: ESP-IDF: v5.1.3-416-gd23b7a0361 I (361) cpu_start: Min chip rev: v0.3 I (366) cpu_start: Max chip rev: v1.99 I (370) cpu_start: Chip rev: v0.4 I (375) heap_init: Initializing. RAM available for dynamic allocation: I (382) heap_init: At 3FC9C8B0 len 00023750 (141 KiB): DRAM I (389) heap_init: At 3FCC0000 len 0001C710 (113 KiB): DRAM/RETENTION I (396) heap_init: At 3FCDC710 len 00002950 (10 KiB): DRAM/RETENTION/STACK I (403) heap_init: At 50000010 len 00001FD8 (7 KiB): RTCRAM I (410) spi_flash: detected chip: generic I (414) spi_flash: flash io: dio I (419) sleep: Configure to isolate all GPIO pins in sleep state I (425) sleep: Enable automatic switching of GPIO sleep configuration I (432) app_start: Starting scheduler on CPU0 I (437) main_task: Started on CPU0 I (437) main_task: Calling app_main() I (547) pp: pp rom version: 9387209 I (547) net80211: net80211 rom version: 9387209 I (557) wifi:wifi driver task: 3fca4f94, prio:23, stack:6656, core=0 I (557) wifi:wifi firmware version: 92daf4348 I (557) wifi:wifi certification version: v7.0 I (557) wifi:config NVS flash: enabled I (557) wifi:config nano formating: disabled I (567) wifi:Init data frame dynamic rx buffer num: 32 I (567) wifi:Init static rx mgmt buffer num: 5 I (567) wifi:Init management short buffer num: 32 I (577) wifi:Init dynamic tx buffer num: 32 I (577) wifi:Init static tx FG buffer num: 2 I (587) wifi:Init static rx buffer size: 1600 I (587) wifi:Init static rx buffer num: 10 I (597) wifi:Init dynamic rx buffer num: 32 I (597) wifi_init: rx ba win: 6 I (597) wifi_init: tcpip mbox: 32 I (607) wifi_init: udp mbox: 6 I (607) wifi_init: tcp mbox: 6 I (607) wifi_init: tcp tx win: 5760 I (617) wifi_init: tcp rx win: 5760 I (617) wifi_init: tcp mss: 1440 I (627) wifi_init: WiFi IRAM OP enabled I (627) wifi_init: WiFi RX IRAM OP enabled I (637) sample_azureiotkit: Connecting to ... I (637) phy_init: phy_version 1150,7c3c08f,Jan 24 2024,17:32:21 I (677) wifi:mode : sta (74:4d:bd:fd:1f:c4) I (677) wifi:enable tsf I (687) sample_azureiotkit: Waiting for IP(s) I (3087) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1 I (3397) wifi:state: init -> auth (b0) I (3407) wifi:state: auth -> assoc (0) I (3417) wifi:state: assoc -> run (10) I (3467) wifi:connected with , aid = 1, channel 11, BW20, bssid = 78:8a:20:49:91:a7 I (3467) wifi:security: WPA2-PSK, phy: bgn, rssi: -59 I (3467) wifi:pm start, type: 1 I (3467) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us I (3477) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 25000, mt_pti: 0, mt_time: 10000 I (3517) wifi:idx:0 (ifx:0, 78:8a:20:49:91:a7), tid:0, ssn:0, winSize:64 I (3537) wifi:AP's beacon interval = 102400 us, DTIM period = 1 I (4487) esp_netif_handlers: sample_azureiotkit: sta ip: .224, mask: 255.255.255.0, gw: .1 I (4487) sample_azureiotkit: Got IPv4 event: Interface "sample_azureiotkit: sta" address: .224 I (4497) sample_azureiotkit: Connected to sample_azureiotkit: sta I (4497) sample_azureiotkit: - IPv4 address: .224 I (4507) sample_azureiotkit: Waiting for time synchronization with SNTP server I (8837) sample_azureiotkit: Notification of a time synchronization event I (9517) main_task: Returned from app_main() I (9517) AZ IOT: ------------------------------------------------------------------------------ I (9517) AZ IOT: ADU SAMPLE I (9517) AZ IOT: Version: 1.0 I (9537) AZ IOT: ------------------------------------------------------------------------------ I (9537) AZ IOT: Creating a TLS connection to myhub.azure-devices.net:8883. I (10457) esp_tls: (Network connection 0x3fcad55c) Connection to myhub.azure-devices.net established. I (10457) AZ IOT: Creating an MQTT connection to myhub.azure-devices.net. I (10487) AZ IOT: myhub.azure-devices.net%2Fdevices%2FtestDevice 1724142316 I (10567) MQTT: Packet received. ReceivedBytes=2. I (10567) MQTT: CONNACK session present bit set. I (10567) MQTT: Connection accepted. I (10567) MQTT: Received MQTT CONNACK successfully from broker. I (10587) MQTT: MQTT connection established with the broker. I (10587) AZ IOT: An MQTT connection is established with myhub.azure-devices.net I (10617) MQTT: Packet received. ReceivedBytes=3. I (10617) AZ IOT: Suback receive context found: 0x00000001 I (10647) MQTT: Packet received. ReceivedBytes=4. I (10647) AZ IOT: Suback receive context found: 0x00000002 I (10687) AZ IOT: Successfully sent telemetry message I (10687) AZ IOT: Attempt to receive publish message from IoT Hub. I (10717) MQTT: Packet received. ReceivedBytes=4023. I (10717) MQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess. I (10737) MQTT: State record updated. New state=MQTTPublishDone. I (10737) AZ IOT: $iothub/twin/res/200/?$rid=2 I (10737) AZ IOT: Writable properties received: {"desired":{"$version":5,"deviceUpdate":{"__t":"c","service":{"fileUrls":{"fda2c221e992746e2":"http://myhub--myhub.b.nlu.dl.adu.microsoft.com/westeurope/myhub--myhub/75ff1a323a814b5d87811f5d2f394078/azure_iot_freertos_esp32-v1.1.bin"},"updateManifest":"{\"manifestVersion\":\"5\",\"updateId\":{\"provider\":\"\",\"name\":\"ESP32-Azure-IoT-Kit\",\"version\":\"1.1\"},\"compatibility\":[{\"deviceManufacturer\":\"ESPRESSIF\",\"deviceModel\":\"ESP32-Azure-IoT-Kit\"}],\"instructions\":{\"steps\":[{\"handler\":\"microsoft/swupdate:1\",\"files\":[\"fda2c221e992746e2\"],\"handlerProperties\":{\"installedCriteria\":\"1.1\"}}]},\"files\":{\"fda2c221e992746e2\":{\"fileName\":\"azure_iot_freertos_esp32-v1.1.bin\",\"sizeInBytes\":1045888,\"hashes\":{\"sha256\":\"u4gbY3O9TsPXmndtjJZvyPNTew0Jhm+oDHDxqnQvfgQ=\"}}},\"createdDateTime\":\"2024-08-20T07:10:24Z\"}","updateManifestSignature":"eyJhbGciOiJSUzI1NiIsInNqd2siOiJleUpoYkdjaU9pSlNVekkxTmlJc0ltdHBaQ0k2SWtGRVZTNHlNREEzTURJdVVpSjkuZXlKcmRIa2lPaUpTVTBFaUxDSnVJam9pY21OM01UVm1OMDByTm5SNGQxbzBiREl2WnpKekwycEpLM2Q0VlhwMFNWYzJkMnBqVEVrNVIxTldObkpSYzJKTUwzWjVXVXcyTTBsblZXWmxZbXgwY1hWMU1qQnhNbGROTkU1c1RHeE1RVFprWnk4ME5XSk5jbWhrYUZCb2VuSk5SVkIxV0d4Q05sSldORFZUY0dOWldHUmxVVnBYUWxvMmJtNWlWRmRTTmtRelZHVXZSaTlHSzFjeFFVRmxRbEF6YzBzd2RWQmxXbnBLTjFJd2EyVmhSbU5ZWW1OR1NrOHdZMVZ6VmpWeGJtaHZWWEpPZVc5M04wZDFXRkkwUzNSUmRHcExOMkZoY0VsWGNrcGlTMDlMU1Vsb09GRlZla0pKYlhZNWMxQkdlR2hGT1ZaSldYVjBjR1YwYkRkcE1tMVJkU3RwVHk5bFlVWkdaV0pLYWpGSlp6SnJNblV4SzFSb1kwWnZWM05GTkRkNWMxWjFUVkpRSzBWVlJtNUlVMGRCYlZSM2JHNWxOa1pXUzNSeGFYUmxSVFJJYW5saWFYRTBSa3ROYkZOQmIxQXdjMVI0UkRFNFN6TmphR2RsYWswMk1URk1NM00xWVcwMWNHZDBSMFF3VTJOc1RHaHBOVFIwY0ZGYWExRTRVSGxaY0N0T09YaDFlV04zTlU1WGJIbFhUWGxtU1VONFNGcHVMMGN5VFV4SVMzSnRiQzltTlU5VWJrdzJkRkpzVmtWTU9YbEJWVnAxVDA5dGRrdFVORlptT0dOWFpHTjBZazltTDAweEx6VlpNbEJYYkdZMFpHVTVVbTlpVm10SFVEWTNaSHBRY0ZwbFZVYzRUeTg0UWswMU56SnFhVWxpT1ZOWVZIRjBRVmxSYjJZdlZUZHNRM1JEY2xSU05ucERaM0FpTENKbElqb2lRVkZCUWlJc0ltRnNaeUk2SWxKVE1qVTJJaXdpYTJsa0lqb2lRVVJWTGpJek1EZ3dOeTVTTGxNaWZRLnpERWhCdXIxcnc4OUdpVUFGZEFTSjR5SHhVaVlSZjhSNE51YnNKSlVYRktfT2JlMEdxRWxTcGE2WXVPekppZks0a0pjUkVXMGdkY2YyaXBZSnBfaE12Ml9SNlFVY0U5SzBNZTM5MEgxczhzVHNzcGFRUGpJVUR3ZzY1N0l4TWpoNFppdVVHUm9rR1BDUENzQmFzOGpkUzE4Z2N2X1N4bmZ4d082UlpEdDlXRlBxOE5kMDdKejRpWFZzMUlSTHVXYzV2d1Q2c1ZzeTVQR0lUWHAydFRLOHgxUGpFWHp0akNoZDQ4ODhZM1NNT2JDSzM1WXBxS2hXdHVYOEl1ZjVOQXdNbFUyaXZRbnduU2cyOVBjeTJiZ01SdF8xT3FFWDQ0MU1Xa2lqXzJITVZFMnB1dld3UVQ1WExCUHZvZ2daUVM4YWk0V3NCd1I3TFpZakN5NWdsWGpub09lRzhpVklQb2k5X0dfdHJiQnpMUFZIM3pVRjdMNVBkSFhIZnVFOTd0LU0zRnYxcFV5dWtYMFNrQmRUeHE3NUpzSU5wUDQxRHlKYWh3SGMxZWRqbHc5Mjc4bkU5bHFYeHRmUkdFa2czTUFOVVktczdtVWtPVU1CdDNvTXJHU3J6a3J0UGhwb2U5eDBKVU9EOC1iVTFwTkZWRUtxRGdaVWNMUkR2VXFXUmFBIn0.eyJzaGEyNTYiOiJXdjFOK01RVzhiUjU3ZTYrWXVGYkhhWVVwR0RrZW5TdnZkb0NmeE1icGhRPSJ9.fqO69XmxD26RncqFAkkW07S610ydLWwL0ZMfarcGr89tmpG97CjGSfS4P_ZEnym2mE1eiw1WMJaVl550FgjRW-kjTFJPIgVAVPPHDBTl7wrojkYpWXA7TwcziSEmbXj7cRq87Xq1pJjB6w-18p2rlUuf4_Mvzjot_rQ7okDBJQS_UkbBap_cj05ulkT2wFwar8miIFA3VWewgt7wl5nL1kp1zI51dCUYO1re5sFFQ7JEVvaQRv-DFbkNqcUPimCQJubx8Uh9PxfXnSF8li505JVX12uuYE7qDXYpu-bMsvNQBeBSeNRuwpJRM9iJA7Cp-mRbPsavHgM3N-Kmqdq3hSpnOEXko8TmRjOn01xTEGXy2c3NBUuroA__U0nAMeUMQvjPqW1DtkZpubfR4dqXmcL_RmEi0DI9on2aeZ1cq0nDI0w40UxQefzZmLOJSv4LVKYhAjHdt8t0fOpRjTL46_EGDmVhglqdx3Q5gLIh6EDuoRsqgCGqskSM1Ww-P3k4","workflow":{"action":3,"id":"e7394386-089b-4f64-b207-e7ef79b13f3b"}}}},"reported":{"$version":14,"deviceUpdate":{"__t":"c","agent":{"compatPropertyNames":"manufacturer,model","deviceProperties":{"aduVer":"DU;agent/1.0.0","contractModelId":"dtmi:azure:iot:deviceUpdateContractModel;2","doVer":"1.0.0","interfaceId":"dtmi:azure:iot:deviceUpdate;1","manufacturer":"ESPRESSIF","model":"ESP32-Azure-IoT-Kit"},"installedUpdateId":"{\"provider\":\"Contoso\",\"name\":\"ESP32-Azure-IoT-Kit\",\"version\":\"1.1\"}","state":0,"workflow":{"action":3,"id":"e7394386-089b-4f64-b207-e7ef79b13f3b"}},"service":{"ac":406,"av":5,"value":{}}}}} I (11097) AZ IOT: Properties component name: deviceUpdate I (11097) AZ IOT: Verifying JWS Manifest I (11297) AZ IOT: [JWS] Calculated manifest SHA matches parsed SHA I (11297) AZ IOT: [ADU] Accepting update request I (16087) AZ IOT: [ADU] Step: eAzureIoTADUUpdateStepFirmwareDownloadStarted I (16087) AZ IOT: [ADU] Send property update. I (16097) AZ IOT: [ADU] Invoke HTTP Connect Callback. I (16097) AZ IOT: Connecting socket to myhub--myhub.b.nlu.dl.adu.microsoft.com I (16147) esp_sockets: (Network connection 0x3fcad46c) Connection to myhub--myhub.b.nlu.dl.adu.microsoft.com established. I (16147) AZ IOT: xStatus: 0 I (16187) HTTP: [HTTP] Size Request Success 200 I (16187) AZ IOT: [ADU] HTTP Range Request was successful: size 62848 bytes I (16187) AZ IOT: [ADU] Send HTTP request. I (16217) HTTP: [HTTP] [Status 206] Received range 0 to 4096 ... I (26457) HTTP: [HTTP] [Status 206] Received range 851968 to 856064 I (26467) AZ IOT: 10 second timeout. Taking a break from downloading image. I (26467) AZ IOT: Receiving messages from IoT Hub. I (26497) MQTT: Packet received. ReceivedBytes=42. I (26497) MQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess. I (26497) MQTT: State record updated. New state=MQTTPublishDone. I (26517) AZ IOT: $iothub/twin/res/204/?$rid=1&$version=15 I (26527) MQTT: Packet received. ReceivedBytes=2. I (26527) MQTT: Ack packet deserialized with result: MQTTSuccess. I (26527) MQTT: State record updated. New state=MQTTPublishDone. I (26527) AZ IOT: Puback received for packet id: 0x00000003 I (26567) MQTT: Packet received. ReceivedBytes=42. I (26567) MQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess. I (26567) MQTT: State record updated. New state=MQTTPublishDone. I (26577) AZ IOT: $iothub/twin/res/204/?$rid=3&$version=16 I (26607) MQTT: Packet received. ReceivedBytes=42. I (26607) MQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess. I (26607) MQTT: State record updated. New state=MQTTPublishDone. I (26627) AZ IOT: $iothub/twin/res/204/?$rid=5&$version=17 I (31667) HTTP: [HTTP] [Status 206] Received range 856064 to 860160 ... I (34017) HTTP: [HTTP] [Status 206] Received range 1044480 to 1045888 I (34017) AZ IOT: Checking for ADU twin updates one more time before committing to update. I (39027) AZ IOT: [ADU] Image validated against hash from ADU I (39027) AZ IOT: Base64 Encoded Hash from ADU: u4gbY3O9TsPXmndtjJZvyPNTew0Jhm+oDHDxqnQvfgQ= I (39027) AZ IOT: Unencoded the base64 encoding I (39037) AZ IOT: Starting the mbedtls calculation: image size 62848 I (40987) AZ IOT: mbedtls calculation completed I (40987) AZ IOT: SHAs match I (40997) AZ IOT: [ADU] Enable the update image I (40997) esp_image: segment 0: paddr=00120020 vaddr=3c0c0020 size=2e850h (190544) map I (41057) esp_image: segment 1: paddr=0014e878 vaddr=3fc90e00 size=017a0h ( 6048) I (41057) esp_image: segment 2: paddr=00150020 vaddr=42000020 size=bd174h (774516) map I (41247) esp_image: segment 3: paddr=0020d19c vaddr=3fc925a0 size=016f4h ( 5876) I (41247) esp_image: segment 4: paddr=0020e898 vaddr=40380000 size=10cc4h ( 68804) I (41327) AZ IOT: [ADU] Send property update. I (41327) AZ IOT: [ADU] Reset the device I (41337) wifi:state: run -> init (0) I (41337) wifi:pm stop, total sleep time: 16294651 us / 37862015 us I (41337) wifi:idx:0, tid:0 I (41337) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:1 I (41437) wifi:flush txq I (41437) wifi:stop sw txq I (41437) wifi:lmac stop hw txq I (41637) wifi:Deinit lldesc rx mblock:10 ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x3 (RTC_SW_SYS_RST),boot:0xf (SPI_FAST_FLASH_BOOT) Saved PC:0x40048b82 0x40048b82: software_reset in ROM SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd5820,len:0x1714 load:0x403cc710,len:0x968 load:0x403ce710,len:0x2f9c entry 0x403cc710 I (24) boot: ESP-IDF v5.1.3-416-gd23b7a0361 2nd stage bootloader I (24) boot: compile time Aug 20 2024 07:02:20 I (24) boot: chip revision: v0.4 I (28) boot.esp32c3: SPI Speed : 80MHz I (33) boot.esp32c3: SPI Mode : DIO I (38) boot.esp32c3: SPI Flash Size : 4MB I (42) boot: Enabling RNG early entropy source... I (48) boot: Partition Table: I (51) boot: ## Label Usage Type ST Offset Length I (59) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (66) boot: 1 otadata OTA data 01 00 0000f000 00002000 I (74) boot: 2 phy_init RF data 01 01 00011000 00001000 I (81) boot: 3 factory factory app 00 00 00020000 00100000 I (89) boot: 4 ota_0 OTA app 00 10 00120000 00100000 I (96) boot: 5 ota_1 OTA app 00 11 00220000 00100000 I (103) boot: End of partition table I (108) esp_image: segment 0: paddr=00120020 vaddr=3c0c0020 size=2e850h (190544) map I (147) esp_image: segment 1: paddr=0014e878 vaddr=3fc90e00 size=017a0h ( 6048) load I (149) esp_image: segment 2: paddr=00150020 vaddr=42000020 size=bd174h (774516) map I (279) esp_image: segment 3: paddr=0020d19c vaddr=3fc925a0 size=016f4h ( 5876) load I (280) esp_image: segment 4: paddr=0020e898 vaddr=40380000 size=10cc4h ( 68804) load I (303) boot: Loaded app from partition at offset 0x120000 I (303) boot: Disabling RNG early entropy source... I (315) cpu_start: Unicore app I (315) cpu_start: Pro cpu up. I (324) cpu_start: Pro cpu start user code I (324) cpu_start: cpu freq: 160000000 Hz I (324) cpu_start: Application information: I (327) cpu_start: Project name: azure_iot_freertos_esp32 I (333) cpu_start: App version: 1 I (338) cpu_start: Compile time: Aug 20 2024 07:05:45 I (344) cpu_start: ELF file SHA256: c655622b6b04c9b0... Warning: checksum mismatch between flashed and built applications. Checksum of built application is b380be4be47953c36cc81afdaaf002dbd05bd9c993fe1adf34618edffc516d2f I (350) cpu_start: ESP-IDF: v5.1.3-416-gd23b7a0361 I (356) cpu_start: Min chip rev: v0.3 I (361) cpu_start: Max chip rev: v1.99 I (365) cpu_start: Chip rev: v0.4 I (370) heap_init: Initializing. RAM available for dynamic allocation: I (377) heap_init: At 3FC9C8B0 len 00023750 (141 KiB): DRAM I (384) heap_init: At 3FCC0000 len 0001C710 (113 KiB): DRAM/RETENTION I (391) heap_init: At 3FCDC710 len 00002950 (10 KiB): DRAM/RETENTION/STACK I (398) heap_init: At 50000010 len 00001FD8 (7 KiB): RTCRAM I (405) spi_flash: detected chip: generic I (409) spi_flash: flash io: dio I (413) sleep: Configure to isolate all GPIO pins in sleep state I (420) sleep: Enable automatic switching of GPIO sleep configuration I (427) app_start: Starting scheduler on CPU0 I (432) main_task: Started on CPU0 I (432) main_task: Calling app_main() I (542) pp: pp rom version: 9387209 I (542) net80211: net80211 rom version: 9387209 I (552) wifi:wifi driver task: 3fca4f94, prio:23, stack:6656, core=0 I (552) wifi:wifi firmware version: 92daf4348 I (552) wifi:wifi certification version: v7.0 I (552) wifi:config NVS flash: enabled I (552) wifi:config nano formating: disabled I (562) wifi:Init data frame dynamic rx buffer num: 32 I (562) wifi:Init static rx mgmt buffer num: 5 I (562) wifi:Init management short buffer num: 32 I (572) wifi:Init dynamic tx buffer num: 32 I (572) wifi:Init static tx FG buffer num: 2 I (582) wifi:Init static rx buffer size: 1600 I (582) wifi:Init static rx buffer num: 10 I (592) wifi:Init dynamic rx buffer num: 32 I (592) wifi_init: rx ba win: 6 I (592) wifi_init: tcpip mbox: 32 I (602) wifi_init: udp mbox: 6 I (602) wifi_init: tcp mbox: 6 I (602) wifi_init: tcp tx win: 5760 I (612) wifi_init: tcp rx win: 5760 I (612) wifi_init: tcp mss: 1440 I (622) wifi_init: WiFi IRAM OP enabled I (622) wifi_init: WiFi RX IRAM OP enabled I (632) sample_azureiotkit: Connecting to ... I (632) phy_init: phy_version 1150,7c3c08f,Jan 24 2024,17:32:21 I (672) wifi:mode : sta (74:4d:bd:fd:1f:c4) I (672) wifi:enable tsf I (682) sample_azureiotkit: Waiting for IP(s) I (3092) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1 I (3392) wifi:state: init -> auth (b0) I (4392) wifi:state: auth -> init (200) I (4392) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1 I (4392) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1 I (4402) wifi:state: init -> auth (b0) I (4402) wifi:state: auth -> assoc (0) I (4412) wifi:state: assoc -> run (10) I (4462) wifi:connected with , aid = 1, channel 11, BW20, bssid = 78:8a:20:49:91:a7 I (4462) wifi:security: WPA2-PSK, phy: bgn, rssi: -60 I (4462) wifi:pm start, type: 1 I (4462) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us I (4472) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 25000, mt_pti: 0, mt_time: 10000 I (4502) wifi:idx:0 (ifx:0, 78:8a:20:49:91:a7), tid:0, ssn:0, winSize:64 I (4532) wifi:AP's beacon interval = 102400 us, DTIM period = 1 I (5482) esp_netif_handlers: sample_azureiotkit: sta ip: .224, mask: 255.255.255.0, gw: .1 I (5482) sample_azureiotkit: Got IPv4 event: Interface "sample_azureiotkit: sta" address: .224 I (5492) sample_azureiotkit: Connected to sample_azureiotkit: sta I (5492) sample_azureiotkit: - IPv4 address: .224 I (5502) sample_azureiotkit: Waiting for time synchronization with SNTP server I (6052) sample_azureiotkit: Notification of a time synchronization event I (6512) main_task: Returned from app_main() I (6512) AZ IOT: ------------------------------------------------------------------------------ I (6512) AZ IOT: ADU SAMPLE I (6512) AZ IOT: Version: 1.1 I (6532) AZ IOT: ------------------------------------------------------------------------------ I (6532) AZ IOT: Creating a TLS connection to myhub.azure-devices.net:8883. I (7362) esp_tls: (Network connection 0x3fcad4cc) Connection to myhub.azure-devices.net established. I (7362) AZ IOT: Creating an MQTT connection to myhub.azure-devices.net. I (7382) AZ IOT: myhub.azure-devices.net%2Fdevices%2FtestDevice 1724142354 I (7462) MQTT: Packet received. ReceivedBytes=2. I (7462) MQTT: CONNACK session present bit set. I (7462) MQTT: Connection accepted. I (7462) MQTT: Received MQTT CONNACK successfully from broker. I (7482) MQTT: MQTT connection established with the broker. I (7482) AZ IOT: An MQTT connection is established with myhub.azure-devices.net I (7492) MQTT: Packet received. ReceivedBytes=3. I (7492) AZ IOT: Suback receive context found: 0x00000001 I (7532) MQTT: Packet received. ReceivedBytes=4. I (7532) AZ IOT: Suback receive context found: 0x00000002 I (7572) AZ IOT: Successfully sent telemetry message I (7572) AZ IOT: Attempt to receive publish message from IoT Hub. I (7622) MQTT: Packet received. ReceivedBytes=4180. I (7622) MQTT: De-serialized incoming PUBLISH packet: DeserializerResult=MQTTSuccess. I (7622) MQTT: State record updated. New state=MQTTPublishDone. I (7642) AZ IOT: $iothub/twin/res/200/?$rid=2 I (7642) AZ IOT: Writable properties received: {"desired":{"$version":5,"deviceUpdate":{"__t":"c","service":{"fileUrls":{"fda2c221e992746e2":"http://myhub--myhub.b.nlu.dl.adu.microsoft.com/westeurope/myhub--myhub/75ff1a323a814b5d87811f5d2f394078/azure_iot_freertos_esp32-v1.1.bin"},"updateManifest":"{\"manifestVersion\":\"5\",\"updateId\":{\"provider\":\"\",\"name\":\"ESP32-Azure-IoT-Kit\",\"version\":\"1.1\"},\"compatibility\":[{\"deviceManufacturer\":\"ESPRESSIF\",\"deviceModel\":\"ESP32-Azure-IoT-Kit\"}],\"instructions\":{\"steps\":[{\"handler\":\"microsoft/swupdate:1\",\"files\":[\"fda2c221e992746e2\"],\"handlerProperties\":{\"installedCriteria\":\"1.1\"}}]},\"files\":{\"fda2c221e992746e2\":{\"fileName\":\"azure_iot_freertos_esp32-v1.1.bin\",\"sizeInBytes\":1045888,\"hashes\":{\"sha256\":\"u4gbY3O9TsPXmndtjJZvyPNTew0Jhm+oDHDxqnQvfgQ=\"}}},\"createdDateTime\":\"2024-08-20T07:10:24Z\"}","updateManifestSignature":"eyJhbGciOiJSUzI1NiIsInNqd2siOiJleUpoYkdjaU9pSlNVekkxTmlJc0ltdHBaQ0k2SWtGRVZTNHlNREEzTURJdVVpSjkuZXlKcmRIa2lPaUpTVTBFaUxDSnVJam9pY21OM01UVm1OMDByTm5SNGQxbzBiREl2WnpKekwycEpLM2Q0VlhwMFNWYzJkMnBqVEVrNVIxTldObkpSYzJKTUwzWjVXVXcyTTBsblZXWmxZbXgwY1hWMU1qQnhNbGROTkU1c1RHeE1RVFprWnk4ME5XSk5jbWhrYUZCb2VuSk5SVkIxV0d4Q05sSldORFZUY0dOWldHUmxVVnBYUWxvMmJtNWlWRmRTTmtRelZHVXZSaTlHSzFjeFFVRmxRbEF6YzBzd2RWQmxXbnBLTjFJd2EyVmhSbU5ZWW1OR1NrOHdZMVZ6VmpWeGJtaHZWWEpPZVc5M04wZDFXRkkwUzNSUmRHcExOMkZoY0VsWGNrcGlTMDlMU1Vsb09GRlZla0pKYlhZNWMxQkdlR2hGT1ZaSldYVjBjR1YwYkRkcE1tMVJkU3RwVHk5bFlVWkdaV0pLYWpGSlp6SnJNblV4SzFSb1kwWnZWM05GTkRkNWMxWjFUVkpRSzBWVlJtNUlVMGRCYlZSM2JHNWxOa1pXUzNSeGFYUmxSVFJJYW5saWFYRTBSa3ROYkZOQmIxQXdjMVI0UkRFNFN6TmphR2RsYWswMk1URk1NM00xWVcwMWNHZDBSMFF3VTJOc1RHaHBOVFIwY0ZGYWExRTRVSGxaY0N0T09YaDFlV04zTlU1WGJIbFhUWGxtU1VONFNGcHVMMGN5VFV4SVMzSnRiQzltTlU5VWJrdzJkRkpzVmtWTU9YbEJWVnAxVDA5dGRrdFVORlptT0dOWFpHTjBZazltTDAweEx6VlpNbEJYYkdZMFpHVTVVbTlpVm10SFVEWTNaSHBRY0ZwbFZVYzRUeTg0UWswMU56SnFhVWxpT1ZOWVZIRjBRVmxSYjJZdlZUZHNRM1JEY2xSU05ucERaM0FpTENKbElqb2lRVkZCUWlJc0ltRnNaeUk2SWxKVE1qVTJJaXdpYTJsa0lqb2lRVVJWTGpJek1EZ3dOeTVTTGxNaWZRLnpERWhCdXIxcnc4OUdpVUFGZEFTSjR5SHhVaVlSZjhSNE51YnNKSlVYRktfT2JlMEdxRWxTcGE2WXVPekppZks0a0pjUkVXMGdkY2YyaXBZSnBfaE12Ml9SNlFVY0U5SzBNZTM5MEgxczhzVHNzcGFRUGpJVUR3ZzY1N0l4TWpoNFppdVVHUm9rR1BDUENzQmFzOGpkUzE4Z2N2X1N4bmZ4d082UlpEdDlXRlBxOE5kMDdKejRpWFZzMUlSTHVXYzV2d1Q2c1ZzeTVQR0lUWHAydFRLOHgxUGpFWHp0akNoZDQ4ODhZM1NNT2JDSzM1WXBxS2hXdHVYOEl1ZjVOQXdNbFUyaXZRbnduU2cyOVBjeTJiZ01SdF8xT3FFWDQ0MU1Xa2lqXzJITVZFMnB1dld3UVQ1WExCUHZvZ2daUVM4YWk0V3NCd1I3TFpZakN5NWdsWGpub09lRzhpVklQb2k5X0dfdHJiQnpMUFZIM3pVRjdMNVBkSFhIZnVFOTd0LU0zRnYxcFV5dWtYMFNrQmRUeHE3NUpzSU5wUDQxRHlKYWh3SGMxZWRqbHc5Mjc4bkU5bHFYeHRmUkdFa2czTUFOVVktczdtVWtPVU1CdDNvTXJHU3J6a3J0UGhwb2U5eDBKVU9EOC1iVTFwTkZWRUtxRGdaVWNMUkR2VXFXUmFBIn0.eyJzaGEyNTYiOiJXdjFOK01RVzhiUjU3ZTYrWXVGYkhhWVVwR0RrZW5TdnZkb0NmeE1icGhRPSJ9.fqO69XmxD26RncqFAkkW07S610ydLWwL0ZMfarcGr89tmpG97CjGSfS4P_ZEnym2mE1eiw1WMJaVl550FgjRW-kjTFJPIgVAVPPHDBTl7wrojkYpWXA7TwcziSEmbXj7cRq87Xq1pJjB6w-18p2rlUuf4_Mvzjot_rQ7okDBJQS_UkbBap_cj05ulkT2wFwar8miIFA3VWewgt7wl5nL1kp1zI51dCUYO1re5sFFQ7JEVvaQRv-DFbkNqcUPimCQJubx8Uh9PxfXnSF8li505JVX12uuYE7qDXYpu-bMsvNQBeBSeNRuwpJRM9iJA7Cp-mRbPsavHgM3N-Kmqdq3hSpnOEXko8TmRjOn01xTEGXy2c3NBUuroA__U0nAMeUMQvjPqW1DtkZpubfR4dqXmcL_RmEi0DI9on2aeZ1cq0nDI0w40UxQefzZmLOJSv4LVKYhAjHdt8t0fOpRjTL46_EGDmVhglqdx3Q5gLIh6EDuoRsqgCGqskSM1Ww-P3k4","workflow":{"action":3,"id":"e7394386-089b-4f64-b207-e7ef79b13f3b"}}}},"reported":{"$version":18,"deviceUpdate":{"__t":"c","agent":{"compatPropertyNames":"manufacturer,model","deviceProperties":{"aduVer":"DU;agent/1.0.0","contractModelId":"dtmi:azure:iot:deviceUpdateContractModel;2","doVer":"1.0.0","interfaceId":"dtmi:azure:iot:deviceUpdate;1","manufacturer":"ESPRESSIF","model":"ESP32-Azure-IoT-Kit"},"installedUpdateId":"{\"provider\":\"Contoso\",\"name\":\"ESP32-Azure-IoT-Kit\",\"version\":\"1.0\"}","lastInstallResult":{"extendedResultCode":1234,"resultCode":0,"resultDetails":"Ok","step_0":{"extendedResultCode":1234,"resultCode":0,"resultDetails":"Ok"}},"state":6,"workflow":{"action":3,"id":"e7394386-089b-4f64-b207-e7ef79b13f3b"}},"service":{"ac":200,"av":5,"value":{}}}}} I (8012) AZ IOT: Properties component name: deviceUpdate I (8012) AZ IOT: Verifying JWS Manifest I (8192) AZ IOT: [JWS] Calculated manifest SHA matches parsed SHA I (8192) AZ IOT: [ADU] Rejecting update request (installed criteria matches current version) I (8222) AZ IOT: Keeping Connection Idle...

Expected/desired behavior

A device update deployment should report success as far as I can tell?

OS and Version?

Built on Linux (ubuntu 22.04), ESP-IDF v5.1.3-416-gd23b7a0361

Versions

sample version: f06e8c7fc8204c98dcbdad7ac86c2fc0429492ab

Mention any other details that might be useful

The overview in the deployment screen:

image

Note that the device reports "result code 0" which should mean that the update was successful as far as I can tell.

Thanks! We'll be in touch soon.

florianhumblot commented 3 months ago

Figured it out. The "current version" that needs to be reported by the device update agent needs to be a JSON string containing the provider, name and version, not just the version number. Not sure if I missed it in the docs somewhere, but I feel that it might be easily overlooked.