RogerSelwyn / Home_Assistant_SkyQ_MediaPlayer

Home Assistant SkyQ Media player component
MIT License
101 stars 17 forks source link

[BUG] Support requested for skyq not turning on after nightly homeassistant restart #121

Closed mark007 closed 1 year ago

mark007 commented 1 year ago

Describe the bug
I am unsure if this is a bug or improvement. I doubt it would affect many users.

Recently due to an issue with our nest wifi becoming unstable after a few days of uptime, I have decided to reboot it each night, at about 5am. I restart this via a homeassistant automation and this has kept it stable. This caused a knock on affect on two other integrations which are not resilient to this, which leads me to have another automation to restart the homeassistant itself each night at 5:10. However each day when we use another automation which we have for setting our living room media into different states (eg sky mode), it has been failing to turn on the sky box. The living room tv / speakers all turn on fine via this automation as they have for some months, however the sky box will not turn on.

Restarting the homeassistant again resolves the issue, and powering on the sky box via the automation will again work. I suspect its something to do with the fact that our sky box goes into a deep sleep/standby at night and only wakes up at about 6am. Could the fact that our wifi and homeassistant restart about 5am, bring the skyq integration online at a time when the box is in a deep sleep and require some resilience code added for this scenario?

To Reproduce
Steps to reproduce the behavior:

  1. What were you doing/watching at the time ?

  2. What channel were you on? Not applicable

  3. What time did the problem occur? Trying to turn on sky at 11am, after those nightly wifi and homeassistant reboots at 5am, triggers the media player turn on action to not do anything for the sky box.

  4. Where are you (bear in mind component supports GBR/ITA at the moment)? Ireland

Expected behavior
I would have expected the sky box to turn on, regardless of those nightly wifi and homeassistant restarts.

Screenshots
na

Component versions

  1. What version of SkyQ component are you using? v2.9.10

  2. What was the last version where the problem was not shown? na as it doesn't seem version related.

Your configuration
How have you setup your devices, by UI or YAML? yaml

Your configuration from the options dialogue
or
Your configuration.yaml

media_player:
 - platform: skyq
   name: Living Room Sky
   host: 192.168.86.23
   sources:
     RTÉ One HD: '1,0,1'
 - platform: skyq
   name: Sitting Room Sky
   host: 192.168.86.43
   sources:
     RTÉ One HD: '1,0,1'

Output of HA logs
Maybe you can instruct what logs might be relevant to this one. I didn't see anything in the existing HA logs in the UI relating to this time of day. Perhaps some other logs might give a clue?

Additional context
Add any other context about the problem here.

RogerSelwyn commented 1 year ago

The SkyQ box goes into deep sleep from 2.45 to 5.45 each morning (at some point during that time it actually does a complete reboot to handle some issues that a reboot resolves).

You haven't stated what time you try to set your living room media to a particular state. In any case trying to do anything to the SkyQ box before 5.45 will have no result. You can of course turn off ECO mode on the box and then it will never deep sleep, but that will consume more power. If you do this, be aware that the box will still do a reboot (which takes a few minutes) every night anyway.

If you reboot your HA instance while the SkyQ box is asleep, then HA will continue to poll the integration which will in turn poll the SkyQ box until it wakes up at 5.45. During the time from when you reboot HA to when the SkyQ box, I believe it will show as 'unavailable', going to 'off' when the box wakes up.

You can add the following to your config to give you more into on what is going on. Change into to debug in the relevant line for extra detail:

logger:
  default: warning
  logs:
    custom_components.skyq: info
mark007 commented 1 year ago

Thanks a lot. I mentioned trying to turn in the sky box about 11am most mornings. I'll set the logs to debug and reproduce tonight/tomorrow morning and hopefully the logs might give a clue as to why the media player turn on has no affect at 11am after the nightly HA reboot.

Thanks again.

RogerSelwyn commented 1 year ago

Assuming you are awake before 11 😄 , have a look and see what state the sky box entity it in developer tools. It should show as 'off' (assuming you haven't switched it on). If it shows as unavailable let me know what the logs say.

mark007 commented 1 year ago

OK so it's reproduced now with the extra logging enabled. I still have not rebooted HA since the sky box has gone unavailable. Here's some screenshots. What log file do you think I should attach. Is it the homeassistant.log?

https://ibb.co/2yzj1f5 https://ibb.co/XVgwqnx

Timeline seems to be

2:30:45 sky box unavailable 2:30:49 sky box off 2:45:25 sky box unavailable 5:10:00 WiFi reboot 5:20:00 HA reboot 11:00:00 sky box still unavailable

Searching through lastnights homeassistant.log, these are the references to the skyq integration.

2022-10-14 05:20:18.141 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration skyq which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-10-14 05:20:34.114 WARNING (MainThread) [custom_components.skyq.media_player] W0020 - Device is not available: Sitting Room Sky 2022-10-14 05:20:34.115 WARNING (MainThread) [custom_components.skyq.media_player] W0020 - Device is not available: Living Room Sky 2022-10-14 05:46:54.651 INFO (MainThread) [custom_components.skyq.classes.power] I0020 - Device is now available after startup: Living Room Sky 2022-10-14 06:01:44.407 INFO (MainThread) [custom_components.skyq.classes.power] I0010 - Device is now available: Living Room Sky 2022-10-14 06:01:45.942 INFO (MainThread) [custom_components.skyq.classes.power] I0020 - Device is now available after startup: Sitting Room Sky

RogerSelwyn commented 1 year ago

You can see the box becomes available at 5:56 am. Are you saying that developer tools still shows it as unavailable?

mark007 commented 1 year ago

Yeah even now as we speak its unavailable. I have not switched the sky box on or rebooted HA today (well apart from the automation that reboots my HA at 5:20). My guess is if I reboot HA now itll become 'off' as opposed to 'unavailable'. Is it possible that if HA reboots during the eco/quiet time at night, some different path through the logic could cause this particular order of events.

When I click the living room sky entity from my dashboard, the history tab still shows the last event as being.

Became unavailable 02:45:25 - 9 hours ago

EDIT: I see part of the issue, theres a second living room sky entity now called

media_player.living_room_sky2 which is 'off'

but the original one which all automations etc point to, ie

media_player.living_room_sky which is 'unavailable'.

https://ibb.co/93hktLX

Heres a screenshot of the second living room sky history to show the times it came alive.

https://ibb.co/YkpRBSS

RogerSelwyn commented 1 year ago

I would remove all sky boxes from your config, reboot ha and then reinstall using the gui. For some reason it is generating a new unique id for the second box.

mark007 commented 1 year ago

OK great will do, thank you. Is it something that can be 'fixed' for yaml users. Is there already a fix for UI users that avoids duplicate entities. I have seen similar behaviour with many integrations in recent months where a second instance of an entity would appear. I guess it's a general HA issue or are the integrations able to get around it from a code point of view.

RogerSelwyn commented 1 year ago

It shouldn’t do it, but logic is different for yaml over ui (I won’t go into the complexities). If you pay your config, I will look at it in a few days but I’m away over the weekend so can’t test anything now.

mark007 commented 1 year ago

Thanks a lot. My config is in the first post. The only difference being I list a huge list of sources. But the rest of the config is the same. Thanks so much.

mark007 commented 1 year ago

Using the UI config did the trick. This morning there's no second entity, just the one. And it's in off state as expected. Thanks a lot. I will leave it to you if you'd like to investigate the yaml based issue further at some point.

RogerSelwyn commented 1 year ago

Fixed with - https://github.com/RogerSelwyn/Home_Assistant_SkyQ_MediaPlayer/releases/tag/v2.9.11