Fix chromecast re-connection issue

[awarecan]

Description:

Since change of #16471, the cast status listener will receive CONNECTION_STATUS_DISCONNECTED status change call back. We should do disconnection clean up in the call back to allow re-connection logic works

Related issue (if applicable): fixes #16686

Pull request in home-assistant.github.io with documentation (if applicable): home-assistant/home-assistant.github.io#<home-assistant.github.io PR number goes here>

Example entry for configuration.yaml (if applicable):

Checklist:

• The code change is tested and works locally.
• Local tests pass with tox. Your PR cannot be merged unless tests pass

[awarecan]

Some local test logs for reference, for quick debugging, reconnection params changed to

CONNECTION_RETRY = 1
CONNECTION_RETRY_WAIT = 1
CONNECTION_TIMEOUT = 3

HA startup with chromecast offline, no blocking

2018-09-19 23:35:20 INFO (MainThread) [homeassistant.components.media_player] Setting up media_player.cast
2018-09-19 23:35:20 DEBUG (SyncWorker_2) [homeassistant.components.media_player.cast] Starting internal pychromecast discovery.
2018-09-19 23:35:20 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 0.41s
2018-09-19 23:35:20 INFO (MainThread) [homeassistant.core] Starting Home Assistant
2018-09-19 23:35:20 INFO (MainThread) [homeassistant.core] Timer:starting
2018-09-19 23:35:25 INFO (MainThread) [homeassistant.components.http.view] Serving /api/websocket to 192.168.182.1 (auth: False)

Plug on chromecast, HA discovered device

2018-09-19 23:36:12 DEBUG (zeroconf-ServiceBrowser__googlecast._tcp.local.) [homeassistant.components.media_player.cast] Discovered chromecast ChromecastInfo(host='192.168.86.29', port=8009, uuid='da3e00ce-xxxx', manufacturer='Google Inc.', model_name='Chromecast', friendly_name='Office TV')
2018-09-19 23:36:12 DEBUG (MainThread) [homeassistant.components.media_player.cast] Connecting to cast device ChromecastInfo(host='192.168.86.29', port=8009, uuid='da3e00ce-xxxx', manufacturer='Google Inc.', model_name='Chromecast', friendly_name='Office TV')
2018-09-19 23:36:12 INFO (SyncWorker_6) [pychromecast] Querying device status
2018-09-19 23:36:12 DEBUG (SyncWorker_6) [pychromecast.controllers] Receiver:Updating status
2018-09-19 23:36:12 DEBUG (SyncWorker_6) [pychromecast.socket_client] Sending: Message urn:x-cast:com.google.cast.tp.connection from sender-0 to receiver-0: {'type': 'CONNECT', 'origin': {}, 'userAgent': 'PyChromecast', 'senderInfo': {'sdkType': 2, 'version': '15.605.1.3', 'browserVersion': '44.0.2403.30', 'platform': 4, 'systemVersion': 'Macintosh; Intel Mac OS X10_10_3', 'connectionType': 1}}
2018-09-19 23:36:12 DEBUG (SyncWorker_6) [pychromecast.socket_client] Sending: Message urn:x-cast:com.google.cast.receiver from sender-0 to receiver-0: {'type': 'GET_STATUS', 'requestId': 1}
2018-09-19 23:36:12 DEBUG (SyncWorker_6) [pychromecast.socket_client] Connected!
2018-09-19 23:36:12 DEBUG (MainThread) [homeassistant.components.media_player.cast] Connection successful!
2018-09-19 23:36:12 DEBUG (Thread-2) [pychromecast.socket_client] Received: Message urn:x-cast:com.google.cast.receiver from receiver-0 to sender-0: {'requestId': 1, 'status': {'applications': [{'appId': 'E8C28D3C', 'displayName': 'Backdrop', 'isIdleScreen': True, 'launchedFromCloud': False, 'namespaces': [{'name': 'urn:x-cast:com.google.cast.debugoverlay'}, {'name': 'urn:x-cast:com.google.cast.cac'}, {'name': 'urn:x-cast:com.google.cast.sse'}, {'name': 'urn:x-cast:com.google.cast.remotecontrol'}], 'sessionId': '55d5aa57-19f6-4fd7-9784-135b25660720', 'statusText': '', 'transportId': '55d5aa57-19f6-4fd7-9784-135b25660720'}], 'userEq': {}, 'volume': {'controlType': 'attenuation', 'level': 1.0, 'muted': False, 'stepInterval': 0.05000000074505806}}, 'type': 'RECEIVER_STATUS'}
2018-09-19 23:36:12 DEBUG (Thread-2) [pychromecast.controllers] Received status: CastStatus(is_active_input=False, is_stand_by=True, volume_level=1.0, volume_muted=False, app_id='E8C28D3C', display_name='Backdrop', namespaces=['urn:x-cast:com.google.cast.debugoverlay', 'urn:x-cast:com.google.cast.cac', 'urn:x-cast:com.google.cast.sse', 'urn:x-cast:com.google.cast.remotecontrol'], session_id='55d5aa57-19f6-4fd7-9784-135b25660720', transport_id='55d5aa57-19f6-4fd7-9784-135b25660720', status_text='')

Plug off chromecast, HA received DISCONNECTED event

2018-09-19 23:36:53 WARNING (Thread-2) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2018-09-19 23:36:53 DEBUG (Thread-2) [pychromecast.socket_client] connection listener: 7fd750931198 (CastStatusListener)
2018-09-19 23:36:53 DEBUG (Thread-2) [homeassistant.components.media_player.cast] Received cast device connection status: LOST
2018-09-19 23:36:53 DEBUG (Thread-2) [homeassistant.components.media_player.cast] Cast device availability changed: LOST
2018-09-19 23:36:53 DEBUG (Thread-2) [pychromecast.socket_client] connection listener: 7fd750931198 (CastStatusListener)
2018-09-19 23:36:53 DEBUG (Thread-2) [homeassistant.components.media_player.cast] Received cast device connection status: CONNECTING
2018-09-19 23:36:56 DEBUG (Thread-2) [pychromecast.socket_client] connection listener: 7fd750931198 (CastStatusListener)
2018-09-19 23:36:56 DEBUG (Thread-2) [homeassistant.components.media_player.cast] Received cast device connection status: FAILED
2018-09-19 23:36:56 ERROR (Thread-2) [pychromecast.socket_client] Failed to connect. No retries.
2018-09-19 23:36:56 DEBUG (Thread-2) [pychromecast.socket_client] connection listener: 7fd750931198 (CastStatusListener)
2018-09-19 23:36:56 DEBUG (Thread-2) [homeassistant.components.media_player.cast] Received cast device connection status: DISCONNECTED

Plug on again

2018-09-19 23:37:52 DEBUG (zeroconf-ServiceBrowser__googlecast._tcp.local.) [homeassistant.components.media_player.cast] Discovered chromecast ChromecastInfo(host='192.168.86.29', port=8009, uuid='da3e00ce-xxxx', manufacturer='', model_name='Chromecast', friendly_name='Office TV')
2018-09-19 23:37:52 DEBUG (MainThread) [homeassistant.components.media_player.cast] Discovered chromecast with same UUID: ChromecastInfo(host='192.168.86.29', port=8009, uuid='da3e00ce-xxxx', manufacturer='', model_name='Chromecast', friendly_name='Office TV')
2018-09-19 23:37:52 DEBUG (MainThread) [homeassistant.components.media_player.cast] Connecting to cast device ChromecastInfo(host='192.168.86.29', port=8009, uuid='da3e00ce-xxxx', manufacturer='', model_name='Chromecast', friendly_name='Office TV')
2018-09-19 23:37:52 INFO (SyncWorker_0) [pychromecast] Querying device status
2018-09-19 23:37:52 DEBUG (SyncWorker_0) [pychromecast.controllers] Receiver:Updating status
2018-09-19 23:37:52 DEBUG (SyncWorker_0) [pychromecast.socket_client] Sending: Message urn:x-cast:com.google.cast.tp.connection from sender-0 to receiver-0: {'type': 'CONNECT', 'origin': {}, 'userAgent': 'PyChromecast', 'senderInfo': {'sdkType': 2, 'version': '15.605.1.3', 'browserVersion': '44.0.2403.30', 'platform': 4, 'systemVersion': 'Macintosh; Intel Mac OS X10_10_3', 'connectionType': 1}}
2018-09-19 23:37:52 DEBUG (SyncWorker_0) [pychromecast.socket_client] Sending: Message urn:x-cast:com.google.cast.receiver from sender-0 to receiver-0: {'type': 'GET_STATUS', 'requestId': 1}
2018-09-19 23:37:52 DEBUG (SyncWorker_0) [pychromecast.socket_client] Connected!
2018-09-19 23:37:52 DEBUG (MainThread) [homeassistant.components.media_player.cast] Connection successful!
2018-09-19 23:37:52 DEBUG (Thread-3) [pychromecast.socket_client] Received: Message urn:x-cast:com.google.cast.receiver from receiver-0 to sender-0: {'requestId': 1, 'status': {'applications': [{'appId': 'E8C28D3C', 'displayName': 'Backdrop', 'isIdleScreen': True, 'launchedFromCloud': False, 'namespaces': [{'name': 'urn:x-cast:com.google.cast.debugoverlay'}, {'name': 'urn:x-cast:com.google.cast.cac'}, {'name': 'urn:x-cast:com.google.cast.sse'}, {'name': 'urn:x-cast:com.google.cast.remotecontrol'}], 'sessionId': 'e9fdf885-ab4e-467c-83f6-416ae7392b48', 'statusText': '', 'transportId': 'e9fdf885-ab4e-467c-83f6-416ae7392b48'}], 'userEq': {}, 'volume': {'controlType': 'attenuation', 'level': 1.0, 'muted': False, 'stepInterval': 0.05000000074505806}}, 'type': 'RECEIVER_STATUS'}
2018-09-19 23:37:52 DEBUG (Thread-3) [pychromecast.controllers] Received status: CastStatus(is_active_input=False, is_stand_by=True, volume_level=1.0, volume_muted=False, app_id='E8C28D3C', display_name='Backdrop', namespaces=['urn:x-cast:com.google.cast.debugoverlay', 'urn:x-cast:com.google.cast.cac', 'urn:x-cast:com.google.cast.sse', 'urn:x-cast:com.google.cast.remotecontrol'], session_id='e9fdf885-ab4e-467c-83f6-416ae7392b48', transport_id='e9fdf885-ab4e-467c-83f6-416ae7392b48', status_text='')

[mh-daedalus]

I've pushed it to my environment, I'll let you know if I see something out of the ordinary with my debugs compared to yours.

[bachoo786]

I am still having Chromecast issues says unavailable have updated HA to 0.78.3. It starts working again until I reboot HA.

[kiwinol]

I am also still having issues. My Chromcast seems to disconnect at night

Failed to connect. No retries.

03:50 /usr/local/lib/python3.6/site-packages/pychromecast/socket_client.py (ERROR)

[bachoo786]

Same issue as @kiwinol

[ryanmelt]

This change seems to make my google home minis disconnect and become unavailable overnight. 👎

[SteveDinn]

Same here. I'm on 0.78.2, and my cast devices remain at 'unavailable' after they are offline for updates.

[MartinHjelmare]

Please keep the feedback in #16686.