home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.57k stars 30.75k forks source link

snapclient integration has zombie connections or something. #126355

Closed Bram-diederik closed 3 weeks ago

Bram-diederik commented 1 month ago

The problem

My snapcast failed. When i analyzed the logs. I had very many connections from home assistant. Sep 20 20:12:16 alfred snapserver[324387]: ControlServer::NewConnection: 192.168.5.4 this flooded the snapserver and it did not start.

I disabled the snapcast integration and still the connections where there. Even when i restarted hass from the config.

after i rebooted the hass server the problem was resolved.

What version of Home Assistant Core has the issue?

2024.9.2

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

snapcast

Link to integration documentation on our website

https://www.home-assistant.io/integrations/snapcast/

Diagnostics information

Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 Sep 20 20:20:02 alfred snapserver[325805]: ControlServer::NewConnection: 192.168.5.4 [ENZ] Sep 20 20:20:02 alfred snapserver[325805]: Error while accepting socket connection: Too many open files Sep 20 20:20:02 alfred snapserver[325805]: (musicha) warning: could not acquire a Shairport Sync native D-Bus interface "org.gnome.ShairportSync.i325824" on the system bus. Sep 20 20:20:02 alfred snapserver[325805]: (musicha) warning: could not acquire an MPRIS interface named "org.mpris.MediaPlayer2.ShairportSync.i325824" on the system bus. Sep 20 20:20:02 alfred snapserver[325805]: Error while accepting socket connection: Too many open files Sep 20 20:20:02 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:03 alfred snapserver[325805]: Service 'Snapcast' successfully established. Sep 20 20:20:03 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:03 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:04 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:04 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:05 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:05 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:06 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:06 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:07 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:07 alfred snapserver[325805]: onResync (mpd): 1.63753 ms Sep 20 20:20:07 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:08 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:08 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:09 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:09 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:10 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:10 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:11 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:11 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:12 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:12 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:13 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:13 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:14 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:14 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:15 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:15 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:16 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:16 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:17 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:17 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:18 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:18 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:19 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:19 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:20 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:20 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:21 alfred snapserver[325805]: State changed: mpdha, state: idle => playing Sep 20 20:20:21 alfred snapserver[325805]: onStateChanged (mpdha): playing Sep 20 20:20:21 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:21 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:22 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:22 alfred snapserver[325805]: Error opening metadata pipe, retrying in 500ms. Error: assign: Bad file descriptor Sep 20 20:20:23 alfred snapserver[325805]: No data since 120 ms, switching to idle

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 1 month ago

Hey there @luar123, mind taking a look at this issue as it has been labeled with an integration (snapcast) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `snapcast` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign snapcast` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


snapcast documentation snapcast source (message by IssueLinks)

Bram-diederik commented 3 weeks ago

had it again. reboot the hass vm (not reload the integration) resolved the issue again

Bram-diederik commented 3 weeks ago

Aha. It was due to extensive disk IO. On the vm host for home assistant and snapserver.

I changed the mpd snapcast fifo to a ramdisk