Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Recurring connection errors #55

Open
1 task done
jhemak opened this issue Sep 2, 2024 · 14 comments
Open
1 task done

Recurring connection errors #55

jhemak opened this issue Sep 2, 2024 · 14 comments
Assignees
Labels
bug Something isn't working

Comments

@jhemak
Copy link

jhemak commented Sep 2, 2024

Troubleshooting Guide

  • I have followed the steps in the troubleshooting guide and my issue is either not listed or is not solved.

Description

Hello, over the past couple weeks I have started to see errors like this in my log. Any idea what may cause or fix it?

2024-09-02 10:16:42.686 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky @ IP: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-02 10:17:46.818 WARNING (MainThread) [homeassistant.components.esphome.manager] Error getting setting up connection for IP: Timeout waiting for ListEntitiesDoneResponse, ListEntitiesAlarmControlPanelResponse, ListEntitiesBinarySensorResponse, ListEntitiesButtonResponse, ListEntitiesCameraResponse, ListEntitiesClimateResponse, ListEntitiesCoverResponse, ListEntitiesDateResponse, ListEntitiesDateTimeResponse, ListEntitiesEventResponse, ListEntitiesFanResponse, ListEntitiesLightResponse, ListEntitiesLockResponse, ListEntitiesMediaPlayerResponse, ListEntitiesNumberResponse, ListEntitiesSelectResponse, ListEntitiesSensorResponse, ListEntitiesServicesResponse, ListEntitiesSirenResponse, ListEntitiesSwitchResponse, ListEntitiesTextResponse, ListEntitiesTextSensorResponse, ListEntitiesTimeResponse, ListEntitiesUpdateResponse, ListEntitiesValveResponse after 60s
2024-09-02 10:17:56.820 ERROR (MainThread) [aioesphomeapi.connection] upsy-desky@IP: disconnect request failed: Timeout waiting for DisconnectResponse after 10.0s

Logs

No response

Which version of the Upsy Desky firmware config are you running?

4.0.0

How do you manage your Upsy Desky's updates?

OTA Updates

If you're using an ESPHome YAML config, which version of ESPHome are you running?

No response

ESPHome Config

No response

@jhemak jhemak added the bug Something isn't working label Sep 2, 2024
@tjhorner
Copy link
Owner

tjhorner commented Sep 2, 2024

Are these errors being manifested through any symptoms like unavailable or unknown sensors?

@jhemak
Copy link
Author

jhemak commented Sep 2, 2024

Yes, I believe so. The sensors go unavailable around the same time and then unknown a few minutes later.

@jhemak
Copy link
Author

jhemak commented Sep 2, 2024

OK ... just confirmed... when this error occurs in the logs, all sensors in the UI go unavailable. A few minutes later, some sensors go to unknown (e.g. preset_1) and others go to their actual values (e.g. max_target_height).

@tjhorner
Copy link
Owner

tjhorner commented Sep 2, 2024

Thanks for confirming. I'm interested to know the following:

  • How often does this occur?
  • What desk model do you have?
  • Are you powering the Upsy Desky directly from the desk or with a USB-C power supply?

@jhemak
Copy link
Author

jhemak commented Sep 3, 2024

It seems to happen a handful of times per day. I'll try to keep better track over the next few days and let you know.

I have an Uplift v2. I've had all this going for several months now but don't think I was getting this error until the past 30 days or so.

Currently powering the board directly from the desk but have tried a separate USB-C power supply over the past few days. At first I thought that had fixed it, but after some time the errors resumed so I'm not sure it had any effect (hard to say, since it's inconsistent.) I currently have USB-C disconnected (and also haven't seen the error since my message ~5 hours ago ... but I'm sure it will be back!)

@jhemak
Copy link
Author

jhemak commented Sep 3, 2024

OK - the answer is that this is happening quite often. Here are some times from error to sensor recovery from just 10 hours today:

6:36:43 -> 6:36:57
9:25:06 -> 9:26:04
11:33:52 -> 11:33:59
1:11:25 -> 1:11:55
1:18:05 -> 1:19:23
1:35:47 -> 1:36:57
1:43:39 -> 1:44:22
1:57:19 -> 1:57:34
2:07:33 -> 2:09:34
2:28:21 -> 2:29:49
3:02:24 -> 3:03:31
3:11:12 -> 3:12:58
3:30:50 -> 3:31:07
3:43:33 -> 3:44:00
3:58:55 -> 3:59:33

And here are the actual log messages:

2024-09-02 14:39:45.759 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-02 14:39:48.829 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='X.X.X.X', port=6053))]: [Errno 113] Connect call failed ('X.X.X.X', 6053) (SocketAPIError)
2024-09-03 06:36:43.858 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 06:36:53.689 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: upsy-desky-xxxxxx @ X.X.X.X: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (Home Assistant 2024.8.3).
2024-09-03 06:36:53.690 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: upsy-desky-xxxxxx @ X.X.X.X: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (Home Assistant 2024.8.3). (HandshakeAPIError)
2024-09-03 09:25:06.233 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 09:25:37.668 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: Handshake timed out after 30.0s (TimeoutAPIError)
2024-09-03 09:25:37.669 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: upsy-desky-xxxxxx @ X.X.X.X: Connection lost
2024-09-03 11:33:52.270 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 13:11:25.845 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 13:11:28.924 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='X.X.X.X', port=6053))]: [Errno 113] Connect call failed ('X.X.X.X', 6053) (SocketAPIError)
2024-09-03 13:18:05.017 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 13:18:18.247 WARNING (MainThread) [homeassistant.components.esphome.manager] Error getting setting up connection for X.X.X.X: Timeout waiting for DeviceInfoResponse after 10.0s
2024-09-03 13:18:28.250 ERROR (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: disconnect request failed: Timeout waiting for DisconnectResponse after 10.0s
2024-09-03 13:35:47.042 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 13:36:46.219 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: Timeout waiting for HelloResponse, ConnectResponse after 30.0s (TimeoutAPIError)
2024-09-03 13:36:46.220 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: upsy-desky-xxxxxx @ X.X.X.X: Connection lost
2024-09-03 13:43:39.843 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 13:57:19.469 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 14:07:33.581 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 14:08:05.814 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: Handshake timed out after 30.0s (TimeoutAPIError)
2024-09-03 14:08:05.815 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: upsy-desky-xxxxxx @ X.X.X.X: Connection lost
2024-09-03 14:28:21.833 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 14:28:57.970 WARNING (MainThread) [homeassistant.components.esphome.manager] Error getting setting up connection for X.X.X.X: Timeout waiting for DeviceInfoResponse after 10.0s
2024-09-03 14:29:07.972 ERROR (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: disconnect request failed: Timeout waiting for DisconnectResponse after 10.0s
2024-09-03 15:02:24.464 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 15:11:12.519 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 15:11:43.511 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: Handshake timed out after 30.0s (TimeoutAPIError)
2024-09-03 15:11:43.512 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: upsy-desky-xxxxxx @ X.X.X.X: Connection lost
2024-09-03 15:12:15.322 WARNING (MainThread) [homeassistant.components.esphome.manager] Error getting setting up connection for X.X.X.X: Timeout waiting for DeviceInfoResponse after 10.0s
2024-09-03 15:12:25.325 ERROR (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: disconnect request failed: Timeout waiting for DisconnectResponse after 10.0s
2024-09-03 15:30:50.351 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 15:43:33.932 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds
2024-09-03 15:43:36.988 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ X.X.X.X: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='X.X.X.X', port=6053))]: [Errno 113] Connect call failed ('X.X.X.X', 6053) (SocketAPIError)
2024-09-03 15:58:55.062 WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ X.X.X.X: Connection error occurred: Ping response not received after 90.0 seconds

And here is my config:

substitutions:
  name: upsy-desky-xxx
  friendly_name: Upsy Desky xxx
packages:
  tj_horner.upsy_desky: github://tjhorner/upsy-desky/firmware/base.yaml@master
esphome:
  name: ${name}
  name_add_mac_suffix: false
  friendly_name: ${friendly_name}
api:
  encryption:
    key: xxx

wifi:
  ssid: !secret wifi_ssid
  password: !secret wifi_password

logger:
  level: INFO

ota:
  - platform: esphome
    password: ""

@jhemak
Copy link
Author

jhemak commented Sep 5, 2024

Hi @tjhorner, I'm going to go ahead and say this must be a power issue after all. Right after I sent you the update yesterday I plugged the USB-C power back in and the errors have been gone for over 24 hours. Still seems strange that it started to be an issue all of a sudden after using it without the external power for many months.

@jhemak
Copy link
Author

jhemak commented Sep 9, 2024

Ugh - just kidding. I am continuing to see various errors like the ones above even with the USB power plugged in. Can't seem to find any pattern to why and when they pop up. However, I get no errors from my Bluetooth proxy, so it seems unique to this device for some reason. Any ideas?

@tjhorner
Copy link
Owner

tjhorner commented Sep 9, 2024

Something I'd like to try is collecting logs via USB - this will let us know if it's a true connection issue or if it's crashing for some reason. The easiest way to get logs via USB is through this page: https://upsy-desky.tjhorner.dev/docs/troubleshooting/#collecting-logs

Keep that open until the device disconnects again, then you can save the logs for inspection.

@jhemak
Copy link
Author

jhemak commented Sep 11, 2024

So I'm not positive I am doing this right... but for the past 24 hours, the only error showing up in the USB log is

Terminal disconnected: BufferOverrunError: Buffer overrun

And in the HA log, I see

WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ xxx.xxx.xxx.xxx: Connection error occurred: [Errno 104] Connection reset by peer

This is the only error I've been seeing now... not the ones mentioned above.

@jhemak
Copy link
Author

jhemak commented Oct 1, 2024

FYI ... this stopped for the past 3 weeks then restarted again yesterday. Super strange, and I'm not really sure if there's anything you can do about it since we don't know what causes it.

Here's the most recent message:

WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ x.x.x.x: Connection error occurred: Ping response not received after 90.0 seconds

@jhemak
Copy link
Author

jhemak commented Oct 5, 2024

Hey @tjhorner - these errors are continuing. Has anyone else reported something like this? Do you have any idea (or even a guess) as to whether the issue is with my device or with my Home Assistant?

Here are the unique errors I've seen in just the past couple hours, and this is with USB-C power connected:

WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ 192.168.x.x: Connection error occurred: upsy-desky-xxxxxx @ 192.168.x.x: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (Home Assistant 2024.10.1).
WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ 192.168.x.x: upsy-desky-xxxxxx @ 192.168.x.x: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (Home Assistant 2024.10.1). (HandshakeAPIError)
WARNING (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ 192.168.x.x: Connection error occurred: Ping response not received after 90.0 seconds
WARNING (MainThread) [homeassistant.components.esphome.manager] Error getting setting up connection for 192.168.x.x: Timeout waiting for ListEntitiesDoneResponse, ListEntitiesAlarmControlPanelResponse, ListEntitiesBinarySensorResponse, ListEntitiesButtonResponse, ListEntitiesCameraResponse, ListEntitiesClimateResponse, ListEntitiesCoverResponse, ListEntitiesDateResponse, ListEntitiesDateTimeResponse, ListEntitiesEventResponse, ListEntitiesFanResponse, ListEntitiesLightResponse, ListEntitiesLockResponse, ListEntitiesMediaPlayerResponse, ListEntitiesNumberResponse, ListEntitiesSelectResponse, ListEntitiesSensorResponse, ListEntitiesServicesResponse, ListEntitiesSirenResponse, ListEntitiesSwitchResponse, ListEntitiesTextResponse, ListEntitiesTextSensorResponse, ListEntitiesTimeResponse, ListEntitiesUpdateResponse, ListEntitiesValveResponse after 60s
ERROR (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ 192.168.x.x: disconnect request failed: [Errno 104] Connection reset by peer
WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ 192.168.x.x: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='192.168.x.x', port=6053))]: [Errno 113] Connect call failed ('192.168.x.x', 6053) (SocketAPIError)
WARNING (MainThread) [homeassistant.components.esphome.manager] Error getting setting up connection for 192.168.x.x: Timeout waiting for DeviceInfoResponse after 10.0s
ERROR (MainThread) [aioesphomeapi.connection] upsy-desky-xxxxxx @ 192.168.x.x: disconnect request failed: Timeout waiting for DisconnectResponse after 10.0s
WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for upsy-desky-xxxxxx @ 192.168.x.x: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='192.168.x.x', port=6053))]: [Errno 113] Connect call failed ('192.168.x.x', 6053) (SocketAPIError)1

@jhemak
Copy link
Author

jhemak commented Oct 18, 2024

After much experimentation, I'm happy to report I seem to have found a fix!

Adding power_save_mode: NONE to the wifi section of my config appears to have resolved the problem.

@tjhorner
Copy link
Owner

@jhemak Glad to hear that solved it! I'll see if this would be a reasonable addition to the stock firmware. Definitely will add it to the troubleshooting section as well.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants