opened
marjon-halter
username_0
Enabled the TCP Echo project.
Setup my laptop to be on the same subnet as the ESP32-WROVER board.
Installed xinetd to get an echo server running.

Configured the TCP Echo project to:
1. Connect to AP
2. Send echo messages.
3. Disconnect from AP
4. Sleep for a fixed time.
5. Wake up.
6. Repeat.

**System information**
- Hardware: Espressif Demo board for ESP32-WROVER
- IDE used:Eclipse
- Operating System [Linux]
- Version of Amazon FreeRTOS (run ``git describe --tags`` to find it): v1.4.6-61-gf0c0efc7
- Project [TCP Echo] with addition of code to disconnect from AP, sleep and reconnect to AP on wakeup.

**Expected behavior**
Expect the TCP stack to handle the error returned by wifi driver and recover.

**Screenshots or console output**
```cpp
--- idf_monitor on /dev/ttyUSB0 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)
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:6312
load:0x40078000,len:11264
ho 0 tail 12 room 4
load:0x40080000,len:6008
0x40080000: _iram_start at /home/marjon/workspace/amazon-freertos/lib/FreeRTOS/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685

entry 0x4008032c
0x4008032c: _KernelExceptionVector at ??:?

I (31) boot: ESP-IDF v3.1.1-18-g607d2ce34 2nd stage bootloader
I (31) boot: compile time 14:23:45
I (31) boot: Enabling RNG early entropy source...
I (37) boot: SPI Speed      : 40MHz
I (41) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 16MB
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 (75) boot:  2 phy_init         RF data          01 01 00018000 00001000
I (82) boot:  3 ota_0            OTA app          00 10 00020000 00177000
I (90) boot:  4 ota_1            OTA app          00 11 001a0000 00177000
I (97) boot:  5 storage          WiFi data        01 02 00317000 00010000
I (105) boot: End of partition table
E (109) boot: ota data partition invalid and no factory, will try all partitions
I (117) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x14160 ( 82272) map
I (155) esp_image: segment 1: paddr=0x00034188 vaddr=0x3ffc0000 size=0x02bf8 ( 11256) load
I (159) esp_image: segment 2: paddr=0x00036d88 vaddr=0x3ffc2bf8 size=0x00000 (     0) load
I (161) esp_image: segment 3: paddr=0x00036d90 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at /home/marjon/workspace/amazon-freertos/lib/FreeRTOS/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685

I (171) esp_image: segment 4: paddr=0x00037198 vaddr=0x40080400 size=0x08e78 ( 36472) load
I (194) esp_image: segment 5: paddr=0x00040018 vaddr=0x400d0018 size=0x75a28 (481832) map
0x400d0018: _stext at ??:?

I (363) esp_image: segment 6: paddr=0x000b5a48 vaddr=0x40089278 size=0x06eb4 ( 28340) load
0x40089278: coex_arbit_clean_overtime_until at ??:?

I (376) esp_image: segment 7: paddr=0x000bc904 vaddr=0x400c0000 size=0x00000 (     0) load
I (376) esp_image: segment 8: paddr=0x000bc90c vaddr=0x50000000 size=0x00000 (     0) load
I (392) boot: Loaded app from partition at offset 0x20000
I (392) boot: ota rollback check done
I (393) boot: Disabling RNG early entropy source...
I (398) cpu_start: Pro cpu up.
I (402) cpu_start: Single core mode
I (407) heap_init: Initializing. RAM available for dynamic allocation:
I (413) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (419) heap_init: At 3FFD2248 len 0000DDB8 (55 KiB): DRAM
I (425) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (432) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (438) heap_init: At 4009012C len 0000FED4 (63 KiB): IRAM
I (444) cpu_start: Pro cpu start user code
I (127) cpu_start: Starting scheduler on PRO CPU.
I (208) wifi: wifi driver task: 3ffda368, prio:23, stack:3584, core=0
I (208) wifi: wifi firmware version: 8f35e40
I (208) wifi: config NVS flash: enabled
I (208) wifi: config nano formating: disabled
I (208) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (218) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (238) wifi: Init dynamic tx buffer num: 32
I (238) wifi: Init data frame dynamic rx buffer num: 5
I (238) wifi: Init management frame dynamic rx buffer num: 5
I (248) wifi: Init static rx buffer size: 1600
I (248) wifi: Init static rx buffer num: 5
I (258) wifi: Init dynamic rx buffer num: 5
0 9 [main] WiFi module initialized. Connecting to AP <accesspoint>...
W (268) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
I (438) phy: phy_version: 4000, b6198fa, Sep  3 2018, 15:11:06, 0, 2
I (478) wifi: mode : sta (30:ae:a4:cf:0c:64)
I (478) WIFI: SYSTEM_EVENT_STA_START
I (848) wifi: n:3 0, o:1 0, ap:255 255, sta:3 0, prof:1
I (1828) wifi: state: init -> auth (b0)
I (1838) wifi: state: auth -> assoc (0)
I (1848) wifi: state: assoc -> run (10)
I (1858) wifi: connected with <accesspoint>, channel 3
I (1858) wifi: pm start, type: 1

I (1858) WIFI: SYSTEM_EVENT_STA_CONNECTED
1 420 [IP-task] vDHCPProcess: offer a0201dfip
I (4388) event: sta ip: 10.2.1.223, mask: 255.255.252.0, gw: 10.2.1.1
I (4388) WIFI: SYSTEM_EVENT_STA_GOT_IP
2 422 [IP-task] vDHCPProcess: offer a0201dfip
3 423 [main] WiFi Connected to AP. Creating tasks which use network...
4 423 [main] ERROR: Failed to provision certificate -1 
5 424 [main] Write certificate...
6 424 [main] ERROR: Failed to provision certificate 7 
7 425 [main] ERROR: Failed to provision private key 7 
I (4418) wifi: state: run -> init (0)
I (4418) wifi: pm stop, total sleep time: 2101247 us / 2560729 us

I (4428) wifi: n:3 0, o:3 0, ap:255 255, sta:3 0, prof:1
I (4438) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8
8 425 [Echo0] WiFi module initialized. Connecting to AP <accesspoint>...
I (4558) wifi: n:3 0, o:3 0, ap:255 255, sta:3 0, prof:1
I (5538) wifi: state: init -> auth (b0)
I (5548) wifi: state: auth -> assoc (0)
I (5558) wifi: state: assoc -> run (10)
I (5578) wifi: connected with <accesspoint>, channel 3
I (5578) wifi: pm start, type: 1

I (5578) WIFI: SYSTEM_EVENT_STA_CONNECTED
9 733 [IP-task] vDHCPProcess: offer a0201dfip
I (7518) event: sta ip: 10.2.1.223, mask: 255.255.252.0, gw: 10.2.1.1
I (7518) WIFI: SYSTEM_EVENT_STA_GOT_IP
10 735 [IP-task] vDHCPProcess: offer a0201dfip
11 735 [Echo0] WiFi Connected to AP. Creating tasks which use network...
12 735 [Echo0] Connecting to echo server
13 936 [Echo0] Echo demo failed to connect to echo server 10.2.2.248.
I (9678) wifi: state: run -> init (0)
I (9678) wifi: pm stop, total sleep time: 2865884 us / 4092174 us

I (9678) wifi: n:3 0, o:3 0, ap:255 255, sta:3 0, prof:1
I (9678) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8
14 951 [Echo0] Connecting to echo server
15 1451 [Echo0] Echo demo failed to connect to echo server 10.2.2.248.
16 1466 [Echo0] Connecting to echo server
E (15678) NetInterface: Failed to tx buffer 0x3ffdd522, len 42, err -16
17 1751 [Echo0] Echo demo failed to connect to echo server 10.2.2.248.
18 1766 [Echo0] Connecting to echo server
E (18678) NetInterface: Failed to tx buffer 0x3ffdd522, len 42, err -16
19 2051 [Echo0] Echo demo failed to connect to echo server 10.2.2.248.
20 2066 [Echo0] Connecting to echo server
E (21678) NetInterface: Failed to tx buffer 0x3ffdd522, len 42, err -16
21 2351 [Echo0] Echo demo failed to connect to echo server 10.2.2.248.
```

**To reproduce**
Steps to reproduce the behavior:
See description on top of this ticket.

**Additional context**
Add any other context about the problem here.

Thank you!
NetInterface: Failed to tx buffer ..., err -16
issue
created
aggarg
username_1
Looking at the logs, it seems that it is failing to provision the certificate and key.

```
4 423 [main] ERROR: Failed to provision certificate -1 
5 424 [main] Write certificate...
6 424 [main] ERROR: Failed to provision certificate 7 
7 425 [main] ERROR: Failed to provision private key 7 
```

Would you please double check that you have set ```keyCLIENT_CERTIFICATE_PEM``` and ```keyCLIENT_PRIVATE_KEY_PEM``` in ```aws_clientcredential_keys.h```? The correct formatting should look something like this:

```
#define keyCLIENT_CERTIFICATE_PEM \
"-----BEGIN CERTIFICATE-----\n" \
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa\n" \
"bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb\n" \
"cccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccc\n" \
"dddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddd\n" \
"eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee\n" \
"ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff\n" \
"gggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggg\n" \
"hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh\n" \
"iiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiii\n" \
"jjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjj\n" \
"kkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkk\n" \
"llllllllllllllllllllllllllllllllllllllllllllllllllllllllllllllll\n" \
"mmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmm\n" \
"nnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnn\n" \
"oooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo\n" \
"pppppppppppppppppppppppppppppppppppppppppppppppppppppppppppppppp\n" \
"qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq\n" \
"rrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrr\n" \
"-----END CERTIFICATE-----\n"
```

```
#define keyCLIENT_PRIVATE_KEY_PEM \
"-----BEGIN RSA PRIVATE KEY-----\n" \
"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa\n" \
"bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb\n" \
"cccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccc\n" \
"dddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddd\n" \
"eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee\n" \
"ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff\n" \
"gggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggggg\n" \
"hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh\n" \
"iiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiiii\n" \
"jjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjjj\n" \
"kkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkkk\n" \
"llllllllllllllllllllllllllllllllllllllllllllllllllllllllllllllll\n" \
"mmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmmm\n" \
"nnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnn\n" \
"oooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo\n" \
"pppppppppppppppppppppppppppppppppppppppppppppppppppppppppppppppp\n" \
"qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq\n" \
"rrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrr\n" \
"ssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssss\n" \
"tttttttttttttttttttttttttttttttttttttttttttttttttttttttttttttttt\n" \
"uuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuuu\n" \
"vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv\n" \
"wwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwww\n" \
"xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n" \
"yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy\n" \
"-----END RSA PRIVATE KEY-----\n"
```

Thanks.
comment
created
marjon-halter
username_0
Fair comment, but I was just testing connecting to the access point and doing a TCP echo to a local echo server (my laptop). I doubt it will need the AWS client keys for that task?
comment
created
aggarg
username_1
Yes you are right. I am setting it up to see what might be going wrong.

The other thing that you might try meanwhile is to check that the laptop's firewall is not blocking the incoming connection as you are failing to connect:

```
12 735 [Echo0] Connecting to echo server
13 936 [Echo0] Echo demo failed to connect to echo server 10.2.2.248.
```

Would you mind sharing your changes to the TCP Echo demo so that I can replicate the same scenario.

Thank you for your patience.
comment
created
marjon-halter
username_0
Is there a private place I can share the file changes?
comment
created
marjon-halter
username_0
https://github.com/username_0/amazon-freertos --> tcp_echo_demo. It would not repeat it so quickly now, but it still happens eventually. The bug is intermittent. The wifi driver has to NOT yet transition from assoc->run, but the IP stack is already sending data out to the wifi driver.
i.e.
`I (5538) wifi: state: init -> auth (b0)`
`I (5548) wifi: state: auth -> assoc (0)`
`I (5558) wifi: state: assoc -> run (10)`
`I (5578) wifi: connected with <accesspoint>, channel 3`
`I (5578) wifi: pm start, type: 1`
comment
closed
qiutongs
username_2
issue