text:
[GreenGrass] Can't create new MQTT connection if the previous one was not closed

Describe the bug
I'm using greengrass demo to connect to greengrass core over EC2 instance.
I'm using mobile phone as AP.
If the hardware was restarted without closing the connection, I have to reboot the mobile phone!
Edit:
Sometimes even with closing the connection, new connection can't be created.
System information

ESP32
VSCode
Operating System [Windows]
Version of Amazon FreeRTOS (201906.00_Major-539-g3a519702)
Project [Greengrass]

Expected behavior
This issue is not visible when using other demos, I think the issue may be related to using the MQTT_Agent instead of directly using MQTT v2 APIs directly
Thank you!

Hello ahmedwahdan,
How do you restart the hardware? Do you power cycle?
I am trying this out.

Hello Sarenameas,
Sometimes after successful demo complete, and some times if I restart the esp32 (power reset) before closing the connection, the connection can't established again with the greengrass core.

Could you please turn on logging in the TCP/IP stack in
vendors\espressif\boards\esp32\aws_demos\config_files\FreeRTOSIPConfig.h by setting:
#define ipconfigHAS_DEBUG_PRINTF    1

Then please post the logs here.

` make flash monitor
Flashing binaries to serial port COM6 (app at offset 0x20000 )...
esptool.py v2.6
Serial port COM6
Connecting.....
Chip is ESP32D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, Coding Scheme None
MAC: 30:ae:a4:22:ce:80
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.
Configuring flash size...
Auto-detected Flash size: 4MB
Compressed 23712 bytes to 14071...
Wrote 23712 bytes (14071 compressed) at 0x00001000 in 0.2 seconds (effective 1100.8 kbit/s)...
Hash of data verified.
Compressed 1099136 bytes to 669493...
Wrote 1099136 bytes (669493 compressed) at 0x00020000 in 10.6 seconds (effective 827.2 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 141...
Wrote 3072 bytes (141 compressed) at 0x00008000 in 0.0 seconds (effective 1804.0 kbit/s)...
Hash of data verified.
Leaving...
Hard resetting via RTS pin...
MONITOR
--- idf_monitor on COM6 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57
rst:0x1 (POWERON_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6252
load:0x40078000,len:11276
ho 0 tail 12 room 4
load:0x40080000,len:6084
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
entry 0x4008032c
0x4008032c: _KernelExceptionVector at ??:?
I (30) boot: ESP-IDF v3.1.3-25-g36733db8d 2nd stage bootloader
I (30) boot: compile time 13:22:56
I (31) boot: Enabling RNG early entropy source...
I (36) boot: SPI Speed      : 40MHz
I (40) boot: SPI Mode       : DIO
I (44) boot: SPI Flash Size : 4MB
I (48) boot: Partition Table:
I (52) boot: ## Label            Usage          Type ST Offset   Length
I (59) boot:  0 nvs              WiFi data        01 02 00010000 00006000
I (67) boot:  1 otadata          OTA data         01 00 00016000 00002000
I (74) boot:  2 phy_init         RF data          01 01 00018000 00001000
I (82) boot:  3 ota_0            OTA app          00 10 00020000 00177000
I (89) boot:  4 ota_1            OTA app          00 11 001a0000 00177000
I (97) boot:  5 storage          WiFi data        01 02 00317000 00010000
I (104) boot: End of partition table
I (108) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x2f4cc (193740) map
I (185) esp_image: segment 1: paddr=0x0004f4f4 vaddr=0x3ffc0000 size=0x00b1c (  2844) load
I (187) esp_image: segment 2: paddr=0x00050018 vaddr=0x400d0018 size=0xc376c (800620) map
0x400d0018: _flash_cache_start at ??:?
I (472) esp_image: segment 3: paddr=0x0011378c vaddr=0x3ffc0b1c size=0x02424 (  9252) load
I (476) esp_image: segment 4: paddr=0x00115bb8 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
I (479) esp_image: segment 5: paddr=0x00115fc0 vaddr=0x40080400 size=0x16598 ( 91544) load
I (539) boot: Loaded app from partition at offset 0x20000
I (539) boot: ota rollback check done
I (539) boot: Disabling RNG early entropy source...
I (544) cpu_start: Pro cpu up.
I (547) cpu_start: Single core mode
I (552) heap_init: Initializing. RAM available for dynamic allocation:
I (559) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (565) heap_init: At 3FFD1258 len 0000EDA8 (59 KiB): DRAM
I (571) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (577) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (583) heap_init: At 40096998 len 00009668 (37 KiB): IRAM
I (590) cpu_start: Pro cpu start user code
I (272) cpu_start: Starting scheduler on PRO CPU.
I (296) uart: queue free spaces: 10
0 1 [IP-task] prvIPTask started
I (296) PKCS11: Initializing NVS partition: "storage"
E (316) PKCS11: failed nvs get file size 4354 0
1 4 [main] Write certificate...
2 15 [main] Device credential provisioning succeeded.
I (446) BTDM_INIT: BT controller compile version [3828e65]
I (446) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (506) phy: phy_version: 4008, c9ae59f, Jan 25 2019, 16:54:06, 0, 0
3 56 [iot_thread] [INFO ][INIT][560] SDK successfully initialized.
I (876) wifi: wifi driver task: 3ffdb480, prio:23, stack:3584, core=0
I (876) wifi: wifi firmware version: dbb148a
I (876) wifi: config NVS flash: enabled
I (876) wifi: config nano formating: disabled
I (886) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (886) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (906) wifi: Init dynamic tx buffer num: 64
I (906) wifi: Init data frame dynamic rx buffer num: 64
I (906) wifi: Init management frame dynamic rx buffer num: 64
I (916) wifi: Init static rx buffer size: 1600
I (916) wifi: Init static rx buffer num: 16
I (926) wifi: Init dynamic rx buffer num: 64
I (936) wifi: mode : sta (30:ae:a4:22:ce:80)
I (936) WIFI: SYSTEM_EVENT_STA_START
I (1666) wifi: n:6 0, o:1 0, ap:255 255, sta:6 0, prof:1
I (2646) wifi: state: init -> auth (b0)
I (2646) wifi: state: auth -> assoc (0)
I (2656) wifi: state: assoc -> run (10)
I (2796) wifi: connected with Wahdan, channel 6
I (2796) wifi: pm start, type: 1
I (2806) WIFI: SYSTEM_EVENT_STA_CONNECTED
4 301 [IP-task] prvInitialiseDHCP: start after 25 ticks
5 301 [IP-task] vDHCPProcess: discover
6 338 [IP-task] vDHCPProcess: offer c0a82bbeip
7 338 [IP-task] vDHCPProcess: reply c0a82bbeip
I (5926) event: sta ip: 192.168.43.190, mask: 255.255.255.0, gw: 192.168.43.1
I (5926) WIFI: SYSTEM_EVENT_STA_GOT_IP
8 564 [IP-task] vDHCPProcess: offer c0a82bbeip
9 564 [IP-task] vDHCPProcess: acked c0a82bbeip
10 565 [iot_thread] [INFO ][DEMO][5650] Successfully initialized the demo. Network type for the demo: 1
11 565 [iot_thread] Attempting automated selection of Greengrass device
12 605 [iot_thread] prvProcessDNSCache: add: 'a3rcy4vytvmu2y-ats.iot.us-west-2.amazonaws.com' @ 22d5391fip
13 605 [iot_thread] FreeRTOS_connect: 64070 to 22d5391fip:8443
14 605 [iot_thread] Socket 64070 -> 22d5391fip:8443 State eCLOSED->eCONNECT_SYN
15 605 [IP-task] prvSocketSetMSS: 1400 bytes for 22d5391fip:8443
16 605 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
17 605 [IP-task] Connect[22d5391fip:8443]: next timeout 1: 3000 ms
18 646 [IP-task] MSS change 1400 -> 1388
19 646 [IP-task] Change mss 1400 => 1388
20 646 [IP-task] TCP: active 64070 => 22d5391fip:8443 set ESTAB (scaling 1)
21 646 [IP-task] Socket 64070 -> 22d5391fip:8443 State eCONNECT_SYN->eESTABLISHED
22 707 [IP-task] MSS: sending 1388
23 1424 [iot_thread] About to close socket.
24 1424 [IP-task] Socket 64070 -> 22d5391fip:8443 State eESTABLISHED->eFIN_WAIT_1
25 1485 [IP-task] Socket 64070 -> 22d5391fip:8443 State eFIN_WAIT_1->eCLOSE_WAIT
26 1485 [IP-task] FreeRTOS_closesocket[64070 to 22d5391fip:8443]: buffers 60 socks 0
27 1486 [iot_thread] Socket closed.
28 1486 [iot_thread] Stack high watermark for discovery helper task: 5220.
29 1526 [iot_thread] prvProcessDNSCache: add: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
30 1526 [iot_thread] FreeRTOS_connect: 24324 to 36d5e2bcip:8883
31 1526 [iot_thread] Socket 24324 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
32 1526 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
33 1526 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
34 1526 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
35 1567 [IP-task] MSS change 1400 -> 1388
36 1567 [IP-task] Change mss 1400 => 1388
37 1567 [IP-task] TCP: active 24324 => 36d5e2bcip:8883 set ESTAB (scaling 1)
38 1567 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
39 1629 [IP-task] MSS: sending 1388
40 2039 [iot_thread] About to close socket.
41 2039 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eESTABLISHED->eFIN_WAIT_1
42 2079 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eFIN_WAIT_1->eLAST_ACK
43 2079 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eLAST_ACK->eCLOSE_WAIT
44 2080 [IP-task] FreeRTOS_closesocket[24324 to 36d5e2bcip:8883]: buffers 60 socks 0
45 2080 [iot_thread] Socket closed.
46 2080 [iot_thread] Stack high watermark for discovery helper task: 2612.
47 2080 [iot_thread] Greengrass device discovered.
48 2080 [iot_thread] Establishing MQTT communication to Greengrass...
49 2080 [iot_thread] prvProcessDNSCache: look-up: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
50 2080 [iot_thread] FreeRTOS_gethostbyname: found 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' in cache: bce2d536ip
51 2080 [iot_thread] FreeRTOS_connect: 25012 to 36d5e2bcip:8883
52 2080 [iot_thread] Socket 25012 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
53 2080 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
54 2080 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
55 2080 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
56 2161 [IP-task] TCP: No active socket on port 24324 (36d5e2bcip:8883)
57 2161 [IP-task] MSS change 1400 -> 1388
58 2161 [IP-task] Change mss 1400 => 1388
59 2161 [IP-task] TCP: active 25012 => 36d5e2bcip:8883 set ESTAB (scaling 1)
60 2161 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
61 2274 [IP-task] MSS: sending 1388
62 2674 [iot_thread] [INFO ][MQTT][26740] Establishing new MQTT connection.
63 2674 [iot_thread] [INFO ][MQTT][26740] Anonymous metrics (SDK language, SDK version) will be provided to AWS IoT. Recompile with AWS_IOT_MQTT_ENABLE_METRICS set to 0 to disable.
64 2674 [iot_thread] [INFO ][MQTT][26740] (MQTT connection 0x3fff6f44, CONNECT operation 0x3ffe9adc) Waiting for operation completion.
65 2735 [iot_thread] [INFO ][MQTT][27350] (MQTT connection 0x3fff6f44, CONNECT operation 0x3ffe9adc) Wait complete with result SUCCESS.
66 2735 [iot_thread] [INFO ][MQTT][27350] New MQTT connection 0x3ffe9ba0 established.
67 2735 [iot_thread] [INFO ][MQTT][27350] (MQTT connection 0x3fff6f44) MQTT PUBLISH operation queued.
68 2885 [iot_thread] [INFO ][MQTT][28850] (MQTT connection 0x3fff6f44) MQTT PUBLISH operation queued.
69 3035 [iot_thread] [INFO ][MQTT][30350] (MQTT connection 0x3fff6f44) MQTT PUBLISH operation queued.
70 3185 [iot_thread] Disconnecting from broker.
71 3185 [iot_thread] [INFO ][MQTT][31850] (MQTT connection 0x3fff6f44) Disconnecting connection.
72 3185 [iot_thread] [INFO ][MQTT][31850] (MQTT connection 0x3fff6f44, DISCONNECT operation 0x3fff8bf8) Waiting for operation completion.
73 3186 [iot_thread] [INFO ][MQTT][31860] (MQTT connection 0x3fff6f44, DISCONNECT operation 0x3fff8bf8) Wait complete with result SUCCESS.
74 3186 [iot_thread] [INFO ][MQTT][31860] (MQTT connection 0x3fff6f44) Connection disconnected.
75 3187 [iot_thread] [INFO ][MQTT][31870] (MQTT connection 0x3fff6f44) Network connection closed.
76 3226 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eESTABLISHED->eFIN_WAIT_1
77 3226 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eFIN_WAIT_1->eLAST_ACK
78 3226 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eLAST_ACK->eLAST_ACK
79 3228 [IP-task] FreeRTOS_closesocket[25012 to 36d5e2bcip:8883]: buffers 60 socks 0
80 3228 [iot_thread] [INFO ][MQTT][32280] (MQTT connection 0x3fff6f44) Network connection destroyed.
81 3228 [iot_thread] Disconnected from the broker.
82 3228 [iot_thread] Deleted Client.
83 3228 [iot_thread] Heap low watermark: 8872. Stack high watermark: 2612.
84 3228 [iot_thread] ----Demo finished----
85 3267 [IP-task] TCP: No active socket on port 25012 (36d5e2bcip:8883)
86 3267 [IP-task] TCP: No active socket on port 25012 (36d5e2bcip:8883)
ets Jun  8 2016 00:22:57
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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6252
load:0x40078000,len:11276
ho 0 tail 12 room 4
load:0x40080000,len:6084
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
entry 0x4008032c
0x4008032c: _KernelExceptionVector at ??:?
I (31) boot: ESP-IDF v3.1.3-25-g36733db8d 2nd stage bootloader
I (31) boot: compile time 13:22:56
I (31) boot: Enabling RNG early entropy source...
I (36) boot: SPI Speed      : 40MHz
I (41) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 4MB
I (49) boot: Partition Table:
I (52) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00010000 00006000
I (67) boot:  1 otadata          OTA data         01 00 00016000 00002000
I (74) boot:  2 phy_init         RF data          01 01 00018000 00001000
I (82) boot:  3 ota_0            OTA app          00 10 00020000 00177000
I (89) boot:  4 ota_1            OTA app          00 11 001a0000 00177000
I (97) boot:  5 storage          WiFi data        01 02 00317000 00010000
I (104) boot: End of partition table
I (109) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x2f4cc (193740) map
I (186) esp_image: segment 1: paddr=0x0004f4f4 vaddr=0x3ffc0000 size=0x00b1c (  2844) load
I (187) esp_image: segment 2: paddr=0x00050018 vaddr=0x400d0018 size=0xc376c (800620) map
0x400d0018: _flash_cache_start at ??:?
I (472) esp_image: segment 3: paddr=0x0011378c vaddr=0x3ffc0b1c size=0x02424 (  9252) load
I (476) esp_image: segment 4: paddr=0x00115bb8 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
I (480) esp_image: segment 5: paddr=0x00115fc0 vaddr=0x40080400 size=0x16598 ( 91544) load
I (539) boot: Loaded app from partition at offset 0x20000
I (539) boot: ota rollback check done
I (539) boot: Disabling RNG early entropy source...
I (544) cpu_start: Pro cpu up.
I (548) cpu_start: Single core mode
I (552) heap_init: Initializing. RAM available for dynamic allocation:
I (559) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (565) heap_init: At 3FFD1258 len 0000EDA8 (59 KiB): DRAM
I (571) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (577) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (584) heap_init: At 40096998 len 00009668 (37 KiB): IRAM
I (590) cpu_start: Pro cpu start user code
I (272) cpu_start: Starting scheduler on PRO CPU.
I (297) uart: queue free spaces: 10
0 1 [IP-task] prvIPTask started
I (297) PKCS11: Initializing NVS partition: "storage"
E (317) PKCS11: failed nvs get file size 4354 0
1 4 [main] Write certificate...
2 15 [main] Device credential provisioning succeeded.
I (437) BTDM_INIT: BT controller compile version [3828e65]
I (437) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (507) phy: phy_version: 4008, c9ae59f, Jan 25 2019, 16:54:06, 0, 0
3 55 [iot_thread] [INFO ][INIT][550] SDK successfully initialized.
I (867) wifi: wifi driver task: 3ffdb13c, prio:23, stack:3584, core=0
I (867) wifi: wifi firmware version: dbb148a
I (867) wifi: config NVS flash: enabled
I (867) wifi: config nano formating: disabled
I (877) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (887) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (897) wifi: Init dynamic tx buffer num: 64
I (897) wifi: Init data frame dynamic rx buffer num: 64
I (897) wifi: Init management frame dynamic rx buffer num: 64
I (907) wifi: Init static rx buffer size: 1600
I (917) wifi: Init static rx buffer num: 16
I (917) wifi: Init dynamic rx buffer num: 64
I (927) wifi: mode : sta (30:ae:a4:22:ce:80)
I (927) WIFI: SYSTEM_EVENT_STA_START
I (1657) wifi: n:6 0, o:1 0, ap:255 255, sta:6 0, prof:1
I (2637) wifi: state: init -> auth (b0)
I (2647) wifi: state: auth -> assoc (0)
I (2647) wifi: state: assoc -> run (10)
I (2667) wifi: connected with Wahdan, channel 6
I (2667) wifi: pm start, type: 1
I (2677) WIFI: SYSTEM_EVENT_STA_CONNECTED
4 301 [IP-task] prvInitialiseDHCP: start after 25 ticks
5 301 [IP-task] vDHCPProcess: discover
6 302 [IP-task] vDHCPProcess: offer c0a82bbeip
7 302 [IP-task] vDHCPProcess: reply c0a82bbeip
I (4797) event: sta ip: 192.168.43.190, mask: 255.255.255.0, gw: 192.168.43.1
I (4797) WIFI: SYSTEM_EVENT_STA_GOT_IP
8 450 [IP-task] vDHCPProcess: offer c0a82bbeip
9 451 [IP-task] vDHCPProcess: acked c0a82bbeip
10 451 [iot_thread] [INFO ][DEMO][4510] Successfully initialized the demo. Network type for the demo: 1
11 451 [iot_thread] Attempting automated selection of Greengrass device
12 452 [iot_thread] prvProcessDNSCache: add: 'a3rcy4vytvmu2y-ats.iot.us-west-2.amazonaws.com' @ 34221bf9ip
13 454 [iot_thread] FreeRTOS_connect: 64070 to 34221bf9ip:8443
14 454 [iot_thread] Socket 64070 -> 34221bf9ip:8443 State eCLOSED->eCONNECT_SYN
15 454 [IP-task] prvSocketSetMSS: 1400 bytes for 34221bf9ip:8443
16 454 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
17 454 [IP-task] Connect[34221bf9ip:8443]: next timeout 1: 3000 ms
18 534 [IP-task] MSS change 1400 -> 1388
19 534 [IP-task] Change mss 1400 => 1388
20 534 [IP-task] TCP: active 64070 => 34221bf9ip:8443 set ESTAB (scaling 1)
21 534 [IP-task] Socket 64070 -> 34221bf9ip:8443 State eCONNECT_SYN->eESTABLISHED
22 635 [IP-task] MSS: sending 1388
23 1311 [iot_thread] About to close socket.
24 1311 [IP-task] Socket 64070 -> 34221bf9ip:8443 State eESTABLISHED->eFIN_WAIT_1
25 1351 [IP-task] Socket 64070 -> 34221bf9ip:8443 State eFIN_WAIT_1->eCLOSE_WAIT
26 1352 [IP-task] FreeRTOS_closesocket[64070 to 34221bf9ip:8443]: buffers 60 socks 0
27 1352 [iot_thread] Socket closed.
28 1352 [iot_thread] Stack high watermark for discovery helper task: 5136.
29 1354 [iot_thread] prvProcessDNSCache: add: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
30 1354 [iot_thread] FreeRTOS_connect: 24324 to 36d5e2bcip:8883
31 1354 [iot_thread] Socket 24324 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
32 1354 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
33 1354 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
34 1354 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
35 1393 [IP-task] MSS change 1400 -> 1388
36 1393 [IP-task] Change mss 1400 => 1388
37 1393 [IP-task] TCP: active 24324 => 36d5e2bcip:8883 set ESTAB (scaling 1)
38 1393 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
39 1454 [IP-task] MSS: sending 1388
40 1885 [iot_thread] About to close socket.
41 1885 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eESTABLISHED->eFIN_WAIT_1
42 1945 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eFIN_WAIT_1->eCLOSE_WAIT
43 1946 [IP-task] FreeRTOS_closesocket[24324 to 36d5e2bcip:8883]: buffers 60 socks 0
44 1946 [iot_thread] Socket closed.
45 1946 [iot_thread] Stack high watermark for discovery helper task: 2848.
46 1947 [iot_thread] Greengrass device discovered.
47 1947 [iot_thread] Establishing MQTT communication to Greengrass...
48 1947 [iot_thread] prvProcessDNSCache: look-up: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
49 1947 [iot_thread] FreeRTOS_gethostbyname: found 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' in cache: bce2d536ip
50 1948 [iot_thread] FreeRTOS_connect: 25012 to 36d5e2bcip:8883
51 1948 [iot_thread] Socket 25012 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
52 1948 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
53 1948 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
54 1948 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
55 2007 [IP-task] MSS change 1400 -> 1388
56 2007 [IP-task] Change mss 1400 => 1388
57 2007 [IP-task] TCP: active 25012 => 36d5e2bcip:8883 set ESTAB (scaling 1)
58 2007 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
59 2089 [IP-task] MSS: sending 1388
60 2581 [iot_thread] [INFO ][MQTT][25810] Establishing new MQTT connection.
61 2581 [iot_thread] [INFO ][MQTT][25810] Anonymous metrics (SDK language, SDK version) will be provided to AWS IoT. Recompile with AWS_IOT_MQTT_ENABLE_METRICS set to 0 to disable.
62 2581 [iot_thread] [INFO ][MQTT][25810] (MQTT connection 0x3fff6e74, CONNECT operation 0x3ffea374) Waiting for operation completion.
63 2642 [iot_thread] [INFO ][MQTT][26420] (MQTT connection 0x3fff6e74, CONNECT operation 0x3ffea374) Wait complete with result SUCCESS.
64 2642 [iot_thread] [INFO ][MQTT][26420] New MQTT connection 0x3ffe9b90 established.
65 2642 [iot_thread] [INFO ][MQTT][26420] (MQTT connection 0x3fff6e74) MQTT PUBLISH operation queued.
66 2792 [iot_thread] [INFO ][MQTT][27920] (MQTT connection 0x3fff6e74) MQTT PUBLISH operation queued.
67 2942 [iot_thread] [INFO ][MQTT][29420] (MQTT connection 0x3fff6e74) MQTT PUBLISH operation queued.
68 3092 [iot_thread] Disconnecting from broker.
69 3092 [iot_thread] [INFO ][MQTT][30920] (MQTT connection 0x3fff6e74) Disconnecting connection.
70 3092 [iot_thread] [INFO ][MQTT][30920] (MQTT connection 0x3fff6e74, DISCONNECT operation 0x3fff8494) Waiting for operation completion.
71 3093 [iot_thread] [INFO ][MQTT][30930] (MQTT connection 0x3fff6e74, DISCONNECT operation 0x3fff8494) Wait complete with result SUCCESS.
72 3093 [iot_thread] [INFO ][MQTT][30930] (MQTT connection 0x3fff6e74) Connection disconnected.
73 3093 [iot_thread] [INFO ][MQTT][30930] (MQTT connection 0x3fff6e74) Network connection closed.
74 3133 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eESTABLISHED->eFIN_WAIT_1
75 3134 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eFIN_WAIT_1->eLAST_ACK
76 3134 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eLAST_ACK->eLAST_ACK
77 3135 [IP-task] FreeRTOS_closesocket[25012 to 36d5e2bcip:8883]: buffers 60 socks 0
78 3135 [iot_thread] [INFO ][MQTT][31350] (MQTT connection 0x3fff6e74) Network connection destroyed.
79 3135 [iot_thread] Disconnected from the broker.
80 3135 [iot_thread] Deleted Client.
81 3135 [iot_thread] Heap low watermark: 9028. Stack high watermark: 2848.
82 3135 [iot_thread] ----Demo finished----
83 3175 [IP-task] TCP: No active socket on port 25012 (36d5e2bcip:8883)
ets Jun  8 2016 00:22:57
rst:0x1 (POWERON_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6252
load:0x40078000,len:11276
ho 0 tail 12 room 4
load:0x40080000,len:6084
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
entry 0x4008032c
0x4008032c: _KernelExceptionVector at ??:?
I (30) boot: ESP-IDF v3.1.3-25-g36733db8d 2nd stage bootloader
I (30) boot: compile time 13:22:56
I (31) boot: Enabling RNG early entropy source...
I (36) boot: SPI Speed      : 40MHz
I (40) boot: SPI Mode       : DIO
I (44) boot: SPI Flash Size : 4MB
I (48) boot: Partition Table:
I (52) boot: ## Label            Usage          Type ST Offset   Length
I (59) boot:  0 nvs              WiFi data        01 02 00010000 00006000
I (67) boot:  1 otadata          OTA data         01 00 00016000 00002000
I (74) boot:  2 phy_init         RF data          01 01 00018000 00001000
I (82) boot:  3 ota_0            OTA app          00 10 00020000 00177000
I (89) boot:  4 ota_1            OTA app          00 11 001a0000 00177000
I (97) boot:  5 storage          WiFi data        01 02 00317000 00010000
I (104) boot: End of partition table
I (108) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x2f4cc (193740) map
I (185) esp_image: segment 1: paddr=0x0004f4f4 vaddr=0x3ffc0000 size=0x00b1c (  2844) load
I (187) esp_image: segment 2: paddr=0x00050018 vaddr=0x400d0018 size=0xc376c (800620) map
0x400d0018: _flash_cache_start at ??:?
I (472) esp_image: segment 3: paddr=0x0011378c vaddr=0x3ffc0b1c size=0x02424 (  9252) load
I (476) esp_image: segment 4: paddr=0x00115bb8 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
I (479) esp_image: segment 5: paddr=0x00115fc0 vaddr=0x40080400 size=0x16598 ( 91544) load
I (539) boot: Loaded app from partition at offset 0x20000
I (539) boot: ota rollback check done
I (539) boot: Disabling RNG early entropy source...
I (544) cpu_start: Pro cpu up.
I (547) cpu_start: Single core mode
I (552) heap_init: Initializing. RAM available for dynamic allocation:
I (559) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (565) heap_init: At 3FFD1258 len 0000EDA8 (59 KiB): DRAM
I (571) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (577) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (584) heap_init: At 40096998 len 00009668 (37 KiB): IRAM
I (590) cpu_start: Pro cpu start user code
I (272) cpu_start: Starting scheduler on PRO CPU.
I (296) uart: queue free spaces: 10
0 1 [IP-task] prvIPTask started
I (296) PKCS11: Initializing NVS partition: "storage"
E (316) PKCS11: failed nvs get file size 4354 0
1 4 [main] Write certificate...
2 19 [main] Device credential provisioning succeeded.
I (476) BTDM_INIT: BT controller compile version [3828e65]
I (476) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (536) phy: phy_version: 4008, c9ae59f, Jan 25 2019, 16:54:06, 0, 0
3 58 [iot_thread] [INFO ][INIT][580] SDK successfully initialized.
I (896) wifi: wifi driver task: 3ffdfd48, prio:23, stack:3584, core=0
I (896) wifi: wifi firmware version: dbb148a
I (896) wifi: config NVS flash: enabled
I (896) wifi: config nano formating: disabled
I (906) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (916) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (926) wifi: Init dynamic tx buffer num: 64
I (926) wifi: Init data frame dynamic rx buffer num: 64
I (936) wifi: Init management frame dynamic rx buffer num: 64
I (936) wifi: Init static rx buffer size: 1600
I (946) wifi: Init static rx buffer num: 16
I (946) wifi: Init dynamic rx buffer num: 64
I (956) wifi: mode : sta (30:ae:a4:22:ce:80)
I (956) WIFI: SYSTEM_EVENT_STA_START
I (1686) wifi: n:6 0, o:1 0, ap:255 255, sta:6 0, prof:1
I (2666) wifi: state: init -> auth (b0)
I (2676) wifi: state: auth -> assoc (0)
I (2676) wifi: state: assoc -> run (10)
I (2716) wifi: connected with Wahdan, channel 6
I (2716) wifi: pm start, type: 1
I (2716) WIFI: SYSTEM_EVENT_STA_CONNECTED
4 301 [IP-task] prvInitialiseDHCP: start after 25 ticks
5 301 [IP-task] vDHCPProcess: discover
6 302 [IP-task] vDHCPProcess: offer c0a82bbeip
7 302 [IP-task] vDHCPProcess: reply c0a82bbeip
I (3356) event: sta ip: 192.168.43.190, mask: 255.255.255.0, gw: 192.168.43.1
I (3356) WIFI: SYSTEM_EVENT_STA_GOT_IP
8 307 [IP-task] vDHCPProcess: offer c0a82bbeip
9 307 [IP-task] vDHCPProcess: acked c0a82bbeip
10 307 [iot_thread] [INFO ][DEMO][3070] Successfully initialized the demo. Network type for the demo: 1
11 307 [iot_thread] Attempting automated selection of Greengrass device
12 365 [iot_thread] prvProcessDNSCache: add: 'a3rcy4vytvmu2y-ats.iot.us-west-2.amazonaws.com' @ 22d2df1eip
13 365 [iot_thread] FreeRTOS_connect: 64070 to 22d2df1eip:8443
14 365 [iot_thread] Socket 64070 -> 22d2df1eip:8443 State eCLOSED->eCONNECT_SYN
15 365 [IP-task] prvSocketSetMSS: 1400 bytes for 22d2df1eip:8443
16 365 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
17 365 [IP-task] Connect[22d2df1eip:8443]: next timeout 1: 3000 ms
18 426 [IP-task] MSS change 1400 -> 1388
19 426 [IP-task] Change mss 1400 => 1388
20 426 [IP-task] TCP: active 64070 => 22d2df1eip:8443 set ESTAB (scaling 1)
21 426 [IP-task] Socket 64070 -> 22d2df1eip:8443 State eCONNECT_SYN->eESTABLISHED
22 487 [IP-task] MSS: sending 1388
23 529 [IP-task] SACK[64070,8443]: optlen 12 sending 2083 - 2777
24 1225 [iot_thread] About to close socket.
25 1225 [IP-task] Socket 64070 -> 22d2df1eip:8443 State eESTABLISHED->eFIN_WAIT_1
26 1286 [IP-task] Socket 64070 -> 22d2df1eip:8443 State eFIN_WAIT_1->eCLOSE_WAIT
27 1286 [IP-task] FreeRTOS_closesocket[64070 to 22d2df1eip:8443]: buffers 60 socks 0
28 1287 [iot_thread] Socket closed.
29 1287 [iot_thread] Stack high watermark for discovery helper task: 5192.
30 1288 [iot_thread] prvProcessDNSCache: add: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
31 1289 [iot_thread] FreeRTOS_connect: 24324 to 36d5e2bcip:8883
32 1289 [iot_thread] Socket 24324 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
33 1289 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
34 1289 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
35 1289 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
36 1347 [IP-task] MSS change 1400 -> 1388
37 1347 [IP-task] Change mss 1400 => 1388
38 1347 [IP-task] TCP: active 24324 => 36d5e2bcip:8883 set ESTAB (scaling 1)
39 1348 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
40 1409 [IP-task] MSS: sending 1388
41 1799 [iot_thread] About to close socket.
42 1799 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eESTABLISHED->eFIN_WAIT_1
43 1839 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eFIN_WAIT_1->eCLOSE_WAIT
44 1839 [IP-task] FreeRTOS_closesocket[24324 to 36d5e2bcip:8883]: buffers 60 socks 0
45 1839 [iot_thread] Socket closed.
46 1840 [iot_thread] Stack high watermark for discovery helper task: 2600.
47 1840 [iot_thread] Greengrass device discovered.
48 1840 [iot_thread] Establishing MQTT communication to Greengrass...
49 1840 [iot_thread] prvProcessDNSCache: look-up: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
50 1840 [iot_thread] FreeRTOS_gethostbyname: found 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' in cache: bce2d536ip
51 1841 [iot_thread] FreeRTOS_connect: 25012 to 36d5e2bcip:8883
52 1841 [iot_thread] Socket 25012 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
53 1841 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
54 1841 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
55 1841 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
56 1890 [IP-task] eCONNECT_SYN: flags 0012 expected, not 0010
57 1890 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eCONNECT_SYN->eCLOSE_WAIT
ets Jun  8 2016 00:22:57
rst:0x1 (POWERON_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6252
load:0x40078000,len:11276
ho 0 tail 12 room 4
load:0x40080000,len:6084
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
entry 0x4008032c
0x4008032c: _KernelExceptionVector at ??:?
I (30) boot: ESP-IDF v3.1.3-25-g36733db8d 2nd stage bootloader
I (31) boot: compile time 13:22:56
I (31) boot: Enabling RNG early entropy source...
I (36) boot: SPI Speed      : 40MHz
I (40) boot: SPI Mode       : DIO
I (44) boot: SPI Flash Size : 4MB
I (48) boot: Partition Table:
I (52) boot: ## Label            Usage          Type ST Offset   Length
I (59) boot:  0 nvs              WiFi data        01 02 00010000 00006000
I (67) boot:  1 otadata          OTA data         01 00 00016000 00002000
I (74) boot:  2 phy_init         RF data          01 01 00018000 00001000
I (82) boot:  3 ota_0            OTA app          00 10 00020000 00177000
I (89) boot:  4 ota_1            OTA app          00 11 001a0000 00177000
I (97) boot:  5 storage          WiFi data        01 02 00317000 00010000
I (104) boot: End of partition table
I (108) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x2f4cc (193740) map
I (185) esp_image: segment 1: paddr=0x0004f4f4 vaddr=0x3ffc0000 size=0x00b1c (  2844) load
I (187) esp_image: segment 2: paddr=0x00050018 vaddr=0x400d0018 size=0xc376c (800620) map
0x400d0018: _flash_cache_start at ??:?
I (472) esp_image: segment 3: paddr=0x0011378c vaddr=0x3ffc0b1c size=0x02424 (  9252) load
I (476) esp_image: segment 4: paddr=0x00115bb8 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
I (479) esp_image: segment 5: paddr=0x00115fc0 vaddr=0x40080400 size=0x16598 ( 91544) load
I (539) boot: Loaded app from partition at offset 0x20000
I (539) boot: ota rollback check done
I (539) boot: Disabling RNG early entropy source...
I (544) cpu_start: Pro cpu up.
I (547) cpu_start: Single core mode
I (552) heap_init: Initializing. RAM available for dynamic allocation:
I (559) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (565) heap_init: At 3FFD1258 len 0000EDA8 (59 KiB): DRAM
I (571) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (577) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (584) heap_init: At 40096998 len 00009668 (37 KiB): IRAM
I (590) cpu_start: Pro cpu start user code
I (272) cpu_start: Starting scheduler on PRO CPU.
I (296) uart: queue free spaces: 10
0 1 [IP-task] prvIPTask started
I (296) PKCS11: Initializing NVS partition: "storage"
E (306) PKCS11: failed nvs get file size 4354 0
1 4 [main] Write certificate...
2 19 [main] Device credential provisioning succeeded.
I (476) BTDM_INIT: BT controller compile version [3828e65]
I (476) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (536) phy: phy_version: 4008, c9ae59f, Jan 25 2019, 16:54:06, 0, 0
3 59 [iot_thread] [INFO ][INIT][580] SDK successfully initialized.
I (906) wifi: wifi driver task: 3ffdb480, prio:23, stack:3584, core=0
I (906) wifi: wifi firmware version: dbb148a
I (906) wifi: config NVS flash: enabled
I (906) wifi: config nano formating: disabled
I (906) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (916) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (936) wifi: Init dynamic tx buffer num: 64
I (936) wifi: Init data frame dynamic rx buffer num: 64
I (936) wifi: Init management frame dynamic rx buffer num: 64
I (946) wifi: Init static rx buffer size: 1600
I (946) wifi: Init static rx buffer num: 16
I (956) wifi: Init dynamic rx buffer num: 64
I (966) wifi: mode : sta (30:ae:a4:22:ce:80)
I (966) WIFI: SYSTEM_EVENT_STA_START
I (1686) wifi: n:6 0, o:1 0, ap:255 255, sta:6 0, prof:1
I (2676) wifi: state: init -> auth (b0)
I (2686) wifi: state: auth -> assoc (0)
I (2686) wifi: state: assoc -> run (10)
I (2716) wifi: connected with Wahdan, channel 6
I (2716) wifi: pm start, type: 1
I (2716) WIFI: SYSTEM_EVENT_STA_CONNECTED
4 301 [IP-task] prvInitialiseDHCP: start after 25 ticks
5 301 [IP-task] vDHCPProcess: discover
6 302 [IP-task] vDHCPProcess: offer c0a82bbeip
7 302 [IP-task] vDHCPProcess: reply c0a82bbeip
I (3496) event: sta ip: 192.168.43.190, mask: 255.255.255.0, gw: 192.168.43.1
I (3496) WIFI: SYSTEM_EVENT_STA_GOT_IP
8 321 [IP-task] vDHCPProcess: offer c0a82bbeip
9 321 [IP-task] vDHCPProcess: acked c0a82bbeip
10 322 [iot_thread] [INFO ][DEMO][3220] Successfully initialized the demo. Network type for the demo: 1
11 322 [iot_thread] Attempting automated selection of Greengrass device
12 324 [iot_thread] prvProcessDNSCache: add: 'a3rcy4vytvmu2y-ats.iot.us-west-2.amazonaws.com' @ 342273a8ip
13 325 [iot_thread] FreeRTOS_connect: 64070 to 342273a8ip:8443
14 325 [iot_thread] Socket 64070 -> 342273a8ip:8443 State eCLOSED->eCONNECT_SYN
15 325 [IP-task] prvSocketSetMSS: 1400 bytes for 342273a8ip:8443
16 325 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
17 325 [IP-task] Connect[342273a8ip:8443]: next timeout 1: 3000 ms
18 403 [IP-task] MSS change 1400 -> 1388
19 403 [IP-task] Change mss 1400 => 1388
20 403 [IP-task] TCP: active 64070 => 342273a8ip:8443 set ESTAB (scaling 1)
21 403 [IP-task] Socket 64070 -> 342273a8ip:8443 State eCONNECT_SYN->eESTABLISHED
22 485 [IP-task] MSS: sending 1388
23 546 [IP-task] SACK[64070,8443]: optlen 12 sending 2083 - 2777
24 1462 [iot_thread] About to close socket.
25 1462 [IP-task] Socket 64070 -> 342273a8ip:8443 State eESTABLISHED->eFIN_WAIT_1
26 1492 [IP-task] Socket 64070 -> 342273a8ip:8443 State eFIN_WAIT_1->eCLOSE_WAIT
27 1492 [IP-task] FreeRTOS_closesocket[64070 to 342273a8ip:8443]: buffers 60 socks 0
28 1493 [iot_thread] Socket closed.
29 1493 [iot_thread] Stack high watermark for discovery helper task: 5140.
30 1506 [iot_thread] prvProcessDNSCache: add: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
31 1507 [iot_thread] FreeRTOS_connect: 24324 to 36d5e2bcip:8883
32 1507 [iot_thread] Socket 24324 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
33 1507 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
34 1507 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
35 1507 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
36 1556 [IP-task] MSS change 1400 -> 1388
37 1556 [IP-task] Change mss 1400 => 1388
38 1556 [IP-task] TCP: active 24324 => 36d5e2bcip:8883 set ESTAB (scaling 1)
39 1556 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
40 1617 [IP-task] MSS: sending 1388
41 2001 [iot_thread] About to close socket.
42 2001 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eESTABLISHED->eFIN_WAIT_1
43 2062 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eFIN_WAIT_1->eCLOSE_WAIT
44 2062 [IP-task] FreeRTOS_closesocket[24324 to 36d5e2bcip:8883]: buffers 60 socks 0
45 2062 [iot_thread] Socket closed.
46 2062 [iot_thread] Stack high watermark for discovery helper task: 2772.
47 2062 [iot_thread] Greengrass device discovered.
48 2062 [iot_thread] Establishing MQTT communication to Greengrass...
49 2062 [iot_thread] prvProcessDNSCache: look-up: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
50 2062 [iot_thread] FreeRTOS_gethostbyname: found 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' in cache: bce2d536ip
51 2063 [iot_thread] FreeRTOS_connect: 25012 to 36d5e2bcip:8883
52 2063 [iot_thread] Socket 25012 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
53 2063 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
54 2063 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
55 2063 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
56 2123 [IP-task] eCONNECT_SYN: flags 0012 expected, not 0010
57 2123 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eCONNECT_SYN->eCLOSE_WAIT
58 2564 [iot_thread] [ERROR][NET][25640] Failed to establish new connection.
59 2564 [IP-task] FreeRTOS_closesocket[25012 to 36d5e2bcip:8883]: buffers 60 socks 0
60 2564 [iot_thread] [ERROR][MQTT][25640] Failed to establish new MQTT connection, error NETWORK ERROR.
61 2564 [iot_thread] ERROR: Could not connect to the Broker.
62 2564 [iot_thread] Heap low watermark: 8840. Stack high watermark: 2772.
63 2564 [iot_thread] ----Demo finished----
ets Jun  8 2016 00:22:57
rst:0x1 (POWERON_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6252
load:0x40078000,len:11276
ho 0 tail 12 room 4
load:0x40080000,len:6084
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
entry 0x4008032c
0x4008032c: _KernelExceptionVector at ??:?
I (30) boot: ESP-IDF v3.1.3-25-g36733db8d 2nd stage bootloader
I (30) boot: compile time 13:22:56
I (31) boot: Enabling RNG early entropy source...
I (36) boot: SPI Speed      : 40MHz
I (40) boot: SPI Mode       : DIO
I (44) boot: SPI Flash Size : 4MB
I (48) boot: Partition Table:
I (52) boot: ## Label            Usage          Type ST Offset   Length
I (59) boot:  0 nvs              WiFi data        01 02 00010000 00006000
I (67) boot:  1 otadata          OTA data         01 00 00016000 00002000
I (74) boot:  2 phy_init         RF data          01 01 00018000 00001000
I (82) boot:  3 ota_0            OTA app          00 10 00020000 00177000
I (89) boot:  4 ota_1            OTA app          00 11 001a0000 00177000
I (97) boot:  5 storage          WiFi data        01 02 00317000 00010000
I (104) boot: End of partition table
I (108) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x2f4cc (193740) map
I (185) esp_image: segment 1: paddr=0x0004f4f4 vaddr=0x3ffc0000 size=0x00b1c (  2844) load
I (187) esp_image: segment 2: paddr=0x00050018 vaddr=0x400d0018 size=0xc376c (800620) map
0x400d0018: _flash_cache_start at ??:?
I (472) esp_image: segment 3: paddr=0x0011378c vaddr=0x3ffc0b1c size=0x02424 (  9252) load
I (476) esp_image: segment 4: paddr=0x00115bb8 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
I (479) esp_image: segment 5: paddr=0x00115fc0 vaddr=0x40080400 size=0x16598 ( 91544) load
I (539) boot: Loaded app from partition at offset 0x20000
I (539) boot: ota rollback check done
I (539) boot: Disabling RNG early entropy source...
I (544) cpu_start: Pro cpu up.
I (547) cpu_start: Single core mode
I (552) heap_init: Initializing. RAM available for dynamic allocation:
I (559) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (565) heap_init: At 3FFD1258 len 0000EDA8 (59 KiB): DRAM
I (571) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (577) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (584) heap_init: At 40096998 len 00009668 (37 KiB): IRAM
I (590) cpu_start: Pro cpu start user code
I (272) cpu_start: Starting scheduler on PRO CPU.
I (296) uart: queue free spaces: 10
0 1 [IP-task] prvIPTask started
I (296) PKCS11: Initializing NVS partition: "storage"
E (306) PKCS11: failed nvs get file size 4354 0
1 7 [main] Write certificate...
2 18 [main] Device credential provisioning succeeded.
I (466) BTDM_INIT: BT controller compile version [3828e65]
I (476) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (536) phy: phy_version: 4008, c9ae59f, Jan 25 2019, 16:54:06, 0, 0
3 58 [iot_thread] [INFO ][INIT][580] SDK successfully initialized.
I (896) wifi: wifi driver task: 3ffdb13c, prio:23, stack:3584, core=0
I (896) wifi: wifi firmware version: dbb148a
I (896) wifi: config NVS flash: enabled
I (906) wifi: config nano formating: disabled
I (906) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (916) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (936) wifi: Init dynamic tx buffer num: 64
I (936) wifi: Init data frame dynamic rx buffer num: 64
I (936) wifi: Init management frame dynamic rx buffer num: 64
I (936) wifi: Init static rx buffer size: 1600
I (946) wifi: Init static rx buffer num: 16
I (946) wifi: Init dynamic rx buffer num: 64
I (956) wifi: mode : sta (30:ae:a4:22:ce:80)
I (956) WIFI: SYSTEM_EVENT_STA_START
I (1686) wifi: n:6 0, o:1 0, ap:255 255, sta:6 0, prof:1
I (2666) wifi: state: init -> auth (b0)
I (2676) wifi: state: auth -> assoc (0)
I (2686) wifi: state: assoc -> run (10)
I (2716) wifi: connected with Wahdan, channel 6
I (2716) wifi: pm start, type: 1
I (2716) WIFI: SYSTEM_EVENT_STA_CONNECTED
4 301 [IP-task] prvInitialiseDHCP: start after 25 ticks
5 301 [IP-task] vDHCPProcess: discover
6 303 [IP-task] vDHCPProcess: offer c0a82bbeip
7 303 [IP-task] vDHCPProcess: reply c0a82bbeip
I (3346) event: sta ip: 192.168.43.190, mask: 255.255.255.0, gw: 192.168.43.1
I (3346) WIFI: SYSTEM_EVENT_STA_GOT_IP
8 306 [IP-task] vDHCPProcess: offer c0a82bbeip
9 306 [IP-task] vDHCPProcess: acked c0a82bbeip
10 307 [iot_thread] [INFO ][DEMO][3070] Successfully initialized the demo. Network type for the demo: 1
11 307 [iot_thread] Attempting automated selection of Greengrass device
12 308 [iot_thread] prvProcessDNSCache: add: 'a3rcy4vytvmu2y-ats.iot.us-west-2.amazonaws.com' @ 22d2df1eip
13 310 [iot_thread] FreeRTOS_connect: 64070 to 22d2df1eip:8443
14 310 [iot_thread] Socket 64070 -> 22d2df1eip:8443 State eCLOSED->eCONNECT_SYN
15 310 [IP-task] prvSocketSetMSS: 1400 bytes for 22d2df1eip:8443
16 310 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
17 310 [IP-task] Connect[22d2df1eip:8443]: next timeout 1: 3000 ms
18 377 [IP-task] MSS change 1400 -> 1388
19 377 [IP-task] Change mss 1400 => 1388
20 377 [IP-task] TCP: active 64070 => 22d2df1eip:8443 set ESTAB (scaling 1)
21 377 [IP-task] Socket 64070 -> 22d2df1eip:8443 State eCONNECT_SYN->eESTABLISHED
22 469 [IP-task] MSS: sending 1388
23 1248 [iot_thread] About to close socket.
24 1248 [IP-task] Socket 64070 -> 22d2df1eip:8443 State eESTABLISHED->eFIN_WAIT_1
25 1288 [IP-task] Socket 64070 -> 22d2df1eip:8443 State eFIN_WAIT_1->eCLOSE_WAIT
26 1289 [IP-task] FreeRTOS_closesocket[64070 to 22d2df1eip:8443]: buffers 60 socks 0
27 1289 [iot_thread] Socket closed.
28 1289 [iot_thread] Stack high watermark for discovery helper task: 5200.
29 1290 [iot_thread] prvProcessDNSCache: add: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
30 1291 [iot_thread] FreeRTOS_connect: 24324 to 36d5e2bcip:8883
31 1291 [iot_thread] Socket 24324 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
32 1291 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
33 1291 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
34 1291 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
35 1329 [IP-task] MSS change 1400 -> 1388
36 1329 [IP-task] Change mss 1400 => 1388
37 1329 [IP-task] TCP: active 24324 => 36d5e2bcip:8883 set ESTAB (scaling 1)
38 1329 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
39 1391 [IP-task] MSS: sending 1388
40 1780 [iot_thread] About to close socket.
41 1781 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eESTABLISHED->eFIN_WAIT_1
42 1841 [IP-task] Socket 24324 -> 36d5e2bcip:8883 State eFIN_WAIT_1->eCLOSE_WAIT
43 1842 [IP-task] FreeRTOS_closesocket[24324 to 36d5e2bcip:8883]: buffers 60 socks 0
44 1842 [iot_thread] Socket closed.
45 1842 [iot_thread] Stack high watermark for discovery helper task: 2768.
46 1842 [iot_thread] Greengrass device discovered.
47 1842 [iot_thread] Establishing MQTT communication to Greengrass...
48 1842 [iot_thread] prvProcessDNSCache: look-up: 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' @ 36d5e2bcip
49 1842 [iot_thread] FreeRTOS_gethostbyname: found 'ec2-54-213-226-188.us-west-2.compute.amazonaws.com' in cache: bce2d536ip
50 1843 [iot_thread] FreeRTOS_connect: 25012 to 36d5e2bcip:8883
51 1843 [iot_thread] Socket 25012 -> 36d5e2bcip:8883 State eCLOSED->eCONNECT_SYN
52 1843 [IP-task] prvSocketSetMSS: 1400 bytes for 36d5e2bcip:8883
53 1843 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
54 1843 [IP-task] Connect[36d5e2bcip:8883]: next timeout 1: 3000 ms
55 1923 [IP-task] MSS change 1400 -> 1388
56 1923 [IP-task] Change mss 1400 => 1388
57 1923 [IP-task] TCP: active 25012 => 36d5e2bcip:8883 set ESTAB (scaling 1)
58 1923 [IP-task] Socket 25012 -> 36d5e2bcip:8883 State eCONNECT_SYN->eESTABLISHED
59 2438 [iot_thread] ERROR: Handshake failed with error code -29312
60 2438 [iot_thread] [ERROR][NET][24380] Failed to establish new connection.
61 2438 [IP-task] FreeRTOS_closesocket[25012 to 36d5e2bcip:8883]: buffers 60 socks 0
62 2439 [iot_thread] [ERROR][MQTT][24390] Failed to establish new MQTT connection, error NETWORK ERROR.
63 2439 [iot_thread] ERROR: Could not connect to the Broker.
64 2439 [iot_thread] Heap low watermark: 8848. Stack high watermark: 2768.
65 2439 [iot_thread] ----Demo finished----
I (83686) wifi: state: run -> init (7c0)
`

@sarenameas Any updates related to this issue?

Hey ahmedwahdan,
Apologies for the delay. We are under investigation. I asked for logs earlier because I could reproduce your issue, but I wanted to see if you had the same one as me; and you did!
This the log I wanted to see if you had also:
56 2123 [IP-task] eCONNECT_SYN: flags 0012 expected, not 0010

It appears the server is responding with just and ACK instead of a SYN-ACK for a new connection request.  We are working on this now. We will get back to you on our findings.
Thanks for your patience.

Hello again,
This has been addressed now with PR #1413 .
Thanks for bringing this issue to the light.

Thanks @sarenameas  for the fix.
Could you please explain what was the issue?

I got this crash sometimes
`10 892 [IP-task] vDHCPProcess: offer c0a80106ip
11 892 [IP-task] vDHCPProcess: acked c0a80106ip
12 893 [iot_thread] [INFO ][DEMO][8930] Successfully initialized the demo. Network type for the demo: 1
13 893 [iot_thread] [INFO ][MQTT][8930] MQTT library successfully initialized.
14 893 [iot_thread] [INFO ][DEMO][8930] Attempting automated selection of Greengrass device
15 923 [iot_thread] prvProcessDNSCache: add: 'a3rcy4vytvmu2y-ats.iot.us-west-2.amazonaws.com' @ 327087e0ip
16 923 [iot_thread] FreeRTOS_connect: 35869 to 327087e0ip:8443
17 923 [iot_thread] Socket 35869 -> 327087e0ip:8443 State eCLOSED->eCONNECT_SYN
18 923 [IP-task] prvSocketSetMSS: 1400 bytes for 327087e0ip:8443
19 923 [IP-task] prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
20 923 [IP-task] Connect[327087e0ip:8443]: next timeout 1: 3000 ms
21 1076 [IP-task] MSS change 1400 -> 1412
22 1076 [IP-task] TCP: active 35869 => 327087e0ip:8443 set ESTAB (scaling 1)
23 1076 [IP-task] Socket 35869 -> 327087e0ip:8443 State eCONNECT_SYN->eESTABLISHED
24 1076 [IP-task] MSS change 1400 -> 1412
25 1592 [iot_thread] ERROR: Handshake failed with error code -29312
26 1592 [iot_thread] About to close socket.
CORRUPT HEAP: multi_heap.c:474 detected at 0x3ffef288
abort() was called at PC 0x40093dc9 on core 0
0x40093dc9: multi_heap_assert at D:/Wahdan/AFR_08_19/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:377
(inlined by) multi_heap_free_impl at D:/Wahdan/AFR_08_19/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:474
Backtrace: 0x400943e8:0x3ffddda0 0x400945b7:0x3ffdddc0 0x40093dc9:0x3ffddde0 0x400823de:0x3ffdde00 0x40091dca:0x3ffdde20 0x400ebb72:0x3ffdde40 0x400f129e:0x3ffdde60 0x400f14dc:0x3ffdde80 0x400
edf99:0x3ffddea0 0x400e9a4e:0x3ffddec0 0x400e9b8f:0x3ffddef0 0x400e9521:0x3ffddf20 0x400e996b:0x3ffddf50 0x400e2ff1:0x3ffddf80 0x400e309b:0x3ffddfc0 0x400efbf3:0x3ffddfe0 0x400edaa1:0x3ffde000
0x400943e8: invoke_abort at D:/Wahdan/AFR_08_19/amazon-freertos/vendors/espressif/esp-idf/components/esp32/panic.c:676
0x400945b7: abort at D:/Wahdan/AFR_08_19/amazon-freertos/vendors/espressif/esp-idf/components/esp32/panic.c:676
0x40093dc9: multi_heap_assert at D:/Wahdan/AFR_08_19/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:377
(inlined by) multi_heap_free_impl at D:/Wahdan/AFR_08_19/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:474
0x400823de: heap_caps_free at D:/Wahdan/AFR_08_19/amazon-freertos/vendors/espressif/esp-idf/components/heap/heap_caps.c:123
0x40091dca: vQueueDelete at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/queue.c:2364
0x400ebb72: C_CloseSession at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/abstractions/pkcs11/mbedtls/iot_pkcs11_mbedtls.c:628
0x400f129e: prvFreeContext at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/freertos_plus/standard/tls/src/iot_tls.c:129
0x400f14dc: TLS_Recv at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/freertos_plus/standard/tls/src/iot_tls.c:886
0x400edf99: SOCKETS_Recv at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/abstractions/secure_sockets/freertos_plus_tcp/iot_secure_sockets.c:231
0x400e9a4e: GGD_SecureConnect_Disconnect at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/freertos_plus/aws/greengrass/src/aws_helper_secure_connect.c:201
0x400e9b8f: GGD_SecureConnect_Connect at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/freertos_plus/aws/greengrass/src/aws_helper_secure_connect.c:165
0x400e9521: GGD_JSONRequestStart at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/freertos_plus/aws/greengrass/src/aws_greengrass_discovery.c:251
0x400e996b: GGD_GetGGCIPandCertificate at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/freertos_plus/aws/greengrass/src/aws_greengrass_discovery.c:174
0x400e2ff1: _discoverGreengrassCore at D:/Wahdan/AFR_08_19/amazon-freertos/demos/greengrass_connectivity/aws_greengrass_discovery_demo.c:215
0x400e309b: vStartGreenGrassDiscoveryTask at D:/Wahdan/AFR_08_19/amazon-freertos/demos/greengrass_connectivity/aws_greengrass_discovery_demo.c:284
0x400efbf3: runDemoTask at D:/Wahdan/AFR_08_19/amazon-freertos/demos/demo_runner/iot_demo_freertos.c:372
0x400edaa1: _threadRoutineWrapper at D:/Wahdan/AFR_08_19/amazon-freertos/libraries/abstractions/platform/freertos/iot_threads_freertos.c:318
Rebooting...
ets Jun  8 2016 00:22:57
rst:0xc (SW_CPU_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6252
load:0x40078000,len:11276
ho 0 tail 12 room 4
load:0x40080000,len:6084
0x40080000: _WindowOverflow4 at D:/Wahdan/AFR_08_19/amazon-freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685
entry 0x4008032c
0x4008032c: _KernelExceptionVector at ??:?
`

authors: ahmedwahdan sarenameas

repo: aws/amazon-freertos


text:
Fix ST I2C bug by adding break in switch block

Description

Fix ST I2C bug by adding break in switch block
Checklist:

[ ] I have tested my changes. No regression in existing tests.
[ ] My code is Linted.

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

/bot run checks

/bot run checks

/bot run checks

source: gharchive/pull-request

license: MIT

license_type: permissive

license_source: github-api


text:
fix: DynamoDB key & filter expressions attribute overwrite

Feature or Bugfix

Bugfix

Detail

DynamoDB Key and Filter expressions end up overwriting each other.

Relates

https://github.com/aws/aws-sdk-pandas/issues/2614

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

AWS CodeBuild CI Report

CodeBuild project: GitHubCodeBuild8756EF16-4rfo0GHQ0u9a
Commit ID: 25146e96cbe2aca7871e467fe39208c70f9497e5
Result: FAILED
Build Logs (available for 30 days)

Powered by github-codebuild-logs, available on the AWS Serverless Application Repository

AWS CodeBuild CI Report

CodeBuild project: GitHubDistributedCodeBuild6-jWcl5DLmvupS
Commit ID: 25146e96cbe2aca7871e467fe39208c70f9497e5
Result: FAILED
Build Logs (available for 30 days)

Powered by github-codebuild-logs, available on the AWS Serverless Application Repository

AWS CodeBuild CI Report

CodeBuild project: GitHubCodeBuild8756EF16-4rfo0GHQ0u9a
Commit ID: 7548fb268a9c8bafd540ceb94d14062a4dd62809
Result: SUCCEEDED
Build Logs (available for 30 days)

Powered by github-codebuild-logs, available on the AWS Serverless Application Repository

authors: kukushking malachi-constant

repo: aws/aws-sdk-pandas


text:
Fix Actions version in Workflows and Go mod tidy on Example App

Issue #, if available:
N/A
Description of changes:
Fixing broken example app and updateing versions of actions used in Github workflows
By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

@vastin Can we get a version cut after merging this?

repo: aws/aws-xray-sdk-go


text:
Add version v1.0.0 to all source files.

Add v1.0.0 to all source files.
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

Close in favor of https://github.com/aws/device-defender-for-aws-iot-embedded-sdk/pull/16


text:
Add base image notifiers

Issue #, if available:
Description of changes:
Add GH workflow that sends out notifications regarding new base image and builder-base updates.
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

/approved

repo: aws/eks-anywhere-prow-jobs


text:
Bump Golang version to 1.18.5 on builder-base

Bumping Golang to v1.18.5 on builder-base.
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

We're force-merging this and hoping for the best. According to Abhay, "we'll need to fix the EOF issue before adding more tools to builder-base"

authors: abhay-krishna kschumy

repo: aws/eks-distro-build-tooling


text:
Set GOPROXY env variable for Athens

Issue #, if available:
Description of changes:
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

Creating a prow setup. Will upload test results.

/hold
@bnrjee just comment with/unhold when you want to merge

/lgtm
/approve

Will retest one of the existing job. Merging this PR.
/unhold

authors: bnrjee micahhausler

repo: aws/eks-distro-prow-jobs


text:
1.27 11 docs 1693585469

Issue #, if available:
Description of changes:
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

/unhold
/lgtm
/approve

repo: aws/eks-distro


text:
test: add benchmarking into deprovisioning suite tests

Fixes #
Description
This uses the gmeasure library from ginkgo to get some deprovisioning stats.
  Report Entries >>
  deprovisioning benchmarks - /Volumes/workplace/go/src/github.com/aws/karpenter-core/pkg/controllers/deprovisioning/suite_test.go:926 @ 03/17/23 15:19:26.346
    deprovisioning benchmarks
    Name                                            | N  | Min      | Median   | Mean     | StdDev  | Max
    ==========================================================================================================
    deleting empty nodes [duration]                 | 20 | 295.5ms  | 303.1ms  | 406.7ms  | 441.8ms | 2.332s
    ----------------------------------------------------------------------------------------------------------
    replacing with zonal topology spread [duration] | 20 | 485.3ms  | 2.55s    | 2.0431s  | 891.3ms | 2.5947s
    ----------------------------------------------------------------------------------------------------------
    merging 3 nodes into 1 [duration]               | 20 | 2.4869s  | 2.5589s  | 2.5582s  | 36.7ms  | 2.6508s
    ----------------------------------------------------------------------------------------------------------
    replacing nodes [duration]                      | 20 | 393.8ms  | 2.4499s  | 2.0536s  | 822.5ms | 2.5717s
    ----------------------------------------------------------------------------------------------------------
    deleting nodes [duration]                       | 20 | 368.2ms  | 384.6ms  | 390.7ms  | 23.7ms  | 464ms
  << Report Entries

How was this change tested?
make ci-benchmark
By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

Pull Request Test Coverage Report for Build 4569729296

0 of 0   changed or added relevant lines in 0 files are covered.
1 unchanged line in 1 file lost coverage.
Overall coverage decreased (-1.2%) to 79.991%

Files with Coverage Reduction
New Missed Lines
%

pkg/controllers/deprovisioning/controller.go
1
81.92%

Totals

Change from base Build 4558530184:
-1.2%

Covered Lines:
3530

Relevant Lines:
4413

💛  - Coveralls

authors: coveralls njtran

repo: aws/karpenter-core


text:
2022-12-06_00-09-41_master-next_aws-sdk-cpp

Automatically created.

/run

/run


text:
Use kernel 5.10

Issue #, if available:
#857
Description of changes:
Upgrade kernel version to 5.10 for kubernetes version above 1.19 1.22.
It's useful for wireguard transparent encryption, it also includes performance improvements for Intel Ice Lake processors and AWS Graviton2 processors.
More details here
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

Hi, can I have input on this PR ?
Is it something possible ? Should we build additional ami with kernel-5.10 in the name ?
Thanks in advance for your response.

Hi @cartermckinnon , thanks for your response,
I'm pretty confident that it's will not break things, we already use this kernel with kops clusters without any issues (I agree with you, it's not the EKS ami)

I got feedback from the wider team today: we'll have to make this change in tandem with a Kubernetes release. While 5.10 has largely stabilized, it isn't as battle-tested as 5.4; and we shouldn't ask users to undertake this sort of upgrade in the middle of their k8s version's support cycle. I'll update the title to reflect this.
@rtripat @prasad0896 Do you think this is realistic for 1.22?

I modified the pull request to get the kernel 5.10 for kubernetes version >= 1.22 regarding your last comment. 👍

With Dirty Pipe I assume this upgrade may be more pressing?

With Dirty Pipe I assume this upgrade may be more pressing?

My .02: probably not exactly.
The sha of the fix for dirty pipe: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/lib/iov_iter.c?id=9d2231c5d74e13b2a0546fee6737ee4446017903
cinlin lists backported patches in: 5.16.11, 5.15.25, 5.10.102, 5.4.181, 4.19.231, 4.14.268, and 4.9.303`
At the time of this writing the latest ami (1.21.5-20220303) is still on 5.4.176-91.338.amzn2. Its yet unclear to me whether this kernel is modified outside the upstream versioning -- it'd be great to get confirmation from this team whether these amzn2 kernel versions are expected to precisely match upstream.
That is to say, the shortest path to patching dirty pipe seems to be 5.4.181, which is a somewhat distinct issue from upgrading to 5.10 -- since they're talking about bundling with a 1.22 upgrade, etc.

@cartermckinnon since EKS 1.22 has been released and this didn't land, is there any idea when we can get this kernel upgrade landed?

We're in a bind here, because:

At present, 5.10 isn't/wasn't stable enough to use as the default for 1.22, and we doubt that will change in time for 1.23.
We can't add a bootstrap flag for customers to opt-in to 5.10, because choosing a kernel at runtime isn't acceptable (it requires a reboot).
We can't ship a AMI variant for things like this, because it blows out our matrix and would change our support contract by requiring a deprecation path.

My best guess is that 5.10 will be the default kernel for the 1.24 release. In the meantime, if your workload necessitates 5.10, you should use a custom AMI.

For others that land here, my workaround for this issue, was to create an EKS node group based on the Bottlerocket OS. The officially supported image for EKS versions 1.20 and above is using kernel 5.10. It is a completely different architecture of a host system, so it might not be suitable for usecases that required deep modifications of the host environment. But if you are just looking to use features of 5.10 kernel in your workloads, like utilizing Wireguard, then Bottlerocket OS 1.5.3 (aws-k8s-1.20) can help.

@LCaparelli we're not aware of any active kernel CVE's in our current AMI's; it's possible the one you're referring to has already been addressed. Please follow the instructions here if otherwise.

@cartermckinnon could we get a status update on this for EKS v1.24 (November 2022 I think)?

@cartermckinnon @bwagner5 could we get a status update on this as the first EKS v1.24 AMI has been released and I don't see any mention of the v5.10 kernel? This is going to be a major issue if we can't use tools which require a modern kernel (e.g. eBPF).

You're correct, apologies for not updating the status here. Timelines haven't align as planned with 1.24 GA and the 5.10 migration; but we're working on it, and I expect 1.24 AMI's to use 5.10 before the end of the year.

@cartermckinnon does AL 2022 come into this discussion at all? Based on the docs it looks to be using kernel v5.15 by default. Is there a plan to move this to AL 2022 or to add an additional image based on it?

We do plan to use an AL2022 base when possible; my current forecast is 1.25 will ship atop AL2022, assuming the GA dates are reasonably aligned.

authors: cartermckinnon domderen mars64 matdehaast noony stefansedich stevehipwell

repo: awslabs/amazon-eks-ami


text:
Question regarding TPS service limit.

Hello.
We have implemented this and during testing we are seeing some errors in the logs.
Caused by: com.amazonaws.services.sqs.model.AmazonSQSException: Request is throttled. (Service: AmazonSQS; Status Code: 403; Error Code: RequestThrottled; Request ID: c8096cbe-1be5-5b2e-8a18-3a9c5fe245d8) at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleErrorResponse(AmazonHttpClient.java:1712) at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1367) at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1113) at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:770) at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:744) at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:726) at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:686) at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:668) at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:532) at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:512) at com.amazonaws.services.sqs.AmazonSQSClient.doInvoke(AmazonSQSClient.java:2235) at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2202) at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2191) at com.amazonaws.services.sqs.AmazonSQSClient.executeTagQueue(AmazonSQSClient.java:2043) at com.amazonaws.services.sqs.AmazonSQSClient.tagQueue(AmazonSQSClient.java:2015) at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.tagQueue(AbstractAmazonSQSClientWrapper.java:195) at com.amazonaws.services.sqs.AmazonSQSVirtualQueuesClient.lambda$tagQueue$13(AmazonSQSVirtualQueuesClient.java:235)
We suspect this is related to the service limit on our account (which is initially set to 5 TPS).
Do you have any recommendation as to which is a good limit to request when submitting a request for service limit increase ?

Hi there! Most of the usage of TagQueue in the library is for heartbeating to keep queues from appearing idle, so it's very likely this is harmless. I'd prefer to improve the library to handle this automatically rather than expect users to increase their limits.
Can you provide the complete stack trace so I can confirm? It's likely there just needs to be a bit more intelligent handling of TagQueue throttling on one of the code paths.
Could you also describe what your testing TPS looks like?

Hello. Thanks for the quick reply.
We are using the default values when building the request/response-clients, using two requesters and one responder. The documentation on aws states that the queue-tag limit is default 5 TPS.
The message queue is configured as a fifo queue.
I have done some more digging into the issue we encountered, and it made me uncertain about whether the root cause is related to the TPS service limit at all. Further examination of the error messages led me to the discovery that our requestors IAM role was missing the sqs:ListQueues, and might be the reason we encountered the throttling issue. It looks like this might be the root cause for being throttled. We added the correct permission to our requestors task role, and today we are not experiencing the same issue. I have included a sample of stacktraces:
`Oct 17, 2019 7:45:48 AM com.amazonaws.services.sqs.util.SQSQueueUtils lambda$static$0
SEVERE: Unexpected exception
java.lang.RuntimeException: Exception encounted while processing message with ID 4d8fdad4-5a10-46d9-897f-bc055783c38d
at com.amazonaws.services.sqs.util.SQSMessageConsumer.handleMessage(SQSMessageConsumer.java:152)
at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1382)
at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482)
at java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:291)
at java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:731)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.execLocalTasks(ForkJoinPool.java:1040)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1058)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Caused by: com.amazonaws.services.sqs.model.AmazonSQSException: Request is throttled. (Service: AmazonSQS; Status Code: 403; Error Code: RequestThrottled; Request ID: 4ab7c2ac-bc73-5a64-8355-948ea21fcffc)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleErrorResponse(AmazonHttpClient.java:1712)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1367)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1113)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:770)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:744)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:726)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:686)
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:668)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:532)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:512)
at com.amazonaws.services.sqs.AmazonSQSClient.doInvoke(AmazonSQSClient.java:2235)
at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2202)
at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2191)
at com.amazonaws.services.sqs.AmazonSQSClient.executeTagQueue(AmazonSQSClient.java:2043)
at com.amazonaws.services.sqs.AmazonSQSClient.tagQueue(AmazonSQSClient.java:2015)
at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.tagQueue(AbstractAmazonSQSClientWrapper.java:195)
at com.amazonaws.services.sqs.AmazonSQSVirtualQueuesClient.lambda$tagQueue$13(AmazonSQSVirtualQueuesClient.java:235)
at java.util.Optional.orElseGet(Optional.java:267)
at com.amazonaws.services.sqs.AmazonSQSVirtualQueuesClient.tagQueue(AmazonSQSVirtualQueuesClient.java:235)
at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.tagQueue(AbstractAmazonSQSClientWrapper.java:195)
at com.amazonaws.services.sqs.AbstractAmazonSQS.tagQueue(AbstractAmazonSQS.java:223)
at com.amazonaws.services.sqs.SQSExecutorService$Metadata.saveToTag(SQSExecutorService.java:159)
at com.amazonaws.services.sqs.SQSExecutorService$SQSFutureTask.send(SQSExecutorService.java:325)
at com.amazonaws.services.sqs.SQSScheduledExecutorService$ScheduledSQSFutureTask.run(SQSScheduledExecutorService.java:152)
at com.amazonaws.services.sqs.SQSExecutorService.accept(SQSExecutorService.java:196)
at com.amazonaws.services.sqs.util.SQSMessageConsumer.accept(SQSMessageConsumer.java:166)
at com.amazonaws.services.sqs.util.SQSMessageConsumer.handleMessage(SQSMessageConsumer.java:145)
... 10 more
Oct 17, 2019 7:45:48 AM com.amazonaws.services.sqs.AmazonSQSIdleQueueDeletingClient checkQueuesForIdleness
INFO: Checking all queues begining with prefix tmpQueue for idleness
Oct 17, 2019 7:45:49 AM com.amazonaws.services.sqs.util.SQSQueueUtils lambda$static$0
SEVERE: Unexpected exception
java.lang.RuntimeException: Encounted error when checking queues for idleness (prefix = tmpQueue)
at com.amazonaws.services.sqs.IdleQueueSweeper.checkQueuesForIdleness(IdleQueueSweeper.java:61)
at com.amazonaws.services.sqs.IdleQueueSweeper.lambda$new$f73a843a$1(IdleQueueSweeper.java:46)
at com.amazonaws.services.sqs.executors.DeduplicatedRunnable.run(DeduplicatedRunnable.java:29)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at com.amazonaws.services.sqs.SQSScheduledExecutorService$ScheduledSQSFutureTask.access$201(SQSScheduledExecutorService.java:33)
at com.amazonaws.services.sqs.SQSScheduledExecutorService$ScheduledSQSFutureTask.run(SQSScheduledExecutorService.java:150)
at com.amazonaws.services.sqs.SQSExecutorService.accept(SQSExecutorService.java:196)
at com.amazonaws.services.sqs.util.SQSMessageConsumer.accept(SQSMessageConsumer.java:166)
at com.amazonaws.services.sqs.util.SQSMessageConsumer.handleMessage(SQSMessageConsumer.java:145)
at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1382)
at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482)
at java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:291)
at java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:731)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.execLocalTasks(ForkJoinPool.java:1040)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1058)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Caused by: com.amazonaws.services.sqs.model.AmazonSQSException: Access to the resource https://sqs.eu-west-1.amazonaws.com/ is denied. (Service: AmazonSQS; Status Code: 403; Error Code: AccessDenied; Request ID: 948de23d-36c1-5401-88d1-b41f28adb291)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleErrorResponse(AmazonHttpClient.java:1712)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1367)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1113)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:770)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:744)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:726)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:686)
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:668)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:532)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:512)
at com.amazonaws.services.sqs.AmazonSQSClient.doInvoke(AmazonSQSClient.java:2235)
at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2202)
at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2191)
at com.amazonaws.services.sqs.AmazonSQSClient.executeListQueues(AmazonSQSClient.java:1404)
at com.amazonaws.services.sqs.AmazonSQSClient.listQueues(AmazonSQSClient.java:1376)
at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.listQueues(AbstractAmazonSQSClientWrapper.java:135)
at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.listQueues(AbstractAmazonSQSClientWrapper.java:135)
at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.listQueues(AbstractAmazonSQSClientWrapper.java:135)
at com.amazonaws.services.sqs.AbstractAmazonSQS.listQueues(AbstractAmazonSQS.java:158)
at com.amazonaws.services.sqs.IdleQueueSweeper.lambda$checkQueuesForIdleness$7dce85cd$1(IdleQueueSweeper.java:54)
at com.amazonaws.services.sqs.util.SQSQueueUtils.forEachQueue(SQSQueueUtils.java:153)
at com.amazonaws.services.sqs.IdleQueueSweeper.checkQueuesForIdleness(IdleQueueSweeper.java:54)
... 19 more`
Regards
Hans Christian

Thanks for the information. I'll definitely leave this issue open since the library should handle this case better, but can I assume that you are at least unblocked for now?

Thanks for the feedback. We are unblocked now, but we had to set the IdleQueueSweepingPeriod to 0 for our testing account, thats seems to solve the issue with throttling.

Hi,
Facing same issue of "Request is throttled" and setting IdleQueueSweepingPeriod = 0 is not working either...
Caused by: com.amazonaws.services.sqs.model.AmazonSQSException: Request is throttled. (Service: AmazonSQS; Status Code: 403; Error Code: RequestThrottled; Request ID: 798ffc63-8afa-5f06-a18e-ab50eaa28b58)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleErrorResponse(AmazonHttpClient.java:1799) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleServiceErrorResponse(AmazonHttpClient.java:1383) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1359) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1139) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:796) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:764) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:738) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:698) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:680) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:544) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:524) ~[aws-java-sdk-core-1.11.721.jar:na]
at com.amazonaws.services.sqs.AmazonSQSClient.doInvoke(AmazonSQSClient.java:2207) ~[aws-java-sdk-sqs-1.11.721.jar:na]
at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2174) ~[aws-java-sdk-sqs-1.11.721.jar:na]
at com.amazonaws.services.sqs.AmazonSQSClient.invoke(AmazonSQSClient.java:2163) ~[aws-java-sdk-sqs-1.11.721.jar:na]
at com.amazonaws.services.sqs.AmazonSQSClient.executeListQueueTags(AmazonSQSClient.java:1329) ~[aws-java-sdk-sqs-1.11.721.jar:na]
at com.amazonaws.services.sqs.AmazonSQSClient.listQueueTags(AmazonSQSClient.java:1301) ~[aws-java-sdk-sqs-1.11.721.jar:na]
at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.listQueueTags(AbstractAmazonSQSClientWrapper.java:141) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at com.amazonaws.services.sqs.AmazonSQSVirtualQueuesClient.lambda$listQueueTags$17(AmazonSQSVirtualQueuesClient.java:249) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at java.base/java.util.Optional.orElseGet(Optional.java:369) ~[na:na]
at com.amazonaws.services.sqs.AmazonSQSVirtualQueuesClient.listQueueTags(AmazonSQSVirtualQueuesClient.java:249) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at com.amazonaws.services.sqs.util.AbstractAmazonSQSClientWrapper.listQueueTags(AbstractAmazonSQSClientWrapper.java:141) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at com.amazonaws.services.sqs.AbstractAmazonSQS.listQueueTags(AbstractAmazonSQS.java:143) ~[aws-java-sdk-sqs-1.11.721.jar:na]
at com.amazonaws.services.sqs.SQSExecutorService$SQSFutureTask.getMetadataFromTags(SQSExecutorService.java:289) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at com.amazonaws.services.sqs.SQSExecutorService$SQSFutureTask.send(SQSExecutorService.java:295) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at com.amazonaws.services.sqs.SQSExecutorService.execute(SQSExecutorService.java:94) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at com.amazonaws.services.sqs.SQSScheduledExecutorService.execute(SQSScheduledExecutorService.java:19) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118) ~[na:na]
at com.amazonaws.services.sqs.executors.ExecutorUtils.lambda$acceptOn$2(ExecutorUtils.java:69) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at java.base/java.util.ArrayList.forEach(ArrayList.java:1540) ~[na:na]
at com.amazonaws.services.sqs.util.SQSQueueUtils.forEachQueue(SQSQueueUtils.java:164) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
at com.amazonaws.services.sqs.IdleQueueSweeper.checkQueuesForIdleness(IdleQueueSweeper.java:54) ~[amazon-sqs-java-temporary-queues-client-1.0.2.jar:na]
... 19 common frames omitted

Reopening to investigate "Request is throttled"  issues

Closing this since increasing the sweeping period  and heartbeating can help prevent throttling issues

source: gharchive/issue

authors: adam-aws hcalsos robin-aws saurabhmbm


text:
Configure Logging?

I’m really digging this tool for creating and configuring APIs. I consider setting up CloudWatch logging in-scope for this automation, but so far I haven’t found any reference to this in the examples or the code… am I missing something? If not, is this maybe on the roadmap? Come to think of it, is there a roadmap anywhere? Thanks!

To answer your specific questions, you aren't missing something. This tool doesn't support the CloudWatch logging setup operations. The CW Logs settings are on the stage settings which are applied outside of the actual API definition deployment, so it's debatable whether that fits in the scope of the tool. The tool does support doing a basic deployment with a stage name, as I'm sure you've noticed, so you could patch that code with additional parameters since the ApiGateway SDK under the hood supports all operations and settings and is easy to use.
In terms of roadmap, we don't have one publicly. I'll have to get back to you on adding a feature like this to the importer.

Thanks @jackrk for the thorough and thoughtful response!

I wrote a PR to provide this functionality. I haven't merged in any recent changes in a while from mainline. We're using my PR in production and have been for a while with no issues.
It made sense for us to add the code into the swagger-importer because the logic to parse the swagger file was already in place. The PR I had: https://github.com/awslabs/aws-apigateway-importer/pull/31

Thanks @cfair that seems perfect for @aviflax

Sure, no problem. The code was out there so I figured I'd point it out.
One note: the PR I have issued against this repo is missing a commit to make caching work. However, it is in my forked repo in the same branch where I issued the PR from. I also have an additional commit there to allow for the standard AWS credential provider chain, so we could use this on Jenkins.

Thanks @cfair that sounds very promising!
@jackrk any chance of some of the changes making their way into master?

Not in the near future. The feature set on master is pretty much locked, so only bug fixes. It's good to have input from customers on stage management as a part of this tool though!

authors: aviflax cfair jackrk

repo: awslabs/aws-apigateway-importer

license_source: bigquery


text:
fix(codebuild): remove oauthToken property from source

Auth field should not be set since it's ignored by CodeBuild
https://docs.aws.amazon.com/codebuild/latest/APIReference/API_ProjectSource.html#CodeBuild-Type-ProjectSource-auth
Refactored some unit tests as well
BREAKING CHANGE: customers who use GitHub, GitHubEnterprise or Bitbucket as source
will need to remove the oauthToken field as it's no longer available
Fixes #2199

Pull Request Checklist

[x] Testing

Unit test added (prefer not to modify an existing test, otherwise, it's probably a breaking change)
CLI change?: coordinate update of integration tests with team
cdk-init template change?: coordinated update of integration tests with team

[x] Docs

jsdocs: All public APIs documented
README: README and/or documentation topic updated

[x] Title and Description

Change type: title prefixed with fix, feat will appear in changelog
Title: use lower-case and doesn't end with a period
Breaking?: last paragraph: "BREAKING CHANGE: <describe what changed + link for details>"
Issues: Indicate issues fixed via: "Fixes #xxx" or "Closes #xxx"

[x] Sensitive Modules (requires 2 PR approvers)

IAM Policy Document (in @aws-cdk/aws-iam)
EC2 Security Groups and ACLs (in @aws-cdk/aws-ec2)
Grant APIs (only if not based on official documentation with a reference)

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license.

I think it would also be good to add an example of an ImportCredentials call. Can you add this to the README in a section title "Using GitHub repositories" or something similar?
aws codebuild import-source-credentials --server-type GITHUB --auth-type PERSONAL_ACCESS_TOKEN --token <token_value>

repo: awslabs/aws-cdk


text:
chore: upgrade to monocdk 1.70.0

BREAKING CHANGE: From this release on, aws-delivlib has a dependency
on monocdk instead of monocdk-experiment.

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

AWS CodeBuild CI Report

CodeBuild project: GitHubPipelineAutoBuildProj-eNGjrh4O6eRH
Commit ID: a3f84c5328b3d6a2495dff3bd5f9b42c4342c893
Result: FAILED
Build Logs (available for 30 days)

Powered by github-codebuild-logs, available on the AWS Serverless Application Repository

Curious what's the motivation for this change? Are we planning to stop releasing monocdk-experiment?

Yeah, monocdk-experiment has been deprecated in favor of monocdk, which surprised me quite a bit.

AWS CodeBuild CI Report

CodeBuild project: GitHubPipelineAutoBuildProj-eNGjrh4O6eRH
Commit ID: 22f70030f810d989716db7e2b15326b821d597fd
Result: FAILED
Build Logs (available for 30 days)

Powered by github-codebuild-logs, available on the AWS Serverless Application Repository

AWS CodeBuild CI Report

CodeBuild project: GitHubPipelineAutoBuildProj-eNGjrh4O6eRH
Commit ID: 4af2dfbd9b8bcf12759ca3138edbdb482be2ff25
Result: FAILED
Build Logs (available for 30 days)

Powered by github-codebuild-logs, available on the AWS Serverless Application Repository

AWS CodeBuild CI Report

CodeBuild project: GitHubPipelineAutoBuildProj-eNGjrh4O6eRH
Commit ID: 472b4a198ed5a6a69f0b52324f590e466300e9ea
Result: SUCCEEDED
Build Logs (available for 30 days)

Powered by github-codebuild-logs, available on the AWS Serverless Application Repository

authors: RomainMuller aws-cdk-automation

repo: awslabs/aws-delivlib


text:
Missing return type in lambda_handler_decorator leads to 'Untyped decorator makes function "..." untyped' errors in mypy strict mode

What were you trying to accomplish?
I'm trying to use aws_lambda_powertools.utilities.data_classes.event_source with mypy --strict, and receive errors about Untyped decorator makes function "handler" untyped. This is because lambda_handler_decorator is missing a return value, so mypy doesn't know anything about any function decorated with it (including event_source):
https://github.com/awslabs/aws-lambda-powertools-python/blob/22f8b9a7f47a2a4682c6f3f03536ac848ae7dc0d/aws_lambda_powertools/middleware_factory/factory.py#L15
Expected Behavior
@event_source and other decorators using @lambda_handler_decorator should work in mypy strict mode.
Current Behavior
Mypy emits errors.
Possible Solution

Add an appropriate Callable[something, here] return value to lambda_handler_decorator
Run mypy --strict in this package's CI

Steps to Reproduce (for bugs)
requirements:
aws-lambda-powertools==1.25.1
aws-xray-sdk==2.9.0
boto3==1.21.13
botocore==1.24.13
fastjsonschema==2.15.3
future==0.18.2
jmespath==0.10.0
mypy-extensions==0.4.3
mypy==0.931
python-dateutil==2.8.2
s3transfer==0.5.2
six==1.16.0
tomli==2.0.1
typing-extensions==4.1.1
urllib3==1.26.8
wrapt==1.13.3

input.py:
from typing import Any

from aws_lambda_powertools.middleware_factory import lambda_handler_decorator

from aws_lambda_powertools.utilities.data_classes import (
    event_source,
    KinesisStreamEvent,
)

@lambda_handler_decorator
def custom_decorator() -> None:
    return

@event_source(data_class=KinesisStreamEvent)
@custom_decorator
def handler(event: KinesisStreamEvent, context: Any) -> None:
    pass

invocation:
$ mypy --strict input.py
input.py:16: error: Untyped decorator makes function "handler" untyped
input.py:17: error: Untyped decorator makes function "handler" untyped

Environment

Powertools version used: 1.25.1
Packaging format (Layers, PyPi): N/A
AWS Lambda function runtime: N/A
Debugging logs N/A

hey @huonw thanks for yet another high quality bug report! We should definitely go for option 1. This utility predates our experience with Mypy. It's also due for a refresh on docs, and making a generic decorator factory for any sync Python function.
The reason we didn't choose --strict is that it'd raise the bar to contributions, as we've noticed (back then) some of the errors were too picky.
Are you able to run without strict until we get other high priority fixes in place? I'd estimate looking into this next week.
Thanks again!

Ah, that's fair enough. I've done two attempts in #1066: first commit is a more complex version that I couldn't get to work, while the second undoes most of it to make a small improvement.
As a middle-ground between the current state and --strict, one could activate strict on key files/modules (not sure if that is possible), or just enable specific additional strictnesses. For instance, disallow_untyped_defs would've caught this by ensuring that lambda_handler_decorator has a return type. Arguably, since this is a library, it'd be good to have that set to ensure that the public API is fully typed. (I'm not sure if one can relax it for _'d functions. 🤷♂)

hey @huonw I haven't forgotten this - fixing some important bugs on Logger and Logger utils, and will start reviewing this.
I'd like to run a full scan using --strict to see how much it's nitpick vs actual using disallow_untyped_defs only. I know @ran-isenberg ran into a similar issue on Parameters which I'm still puzzled by it. Whatever it happens, we should change re-evaluate our Mypy settings and strike a balance on easing contributions and strictness - --strict does get us closer to use something like Mypyc, or even Cython in a remote future for areas that require strict performance

authors: heitorlessa huonw

repo: awslabs/aws-lambda-powertools-python


text:
Bug: Warning on Capturing ColdStart metrics

Expected Behaviour
When metric decorator is added on top of the lambda handler to capture Cold Start metric, we should not get any warning message for cold or warm lambda invocation.
Current Behaviour
When metric decorator is added on top of the lambda handler to capture Cold Start metric, we get a warning message. No metrics to publish, skipping.
Code snippet
@metrics.log_metrics(capture_cold_start_metric=True)
def lambda_handler(event: dict, context: LambdaContext):
    ...

Possible Solution
No response
Steps to Reproduce

Add @metrics.log_metrics(capture_cold_start_metric=True) to the lambda handler
Ensure no more metrics is added in the lambda
Run Lambda
UserWarning: No metrics to publish, skipping appears in function log

AWS Lambda Powertools for Python version
latest
AWS Lambda function runtime
3.9
Packaging format used
Lambda Layers
Debugging logs
No response

Hi @amirkaws thank you so much for opening this issue! We did a check on the code, and as we understand it, the feature works correctly. We think the confusion is that capture_cold_start creates a separate EMF Blob because it uses a different Metric dimensions (to avoid data loss). It happens regardless if there are application metrics or not, as long as it's a cold start.

The "empty metrics" warning is expected if there are no metrics being added to be flushed. Cold start metrics will always be flushed if there is a cold start:

Does this help explain the behavior you're seeing?

Hi @rubenfonseca, thanks for your prompts response. From the end user prospective, if capturing the ColdStart is the only metric I am interested in, Should I get warning, which is the case here?

The reason we add the warning and print what seems to be an empty metric warning is that it could be useful to detect bugs on the customer code (we already had cases with conditional metrics). In those cases, there could be useful metric metadata which would be lost otherwise.
Having said that, you have a point that the current DX could be misleading or create confusion. Would it make sense to change the warning message to be more explicit? "No application metrics to publish, skipping".

Sure no problem, I just wanted to ensure that's expected results, customer capturing cold start metrics and we are warning them metrics to publish. As you mentioned may be more specific message would help. thanks

@amirkaws we were discussing this internally and come up with even a better one:
No application metrics to publish. The cold-start metric may be published if enabled. If application metrics should never be empty, consider using "raise_on_empty_metrics".
WDYT?

@amirkaws we were discussing this internally and come up with even a better one:
No application metrics to publish. The cold-start metric may be published if enabled. If application metrics should never be empty, consider using "raise_on_empty_metrics".
WDYT?

Much much better cc @dreamorosi too

@amirkaws if it's ok with you we would move forward with a PR to make this change

Thank you for the mention, we currently don't have this warn behavior in our implementation. I'll open an issue so we can look into it, and if we do implement it, we'll use a similar wording to the one above.

LGTM, Thanks @rubenfonseca

authors: amirkaws dreamorosi heitorlessa rubenfonseca


text:
Idempotency: Single DynamoDB table for multiple AWS Lambda functions

First of all, thanks for another great release. :+1:
I got a feature request for the new idempotency feature: As I understand the documentation, the key_attr of the DynamoDB table consists solely of the hashed idempotency key, which is based on the payload. That makes it hard to use a single DynamoDB table for multiple different AWS Lambda functions which expect the same payloads. I guess it'd be possible to somehow ensure that there is some kind of static identifier in event_key_jmespath, but that feels cumbersome and error prone.
It'd be great to have the ability to have something like the function name included in the key_attr so it's possible for multiple AWS Lambda functions to share the same DynamoDB table to avoid having to create a new table for each AWS Lambda function.

Hey @Dunedan - Thanks for raising this feature request, and it's also awesome to hear about the new release.
Could you share an example where different Lambda functions would handle the same payload and idempotence key?
I can see that when you're using an orchestration layer like Step Functions, where the same state could be sent to multiple functions. For example, a booking process where the idempotency key, event_key_jmespath, would be  order_id and customer_id the same for multiple functions - Problem here is that the return differs because one might be used for reserve booking, other for reserve payment, and while you could have a slight different idempotence key it could be error prone.
Does that capture the challenge you had in mind?

Could you share an example where different Lambda functions would handle the same payload and idempotence key?

The example I had in mind have been multiple AWS Lambda functions triggered by the same SNS topic. However I now believe the payload would be slightly different in this case for each AWS Lambda function, as at least the EventSubscriptionArn key should have a different value per invoked AWS Lambda function.

I can see that when you're using an orchestration layer like Step Functions, where the same state could be sent to multiple functions. For example, a booking process where the idempotency key, event_key_jmespath, would be order_id and customer_id the same for multiple functions - Problem here is that the return differs because one might be used for reserve booking, other for reserve payment, and while you could have a slight different idempotence key it could be error prone.
Does that capture the challenge you had in mind?

Yes, that'd be a similar situation to the one I had in mind with SNS.
I believe in practice the chance to have multiple AWS Lambda functions with the same payload and idempotence key is very low, but nevertheless as far as I can see, there is nothing in the code to prevent unexpected behavior in case it does happen. That makes me a bit uncomfortable using the same DynamoDB table for multiple functions, as I have to remember to explicitly check each AWS Lambda function for possible collisions of the payload and idempotence key.

@heitorlessa  @Dunedan  I drafted a PR for this.

it's now merged @Dunedan - Set a release date for 1.12 with this and other minor enhancements like correlation_id to be launched next Wed

Awesome. Thanks a lot. :+1:

Awesome. Thanks a lot. 👍

thanks for bringing it up, it was a good catch

Hey @Dunedan this is now available in 1.12.0 ;) Give it a try, and let us know if there's anything else you need before we prepare to go GA in one or two releases: https://github.com/awslabs/aws-lambda-powertools-python/releases/tag/v1.12.0
Thanks again for the idea!

authors: Dunedan heitorlessa michaelbrewer