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
74.14k stars 31.12k forks source link

Sony Songpal becomes unavailable/available every minute #111121

Closed clowncracker closed 8 months ago

clowncracker commented 9 months ago

The problem

The device becomes unavailable and available every minute.

What version of Home Assistant Core has the issue?

core-2024.2.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

Sony Songpal

Link to integration documentation on our website

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

Diagnostics information

There isn't an option to download diagnostics data, so I'm just pulling an excerpt from the logs file. Songpal Logs.txt

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: homeassistant.components.songpal.media_player
Source: components/songpal/media_player.py:160
Integration: Sony Songpal (documentation, issues)
First occurred: February 19, 2024 at 4:00:03 AM (3897 occurrences)
Last logged: 10:41:28 PM

[None(http://xxx.xxx.xx.xx:10000/sony)] Got disconnected, trying to reconnect

Logger: homeassistant.components.songpal.media_player
Source: components/songpal/media_player.py:160
Integration: Sony Songpal (documentation, issues)
First occurred: February 19, 2024 at 4:00:03 AM (3897 occurrences)
Last logged: 10:41:28 PM

[None(http://xxx.xxx.xx.xx:10000/sony)] Got disconnected, trying to reconnect

Additional information

No response

home-assistant[bot] commented 9 months ago

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

Code owner commands Code owners of `songpal` 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 songpal` 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)


songpal documentation songpal source (message by IssueLinks)

rytilahti commented 9 months ago

This happens when the connection with the device gets disconnected for any reason. Please enable debug logging from the device page and take a look if you receive more information what might be causing this.

clowncracker commented 9 months ago

This happens when the connection with the device gets disconnected for any reason. Please enable debug logging from the device page and take a look if you receive more information what might be causing this.

Did the debug logs I provided not supply that information?

rytilahti commented 9 months ago

Unfortunately no, it just tells that the connection was disconnected.

clowncracker commented 9 months ago

I checked and it's not dropping off of my wifi network, it makes me think it has to be something with Home Assistant. I've provided new debug logs, but it looks like more of the same. home-assistant_songpal_2024-02-23T23-15-34.102Z.log

rytilahti commented 9 months ago

So, I have no clue nor time to research on this at the moment, but what is happening is that the websocket connection breaks due to some low-level protocol issue.

This might be a bug in the firmware of the device, an issue with some request the library is sending, or something completely else. This is the relevant log entry from the exception raised by the websocket library used by python-songpal:

Disconnected: Unable to make a request: Received message 257:None is not str: None

I see you didn't fill in the version where it still worked. Did it ever work for you if you have used homeassistant prior to 2024.2.2?

clowncracker commented 9 months ago

I don't recall the last time that it worked correctly. I want to say 2023.12.x but I cannot say for sure.

rytilahti commented 9 months ago

So there haven't been that many changes in the library code for a long time outside https://github.com/rytilahti/python-songpal/pull/132 so that might be related.

clowncracker commented 9 months ago

@rytilahti anything I can do to help?

rytilahti commented 8 months ago

You could try to downgrade the dependency and/or homeassistant to see if that helps. That would help to find out if the issue is indeed in the library changes and not in your environment/network/elsewhere. As I mentioned, this error is not coming from the device itself but from the "transport", but it is always possible that the device implementation does not like some of the changes, or it might just be some sort of network issue, it is really hard to say without further tests.

clowncracker commented 8 months ago

You could try to downgrade the dependency and/or homeassistant to see if that helps. That would help to find out if the issue is indeed in the library changes and not in your environment/network/elsewhere. As I mentioned, this error is not coming from the device itself but from the "transport", but it is always possible that the device implementation does not like some of the changes, or it might just be some sort of network issue, it is really hard to say without further tests.

How can I downgrade the dependency?

rytilahti commented 8 months ago

You could copy the whole integration directory under custom_components and modify the version key inside the manifest.json file. Or if using virtualenv installation, simply by specifying the version like pip install python-songpal==0.16.

clowncracker commented 8 months ago

I downloaded https://github.com/home-assistant/core/tree/2024.3.0/homeassistant/components/songpal and put it in the custom_components folder of my HA VM. I updated manifest.json to "requirements": ["python-songpal==0.16.0"], and restarted HA. It's been about 12 hours and I have not gotten any errors yet, so I think it's safe to assume that the error was introduced in 0.16.1.

rytilahti commented 8 months ago

Okay, that sounds like a regression caused by https://github.com/rytilahti/python-songpal/pull/145 then. Please open a report at https://github.com/rytilahti/python-songpal as this needs to be fixed upstream.

pchimbolo commented 8 months ago

Any status on this? Experiencing the same issue. Tried the suggested workaround (download entire songpal components folder from github to custom_components folder and change manifest.json "requirements" to 0.16.0 but it doesn't work for me. Message on the device in HA says "This entity is no longer being provided by the songpal integration. If the entity is no longer in use, delete it in settings."

Versions: Core = 2024.3.3 Supervisor = 2024.03.1 Operating System = 12.1 Frontend = 20240307.0

rytilahti commented 8 months ago

Try to change the version to 0.16.2 and please report back if that helps, it's the version that contains a potential fix.

pchimbolo commented 8 months ago

That seems to have done it. Working so far. Automations now triggering etc. Well done! Thank you!!! Goes to show you how these great integrations can spoil you and cause you to forget the basic operation of these devices. LOL

rytilahti commented 8 months ago

Great, thanks for reporting back! This is now fixed by #114525, so it should work again in 2024.4 and this can be closed. @clowncracker feel free to reopen the python-songpal issue with more information, if it isn't working for you with the new release.