Sony Bravia TV Integration doesn't work if TV is off when integration starts

[jumpinf00l]

The problem

Similar to idominiki's issue #77745 but with core 2022.9.5, if the Bravia TV is off/standby when the integration loads, then the integration will fail with the error "Retrying setup: Error communicating with device" appearing in Settings > Devices & Services > Integrations tab. Powering on/waking the Bravia TV allows the integration to work until the integration is reloaded while the Bravia TV is powered off/standby.

The issue is experienced with beta 2022.9.0b6 mentioned in idominiki's issue #77745, but worked fine in 2022.8.7 with no configuration differences in Home Assistant or on the TV.

The Bravia TV model is KDL-60W600B.

What version of Home Assistant Core has the issue?

2022.9.5

What was the last working version of Home Assistant Core?

2022.8.7

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Sony Bravia TV

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2022-09-21 16:41:28.970 WARNING (MainThread) [homeassistant.config_entries] Config entry 'KDL-60W600B' for braviatv integration not ready yet: Error communicating with device; Retrying in background

Additional information

I've recreated the Bravia TV device using the PIN shown on the screen when running the following command, but the issue continues.

curl -X POST http://<TV IP>/sony/accessControl -H 'authorization: Basic '$(echo :"0000" | base64) -H 'cache-control: no-cache' -H 'content-type: application/json' -d '{"method": "actRegister", "params": [{"clientid": "HomeAssistantTest", "nickname": "Home Assistant", "level": "private"}, [{"value": "yes", "function": "WOL"}]], "id": 1, "version": "1.0"}' -v

When executing the above command using the PIN which was displayed on screen while the Bravia TV is powered off/standby, the below output is received:

Note: Unnecessary use of -X or --request, POST is already inferred.

• Trying 172.16.20.108:80...
• Connected to 172.16.20.108 (172.16.20.108) port 80 (#0)

POST /sony/accessControl HTTP/1.1 Host: 172.16.20.108 User-Agent: curl/7.74.0 Accept: / authorization: Basic OjAzNTQK cache-control: no-cache content-type: application/json Content-Length: 188

• upload completely sent off: 188 out of 188 bytes
• Mark bundle as not supporting multiuse < HTTP/1.1 200 OK < Content-Type: application/json < Content-Length: 35 < Connection: keep-alive < Date: Wed, 21 Sep 2022 09:15:43 GMT <
• Connection #0 to host 172.16.20.108 left intact {"error":[7,"not power-on"],"id":1}

[probot-home-assistant[bot]]

braviatv documentation braviatv source _{^{(message by IssueLinks)}}

[probot-home-assistant[bot]]

Hey there @bieniu, @drafteed, mind taking a look at this issue as it has been labeled with an integration (braviatv) you are listed as a code owner for? Thanks! _{^{(message by CodeOwnersMention)}}

[negebauer]

I also started seeing this! Before it was working fine when the TV was off

[Drafteed]

Please show debug logs for integration (put there as txt file) when it starts.

Add this to your configuration.yaml file:

logger:
  logs:
    homeassistant.components.braviatv: debug
    pybravia: debug

Then restart HA.

[negebauer]

Seems it's not treating the error not power on response as error? Even though it has a response status of 200 (meaning the tv responded?)

log.txt

2022-09-23 11:08:56.421 DEBUG (MainThread) [pybravia.client] Connect with pin: ****, psk: None, clientid: HomeAssistant, nickname: Home Assistant
2022-09-23 11:08:56.422 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/accessControl, data: {'method': 'actRegister', 'params': [{'clientid': 'HomeAssistant', 'nickname': 'Home Assistant', 'level': 'private'}, [{'value': 'yes', 'function': 'WOL'}]], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:08:57.354 DEBUG (MainThread) [pybravia.client] Response status: 200
2022-09-23 11:08:57.357 DEBUG (MainThread) [pybravia.client] Response result: {'error': [7, 'not power-on'], 'id': 1}
2022-09-23 11:08:57.357 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/system, data: {'method': 'getSystemInformation', 'params': [], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:08:58.590 DEBUG (MainThread) [pybravia.client] Response status: 403
2022-09-23 11:08:58.590 DEBUG (MainThread) [homeassistant.components.braviatv.coordinator] Finished fetching braviatv data in 2.169 seconds (success: False)
2022-09-23 11:08:58.590 WARNING (MainThread) [homeassistant.config_entries] Config entry 'KDL-60W610B' for braviatv integration not ready yet: Error communicating with device; Retrying in background
2022-09-23 11:09:18.483 DEBUG (MainThread) [pybravia.client] Connect with pin: ****, psk: None, clientid: HomeAssistant, nickname: Home Assistant
2022-09-23 11:09:18.484 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/accessControl, data: {'method': 'actRegister', 'params': [{'clientid': 'HomeAssistant', 'nickname': 'Home Assistant', 'level': 'private'}, [{'value': 'yes', 'function': 'WOL'}]], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:09:22.515 DEBUG (MainThread) [pybravia.client] Response status: 200
2022-09-23 11:09:22.517 DEBUG (MainThread) [pybravia.client] Response result: {'error': [7, 'not power-on'], 'id': 1}
2022-09-23 11:09:22.517 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/system, data: {'method': 'getSystemInformation', 'params': [], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:09:22.831 DEBUG (MainThread) [pybravia.client] Response status: 403
2022-09-23 11:09:22.831 DEBUG (MainThread) [homeassistant.components.braviatv.coordinator] Finished fetching braviatv data in 4.348 seconds (success: False)
2022-09-23 11:09:32.833 DEBUG (MainThread) [pybravia.client] Connect with pin: ****, psk: None, clientid: HomeAssistant, nickname: Home Assistant
2022-09-23 11:09:32.834 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/accessControl, data: {'method': 'actRegister', 'params': [{'clientid': 'HomeAssistant', 'nickname': 'Home Assistant', 'level': 'private'}, [{'value': 'yes', 'function': 'WOL'}]], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:09:32.933 DEBUG (MainThread) [pybravia.client] Response status: 200
2022-09-23 11:09:32.934 DEBUG (MainThread) [pybravia.client] Response result: {'error': [7, 'not power-on'], 'id': 1}
2022-09-23 11:09:32.935 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/system, data: {'method': 'getSystemInformation', 'params': [], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:09:33.033 DEBUG (MainThread) [pybravia.client] Response status: 403
2022-09-23 11:09:33.033 DEBUG (MainThread) [homeassistant.components.braviatv.coordinator] Finished fetching braviatv data in 0.200 seconds (success: False)
2022-09-23 11:09:53.040 DEBUG (MainThread) [pybravia.client] Connect with pin: ****, psk: None, clientid: HomeAssistant, nickname: Home Assistant
2022-09-23 11:09:53.040 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/accessControl, data: {'method': 'actRegister', 'params': [{'clientid': 'HomeAssistant', 'nickname': 'Home Assistant', 'level': 'private'}, [{'value': 'yes', 'function': 'WOL'}]], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:09:53.150 DEBUG (MainThread) [pybravia.client] Response status: 200
2022-09-23 11:09:53.151 DEBUG (MainThread) [pybravia.client] Response result: {'error': [7, 'not power-on'], 'id': 1}
2022-09-23 11:09:53.151 DEBUG (MainThread) [pybravia.client] Request http://192.168.50.115/sony/system, data: {'method': 'getSystemInformation', 'params': [], 'id': 1, 'version': '1.0'}, headers: {'Cache-Control': 'no-cache', 'Connection': 'keep-alive'}
2022-09-23 11:09:53.249 DEBUG (MainThread) [pybravia.client] Response status: 403
2022-09-23 11:09:53.249 DEBUG (MainThread) [homeassistant.components.braviatv.coordinator] Finished fetching braviatv data in 0.209 seconds (success: False)

[jumpinf00l]

I'm seeing the same as @negebauer, a 200 followed by a 403 home-assistant.log

Here's the message in Settings > Devices & Services > integrations tab:

[bieniu]

Please use this braviatv.zip as a custom component and report back.

[jumpinf00l]

Thanks @bieniu, it seems to work! I'll test it a bit more and report back