OTA output log debug

Tom · July 20, 2020, 3:14pm

I’m trying to perform an OTA update on an ESP32 WROVER module and get the following log. Since the current OTA software doesn’t output the messages as shown starting on page 242 in the “Amazon FreeRTOS User Guide” or as shown on ( https://docs.aws.amazon.com/freertos/latest/userguide/ota-demo.html ) it’s difficult to compare my log and determine what is not working correctly.

Would someone please review my log and let me know what I should be investigating? And/or, is a “working log” for the current OTA code available somewhere?

Currently, I’m not sure if my problem is even in the ESP32 code or in how I have the “OTA job” setup in AWS.

Tom

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:956
load:0x40078000,len:0
load:0x40078000,len:13256
entry 0x40078a90
I (275) cpu_start: Pro cpu up.
I (275) cpu_start: Application information:
I (275) cpu_start: Project name: esp-idf
I (277) cpu_start: App version: 1
I (282) cpu_start: Compile time: Jul 18 2020 13:45:48
I (288) cpu_start: ELF file SHA256: aa1006a64fa5970c…
I (294) cpu_start: ESP-IDF: v3.3.2-235-ga3ce2f400
I (300) cpu_start: Single core mode
I (304) heap_init: Initializing. RAM available for dynamic allocation:
I (311) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (317) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (323) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (330) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (336) heap_init: At 3FFCC480 len 00013B80 (78 KiB): DRAM
I (342) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM
I (348) heap_init: At 40078000 len 00008000 (32 KiB): IRAM
I (354) heap_init: At 40094F6C len 0000B094 (44 KiB): IRAM
I (361) cpu_start: Pro cpu start user code
I (42) cpu_start: Starting scheduler on PRO CPU.
I (51) PKCS11: Initializing NVS partition: “storage”
E (71) PKCS11: failed nvs get file size 4354 0
0 3 [loopTask] Write certificate…
1 4 [iot_thread] [INFO ][DEMO][40] ---------STARTING DEMO---------

2 4 [iot_thread] [INFO ][INIT][40] SDK successfully initialized.
I (111) wifi:wifi driver task: 3ffb2388, prio:23, stack:3584, core=0
I (111) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (111) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (131) wifi:wifi firmware version: 1afdae0
I (131) wifi:config NVS flash: enabled
I (131) wifi:config nano formating: disabled
I (131) wifi:Init dynamic tx buffer num: 32
I (141) wifi:Init data frame dynamic rx buffer num: 32
I (141) wifi:Init management frame dynamic rx buffer num: 32
I (151) wifi:Init management short buffer num: 32
I (151) wifi:Init static rx buffer size: 1600
I (161) wifi:Init static rx buffer num: 10
I (161) wifi:Init dynamic rx buffer num: 32
I (251) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (251) wifi:mode : sta (4c:11:ae:61:21:ac)
I (251) WIFI: SYSTEM_EVENT_STA_START
I (1341) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:3
I (2321) wifi:state: init -> auth (b0)
I (2331) wifi:state: auth -> assoc (0)
I (2331) wifi:state: assoc -> run (10)
I (2671) wifi:connected with Nxxx21, aid = 4, channel 9, BW20, bssid = 50:6a:03:a9:40:a9
I (2671) wifi:security type: 3, phy: bgn, rssi: -38
I (2671) wifi:pm start, type: 1

I (2681) WIFI: SYSTEM_EVENT_STA_CONNECTED
I (2751) wifi:AP’s beacon interval = 102400 us, DTIM period = 2
I (4511) event: sta ip: 192.168.1.12, mask: 255.255.255.0, gw: 192.168.1.1
I (4511) WIFI: SYSTEM_EVENT_STA_GOT_IP
3 446 [iot_thread] [INFO ][DEMO][4460] Successfully initialized the demo. Network type for the demo: 1
4 447 [iot_thread] [INFO ][MQTT][4470] MQTT library successfully initialized.
5 447 [iot_thread] [INFO ][DEMO][4470] OTA demo version 0.0.1

6 447 [iot_thread] [INFO ][DEMO][4470] Connecting to broker…

7 447 [iot_thread] [INFO ][DEMO][4470] MQTT demo client identifier is Axxxxxxxxxx (length 11).
E (4611) PKCS11: failed nvs get file size 4354 0
8 1007 [iot_thread] [INFO ][MQTT][10070] Establishing new MQTT connection.
9 1007 [iot_thread] [INFO ][MQTT][10070] Anonymous metrics (SDK language, SDK version) will be provided to AWS IoT. Recompile with AWS_IOT_MQTT_ENABLE_METRICS set to 0 to disable.
10 1007 [iot_thread] [INFO ][MQTT][10070] (MQTT connection 0x3ffd14fc, CONNECT operation 0x3ffdab78) Waiting for operation completion.
11 1059 [iot_thread] [INFO ][MQTT][10590] (MQTT connection 0x3ffd14fc, CONNECT operation 0x3ffdab78) Wait complete with result SUCCESS.
12 1059 [iot_thread] [INFO ][MQTT][10590] New MQTT connection 0x3ffc119c established.
13 1060 [iot_thread] [OTA_AgentInit_internal] OTA Task is Ready.
I (10651) ota_pal: prvPAL_GetPlatformImageState
I (10661) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (10671) esp_ota_ops: [0] aflags/seq:0xffffffff/0x1, pflags/seq:0xffffffff/0x0
14 1063 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [Ready] Event [Start] New state [RequestingJob]
15 1063 [OTA Agent Task] [INFO ][MQTT][10630] (MQTT connection 0x3ffd14fc) SUBSCRIBE operation scheduled.
16 1063 [OTA Agent Task] [INFO ][MQTT][10630] (MQTT connection 0x3ffd14fc, SUBSCRIBE operation 0x3ffdab78) Waiting for operation completion.
17 1072 [OTA Agent Task] [INFO ][MQTT][10720] (MQTT connection 0x3ffd14fc, SUBSCRIBE operation 0x3ffdab78) Wait complete with result SUCCESS.
18 1072 [OTA Agent Task] [prvSubscribeToJobNotificationTopics] OK: $aws/things/A1234567891/jobs/$next/get/accepted
19 1072 [OTA Agent Task] [INFO ][MQTT][10720] (MQTT connection 0x3ffd14fc) SUBSCRIBE operation scheduled.
20 1072 [OTA Agent Task] [INFO ][MQTT][10720] (MQTT connection 0x3ffd14fc, SUBSCRIBE operation 0x3ffdab78) Waiting for operation completion.
21 1100 [OTA Agent Task] [INFO ][MQTT][11000] (MQTT connection 0x3ffd14fc, SUBSCRIBE operation 0x3ffdab78) Wait complete with result SUCCESS.
22 1100 [OTA Agent Task] [prvSubscribeToJobNotificationTopics] OK: $aws/things/A1234567891/jobs/notify-next
23 1100 [OTA Agent Task] [prvRequestJob_Mqtt] Request #0
24 1100 [OTA Agent Task] [INFO ][MQTT][11000] (MQTT connection 0x3ffd14fc) MQTT PUBLISH operation queued.
25 1100 [OTA Agent Task] [INFO ][MQTT][11000] (MQTT connection 0x3ffd14fc, PUBLISH operation 0x3ffdab78) Waiting for operation completion.
26 1106 [OTA Agent Task] [INFO ][MQTT][11060] (MQTT connection 0x3ffd14fc, PUBLISH operation 0x3ffdab78) Wait complete with result SUCCESS.
27 1106 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [RequestingJob] Event [RequestJobDocument] New state [WaitingForJob]
I (11121) ota_pal: prvPAL_SetPlatformImageState, 4
W (11131) ota_pal: Set image as aborted!
I (11131) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (11141) esp_ota_ops: [0] aflags/seq:0xffffffff/0x1, pflags/seq:0xffffffff/0x0
W (11141) ota_pal: Image not in self test mode -1
I (11151) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (11161) esp_ota_ops: [0] aflags/seq:0xffffffff/0x1, pflags/seq:0xffffffff/0x0
28 1107 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ clientToken: 0:A1234567891 ]
29 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: execution
30 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: jobId
31 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: jobDocument
32 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: afr_ota
33 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: protocols
34 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: files
35 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: filepath
36 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: filesize
37 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: fileid
38 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: certfile
39 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: sig-sha256-ecdsa
40 1107 [OTA Agent Task] [prvDefaultCustomJobCallback] Received Custom Job inside OTA Agent which is not supported.
41 1107 [OTA Agent Task] [prvParseJobDoc] Ignoring job without ID.
42 1107 [OTA Agent Task] [prvOTA_Close] Context->0x0x3ffbfa3c
43 1111 [OTA Agent Task] [prvExecuteHandler] Handler failed. Current State [WaitingForJob] Event [ReceivedJobDocument] Error Code [603979776]
44 1160 [iot_thread] [INFO ][DEMO][11600] State: Ready Received: 1 Queued: 0 Processed: 0 Dropped: 0

45 1260 [iot_thread] [INFO ][DEMO][12600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

46 1360 [iot_thread] [INFO ][DEMO][13600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

47 1460 [iot_thread] [INFO ][DEMO][14600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

48 1560 [iot_thread] [INFO ][DEMO][15600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

49 1660 [iot_thread] [INFO ][DEMO][16600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

H50 1760 [iot_thread] [INFO ][DEMO][17600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

51 1860 [iot_thread] [INFO ][DEMO][18600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

52 1960 [iot_thread] [INFO ][DEMO][19600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

53 2060 [iot_thread] [INFO ][DEMO][20600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

54 2160 [iot_thread] [INFO ][DEMO][21600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

55 2260 [iot_thread] [INFO ][DEMO][22600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

56 2360 [iot_thread] [INFO ][DEMO][23600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

57 2460 [iot_thread] [INFO ][DEMO][24600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

58 2560 [iot_thread] [INFO ][DEMO][25600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

59 2660 [iot_thread] [INFO ][DEMO][26600] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

pvyawaha · July 20, 2020, 5:15pm

Hi Tom,

The device logs shows that MQTT connection was established successfully.

12 1059 [iot_thread] [INFO ][MQTT][10590] New MQTT connection 0x3ffc119c established.

The OTA Agent was initialized and next available OTA job document was requested

13 1060 [iot_thread] [OTA_AgentInit_internal] OTA Task is Ready.

27 1106 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [RequestingJob] Event [RequestJobDocument] New state [WaitingForJob]

Device then received a response from OTA job service which does not have any execution, this is due to no OTA jobs available in the service.

29 1107 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: execution

Can you please check if you have created an OTA job for the thing from the OTA console and it is in Queued state? You can also refer to https://freertos.org/ota/preconfiguredexamplesCodeSigning.html for creating OTA jobs steps.

Also in the latest release, OTA Library checks for no execution in the job response and adds a log in device console. Which version are you using ?

Tom · July 20, 2020, 8:39pm

I’m using the 202002.00 version of the FreeRTOS demo code.

After fixing a “typo” in the thing name, I’m now starting to get an update, but it doesn’t appear to finish correctly and just stops receiving data as shown below. Any recommendations on what to try?

567 8386 [OTA Agent Task] [prvIngestDataBlock] Received file block 186, size 4096
568 8388 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
569 8427 [OTA Agent Task] [prvIngestDataBlock] Received file block 187, size 4096
570 8428 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
571 8430 [OTA Agent Task] [prvIngestDataBlock] Received file block 188, size 4096
572 8431 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
573 8466 [iot_thread] [INFO ][DEMO][84660] State: WaitingForFileBlock Received: 190 Queued: 0 Processed: 0 Dropped: 0

574 8469 [OTA Agent Task] [prvIngestDataBlock] Received file block 189, size 4096
575 8470 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
576 8510 [OTA Agent Task] [prvIngestDataBlock] Received file block 190, size 4096
577 8511 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
578 8530 [OTA Agent Task] [prvIngestDataBlock] Received file block 191, size 4096
579 8531 [OTA Agent Task] [prvPublishStatusMessage] Msg: {“status”:“IN_PROGRESS”,“statusDetails”:{“receive”:“192/207”}}
580 8531 [OTA Agent Task] [INFO ][MQTT][85310] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
581 8531 [OTA Agent Task] [prvPublishStatusMessage] ‘IN_PROGRESS’ to $aws/things/A12345-67891/jobs/AFR_OTA-H20_2/update
582 8531 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
583 8531 [OTA Agent Task] [INFO ][MQTT][85310] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
584 8531 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
585 8531 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
586 8566 [iot_thread] [INFO ][DEMO][85660] State: WaitingForFileBlock Received: 193 Queued: 0 Processed: 0 Dropped: 0

587 8571 [OTA Agent Task] [prvIngestDataBlock] Received file block 199, size 4096
588 8572 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
589 8581 [OTA Agent Task] [prvIngestDataBlock] Received file block 197, size 4096
590 8582 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
591 8589 [OTA Agent Task] [prvIngestDataBlock] Received file block 192, size 4096
592 8590 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
593 8612 [OTA Agent Task] [prvIngestDataBlock] Received file block 198, size 4096
594 8613 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
595 8615 [OTA Agent Task] [prvIngestDataBlock] Received file block 195, size 4096
596 8616 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
597 8653 [OTA Agent Task] [prvIngestDataBlock] Received file block 196, size 4096
598 8654 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
599 8666 [iot_thread] [INFO ][DEMO][86660] State: WaitingForFileBlock Received: 199 Queued: 0 Processed: 0 Dropped: 0

600 8694 [OTA Agent Task] [prvIngestDataBlock] Received file block 193, size 4096
601 8695 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
602 8734 [OTA Agent Task] [prvIngestDataBlock] Received file block 194, size 4096
603 8735 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
604 8735 [OTA Agent Task] [INFO ][MQTT][87350] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
605 8735 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
606 8735 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
607 8766 [iot_thread] [INFO ][DEMO][87660] State: WaitingForFileBlock Received: 201 Queued: 0 Processed: 0 Dropped: 0

608 8776 [OTA Agent Task] [prvIngestDataBlock] Received file block 200, size 4096
609 8777 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
610 8817 [OTA Agent Task] [prvIngestDataBlock] Received file block 201, size 4096
611 8818 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
612 8858 [OTA Agent Task] [prvIngestDataBlock] Received file block 202, size 4096
613 8859 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
614 8866 [iot_thread] [INFO ][DEMO][88660] State: WaitingForFileBlock Received: 204 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
615 8898 [OTA Agent Task] [prvIngestDataBlock] Received file block 203, size 4096
616 8899 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
617 8901 [OTA Agent Task] [prvIngestDataBlock] Received file block 205, size 4096
618 8902 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
619 8940 [OTA Agent Task] [prvIngestDataBlock] Received file block 206, size 3728
620 8941 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
621 8966 [iot_thread] [INFO ][DEMO][89660] State: WaitingForFileBlock Received: 207 Queued: 0 Processed: 0 Dropped: 0

622 8981 [OTA Agent Task] [prvIngestDataBlock] Received file block 204, size 4096
623 8982 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
624 9066 [iot_thread] [INFO ][DEMO][90660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
625 9166 [iot_thread] [INFO ][DEMO][91660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

626 9266 [iot_thread] [INFO ][DEMO][92660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

627 9366 [iot_thread] [INFO ][DEMO][93660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
628 9466 [iot_thread] [INFO ][DEMO][94660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

629 9566 [iot_thread] [INFO ][DEMO][95660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
630 9666 [iot_thread] [INFO ][DEMO][96660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

631 9766 [iot_thread] [INFO ][DEMO][97660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

632 9866 [iot_thread] [INFO ][DEMO][98660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
633 9966 [iot_thread] [INFO ][DEMO][99660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

634 9981 [OTA Agent Task] [prvExecuteHandler] Handler failed. Current State [WaitingForFileBlock] Event [RequestTimer] Error Code [-16777216]
635 10066 [iot_thread] [INFO ][DEMO][100660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
636 10166 [iot_thread] [INFO ][DEMO][101660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

637 10266 [iot_thread] [INFO ][DEMO][102660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

638 10366 [iot_thread] [INFO ][DEMO][103660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
639 10466 [iot_thread] [INFO ][DEMO][104660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

640 10566 [iot_thread] [INFO ][DEMO][105660] State: WaitingForFileBlock Received: 208 Queued: 0 Processed: 0 Dropped: 0

pvyawaha · July 20, 2020, 11:52pm

Hello Tom,

Do you get MQTT disconnect if you leave it running for a while ? The default keep alive in the release 202002.00 OTA demo is long so it will take few minutes to get the MQTT disconnect callback. You can try reducing the keep alive and set a breakpoint at MQTT disconnect callback to check if you are getting disconnected.

Alternatively, I recommend using the latest release 202007.00. The OTA demo in this release handles MQTT disconnect and resumes OTA download after re-connection.

Please upload the complete logs if possible.

Tom · July 21, 2020, 12:37am

I left it run for 10 minutes after the “download” stops and all I still get is the “WaitingForFileBlock” messages as shown above, but the “Received:” this latest time is 285 and not 208 as shown above.

Can I ask what you use to “set a breakpoint at MQTT”? I’m currently just using a python script to program the device and a “python idf.py monitor” command to capture the “log”.

pvyawaha · July 21, 2020, 2:56am

Please check instructions here on setting up debugging on ESP32 https://docs.aws.amazon.com/freertos/latest/userguide/getting_started_espressif.html

If you just want to check if MQTT disconnected then in the OTA demo you can add logging in the MQTT disconnect callback prvNetworkDisconnectCallback. The default keep alive is 20 minutes in the release you are using, and it can be reduced to 120 seconds by updating otaDemoKEEPALIVE_SECONDS.

What are your thoughts on using the release 202007.00 as the OTA demo monitors for MQTT disconnect ?

Tom · July 21, 2020, 7:26pm

I apparently was wrong on which version of FreeRTOS I currently am using. On 6/24/20 I used “git” to download the latest version ( where previously I had downloaded the 202002.00 version as a single file ). On the link you sent for the 202007.00 version, I see that version “2” was released on 2/18/20 while version “7” was released 4 days ago. So the version I have been using is “somewhere between” those two.

In checking the MQTT disconnect callback it has OTA_DEMO_KEEP_ALIVE_SECONDS set to 120, and the prvNetworkDisconnectCallback function has multiple logging “cases” that all start with “Mqtt disconnected due to”. In searching the output log, this text does not appear, so I don’t think my problem is with the MQTT disconnecting.

Is there something I can check to determine if the version of FreeRTOS I’m using has the “handles MQTT disconnect and resumes OTA download after re-connection”?

I’ll send the “complete log” you requested as a separate posting.

Tom · July 21, 2020, 7:28pm

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:956
load:0x40078000,len:0
load:0x40078000,len:13256
entry 0x40078a90
I (275) cpu_start: Pro cpu up.
I (275) cpu_start: Application information:
I (275) cpu_start: Project name: esp-idf
I (277) cpu_start: App version: 1
I (282) cpu_start: Compile time: Jul 20 2020 14:02:25
I (288) cpu_start: ELF file SHA256: 2feee966c066958a…
I (294) cpu_start: ESP-IDF: v3.3.2-235-ga3ce2f400
I (300) cpu_start: Single core mode
I (304) heap_init: Initializing. RAM available for dynamic allocation:
I (311) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (317) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (323) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (330) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (336) heap_init: At 3FFCC480 len 00013B80 (78 KiB): DRAM
I (342) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM
I (348) heap_init: At 40078000 len 00008000 (32 KiB): IRAM
I (354) heap_init: At 40094F6C len 0000B094 (44 KiB): IRAM
I (361) cpu_start: Pro cpu start user code
I (42) cpu_start: Starting scheduler on PRO CPU.
I (51) PKCS11: Initializing NVS partition: “storage”
E (71) PKCS11: failed nvs get file size 4354 0
0 3 [loopTask] Write certificate…
1 4 [iot_thread] [INFO ][DEMO][40] ---------STARTING DEMO---------

2 4 [iot_thread] [INFO ][INIT][40] SDK successfully initialized.
Hello, from loop!
I (111) wifi:wifi driver task: 3ffb2388, prio:23, stack:3584, core=0
I (111) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (111) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (131) wifi:wifi firmware version: 1afdae0
I (131) wifi:config NVS flash: enabled
I (131) wifi:config nano formating: disabled
I (131) wifi:Init dynamic tx buffer num: 32
I (141) wifi:Init data frame dynamic rx buffer num: 32
I (141) wifi:Init management frame dynamic rx buffer num: 32
I (151) wifi:Init management short buffer num: 32
I (151) wifi:Init static rx buffer size: 1600
I (161) wifi:Init static rx buffer num: 10
I (161) wifi:Init dynamic rx buffer num: 32
I (251) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (251) wifi:mode : sta (4c:11:ae:61:21:ac)
I (251) WIFI: SYSTEM_EVENT_STA_START
I (1341) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:3
I (2321) wifi:state: init -> auth (b0)
I (2331) wifi:state: auth -> assoc (0)
I (2341) wifi:state: assoc -> run (10)
I (2351) wifi:connected with NETGEAR21, aid = 3, channel 9, BW20, bssid = 50:6a:03:a9:40:a9
I (2351) wifi:security type: 3, phy: bgn, rssi: -38
I (2361) wifi:pm start, type: 1

I (2361) WIFI: SYSTEM_EVENT_STA_CONNECTED
I (2391) wifi:AP’s beacon interval = 102400 us, DTIM period = 2
Hello, from loop!
I (4521) event: sta ip: 192.168.1.12, mask: 255.255.255.0, gw: 192.168.1.1
I (4521) WIFI: SYSTEM_EVENT_STA_GOT_IP
3 447 [iot_thread] [INFO ][DEMO][4470] Successfully initialized the demo. Network type for the demo: 1
4 447 [iot_thread] [INFO ][MQTT][4470] MQTT library successfully initialized.
5 447 [iot_thread] [INFO ][DEMO][4470] OTA demo version 0.0.1

6 447 [iot_thread] [INFO ][DEMO][4470] Connecting to broker…

7 447 [iot_thread] [INFO ][DEMO][4470] MQTT demo client identifier is A12345-67891 (length 12).
Hello, from loop!
E (5281) PKCS11: failed nvs get file size 4354 0
Hello, from loop!
8 1198 [iot_thread] [INFO ][MQTT][11980] Establishing new MQTT connection.
9 1198 [iot_thread] [INFO ][MQTT][11980] Anonymous metrics (SDK language, SDK version) will be provided to AWS IoT. Recompile with AWS_IOT_MQTT_ENABLE_METRICS set to 0 to disable.
10 1198 [iot_thread] [INFO ][MQTT][11980] (MQTT connection 0x3ffd08ec, CONNECT operation 0x3ffd8e48) Waiting for operation completion.
11 1239 [iot_thread] [INFO ][MQTT][12390] (MQTT connection 0x3ffd08ec, CONNECT operation 0x3ffd8e48) Wait complete with result SUCCESS.
12 1239 [iot_thread] [INFO ][MQTT][12390] New MQTT connection 0x3ffc119c established.
13 1240 [iot_thread] [OTA_AgentInit_internal] OTA Task is Ready.
I (12461) ota_pal: prvPAL_GetPlatformImageState
I (12461) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (12471) esp_ota_ops: [0] aflags/seq:0xffffffff/0x1, pflags/seq:0xffffffff/0x0
14 1242 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [Ready] Event [Start] New state [RequestingJob]
15 1244 [OTA Agent Task] [INFO ][MQTT][12420] (MQTT connection 0x3ffd08ec) SUBSCRIBE operation scheduled.
16 1244 [OTA Agent Task] [INFO ][MQTT][12440] (MQTT connection 0x3ffd08ec, SUBSCRIBE operation 0x3ffd8e48) Waiting for operation completion.
17 1280 [OTA Agent Task] [INFO ][MQTT][12800] (MQTT connection 0x3ffd08ec, SUBSCRIBE operation 0x3ffd8e48) Wait complete with result SUCCESS.
18 1280 [OTA Agent Task] [prvSubscribeToJobNotificationTopics] OK: $aws/things/A12345-67891/jobs/$next/get/accepted
19 1280 [OTA Agent Task] [INFO ][MQTT][12800] (MQTT connection 0x3ffd08ec) SUBSCRIBE operation scheduled.
20 1280 [OTA Agent Task] [INFO ][MQTT][12800] (MQTT connection 0x3ffd08ec, SUBSCRIBE operation 0x3ffd8e48) Waiting for operation completion.
21 1340 [iot_thread] [INFO ][DEMO][13400] State: Ready Received: 0 Queued: 0 Processed: 0 Dropped: 0

22 1341 [OTA Agent Task] [INFO ][MQTT][13410] (MQTT connection 0x3ffd08ec, SUBSCRIBE operation 0x3ffd8e48) Wait complete with result SUCCESS.
23 1341 [OTA Agent Task] [prvSubscribeToJobNotificationTopics] OK: $aws/things/A12345-67891/jobs/notify-next
24 1341 [OTA Agent Task] [prvRequestJob_Mqtt] Request #0
25 1341 [OTA Agent Task] [INFO ][MQTT][13410] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
26 1341 [OTA Agent Task] [INFO ][MQTT][13410] (MQTT connection 0x3ffd08ec, PUBLISH operation 0x3ffd8e48) Waiting for operation completion.
Hello, from loop!
27 1402 [OTA Agent Task] [INFO ][MQTT][14020] (MQTT connection 0x3ffd08ec, PUBLISH operation 0x3ffd8e48) Wait complete with result SUCCESS.
28 1402 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [RequestingJob] Event [RequestJobDocument] New state [WaitingForJob]
I (14091) ota_pal: prvPAL_GetPlatformImageState
I (14091) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
I (14101) esp_ota_ops: [0] aflags/seq:0xffffffff/0x1, pflags/seq:0xffffffff/0x0
I (14111) ota_pal: Writing to partition subtype 17 at offset 0x400000
29 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ clientToken: 0:A12345-67891 ]
30 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ jobId: AFR_OTA-H20_2 ]
31 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ protocols: [“MQTT”] ]
32 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ streamname: AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee ]
33 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ filepath: - ]
34 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ filesize: 847504 ]
35 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ fileid: 0 ]
36 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ certfile: C:\Program Files\OpenSSL-Win64\bin ]
37 1404 [OTA Agent Task] [prvParseJSONbyModel] Extracted parameter [ sig-sha256-ecdsa: MEUCIQCeD0d38b9x/wJUWDVXiBpvJ6CV… ]
38 1404 [OTA Agent Task] [prvParseJobDoc] Job was accepted. Attempting to start transfer.
39 1450 [iot_thread] [INFO ][DEMO][14500] State: RequestingJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

40 1557 [iot_thread] [INFO ][DEMO][15570] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
41 1665 [iot_thread] [INFO ][DEMO][16650] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

42 1765 [iot_thread] [INFO ][DEMO][17650] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

43 1865 [iot_thread] [INFO ][DEMO][18650] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
I (19071) ota_pal: aws_esp_ota_begin succeeded
44 1902 [OTA Agent Task] [prvSetDataInterface] Data interface is set to MQTT.
45 1902 [OTA Agent Task] [prvProcessJobHandler] Setting OTA data inerface.
46 1902 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForJob] Event [ReceivedJobDocument] New state [CreatingFile]
47 1902 [OTA Agent Task] [INFO ][MQTT][19020] (MQTT connection 0x3ffd08ec) SUBSCRIBE operation scheduled.
48 1902 [OTA Agent Task] [INFO ][MQTT][19020] (MQTT connection 0x3ffd08ec, SUBSCRIBE operation 0x3ffd8e48) Waiting for operation completion.
49 1935 [OTA Agent Task] [INFO ][MQTT][19350] (MQTT connection 0x3ffd08ec, SUBSCRIBE operation 0x3ffd8e48) Wait complete with result SUCCESS.
50 1935 [OTA Agent Task] [prvInitFileTransfer_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/data/cbor
51 1935 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [CreatingFile] Event [CreateFile] New state [RequestingFileBlock]
52 1935 [OTA Agent Task] [INFO ][MQTT][19350] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
53 1935 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
54 1935 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [RequestingFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
55 1965 [iot_thread] [INFO ][DEMO][19650] State: WaitingForJob Received: 1 Queued: 0 Processed: 0 Dropped: 0

56 1977 [OTA Agent Task] [prvIngestDataBlock] Received file block 1, size 4096
57 1978 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
58 2018 [OTA Agent Task] [prvIngestDataBlock] Received file block 2, size 4096
59 2019 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
60 2059 [OTA Agent Task] [prvIngestDataBlock] Received file block 4, size 4096
61 2060 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
62 2065 [iot_thread] [INFO ][DEMO][20650] State: WaitingForFileBlock Received: 4 Queued: 0 Processed: 0 Dropped: 0

63 2078 [OTA Agent Task] [prvIngestDataBlock] Received file block 3, size 4096
64 2080 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
65 2081 [OTA Agent Task] [prvIngestDataBlock] Received file block 5, size 4096
66 2082 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
67 2120 [OTA Agent Task] [prvIngestDataBlock] Received file block 6, size 4096
68 2121 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
69 2161 [OTA Agent Task] [prvIngestDataBlock] Received file block 7, size 4096
70 2162 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
71 2165 [iot_thread] [INFO ][DEMO][21650] State: WaitingForFileBlock Received: 8 Queued: 0 Processed: 0 Dropped: 0

72 2201 [OTA Agent Task] [prvIngestDataBlock] Received file block 0, size 4096
73 2202 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
74 2202 [OTA Agent Task] [INFO ][MQTT][22020] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
75 2202 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
76 2202 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
77 2243 [OTA Agent Task] [prvIngestDataBlock] Received file block 8, size 4096
78 2244 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
79 2265 [iot_thread] [INFO ][DEMO][22650] State: WaitingForFileBlock Received: 10 Queued: 0 Processed: 0 Dropped: 0

80 2283 [OTA Agent Task] [prvIngestDataBlock] Received file block 10, size 4096
81 2284 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
82 2325 [OTA Agent Task] [prvIngestDataBlock] Received file block 9, size 4096
83 2326 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
84 2365 [iot_thread] [INFO ][DEMO][23650] State: WaitingForFileBlock Received: 12 Queued: 0 Processed: 0 Dropped: 0

85 2365 [OTA Agent Task] [prvIngestDataBlock] Received file block 11, size 4096
86 2366 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
87 2368 [OTA Agent Task] [prvIngestDataBlock] Received file block 13, size 4096
88 2369 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
89 2407 [OTA Agent Task] [prvIngestDataBlock] Received file block 14, size 4096
90 2408 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
91 2448 [OTA Agent Task] [prvIngestDataBlock] Received file block 15, size 4096
92 2449 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
93 2465 [iot_thread] [INFO ][DEMO][24650] State: WaitingForFileBlock Received: 16 Queued: 0 Processed: 0 Dropped: 0

94 2488 [OTA Agent Task] [prvIngestDataBlock] Received file block 12, size 4096
95 2489 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
96 2489 [OTA Agent Task] [INFO ][MQTT][24890] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
97 2489 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
98 2489 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
99 2530 [OTA Agent Task] [prvIngestDataBlock] Received file block 16, size 4096
100 2531 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
101 2550 [OTA Agent Task] [prvIngestDataBlock] Received file block 18, size 4096
102 2551 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
103 2565 [iot_thread] [INFO ][DEMO][25650] State: WaitingForFileBlock Received: 19 Queued: 0 Processed: 0 Dropped: 0

104 2570 [OTA Agent Task] [prvIngestDataBlock] Received file block 20, size 4096
105 2572 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
106 2591 [OTA Agent Task] [prvIngestDataBlock] Received file block 21, size 4096
107 2592 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
108 2594 [OTA Agent Task] [prvIngestDataBlock] Received file block 22, size 4096
109 2595 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
110 2612 [OTA Agent Task] [prvIngestDataBlock] Received file block 23, size 4096
111 2613 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
112 2632 [OTA Agent Task] [prvIngestDataBlock] Received file block 19, size 4096
113 2633 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
114 2652 [OTA Agent Task] [prvIngestDataBlock] Received file block 17, size 4096
115 2653 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
116 2655 [OTA Agent Task] [INFO ][MQTT][26550] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
117 2655 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
118 2655 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
119 2665 [iot_thread] [INFO ][DEMO][26650] State: WaitingForFileBlock Received: 25 Queued: 0 Processed: 0 Dropped: 0

120 2694 [OTA Agent Task] [prvIngestDataBlock] Received file block 24, size 4096
121 2695 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
122 2734 [OTA Agent Task] [prvIngestDataBlock] Received file block 25, size 4096
123 2736 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
124 2755 [OTA Agent Task] [prvIngestDataBlock] Received file block 26, size 4096
125 2756 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
126 2765 [iot_thread] [INFO ][DEMO][27650] State: WaitingForFileBlock Received: 28 Queued: 0 Processed: 0 Dropped: 0

127 2775 [OTA Agent Task] [prvIngestDataBlock] Received file block 27, size 4096
128 2776 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
129 2777 [OTA Agent Task] [prvIngestDataBlock] Received file block 28, size 4096
130 2778 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
131 2816 [OTA Agent Task] [prvIngestDataBlock] Received file block 29, size 4096
132 2817 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
133 2857 [OTA Agent Task] [prvIngestDataBlock] Received file block 30, size 4096
134 2858 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
135 2865 [iot_thread] [INFO ][DEMO][28650] State: WaitingForFileBlock Received: 32 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
136 2898 [OTA Agent Task] [prvIngestDataBlock] Received file block 31, size 4096
137 2899 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
138 2899 [OTA Agent Task] [INFO ][MQTT][28990] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
139 2899 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
140 2899 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
141 2919 [OTA Agent Task] [prvIngestDataBlock] Received file block 32, size 4096
142 2920 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
143 2939 [OTA Agent Task] [prvIngestDataBlock] Received file block 33, size 4096
144 2940 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
145 2960 [OTA Agent Task] [prvIngestDataBlock] Received file block 35, size 4096
146 2961 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
147 2965 [iot_thread] [INFO ][DEMO][29650] State: WaitingForFileBlock Received: 36 Queued: 0 Processed: 0 Dropped: 0

148 2979 [OTA Agent Task] [prvIngestDataBlock] Received file block 34, size 4096
149 2981 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
150 2982 [OTA Agent Task] [prvIngestDataBlock] Received file block 36, size 4096
151 2983 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
152 3021 [OTA Agent Task] [prvIngestDataBlock] Received file block 37, size 4096
153 3022 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
154 3062 [OTA Agent Task] [prvIngestDataBlock] Received file block 39, size 4096
155 3063 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
156 3065 [iot_thread] [INFO ][DEMO][30650] State: WaitingForFileBlock Received: 40 Queued: 0 Processed: 0 Dropped: 0

157 3103 [OTA Agent Task] [prvIngestDataBlock] Received file block 38, size 4096
158 3104 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
159 3104 [OTA Agent Task] [INFO ][MQTT][31040] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
160 3104 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
161 3104 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
162 3144 [OTA Agent Task] [prvIngestDataBlock] Received file block 41, size 4096
163 3145 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
164 3165 [iot_thread] [INFO ][DEMO][31650] State: WaitingForFileBlock Received: 42 Queued: 0 Processed: 0 Dropped: 0

165 3165 [OTA Agent Task] [prvIngestDataBlock] Received file block 40, size 4096
166 3166 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
167 3185 [OTA Agent Task] [prvIngestDataBlock] Received file block 44, size 4096
168 3186 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
169 3226 [OTA Agent Task] [prvIngestDataBlock] Received file block 42, size 4096
170 3227 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
171 3229 [OTA Agent Task] [prvIngestDataBlock] Received file block 43, size 4096
172 3230 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
173 3265 [iot_thread] [INFO ][DEMO][32650] State: WaitingForFileBlock Received: 46 Queued: 0 Processed: 0 Dropped: 0

174 3267 [OTA Agent Task] [prvIngestDataBlock] Received file block 45, size 4096
175 3268 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
176 3308 [OTA Agent Task] [prvIngestDataBlock] Received file block 46, size 4096
177 3309 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
178 3348 [OTA Agent Task] [prvIngestDataBlock] Received file block 47, size 4096
179 3349 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
180 3349 [OTA Agent Task] [INFO ][MQTT][33490] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
181 3349 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
182 3349 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
183 3365 [iot_thread] [INFO ][DEMO][33650] State: WaitingForFileBlock Received: 49 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
184 3390 [OTA Agent Task] [prvIngestDataBlock] Received file block 48, size 4096
185 3391 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
186 3431 [OTA Agent Task] [prvIngestDataBlock] Received file block 49, size 4096
187 3432 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
188 3465 [iot_thread] [INFO ][DEMO][34650] State: WaitingForFileBlock Received: 51 Queued: 0 Processed: 0 Dropped: 0

189 3472 [OTA Agent Task] [prvIngestDataBlock] Received file block 50, size 4096
190 3473 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
191 3513 [OTA Agent Task] [prvIngestDataBlock] Received file block 51, size 4096
192 3514 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
193 3553 [OTA Agent Task] [prvIngestDataBlock] Received file block 53, size 4096
194 3555 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
195 3565 [iot_thread] [INFO ][DEMO][35650] State: WaitingForFileBlock Received: 54 Queued: 0 Processed: 0 Dropped: 0

196 3594 [OTA Agent Task] [prvIngestDataBlock] Received file block 54, size 4096
197 3595 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
198 3597 [OTA Agent Task] [prvIngestDataBlock] Received file block 55, size 4096
199 3598 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
200 3636 [OTA Agent Task] [prvIngestDataBlock] Received file block 52, size 4096
201 3637 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
202 3637 [OTA Agent Task] [INFO ][MQTT][36370] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
203 3637 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
204 3637 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
205 3665 [iot_thread] [INFO ][DEMO][36650] State: WaitingForFileBlock Received: 57 Queued: 0 Processed: 0 Dropped: 0

206 3676 [OTA Agent Task] [prvIngestDataBlock] Received file block 59, size 4096
207 3678 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
208 3697 [OTA Agent Task] [prvIngestDataBlock] Received file block 56, size 4096
209 3698 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
210 3717 [OTA Agent Task] [prvIngestDataBlock] Received file block 58, size 4096
211 3718 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
212 3758 [OTA Agent Task] [prvIngestDataBlock] Received file block 61, size 4096
213 3759 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
214 3760 [OTA Agent Task] [prvIngestDataBlock] Received file block 60, size 4096
215 3761 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
216 3765 [iot_thread] [INFO ][DEMO][37650] State: WaitingForFileBlock Received: 62 Queued: 0 Processed: 0 Dropped: 0

217 3779 [OTA Agent Task] [prvIngestDataBlock] Received file block 62, size 4096
218 3780 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
219 3820 [OTA Agent Task] [prvIngestDataBlock] Received file block 63, size 4096
220 3821 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
221 3860 [OTA Agent Task] [prvIngestDataBlock] Received file block 57, size 4096
222 3861 [OTA Agent Task] [prvPublishStatusMessage] Msg: {“status”:“IN_PROGRESS”,“statusDetails”:{“receive”:“64/207”}}
223 3861 [OTA Agent Task] [INFO ][MQTT][38610] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
224 3861 [OTA Agent Task] [prvPublishStatusMessage] ‘IN_PROGRESS’ to $aws/things/A12345-67891/jobs/AFR_OTA-H20_2/update
225 3861 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
226 3863 [OTA Agent Task] [INFO ][MQTT][38630] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
227 3863 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
228 3863 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
229 3865 [iot_thread] [INFO ][DEMO][38650] State: WaitingForFileBlock Received: 65 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
230 3943 [OTA Agent Task] [prvIngestDataBlock] Received file block 64, size 4096
231 3944 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
232 3963 [OTA Agent Task] [prvIngestDataBlock] Received file block 65, size 4096
233 3964 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
234 3965 [iot_thread] [INFO ][DEMO][39650] State: WaitingForFileBlock Received: 67 Queued: 0 Processed: 0 Dropped: 0

235 3983 [OTA Agent Task] [prvIngestDataBlock] Received file block 66, size 4096
236 3984 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
237 4024 [OTA Agent Task] [prvIngestDataBlock] Received file block 67, size 4096
238 4025 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
239 4027 [OTA Agent Task] [prvIngestDataBlock] Received file block 68, size 4096
240 4028 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
241 4065 [iot_thread] [INFO ][DEMO][40650] State: WaitingForFileBlock Received: 70 Queued: 0 Processed: 0 Dropped: 0

242 4066 [OTA Agent Task] [prvIngestDataBlock] Received file block 69, size 4096
243 4067 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
244 4106 [OTA Agent Task] [prvIngestDataBlock] Received file block 70, size 4096
245 4108 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
246 4147 [OTA Agent Task] [prvIngestDataBlock] Received file block 71, size 4096
247 4148 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
248 4148 [OTA Agent Task] [INFO ][MQTT][41480] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
249 4148 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
250 4148 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
251 4165 [iot_thread] [INFO ][DEMO][41650] State: WaitingForFileBlock Received: 73 Queued: 0 Processed: 0 Dropped: 0

252 4189 [OTA Agent Task] [prvIngestDataBlock] Received file block 72, size 4096
253 4190 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
254 4230 [OTA Agent Task] [prvIngestDataBlock] Received file block 73, size 4096
255 4231 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
256 4265 [iot_thread] [INFO ][DEMO][42650] State: WaitingForFileBlock Received: 75 Queued: 0 Processed: 0 Dropped: 0

257 4271 [OTA Agent Task] [prvIngestDataBlock] Received file block 74, size 4096
258 4272 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
259 4311 [OTA Agent Task] [prvIngestDataBlock] Received file block 75, size 4096
260 4313 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
261 4314 [OTA Agent Task] [prvIngestDataBlock] Received file block 76, size 4096
262 4315 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
263 4352 [OTA Agent Task] [prvIngestDataBlock] Received file block 77, size 4096
264 4354 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
265 4365 [iot_thread] [INFO ][DEMO][43650] State: WaitingForFileBlock Received: 79 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
266 4393 [OTA Agent Task] [prvIngestDataBlock] Received file block 79, size 4096
267 4394 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
268 4434 [OTA Agent Task] [prvIngestDataBlock] Received file block 78, size 4096
269 4435 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
270 4435 [OTA Agent Task] [INFO ][MQTT][44350] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
271 4435 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
272 4435 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
273 4465 [iot_thread] [INFO ][DEMO][44650] State: WaitingForFileBlock Received: 81 Queued: 0 Processed: 0 Dropped: 0

274 4476 [OTA Agent Task] [prvIngestDataBlock] Received file block 80, size 4096
275 4477 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
276 4516 [OTA Agent Task] [prvIngestDataBlock] Received file block 81, size 4096
277 4517 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
278 4557 [OTA Agent Task] [prvIngestDataBlock] Received file block 82, size 4096
279 4558 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
280 4565 [iot_thread] [INFO ][DEMO][45650] State: WaitingForFileBlock Received: 84 Queued: 0 Processed: 0 Dropped: 0

281 4597 [OTA Agent Task] [prvIngestDataBlock] Received file block 83, size 4096
282 4599 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
283 4600 [OTA Agent Task] [prvIngestDataBlock] Received file block 84, size 4096
284 4601 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
285 4639 [OTA Agent Task] [prvIngestDataBlock] Received file block 85, size 4096
286 4640 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
287 4665 [iot_thread] [INFO ][DEMO][46650] State: WaitingForFileBlock Received: 87 Queued: 0 Processed: 0 Dropped: 0

288 4680 [OTA Agent Task] [prvIngestDataBlock] Received file block 86, size 4096
289 4681 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
290 4720 [OTA Agent Task] [prvIngestDataBlock] Received file block 87, size 4096
291 4721 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
292 4721 [OTA Agent Task] [INFO ][MQTT][47210] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
293 4721 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
294 4721 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
295 4762 [OTA Agent Task] [prvIngestDataBlock] Received file block 88, size 4096
296 4763 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
297 4765 [iot_thread] [INFO ][DEMO][47650] State: WaitingForFileBlock Received: 90 Queued: 0 Processed: 0 Dropped: 0

298 4782 [OTA Agent Task] [prvIngestDataBlock] Received file block 89, size 4096
299 4783 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
300 4805 [OTA Agent Task] [prvIngestDataBlock] Received file block 90, size 4096
301 4806 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
302 4823 [OTA Agent Task] [prvIngestDataBlock] Received file block 91, size 4096
303 4825 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
304 4826 [OTA Agent Task] [prvIngestDataBlock] Received file block 92, size 4096
305 4827 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
306 4864 [OTA Agent Task] [prvIngestDataBlock] Received file block 93, size 4096
307 4866 [iot_thread] [INFO ][DEMO][48660] State: WaitingForFileBlock Received: 95 Queued: 0 Processed: 0 Dropped: 0

308 4866 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
309 4885 [OTA Agent Task] [prvIngestDataBlock] Received file block 94, size 4096
310 4886 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
311 4925 [OTA Agent Task] [prvIngestDataBlock] Received file block 95, size 4096
312 4926 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
313 4926 [OTA Agent Task] [INFO ][MQTT][49260] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
314 4926 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
315 4926 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
316 4966 [iot_thread] [INFO ][DEMO][49660] State: WaitingForFileBlock Received: 97 Queued: 0 Processed: 0 Dropped: 0

317 4967 [OTA Agent Task] [prvIngestDataBlock] Received file block 96, size 4096
318 4968 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
319 4988 [OTA Agent Task] [prvIngestDataBlock] Received file block 97, size 4096
320 4989 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
321 5008 [OTA Agent Task] [prvIngestDataBlock] Received file block 98, size 4096
322 5010 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
323 5048 [OTA Agent Task] [prvIngestDataBlock] Received file block 99, size 4096
324 5049 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
325 5051 [OTA Agent Task] [prvIngestDataBlock] Received file block 100, size 4096
326 5052 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
327 5066 [iot_thread] [INFO ][DEMO][50660] State: WaitingForFileBlock Received: 102 Queued: 0 Processed: 0 Dropped: 0

328 5089 [OTA Agent Task] [prvIngestDataBlock] Received file block 101, size 4096
329 5090 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
330 5130 [OTA Agent Task] [prvIngestDataBlock] Received file block 102, size 4096
331 5132 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
332 5166 [iot_thread] [INFO ][DEMO][51660] State: WaitingForFileBlock Received: 104 Queued: 0 Processed: 0 Dropped: 0

333 5192 [OTA Agent Task] [prvIngestDataBlock] Received file block 103, size 4096
334 5193 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
335 5193 [OTA Agent Task] [INFO ][MQTT][51930] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
336 5193 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
337 5193 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
338 5253 [OTA Agent Task] [prvIngestDataBlock] Received file block 106, size 4096
339 5255 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
340 5266 [iot_thread] [INFO ][DEMO][52660] State: WaitingForFileBlock Received: 106 Queued: 0 Processed: 0 Dropped: 0

341 5294 [OTA Agent Task] [prvIngestDataBlock] Received file block 109, size 4096
342 5296 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
343 5335 [OTA Agent Task] [prvIngestDataBlock] Received file block 110, size 4096
344 5336 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
345 5366 [iot_thread] [INFO ][DEMO][53660] State: WaitingForFileBlock Received: 108 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
346 5376 [OTA Agent Task] [prvIngestDataBlock] Received file block 107, size 4096
347 5377 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
348 5379 [OTA Agent Task] [prvIngestDataBlock] Received file block 104, size 4096
349 5380 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
350 5438 [OTA Agent Task] [prvIngestDataBlock] Received file block 111, size 4096
351 5439 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
352 5466 [iot_thread] [INFO ][DEMO][54660] State: WaitingForFileBlock Received: 111 Queued: 0 Processed: 0 Dropped: 0

353 5479 [OTA Agent Task] [prvIngestDataBlock] Received file block 105, size 4096
354 5480 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
355 5519 [OTA Agent Task] [prvIngestDataBlock] Received file block 108, size 4096
356 5520 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
357 5520 [OTA Agent Task] [INFO ][MQTT][55200] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
358 5520 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
359 5520 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
360 5561 [OTA Agent Task] [prvIngestDataBlock] Received file block 112, size 4096
361 5562 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
362 5566 [iot_thread] [INFO ][DEMO][55660] State: WaitingForFileBlock Received: 114 Queued: 0 Processed: 0 Dropped: 0

363 5602 [OTA Agent Task] [prvIngestDataBlock] Received file block 113, size 4096
364 5603 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
365 5643 [OTA Agent Task] [prvIngestDataBlock] Received file block 114, size 4096
366 5644 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
367 5666 [iot_thread] [INFO ][DEMO][56660] State: WaitingForFileBlock Received: 116 Queued: 0 Processed: 0 Dropped: 0

368 5684 [OTA Agent Task] [prvIngestDataBlock] Received file block 115, size 4096
369 5685 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
370 5686 [OTA Agent Task] [prvIngestDataBlock] Received file block 116, size 4096
371 5687 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
372 5725 [OTA Agent Task] [prvIngestDataBlock] Received file block 117, size 4096
373 5726 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
374 5766 [iot_thread] [INFO ][DEMO][57660] State: WaitingForFileBlock Received: 119 Queued: 0 Processed: 0 Dropped: 0

375 5766 [OTA Agent Task] [prvIngestDataBlock] Received file block 118, size 4096
376 5767 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
377 5806 [OTA Agent Task] [prvIngestDataBlock] Received file block 119, size 4096
378 5807 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
379 5807 [OTA Agent Task] [INFO ][MQTT][58070] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
380 5807 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
381 5807 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
382 5847 [OTA Agent Task] [prvIngestDataBlock] Received file block 120, size 4096
383 5848 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
384 5866 [iot_thread] [INFO ][DEMO][58660] State: WaitingForFileBlock Received: 122 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
385 5888 [OTA Agent Task] [prvIngestDataBlock] Received file block 121, size 4096
386 5889 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
387 5929 [OTA Agent Task] [prvIngestDataBlock] Received file block 122, size 4096
388 5930 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
389 5966 [iot_thread] [INFO ][DEMO][59660] State: WaitingForFileBlock Received: 124 Queued: 0 Processed: 0 Dropped: 0

390 5990 [OTA Agent Task] [prvIngestDataBlock] Received file block 124, size 4096
391 5991 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
392 5993 [OTA Agent Task] [prvIngestDataBlock] Received file block 126, size 4096
393 5994 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
394 6052 [OTA Agent Task] [prvIngestDataBlock] Received file block 125, size 4096
395 6053 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
396 6066 [iot_thread] [INFO ][DEMO][60660] State: WaitingForFileBlock Received: 127 Queued: 0 Processed: 0 Dropped: 0

397 6093 [OTA Agent Task] [prvIngestDataBlock] Received file block 123, size 4096
398 6094 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
399 6133 [OTA Agent Task] [prvIngestDataBlock] Received file block 127, size 4096
400 6134 [OTA Agent Task] [prvPublishStatusMessage] Msg: {“status”:“IN_PROGRESS”,“statusDetails”:{“receive”:“128/207”}}
401 6134 [OTA Agent Task] [INFO ][MQTT][61340] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
402 6136 [OTA Agent Task] [prvPublishStatusMessage] ‘IN_PROGRESS’ to $aws/things/A12345-67891/jobs/AFR_OTA-H20_2/update
403 6136 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
404 6137 [OTA Agent Task] [INFO ][MQTT][61370] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
405 6137 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
406 6137 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
407 6166 [iot_thread] [INFO ][DEMO][61660] State: WaitingForFileBlock Received: 129 Queued: 0 Processed: 0 Dropped: 0

408 6236 [OTA Agent Task] [prvIngestDataBlock] Received file block 128, size 4096
409 6237 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
410 6266 [iot_thread] [INFO ][DEMO][62660] State: WaitingForFileBlock Received: 130 Queued: 0 Processed: 0 Dropped: 0

411 6318 [OTA Agent Task] [prvIngestDataBlock] Received file block 129, size 4096
412 6319 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
413 6366 [iot_thread] [INFO ][DEMO][63660] State: WaitingForFileBlock Received: 131 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
414 6401 [OTA Agent Task] [prvIngestDataBlock] Received file block 130, size 4096
415 6402 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
416 6466 [iot_thread] [INFO ][DEMO][64660] State: WaitingForFileBlock Received: 132 Queued: 0 Processed: 0 Dropped: 0

417 6482 [OTA Agent Task] [prvIngestDataBlock] Received file block 131, size 4096
418 6483 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
419 6484 [OTA Agent Task] [prvIngestDataBlock] Received file block 132, size 4096
420 6485 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
421 6544 [OTA Agent Task] [prvIngestDataBlock] Received file block 133, size 4096
422 6545 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
423 6566 [iot_thread] [INFO ][DEMO][65660] State: WaitingForFileBlock Received: 135 Queued: 0 Processed: 0 Dropped: 0

424 6605 [OTA Agent Task] [prvIngestDataBlock] Received file block 134, size 4096
425 6606 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
426 6666 [iot_thread] [INFO ][DEMO][66660] State: WaitingForFileBlock Received: 136 Queued: 0 Processed: 0 Dropped: 0

427 6666 [OTA Agent Task] [prvIngestDataBlock] Received file block 135, size 4096
428 6667 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
429 6667 [OTA Agent Task] [INFO ][MQTT][66670] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
430 6667 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
431 6667 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
432 6748 [OTA Agent Task] [prvIngestDataBlock] Received file block 136, size 4096
433 6750 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
434 6766 [iot_thread] [INFO ][DEMO][67660] State: WaitingForFileBlock Received: 138 Queued: 0 Processed: 0 Dropped: 0

435 6811 [OTA Agent Task] [prvIngestDataBlock] Received file block 137, size 4096
436 6812 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
437 6866 [iot_thread] [INFO ][DEMO][68660] State: WaitingForFileBlock Received: 139 Queued: 0 Processed: 0 Dropped: 0

438 6871 [OTA Agent Task] [prvIngestDataBlock] Received file block 138, size 4096
439 6872 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
440 6953 [OTA Agent Task] [prvIngestDataBlock] Received file block 139, size 4096
441 6954 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
442 6956 [OTA Agent Task] [prvIngestDataBlock] Received file block 141, size 4096
443 6957 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
444 6966 [iot_thread] [INFO ][DEMO][69660] State: WaitingForFileBlock Received: 142 Queued: 0 Processed: 0 Dropped: 0

445 7035 [OTA Agent Task] [prvIngestDataBlock] Received file block 142, size 4096
446 7036 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
447 7066 [iot_thread] [INFO ][DEMO][70660] State: WaitingForFileBlock Received: 143 Queued: 0 Processed: 0 Dropped: 0

448 7100 [OTA Agent Task] [prvIngestDataBlock] Received file block 143, size 4096
449 7101 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
450 7166 [iot_thread] [INFO ][DEMO][71660] State: WaitingForFileBlock Received: 144 Queued: 0 Processed: 0 Dropped: 0

451 7179 [OTA Agent Task] [prvIngestDataBlock] Received file block 140, size 4096
452 7180 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
453 7180 [OTA Agent Task] [INFO ][MQTT][71800] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
454 7180 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
455 7180 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
456 7199 [OTA Agent Task] [prvIngestDataBlock] Received file block 144, size 4096
457 7200 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
458 7220 [OTA Agent Task] [prvIngestDataBlock] Received file block 145, size 4096
459 7221 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
460 7241 [OTA Agent Task] [prvIngestDataBlock] Received file block 146, size 4096
461 7242 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
462 7266 [iot_thread] [INFO ][DEMO][72660] State: WaitingForFileBlock Received: 148 Queued: 0 Processed: 0 Dropped: 0

463 7281 [OTA Agent Task] [prvIngestDataBlock] Received file block 147, size 4096
464 7282 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
465 7284 [OTA Agent Task] [prvIngestDataBlock] Received file block 148, size 4096
466 7285 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
467 7322 [OTA Agent Task] [prvIngestDataBlock] Received file block 150, size 4096
468 7323 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
469 7363 [OTA Agent Task] [prvIngestDataBlock] Received file block 149, size 4096
470 7364 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
471 7366 [iot_thread] [INFO ][DEMO][73660] State: WaitingForFileBlock Received: 152 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
472 7403 [OTA Agent Task] [prvIngestDataBlock] Received file block 151, size 4096
473 7404 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
474 7404 [OTA Agent Task] [INFO ][MQTT][74040] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
475 7404 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
476 7404 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
477 7445 [OTA Agent Task] [prvIngestDataBlock] Received file block 152, size 4096
478 7446 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
479 7466 [iot_thread] [INFO ][DEMO][74660] State: WaitingForFileBlock Received: 154 Queued: 0 Processed: 0 Dropped: 0

480 7486 [OTA Agent Task] [prvIngestDataBlock] Received file block 153, size 4096
481 7487 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
482 7506 [OTA Agent Task] [prvIngestDataBlock] Received file block 154, size 4096
483 7508 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
484 7527 [OTA Agent Task] [prvIngestDataBlock] Received file block 155, size 4096
485 7528 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
486 7547 [OTA Agent Task] [prvIngestDataBlock] Received file block 156, size 4096
487 7548 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
488 7566 [iot_thread] [INFO ][DEMO][75660] State: WaitingForFileBlock Received: 158 Queued: 0 Processed: 0 Dropped: 0

489 7567 [OTA Agent Task] [prvIngestDataBlock] Received file block 157, size 4096
490 7568 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
491 7570 [OTA Agent Task] [prvIngestDataBlock] Received file block 158, size 4096
492 7571 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
493 7609 [OTA Agent Task] [prvIngestDataBlock] Received file block 159, size 4096
494 7610 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
495 7610 [OTA Agent Task] [INFO ][MQTT][76100] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
496 7610 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
497 7610 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
498 7650 [OTA Agent Task] [prvIngestDataBlock] Received file block 162, size 4096
499 7651 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
500 7666 [iot_thread] [INFO ][DEMO][76660] State: WaitingForFileBlock Received: 162 Queued: 0 Processed: 0 Dropped: 0

501 7691 [OTA Agent Task] [prvIngestDataBlock] Received file block 161, size 4096
502 7692 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
503 7711 [OTA Agent Task] [prvIngestDataBlock] Received file block 163, size 4096
504 7712 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
505 7731 [OTA Agent Task] [prvIngestDataBlock] Received file block 164, size 4096
506 7732 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
507 7734 [OTA Agent Task] [prvIngestDataBlock] Received file block 165, size 4096
508 7735 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
509 7752 [OTA Agent Task] [prvIngestDataBlock] Received file block 166, size 4096
510 7753 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
511 7766 [iot_thread] [INFO ][DEMO][77660] State: WaitingForFileBlock Received: 167 Queued: 0 Processed: 0 Dropped: 0

512 7792 [OTA Agent Task] [prvIngestDataBlock] Received file block 167, size 4096
513 7794 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
514 7834 [OTA Agent Task] [prvIngestDataBlock] Received file block 160, size 4096
515 7835 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
516 7835 [OTA Agent Task] [INFO ][MQTT][78350] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
517 7835 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
518 7835 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
519 7866 [iot_thread] [INFO ][DEMO][78660] State: WaitingForFileBlock Received: 169 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
520 7875 [OTA Agent Task] [prvIngestDataBlock] Received file block 168, size 4096
521 7876 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
522 7901 [OTA Agent Task] [prvIngestDataBlock] Received file block 169, size 4096
523 7902 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
524 7936 [OTA Agent Task] [prvIngestDataBlock] Received file block 170, size 4096
525 7937 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
526 7966 [iot_thread] [INFO ][DEMO][79660] State: WaitingForFileBlock Received: 172 Queued: 0 Processed: 0 Dropped: 0

527 7977 [OTA Agent Task] [prvIngestDataBlock] Received file block 171, size 4096
528 7978 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
529 7979 [OTA Agent Task] [prvIngestDataBlock] Received file block 172, size 4096
530 7980 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
531 8018 [OTA Agent Task] [prvIngestDataBlock] Received file block 173, size 4096
532 8019 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
533 8059 [OTA Agent Task] [prvIngestDataBlock] Received file block 174, size 4096
534 8060 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
535 8066 [iot_thread] [INFO ][DEMO][80660] State: WaitingForFileBlock Received: 176 Queued: 0 Processed: 0 Dropped: 0

536 8099 [OTA Agent Task] [prvIngestDataBlock] Received file block 175, size 4096
537 8100 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
538 8101 [OTA Agent Task] [INFO ][MQTT][81010] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
539 8101 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
540 8101 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
Hello, from loop!
541 8141 [OTA Agent Task] [prvIngestDataBlock] Received file block 182, size 4096
542 8143 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
543 8166 [iot_thread] [INFO ][DEMO][81660] State: WaitingForFileBlock Received: 178 Queued: 0 Processed: 0 Dropped: 0

544 8182 [OTA Agent Task] [prvIngestDataBlock] Received file block 177, size 4096
545 8183 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
546 8223 [OTA Agent Task] [prvIngestDataBlock] Received file block 181, size 4096
547 8224 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
548 8229 [OTA Agent Task] [prvIngestDataBlock] Received file block 180, size 4096
549 8230 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
550 8235 [OTA Agent Task] [prvIngestDataBlock] Received file block 179, size 4096
551 8236 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
552 8264 [OTA Agent Task] [prvIngestDataBlock] Received file block 183, size 4096
553 8265 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
554 8266 [iot_thread] [INFO ][DEMO][82660] State: WaitingForFileBlock Received: 183 Queued: 0 Processed: 0 Dropped: 0

555 8285 [OTA Agent Task] [prvIngestDataBlock] Received file block 178, size 4096
556 8286 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
557 8304 [OTA Agent Task] [prvIngestDataBlock] Received file block 176, size 4096
558 8305 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
559 8305 [OTA Agent Task] [INFO ][MQTT][83050] (MQTT connection 0x3ffd08ec) MQTT PUBLISH operation queued.
560 8305 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/A12345-67891/streams/AFR_OTA-5082f59e-2e70-478b-83b2-06612ce8d9ee/get/cbor
561 8305 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock]
562 8325 [OTA Agent Task] [prvIngestDataBlock] Received file block 184, size 4096
563 8327 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
564 8346 [OTA Agent Task] [prvIngestDataBlock] Received file block 185, size 4096
565 8347 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
566 8366 [iot_thread] [INFO ][DEMO][83660] State: WaitingForFileBlock Received: 187 Queued: 0 Processed: 0 Dropped: 0

Hello, from loop!
567 8386 [OTA Agent Task] [prvIngestDataBlock] Received file block 186, size 4096
568 8388 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
569 8427 [OTA Agent Task] [prvIngestDataBlock] Received file block 187, size 4096
570 8428 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
571 8430 [OTA Agent Task] [prvIngestDataBlock] Received file block 188, size 4096
572 8431 [OTA Agent Task] [prvExecuteHandler] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock]
573 8466 [iot_thread] [INFO ][DEMO][84660] State: WaitingForFileBlock Received: 190 Queued: 0 Processed: 0 Dropped: 0