search

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
71.07k stars 29.73k forks source link

Spotify seems to hang my HA #102921

Closed sanderlv closed 5 days ago

sanderlv commented 10 months ago

The problem

After pressing "browse" Spotify via a media player entity the entire HA system gets slow and unstable.

I am almost sure it is caused by the Spotify integration.

The symptoms: Step1: As soon as I try to browse the playlist from below image where it is the spotify integration, the entire system "hangs" (see symptoms here: https://community.home-assistant.io/t/help-ha-totally-unstable-suddenly/632276) image

Step2: After I do step 1 (try to browse Spotify) and go back to the sonos player and try to browse there I get: 278692858-6f6c97fd-f621-4133-87d2-3c03457201ea

In all situations after I do Step1 my entire system get and stays unstable until I reboot the host completely.

The weird thing is that after I installed the Spotify Integration (Sonos was already there) (and Sonos and Spotify are outside of HA connected) it worked a few times to browse Spotify via the card. But now the entire system get unstable.

Some logging which are taken in normal condition (before I had done step1):

2023-10-27 17:53:44.983 DEBUG (SyncWorker_12) [spotipy.client] RESULTS: {'display_name': 'Lelieveld', 'external_urls': {'spotify': 'https://open.spotify.com/user/p0jjkyiv3kkcr7vj4fei5q1bj'}, 'href': 'https://api.spotify.com/v1/users/p0jjkyiv3kkcr7vj4fei5q1bj', 'id': 'p0jjkyiv3kkcr7vj4fei5q1bj', 'images': [], 'type': 'user', 'uri': 'spotify:user:p0jjkyiv3kkcr7vj4fei5q1bj', 'followers': {'href': None, 'total': 0}, 'country': 'NL', 'product': 'premium', 'explicit_content': {'filter_enabled': False, 'filter_locked': False}}
2023-10-27 17:53:44.989 DEBUG (SyncWorker_8) [spotipy.client] Sending GET to https://api.spotify.com/v1/me/player/devices with Params: {} Headers: {'Authorization': 'Bearer BQCAgNeu-GSWiZKrZiHQWlxC2MQ2RVuGga9uuPB110RvI74QJpZj3RV8Seu-OGKAkV7XIc3HQlLGjmRPn0RoxVI3KSNfWWeqyQcyJFxpH5ksKVrBFPZ4yn6Ul7YcHzVAYcf_6f8nEYM63oSYxoNMNzDgkKH0mMzVKdBLM05QwrQ37uMnvacHl_Np7Yhmkb9f6_szu4s3eiclXW5kKBTgF6g6h6Ci5RfiR-51UOPJ8vhx4M2a4lKcAPu48XKLRqyNcg', 'Content-Type': 'application/json'} and Body: None 
2023-10-27 17:53:45.042 DEBUG (SyncWorker_8) [spotipy.client] RESULTS: {'devices': [{'id': '4886fff1-9b48-4e4a-9e7a-08c4569e6292_amzn_2', 'is_active': False, 'is_private_session': False, 'is_restricted': False, 'name': 'Everywhere', 'supports_volume': False, 'type': 'Speaker', 'volume_percent': 16}, {'id': '4886fff1-9b48-4e4a-9e7a-08c4569e6292_amzn_1', 'is_active': False, 'is_private_session': False, 'is_restricted': False, 'name': 'Overkapping', 'supports_volume': False, 'type': 'Speaker', 'volume_percent': 16}, {'id': '49da9001-05eb-4285-b310-9d9a1a4f6520_amzn_1', 'is_active': False, 'is_private_session': False, 'is_restricted': False, 'name': 'Schuur', 'supports_volume': False, 'type': 'Speaker', 'volume_percent': 49}, {'id': '0c8aa32e-6e9e-41af-95c9-f2f9170a0e20_amzn_1', 'is_active': False, 'is_private_session': False, 'is_restricted': False, 'name': 'Office', 'supports_volume': True, 'type': 'Speaker', 'volume_percent': 20}]}
2023-10-27 17:53:45.043 DEBUG (MainThread) [homeassistant.components.spotify] Finished fetching Sander Devices data in 0.054 seconds (success: True)

2023-10-27 18:34:17.047 DEBUG (SyncWorker_7) [spotipy.client] Sending GET to https://api.spotify.com/v1/me/player with Params: {'market': None, 'additional_types': [<MediaType.EPISODE: 'episode'>]} Headers: {'Authorization': 'Bearer BQCxKDFDRZ1Xp8vWhzMOw99v4UO7sjWa2bvA9HVGyHDL-Xlbaoxmws4H66Ayy9PWATtkEqYhDC8V97Sucn5fOh--ipRl0lAjHq_Rgd0EtI7m14ImDDyAtHfPb3YzsjeqIoS4V71qcjrQ9ZHf1cHl1XMVdDRSCGj2Dlk13LNsOMCwRUWg-EL96epfDAVMS9GbSVvQxqRfcSpoiD-i2HBufM-nHfDQWEZXL48-V3r6Zu1-cL1y3emmltY2ln2rBzraKA', 'Content-Type': 'application/json'} and Body: None 
2023-10-27 18:34:17.101 DEBUG (SyncWorker_7) [spotipy.client] RESULTS: None
2023-10-27 18:34:23.428 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943

2023-10-27 18:34:47.048 DEBUG (SyncWorker_0) [spotipy.client] Sending GET to https://api.spotify.com/v1/me/player with Params: {'market': None, 'additional_types': [<MediaType.EPISODE: 'episode'>]} Headers: {'Authorization': 'Bearer BQCxKDFDRZ1Xp8vWhzMOw99v4UO7sjWa2bvA9HVGyHDL-Xlbaoxmws4H66Ayy9PWATtkEqYhDC8V97Sucn5fOh--ipRl0lAjHq_Rgd0EtI7m14ImDDyAtHfPb3YzsjeqIoS4V71qcjrQ9ZHf1cHl1XMVdDRSCGj2Dlk13LNsOMCwRUWg-EL96epfDAVMS9GbSVvQxqRfcSpoiD-i2HBufM-nHfDQWEZXL48-V3r6Zu1-cL1y3emmltY2ln2rBzraKA', 'Content-Type': 'application/json'} and Body: None 
2023-10-27 18:34:47.098 DEBUG (SyncWorker_0) [spotipy.client] RESULTS: None

I do not "dare" to press browse because the only thing left is to reboot the entire host...

Mighti it have somethin gto do with oauth?

What version of Home Assistant Core has the issue?

2023.10.5

What was the last working version of Home Assistant Core?

?

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Spotify

Link to integration documentation on our website

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

Diagnostics information

No response

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 10 months ago

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

Code owner commands Code owners of `spotify` 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 spotify` Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)

spotify documentation spotify source (message by IssueLinks)

joostlek commented 10 months ago

Can you maybe get some logs from when this is happening?

sanderlv commented 10 months ago

Yes, but please help me how to get them properly... the logs are flooded and I do not know how to get them out precisely. I do need to enable spotify integration debug and then...?

Can I "clear" the logs" before I start?

joostlek commented 10 months ago

I would guess that if you turned on debug logging for Spotify, do step 1 and then if everything slows down you can restart and I think the logs will move to a file on the file system

sanderlv commented 10 months ago

I think this must be it... I am rebooting HA now :-)

2023-10-27 18:49:08.291 DEBUG (SyncWorker_21) [spotipy.client] Sending GET to https://api.spotify.com/v1/me/playlists with Params: {'limit': 48, 'offset': 0} Headers: {'Authorization': 'Bearer BQCxKDFDRZ1Xp8vWhzMOw99v4UO7sjWa2bvA9HVGyHDL-Xlbaoxmws4H66Ayy9PWATtkEqYhDC8V97Sucn5fOh--ipRl0lAjHq_Rgd0EtI7m14ImDDyAtHfPb3YzsjeqIoS4V71qcjrQ9ZHf1cHl1XMVdDRSCGj2Dlk13LNsOMCwRUWg-EL96epfDAVMS9GbSVvQxqRfcSpoiD-i2HBufM-nHfDQWEZXL48-V3r6Zu1-cL1y3emmltY2ln2rBzraKA', 'Content-Type': 'application/json'} and Body: None 
2023-10-27 18:49:16.868 DEBUG (MainThread) [custom_components.reolink_cctv] Finished fetching reolink.Reolink Video Doorbell.watchdog data in 0.001 seconds (success: True)
2023-10-27 18:49:17.069 DEBUG (SyncWorker_3) [spotipy.client] Sending GET to https://api.spotify.com/v1/me/player with Params: {'market': None, 'additional_types': [<MediaType.EPISODE: 'episode'>]} Headers: {'Authorization': 'Bearer BQCxKDFDRZ1Xp8vWhzMOw99v4UO7sjWa2bvA9HVGyHDL-Xlbaoxmws4H66Ayy9PWATtkEqYhDC8V97Sucn5fOh--ipRl0lAjHq_Rgd0EtI7m14ImDDyAtHfPb3YzsjeqIoS4V71qcjrQ9ZHf1cHl1XMVdDRSCGj2Dlk13LNsOMCwRUWg-EL96epfDAVMS9GbSVvQxqRfcSpoiD-i2HBufM-nHfDQWEZXL48-V3r6Zu1-cL1y3emmltY2ln2rBzraKA', 'Content-Type': 'application/json'} and Body: None 
2023-10-27 18:49:17.128 DEBUG (SyncWorker_3) [spotipy.client] RESULTS: None
2023-10-27 18:49:23.847 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:49:38.456 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:49:38.600 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:49:44.462 WARNING (SyncWorker_13) [py.warnings] /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1061: InsecureRequestWarning: Unverified HTTPS request is being made to host '192.168.1.169'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  warnings.warn(

2023-10-27 18:49:44.479 WARNING (SyncWorker_18) [py.warnings] /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1061: InsecureRequestWarning: Unverified HTTPS request is being made to host '192.168.1.169'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  warnings.warn(

2023-10-27 18:49:44.701 WARNING (SyncWorker_15) [py.warnings] /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1061: InsecureRequestWarning: Unverified HTTPS request is being made to host '192.168.1.169'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  warnings.warn(

2023-10-27 18:49:44.722 WARNING (SyncWorker_4) [py.warnings] /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1061: InsecureRequestWarning: Unverified HTTPS request is being made to host '192.168.1.169'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  warnings.warn(

2023-10-27 18:49:44.822 WARNING (SyncWorker_10) [py.warnings] /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1061: InsecureRequestWarning: Unverified HTTPS request is being made to host '192.168.1.169'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  warnings.warn(

2023-10-27 18:49:44.823 WARNING (SyncWorker_22) [py.warnings] /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1061: InsecureRequestWarning: Unverified HTTPS request is being made to host '192.168.1.169'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  warnings.warn(

2023-10-27 18:49:47.069 DEBUG (SyncWorker_18) [spotipy.client] Sending GET to https://api.spotify.com/v1/me/player with Params: {'market': None, 'additional_types': [<MediaType.EPISODE: 'episode'>]} Headers: {'Authorization': 'Bearer BQCxKDFDRZ1Xp8vWhzMOw99v4UO7sjWa2bvA9HVGyHDL-Xlbaoxmws4H66Ayy9PWATtkEqYhDC8V97Sucn5fOh--ipRl0lAjHq_Rgd0EtI7m14ImDDyAtHfPb3YzsjeqIoS4V71qcjrQ9ZHf1cHl1XMVdDRSCGj2Dlk13LNsOMCwRUWg-EL96epfDAVMS9GbSVvQxqRfcSpoiD-i2HBufM-nHfDQWEZXL48-V3r6Zu1-cL1y3emmltY2ln2rBzraKA', 'Content-Type': 'application/json'} and Body: None 
2023-10-27 18:49:47.123 DEBUG (SyncWorker_18) [spotipy.client] RESULTS: None

2023-10-27 18:49:53.829 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:49:57.234 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
joostlek commented 10 months ago

So this only happens when you click on Spotify in the Media browser?

sanderlv commented 10 months ago

Hm... now after pressing the "playlist" in Spotift I only get: image

It seems the "hang" did not appear (I did not yet reboot). Although browsing Spotify does not work...

sanderlv commented 10 months ago

So this only happens when you click on Spotify in the Media browser?

Yes. Is there another way to browse spotify?

joostlek commented 10 months ago

I think you are trying to play stuff via the media browser on a sonos device, can you maybe try playing something on spotify and then click the browse media on the spotify media player?

sanderlv commented 10 months ago

Update: it seems "all" others BUT "Playlists" work... Now what's weird:

I could never press "playlist", it would never load. I could press others like albums, track, new release and they loaded. But not after clicking around all hang...:

So I got this and only "Playlist" did NOT work: image

Now all is gone and I only get: image

and the system totally is unresponsive...

So the issue is active now. I cannot even download log anymore...

joostlek commented 10 months ago

How much playlists do you have?

sanderlv commented 10 months ago

19 Playlist.

Now the logging gets fuller (due to "the hang"):


2023-10-27 18:55:48.153 DEBUG (MainThread) [custom_components.reolink_cctv] Finished fetching reolink.Reolink Video Doorbell data in 0.299 seconds (success: True)
2023-10-27 18:55:53.990 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:55:56.200 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
2023-10-27 18:56:04.110 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
2023-10-27 18:56:04.381 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
2023-10-27 18:56:10.721 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:15.721 WARNING (MainThread) [homeassistant.helpers.entity] Update of camera.xiaomi_cloud_map_extractor is taking over 10 seconds
2023-10-27 18:56:15.722 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:15.770 ERROR (MainThread) [homeassistant.components.xiaomi_miio] Timeout fetching roborock.vacuum.s5e data
2023-10-27 18:56:19.334 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.avalex_restafval is taking over 10 seconds
2023-10-27 18:56:20.722 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:21.210 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:56:21.350 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:56:24.023 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:56:25.110 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.esxi_vmhost_localhost_lelieveld_local is taking over 10 seconds
2023-10-27 18:56:25.723 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:27.084 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.spotify_lelieveld is taking over 10 seconds
2023-10-27 18:56:30.110 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:56:30.724 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:35.724 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:39.333 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalbeheer sensor took longer than the scheduled update interval 0:00:30
2023-10-27 18:56:40.725 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:40.870 DEBUG (MainThread) [custom_components.reolink_cctv] Finished fetching reolink.Reolink Video Doorbell.watchdog data in 0.002 seconds (success: True)
2023-10-27 18:56:45.111 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:56:45.726 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:47.083 WARNING (MainThread) [homeassistant.components.media_player] Updating spotify media_player took longer than the scheduled update interval 0:00:30

2023-10-27 18:56:50.727 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:52.807 ERROR (MainThread) [homeassistant.components.glances.coordinator] Error fetching glances - localhost data: 
2023-10-27 18:56:54.121 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:56:55.727 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:56:57.248 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
2023-10-27 18:57:00.112 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:57:00.728 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:05.729 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:09.334 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalbeheer sensor took longer than the scheduled update interval 0:00:30
2023-10-27 18:57:10.729 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:15.112 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:57:15.730 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:17.085 WARNING (MainThread) [homeassistant.components.media_player] Updating spotify media_player took longer than the scheduled update interval 0:00:30
2023-10-27 18:57:20.731 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:24.129 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:57:25.731 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:30.113 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:57:30.731 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:35.733 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:39.334 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalbeheer sensor took longer than the scheduled update interval 0:00:30
2023-10-27 18:57:40.734 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:45.113 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:57:45.734 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:47.085 WARNING (MainThread) [homeassistant.components.media_player] Updating spotify media_player took longer than the scheduled update interval 0:00:30

2023-10-27 18:57:50.734 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:54.045 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:57:54.870 DEBUG (MainThread) [custom_components.reolink_cctv] Finished fetching reolink.Reolink Video Doorbell.watchdog data in 0.001 seconds (success: True)
2023-10-27 18:57:55.735 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:57:57.211 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
2023-10-27 18:58:00.114 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:58:00.737 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:05.737 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:09.334 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalbeheer sensor took longer than the scheduled update interval 0:00:30
2023-10-27 18:58:10.739 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:15.115 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:58:15.740 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:17.085 WARNING (MainThread) [homeassistant.components.media_player] Updating spotify media_player took longer than the scheduled update interval 0:00:30
2023-10-27 18:58:20.741 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:20.977 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:21.066 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:24.038 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:58:25.741 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:27.242 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:27.365 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:30.115 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:58:30.742 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:30.954 ERROR (MainThread) [homeassistant.components.emulated_hue.hue_api] Entity not found: media_player.onkyo
2023-10-27 18:58:35.742 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:39.335 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalbeheer sensor took longer than the scheduled update interval 0:00:30
2023-10-27 18:58:40.742 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:45.116 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:58:45.743 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:47.087 WARNING (MainThread) [homeassistant.components.media_player] Updating spotify media_player took longer than the scheduled update interval 0:00:30

2023-10-27 18:58:49.133 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:49.231 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:50.745 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:53.943 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:58:55.746 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:58.019 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
2023-10-27 18:59:00.116 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:59:00.746 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:05.747 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:09.336 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalbeheer sensor took longer than the scheduled update interval 0:00:30
2023-10-27 18:59:10.749 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:15.116 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:59:15.749 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:17.088 WARNING (MainThread) [homeassistant.components.media_player] Updating spotify media_player took longer than the scheduled update interval 0:00:30
2023-10-27 18:59:20.749 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
joostlek commented 10 months ago

Yea looks like something is blocking up your event loop

sanderlv commented 10 months ago

This happens: spotify

sanderlv commented 10 months ago

And now my logging is getting fuller very quickly with all kinds of vague errors which are never there... restarting the host is the only option.

joostlek commented 10 months ago

Yea so there is something that is blocking a lot of other events from happening causing all other integrations to leave warnings updating took too long. I am not sure what causes this as I don't have this issue. Now I know Spotify itself can has its quirks and can respond different to different users (which is very annoying). Are you maybe willing to give it a shot with me testing on your account to be sure? You can reach me on discord @joostlek.

sanderlv commented 10 months ago

CU there! Thanks!

sanderlv commented 10 months ago

Hi Joost, thanks for the time and session! Hope you can solve the complete bus-hang due to this (may I call it bug?) in the Spotify API.

Thanks!!!

joostlek commented 10 months ago

For the others reading this. Apparently this was a problem specific to the client id. Revoking it (or creating a new one) fixed this.

sanderlv commented 9 months ago

Hi there, little update. I had solved the issue initially by creating a new app (api entry) in spotify developer page. That solved the issue for me.

Joost and I were able to replicate the issue with the "faulty" app (api entry with client/secret id) on both our test HA's.

Now, after ~2 weeks of successful usage of sportify in HA my setup suddenly died slowly again. And the issue was the spotify integration, again.

Now it seems/seemed that the "correct" spotify app (api entry) caused the issue.

Now I disable the spotify integration in HA and there is no issue at all.

I hope Joost has time to test, debug and really find the root cause of this issue so I can again enjoy the spotify integration again :-).

Caros2017 commented 9 months ago

19 Playlist.

Now the logging gets fuller (due to "the hang"):


2023-10-27 18:58:49.133 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:49.231 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for edabc42b966d63e21f00e27328b89eb5295ce89d6c07452d8110302f4cc74878
2023-10-27 18:58:50.745 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:53.943 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for cc16e9982676196bcc6a6ed0064af5502837c19cda88921ab9a37d5964c67943
2023-10-27 18:58:55.746 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:58:58.019 DEBUG (MainThread) [homeassistant.components.webhook] Handling webhook POST payload for a8d3674cb93bd2e0f390736614d06a968d86fa4b7ae22503d7b09cafb7af5512
2023-10-27 18:59:00.116 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:59:00.746 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:05.747 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:09.336 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalbeheer sensor took longer than the scheduled update interval 0:00:30
2023-10-27 18:59:10.749 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:15.116 WARNING (MainThread) [homeassistant.components.sensor] Updating esxi_stats sensor took longer than the scheduled update interval 0:00:15
2023-10-27 18:59:15.749 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05
2023-10-27 18:59:17.088 WARNING (MainThread) [homeassistant.components.media_player] Updating spotify media_player took longer than the scheduled update interval 0:00:30
2023-10-27 18:59:20.749 WARNING (MainThread) [homeassistant.components.camera] Updating xiaomi_cloud_map_extractor camera took longer than the scheduled update interval 0:00:05

Last 1.5 months I had a very unstable Home Assistant. I am running it in a container. Due to the lack of time I didn't had the possibility to go troubleshooting. When my HA was not responsive anymore I had to reboot the container every three days. I even downgraded to the version of previous month, but it didn't work. I had configured Spotify, but I never use it for HA. Since I had the same logs as above, I disabled Spotify. As a result, my HA is running a clean six days again (I never had stability issues before).

So thanks for sharing and it is possible that this is a larger problem!

issue-triage-workflows[bot] commented 6 months ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

sanderlv commented 6 months ago

No action?

issue-triage-workflows[bot] commented 3 months ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

sanderlv commented 3 months ago

Issue still open

issue-triage-workflows[bot] commented 1 week ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.