You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
Checked the issue tracker for similar issues to ensure this is not a duplicate
Read the documentation to confirm the issue is not addressed there and your configuration is set correctly
Tested with the latest version to ensure the issue hasn't been fixed
How often does this bug occurs?
always
Expected behavior
WebSocket client's connection stays open for multiple minutes and is reused for sending multiple WebSocket messages
Actual behavior (suspected bug)
Every few seconds the client connection disconnects with this error:
E (83821) websocket_client: esp_transport_connect() failed with -1, transport_error=ESP_OK, tls_error_code=0, tls_flags=0, esp_ws_handshake_status_code=101, errno=119
I (83831) esp_ot_br: WEBSOCKET_EVENT_ERROR
E (83831) esp_ot_br: Last error HTTP status code: 0x65
E (83831) esp_ot_br: Last error reported from tls stack: 0xb33fffff
I (83841) websocket_client: Reconnect after 10000 ms
I (83841) esp_ot_br: WEBSOCKET_EVENT_DISCONNECTED
E (83841) esp_ot_br: Last error HTTP status code: 0x65
Error logs or terminal output
Detecting chip type... ESP32-S3
Running idf_monitor in directory **redacted**/esp/esp-thread-br/examples/basic_thread_border_router
Executing "**redacted**/.espressif/python_env/idf5.4_py3.12_env/bin/python **redacted**/esp/esp-idf/tools/idf_monitor.py -p /dev/cu.usbmodem**redacted** -b 115200 --toolchain-prefix xtensa-esp32s3-elf- --target esp32s3 --revision 0 **redacted**/esp/esp-thread-br/examples/basic_thread_border_router/build/esp_ot_br.elf -m '**redacted**/.espressif/python_env/idf5.4_py3.12_env/bin/python' '**redacted**/esp/esp-idf/tools/idf.py'"...
--- esp-idf-monitor 1.5.0 on /dev/cu.usbmodem**redacted** 115200
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0xb (SPI_FAST_FLASH_BOOT)
Saved PC:0x40048de8
--- 0x40048de8: uart_rx_readbuff in ROM
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce2820,len:0x1874
load:0x403c8700,len:0x4
load:0x403c8704,len:0xc80
load:0x403cb700,len:0x2eb0
entry 0x403c8914
I (26) boot: ESP-IDF v5.4-dev-3201-g46acfdce96 2nd stage bootloader
I (27) boot: compile time Sep 29 2024 10:50:35
I (27) boot: Multicore bootloader
I (27) boot: chip revision: v0.2
I (27) boot: efuse block revision: v1.3
I (28) boot.esp32s3: Boot SPI Speed : 80MHz
I (28) boot.esp32s3: SPI Mode : DIO
I (28) boot.esp32s3: SPI Flash Size : 4MB
I (28) boot: Enabling RNG early entropy source...
I (28) boot: Partition Table:
I (29) boot: ## Label Usage Type ST Offset Length
I (29) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (29) boot: 1 otadata OTA data 01 00 0000f000 00002000
I (30) boot: 2 phy_init RF data 01 01 00011000 00001000
I (30) boot: 3 ota_0 OTA app 00 10 00020000 00190000
I (31) boot: 4 ota_1 OTA app 00 11 001b0000 00190000
I (31) boot: 5 web_storage Unknown data 01 82 00340000 00019000
I (32) boot: 6 rcp_fw Unknown data 01 82 00359000 000a0000
I (32) boot: End of partition table
I (32) esp_image: segment 0: paddr=00020020 vaddr=3c0d0020 size=4c638h (312888) map
I (88) esp_image: segment 1: paddr=0006c660 vaddr=3fc95800 size=0330ch ( 13068) load
I (91) esp_image: segment 2: paddr=0006f974 vaddr=40374000 size=006a4h ( 1700) load
I (92) esp_image: segment 3: paddr=00070020 vaddr=42000020 size=c0764h (788324) map
I (231) esp_image: segment 4: paddr=0013078c vaddr=403746a4 size=110dch ( 69852) load
I (247) esp_image: segment 5: paddr=00141870 vaddr=600fe100 size=00018h ( 24) load
I (254) boot: Loaded app from partition at offset 0x20000
I (254) boot: Disabling RNG early entropy source...
I (255) cpu_start: Multicore app
I (264) cpu_start: Pro cpu start user code
I (264) cpu_start: cpu freq: 160000000 Hz
I (264) app_init: Application information:
I (265) app_init: Project name: esp_ot_br
I (265) app_init: App version: v1.0-88-g34812fe-dirty
I (265) app_init: Compile time: Sep 29 2024 11:19:10
I (266) app_init: ELF file SHA256: cdde91be4...
I (266) app_init: ESP-IDF: v5.4-dev-3201-g46acfdce96
I (266) efuse_init: Min chip rev: v0.0
I (266) efuse_init: Max chip rev: v0.99
I (266) efuse_init: Chip rev: v0.2
I (267) heap_init: Initializing. RAM available for dynamic allocation:
I (267) heap_init: At 3FCA63A8 len 00043368 (268 KiB): RAM
I (267) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (268) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (268) heap_init: At 600FE118 len 00001ED0 (7 KiB): RTCRAM
I (269) spi_flash: detected chip: gd
I (269) spi_flash: flash io: dio
W (269) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (270) sleep_gpio: Configure to isolate all GPIO pins in sleep state
I (271) sleep_gpio: Enable automatic switching of GPIO sleep configuration
I (271) main_task: Started on CPU0
I (281) main_task: Calling app_main()
I (331) RCP_UPDATE: RCP: using update sequence 0
I (331) uart: ESP_INTR_FLAG_IRAM flag not setwhile CONFIG_UART_ISR_IN_IRAM is enabled, flag updated
I (331) OPENTHREAD: spinel UART interface initialization completed
I (331) main_task: Returned from app_main()
I(341) OPENTHREAD:[I] P-SpinelDrive-: co-processor reset: RESET_POWER_ON
E(341) OPENTHREAD:[C] P-SpinelDrive-: Software reset co-processor successfully
I(381) OPENTHREAD:[I] ChildSupervsn-: Timeout: 0 -> 190
I(391) OPENTHREAD:[I] Settings------: Read NetworkInfo {rloc:0xa800, extaddr:92fd023a0467599b, role:leader, mode:0x0f, version:5, keyseq:0x0, ...
I(401) OPENTHREAD:[I] Settings------: ... pid:0x52639581, mlecntr:0x7d8, maccntr:0x7d0, mliid:bf9006afdc475e59}
I (411) esp_ot_br: Internal RCP Version: openthread-esp32/8e4454b285-f32c18bc0; esp32h2; 2024-08-09 14:34:53 UTC
I (411) esp_ot_br: Running RCP Version: openthread-esp32/8e4454b285-f32c18bc0; esp32h2; 2024-08-09 14:34:53 UTC
I (411) OPENTHREAD: OpenThread attached to netif
> I (441) esp_eth.netif.netif_glue: 48:ca:43:06:de:d3
I (441) esp_eth.netif.netif_glue: ethernet attached to netif
I (451) ethernet_connect: Waiting for IP(s).
> I (2451) ethernet_connect: Ethernet Link Up
I (3451) esp_netif_handlers: example_netif_eth ip: **redacted**, mask: 255.255.255.0, gw: **redacted**
I (3451) ethernet_connect: Got IPv4 event: Interface "example_netif_eth" address: **redacted**
I (4331) ethernet_connect: Got IPv6 event: Interface "example_netif_eth" address: fe80:0000:0000:0000:4aca:43ff:fe06:ded3, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I(4331) OPENTHREAD:[N] RoutingManager: BR ULA prefix: fd65:a53:7c64::/48 (loaded)
I(4341) OPENTHREAD:[N] RoutingManager: Local on-link prefix: fdde:ad00:beef:cafe::/64
I (4351) OPENTHREAD: Platform UDP bound to port 49153
I(4351) OPENTHREAD:[N] Mle-----------: Role disabled -> detached
I (4371) OT_STATE: netif up
I (4371) OPENTHREAD: NAT64 ready
I (4381) esp_ot_br: Network interface name: en2
I (4381) esp_ot_br: Connecting to wss://echo.websocket.events...
W (4381) websocket_client: `reconnect_timeout_ms` is not set, or it is less than or equal to zero, using default time out 10000 (milliseconds)
W (4391) websocket_client: `network_timeout_ms` is not set, or it is less than or equal to zero, using default time out 10000 (milliseconds)
E (4391) OT_DNS64: Cannot find NAT64 prefix
E (4391) esp-tls: couldn't get hostname for :echo.websocket.events: getaddrinfo() returns 202, addrinfo=0E (4391) esp-tls: Failed to open new connectionE (4391) transport_base: Failed to open a new connectionE (4391) transport_ws: Error connecting to host echo.websocket.events:443E (4401) websocket_client: esp_transport_connect() failed with -1, transport_error=ESP_ERR_ESP_TLS_CANNOT_RESOLVE_HOSTNAME, tls_error_code=0, tls_flags=0, esp_ws_handshake_status_code=0, errno=0I (4401) esp_ot_br: WEBSOCKET_EVENT_ERRORI (4401) websocket_client: Reconnect after 10000 msI (4401) esp_ot_br: WEBSOCKET_EVENT_DISCONNECTEDE (4401) esp_ot_br: Last error reported from esp-tls: 0x8001E (4401) esp_ot_br: Last error reported from tls stack: 0x3fcb6564I (5331) OPENTHREAD: Received RIOI (5331) OPENTHREAD: prefix FD84:C890:3B8C:: lifetime 1800I (5441) OPENTHREAD: Received RIOI (5441) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (5451) OPENTHREAD: Multicast listener add: FF05::2I (5521) OPENTHREAD: Received RIOI (5521) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (5551) OPENTHREAD: Received RIOI (5551) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (5641) OPENTHREAD: Received RIOI (5641) OPENTHREAD: prefix FD33:2DFB:12CA:1:: lifetime 1800I (5751) OPENTHREAD: Received RIOI (5751) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (5751) OPENTHREAD: Multicast listener add: FF05::2I (6651) OPENTHREAD: Multicast listener add: FF05::2I (7331) ethernet_connect: Got IPv6 event: Interface "example_netif_eth" address: fd69:d7d7:61ad:eaad:4aca:43ff:fe06:ded3, type: ESP_IP6_ADDR_IS_UNIQUE_LOCALI (9471) OPENTHREAD: Received RIOI (9471) OPENTHREAD: prefix FD84:C890:3B8C:: lifetime 1800I (13811) OPENTHREAD: Received RIOI (13811) OPENTHREAD: prefix FD84:C890:3B8C:: lifetime 1800E (14411) OT_DNS64: Cannot find NAT64 prefixE (14411) esp-tls: couldn't get hostname for :echo.websocket.events: getaddrinfo() returns 202, addrinfo=0
E (14411) esp-tls: Failed to open new connection
E (14411) transport_base: Failed to open a new connection
E (14411) transport_ws: Error connecting to host echo.websocket.events:443
E (14411) websocket_client: esp_transport_connect() failed with -1, transport_error=ESP_ERR_ESP_TLS_CANNOT_RESOLVE_HOSTNAME, tls_error_code=0, tls_flags=0, esp_ws_handshake_status_code=0, errno=0
I (14421) esp_ot_br: WEBSOCKET_EVENT_ERROR
E (14421) esp_ot_br: Last error reported from esp-tls: 0x8001
E (14421) esp_ot_br: Last error reported from tls stack: 0x3fcbb550
I (14421) websocket_client: Reconnect after 10000 ms
I (14421) esp_ot_br: WEBSOCKET_EVENT_DISCONNECTED
E (14421) esp_ot_br: Last error reported from tls stack: 0x3fcb6564
I (18081) OPENTHREAD: Received RIO
I (18081) OPENTHREAD: prefix FD84:C890:3B8C:: lifetime 1800
E (29421) OT_DNS64: Cannot find NAT64 prefix
E (29421) esp-tls: couldn't get hostname for :echo.websocket.events: getaddrinfo() returns 202, addrinfo=0E (29421) esp-tls: Failed to open new connectionE (29421) transport_base: Failed to open a new connectionE (29421) transport_ws: Error connecting to host echo.websocket.events:443E (29421) websocket_client: esp_transport_connect() failed with -1, transport_error=ESP_ERR_ESP_TLS_CANNOT_RESOLVE_HOSTNAME, tls_error_code=0, tls_flags=0, esp_ws_handshake_status_code=0, errno=0I (29431) esp_ot_br: WEBSOCKET_EVENT_ERRORE (29431) esp_ot_br: Last error reported from esp-tls: 0x8001E (29431) esp_ot_br: Last error reported from tls stack: 0x3fcbb550I (29431) websocket_client: Reconnect after 10000 msI (29431) esp_ot_br: WEBSOCKET_EVENT_DISCONNECTEDE (29431) esp_ot_br: Last error reported from tls stack: 0x3fcb6564I(30651) OPENTHREAD:[N] Mle-----------: RLOC16 a800 -> fffeI(30961) OPENTHREAD:[N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active DatasetI(37521) OPENTHREAD:[N] RouterTable---: Allocate router id 42I(37521) OPENTHREAD:[N] Mle-----------: RLOC16 fffe -> a800I(37521) OPENTHREAD:[N] Mle-----------: Role detached -> leaderI(37531) OPENTHREAD:[N] Mle-----------: Partition ID 0x6cdb7184I (37541) OPENTHREAD: Platform UDP bound to port 49154I (38131) OPENTHREAD: Received RIOI (38131) OPENTHREAD: prefix FD84:C890:3B8C:: lifetime 1800I (38311) OPENTHREAD: Received RIOI (38321) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (38321) OPENTHREAD: Multicast listener add: FF05::2I (38411) OPENTHREAD: Received RIOI (38411) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (38431) OPENTHREAD: Received RIOI (38431) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (38651) OPENTHREAD: Received RIOI (38651) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (38701) OPENTHREAD: Received RIOI (38701) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (38701) OPENTHREAD: Multicast listener add: FF05::2I (39361) OPENTHREAD: Multicast listener add: FF05::2I (40201) OPENTHREAD: Platform UDP bound to port 53536I (40201) OPENTHREAD: Platform UDP bound to port 49155I (41681) OT_STATE: Set dns server address: FD65:A53:7C64:2::101:101I (42221) OPENTHREAD: Received RIOI (42221) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (42231) OPENTHREAD: Multicast listener add: FF05::2I (42261) OPENTHREAD: Received RIOI (42271) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (42271) OPENTHREAD: Received RIOI (42271) OPENTHREAD: prefix FD84:C890:3B8C:: lifetime 1800I (42491) OPENTHREAD: Received RIOI (42491) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (42611) OPENTHREAD: Received RIOI (42611) OPENTHREAD: prefix FD32:C77E:51A7:1:: lifetime 1800I (42631) OPENTHREAD: Received RIOI (42631) OPENTHREAD: prefix FD33:2DFB:12CA:1:: lifetime 1800I (43011) OPENTHREAD: Multicast listener add: FF05::2I (44771) esp-x509-crt-bundle: Certificate validatedI (46161) esp_ot_br: WEBSOCKET_EVENT_CONNECTEDI (47191) OPENTHREAD: Received RIOI (47191) OPENTHREAD: prefix FD33:2DFB:12CA:1:: lifetime 1800I (50261) esp_ot_br: WEBSOCKET_EVENT_DATAI (50261) esp_ot_br: Received opcode=1W (50261) esp_ot_br: Received=echo.websocket.events sponsored by Lob.comW (50271) esp_ot_br: Total payload length=42, data_len=42, current payload offset=0I (50271) esp_ot_br: WEBSOCKET_EVENT_DATAI (50271) esp_ot_br: Received opcode=10W (50271) esp_ot_br: Received=W (50281) esp_ot_br: Total payload length=0, data_len=0, current payload offset=0I (51451) OPENTHREAD: Received RIOI (51451) OPENTHREAD: prefix FD84:C890:3B8C:: lifetime 1800I (54401) esp_ot_br: Successfully sent messageI (55151) esp_ot_br: WEBSOCKET_EVENT_DATAI (55151) esp_ot_br: Received opcode=2W (55161) esp_ot_br: Received=W (55161) esp_ot_br: Total payload length=50, data_len=50, current payload offset=0E (62721) transport_base: poll_read select error 113, errno = Software caused connection abort, fd = 54E (62721) websocket_client: esp_transport_poll_read() returned -1, transport_error=ESP_OK, tls_error_code=0, tls_flags=0, errno=119I (62721) esp_ot_br: WEBSOCKET_EVENT_ERRORI (62731) websocket_client: Reconnect after 10000 msI (62731) esp_ot_br: WEBSOCKET_EVENT_DISCONNECTEDE (62731) esp_ot_br: Last error reported from tls stack: 0xb33fffffE (62741) esp_ot_br: Last error captured as transport's socket errno: 0x71
I (73051) esp-x509-crt-bundle: Certificate validated
E (83821) transport_ws: Error read response for Upgrade header GET / HTTP/1.1
Connection: Upgrade
Host: echo.websocket.events:443
User-Agent: ESP32 Websocket Client
Upgrade: websocket
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: **redacted**
E (83821) websocket_client: esp_transport_connect() failed with -1, transport_error=ESP_OK, tls_error_code=0, tls_flags=0, esp_ws_handshake_status_code=101, errno=119
I (83831) esp_ot_br: WEBSOCKET_EVENT_ERROR
E (83831) esp_ot_br: Last error HTTP status code: 0x65
E (83831) esp_ot_br: Last error reported from tls stack: 0xb33fffff
I (83841) websocket_client: Reconnect after 10000 ms
I (83841) esp_ot_br: WEBSOCKET_EVENT_DISCONNECTED
E (83841) esp_ot_br: Last error HTTP status code: 0x65
I (94231) esp-x509-crt-bundle: Certificate validated
I (95641) esp_ot_br: WEBSOCKET_EVENT_CONNECTED
I (95671) esp_ot_br: WEBSOCKET_EVENT_DATA
I (95671) esp_ot_br: Received opcode=1
W (95671) esp_ot_br: Received=echo.websocket.events sponsored by Lob.com
W (95671) esp_ot_br: Total payload length=42, data_len=42, current payload offset=0
**redacted**@**redacted**~/e/e/e/basic_thread_border_router (websocket-client-disconnects)>
Steps to reproduce the behavior
See #104 which replicates the issue. I have also reproduced the issue in a normal codebase (not the Thread Boarded Route codebase) and confirmed the issue does not occur there
Project release version
unreleased master
System architecture
ARM 64-bit (Apple M1/M2, Raspberry Pi 4/5)
Operating system
MacOS
Operating system version
Sonoma
Shell
Fish
Additional context
No response
The text was updated successfully, but these errors were encountered:
github-actionsbot
changed the title
Cannot use WebSocket Client due to constant disconnects
Cannot use WebSocket Client due to constant disconnects (TZ-1191)
Sep 30, 2024
Checklist
How often does this bug occurs?
always
Expected behavior
WebSocket client's connection stays open for multiple minutes and is reused for sending multiple WebSocket messages
Actual behavior (suspected bug)
Every few seconds the client connection disconnects with this error:
Error logs or terminal output
Steps to reproduce the behavior
See #104 which replicates the issue. I have also reproduced the issue in a normal codebase (not the Thread Boarded Route codebase) and confirmed the issue does not occur there
Project release version
unreleased master
System architecture
ARM 64-bit (Apple M1/M2, Raspberry Pi 4/5)
Operating system
MacOS
Operating system version
Sonoma
Shell
Fish
Additional context
No response
The text was updated successfully, but these errors were encountered: