Songpal disconnects and then reconnects 11 seconds later constantly

[clowncracker]

Opening a new ticket per #151 (comment)

Here are the debug logs:

2024-06-10 09:50:39.817 WARNING (MainThread) [homeassistant.components.media_player] Setup of media_player platform songpal is taking over 10 seconds.
2024-06-10 09:50:39.834 WARNING (MainThread) [homeassistant.components.songpal.media_player] [HT-A7000(http://192.168.20.42:10000/sony)] Unable to connect
2024-06-10 09:50:39.847 WARNING (MainThread) [homeassistant.components.media_player] Platform songpal not ready yet; Retrying in background in 30 seconds
2024-06-10 11:25:18.858 WARNING (MainThread) [homeassistant.components.songpal.media_player] [None(http://192.168.20.42:10000/sony)] Got disconnected, trying to reconnect
2024-06-10 11:25:18.858 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Disconnected: Unable to make a request: Received message 257:None is not str: None
2024-06-10 11:25:18.859 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Trying to reconnect in 10 seconds
2024-06-10 11:25:30.419 DEBUG (MainThread) [songpal.device] Got 5 services!
2024-06-10 11:25:30.419 DEBUG (MainThread) [songpal.service] Available protocols for appControl: ['xhrpost:jsonizer', 'websocket:jsonizer']
2024-06-10 11:25:30.419 DEBUG (MainThread) [songpal.service] Using protocol: ProtocolType.WebSocket
2024-06-10 11:25:30.458 DEBUG (MainThread) [songpal.service] Available protocols for audio: ['xhrpost:jsonizer', 'websocket:jsonizer']
2024-06-10 11:25:30.458 DEBUG (MainThread) [songpal.service] Using protocol: ProtocolType.WebSocket
2024-06-10 11:25:30.525 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifyVolumeInformation', 'versions': [{'version': '1.0'}]}
2024-06-10 11:25:30.525 DEBUG (MainThread) [songpal.service] Got notifications: [<Notification notifyVolumeInformation, versions=[{'version': '1.0'}], endpoint=http://192.168.20.42:10000/sony/audio>]
2024-06-10 11:25:30.525 DEBUG (MainThread) [songpal.service] Available protocols for avContent: ['xhrpost:jsonizer', 'websocket:jsonizer']
2024-06-10 11:25:30.525 DEBUG (MainThread) [songpal.service] Using protocol: ProtocolType.WebSocket
2024-06-10 11:25:30.589 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifyAvailablePlaybackFunction', 'versions': [{'version': '1.0'}]}
2024-06-10 11:25:30.589 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifyPlayingContentInfo',
 'versions': [{'authLevel': 'private', 'version': '1.0'}]}
2024-06-10 11:25:30.589 DEBUG (MainThread) [songpal.service] Got notifications: [<Notification notifyAvailablePlaybackFunction, versions=[{'version': '1.0'}], endpoint=http://192.168.20.42:10000/sony/avContent>, <Notification notifyPlayingContentInfo, versions=[{'authLevel': 'private', 'version': '1.0'}], endpoint=http://192.168.20.42:10000/sony/avContent>]
2024-06-10 11:25:30.589 DEBUG (MainThread) [songpal.service] Available protocols for guide: ['websocket:jsonizer']
2024-06-10 11:25:30.589 DEBUG (MainThread) [songpal.service] Using protocol: ProtocolType.WebSocket
2024-06-10 11:25:30.629 DEBUG (MainThread) [songpal.service] Available protocols for system: ['xhrpost:jsonizer', 'websocket:jsonizer']
2024-06-10 11:25:30.629 DEBUG (MainThread) [songpal.service] Using protocol: ProtocolType.WebSocket
2024-06-10 11:25:30.699 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifyAlexaRegistrationStatus',
 'versions': [{'authLevel': 'none', 'version': '1.0'}]}
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifyPowerStatus',
 'versions': [{'authLevel': 'none', 'version': '1.0'}]}
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifySettingsUpdate',
 'versions': [{'authLevel': 'none', 'version': '1.1'}]}
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifyStorageStatus',
 'versions': [{'authLevel': 'generic', 'version': '1.1'}]}
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.notification] notification payload: {'name': 'notifySWUpdateInfo',
 'versions': [{'authLevel': 'none', 'version': '1.0'}]}
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.service] Got notifications: [<Notification notifyAlexaRegistrationStatus, versions=[{'authLevel': 'none', 'version': '1.0'}], endpoint=http://192.168.20.42:10000/sony/system>, <Notification notifyPowerStatus, versions=[{'authLevel': 'none', 'version': '1.0'}], endpoint=http://192.168.20.42:10000/sony/system>, <Notification notifySettingsUpdate, versions=[{'authLevel': 'none', 'version': '1.1'}], endpoint=http://192.168.20.42:10000/sony/system>, <Notification notifyStorageStatus, versions=[{'authLevel': 'generic', 'version': '1.1'}], endpoint=http://192.168.20.42:10000/sony/system>, <Notification notifySWUpdateInfo, versions=[{'authLevel': 'none', 'version': '1.0'}], endpoint=http://192.168.20.42:10000/sony/system>]
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for appControl.getMethodTypes, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for appControl.getVersions, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for audio.getCustomEqualizerSettings, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for audio.getMethodTypes, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for audio.getVersions, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for audio.setCustomEqualizerSettings, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.getMethodTypes, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.getVersions, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.presetBroadcastStation, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.seekBroadcastStation, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.setActiveTerminal, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.startContentBrowsing, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.getContentCount, using 1.3
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for avContent.getContentList, using 1.4
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for guide.getMethodTypes, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for guide.getVersions, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for guide.switchNotifications, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for system.getMethodTypes, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.device] No supported version specified for system.getVersions, using 1.0
2024-06-10 11:25:30.700 DEBUG (MainThread) [songpal.service] getVolumeInformation version 1.1 got called with args (({},)) kwargs ({})
2024-06-10 11:25:30.759 DEBUG (MainThread) [songpal.containers] Missing key output with no default for Volume
2024-06-10 11:25:30.759 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Current volume: Volume: 27/100
2024-06-10 11:25:30.759 DEBUG (MainThread) [songpal.service] getPowerStatus version 1.1 got called with args (()) kwargs ({})
2024-06-10 11:25:30.828 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Got state: Power off
2024-06-10 11:25:30.829 DEBUG (MainThread) [songpal.service] getCurrentExternalTerminalsStatus version 1.0 got called with args (()) kwargs ({})
2024-06-10 11:25:30.889 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Got ins: [Input(meta='meta:tv', connection='connected', title='TV', uri='extInput:tv', active=True, label='', iconUrl='', outputs=[]), Input(meta='meta:hdmi', connection='connected', title='HDMI1', uri='extInput:hdmi?port=1', active=True, label='', iconUrl='', outputs=[]), Input(meta='meta:hdmi', connection='connected', title='HDMI2', uri='extInput:hdmi?port=2', active=True, label='', iconUrl='', outputs=[]), Input(meta='meta:linemini', connection='connected', title='Analog', uri='extInput:line', active=True, label='', iconUrl='', outputs=[]), Input(meta='meta:btaudio', connection='connected', title='Bluetooth Audio', uri='extInput:btAudio', active=True, label='', iconUrl='', outputs=[])]
2024-06-10 11:25:30.889 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Active source: Bluetooth Audio (uri: extInput:btAudio) (active)
2024-06-10 11:25:30.890 DEBUG (MainThread) [songpal.service] getSoundSettings version 1.1 got called with args (({'target': 'soundField'},)) kwargs ({})
2024-06-10 11:25:30.944 DEBUG (MainThread) [songpal.containers] Missing key deviceUIInfo with no default for Setting
2024-06-10 11:25:30.944 DEBUG (MainThread) [songpal.containers] Missing key uri with no default for Setting
2024-06-10 11:25:30.944 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Got sound modes: {'auto': SettingCandidate(title='Auto Sound', value='auto', isAvailable=True, min=-1, max=-1, step=-1, titleTextID='sound-soundfield-soundauto'), 'cinemaStudio': SettingCandidate(title='Cinema', value='cinemaStudio', isAvailable=True, min=-1, max=-1, step=-1, titleTextID='sound-soundfield-cinema'), 'music': SettingCandidate(title='Music', value='music', isAvailable=True, min=-1, max=-1, step=-1, titleTextID='sound-soundfield-music-2'), 'standard': SettingCandidate(title='Standard Surround', value='standard', isAvailable=True, min=-1, max=-1, step=-1, titleTextID='sound-soundfield-standard-2')}
2024-06-10 11:25:30.944 DEBUG (MainThread) [homeassistant.components.songpal.media_player] Active sound mode: cinemaStudio
2024-06-10 11:25:30.944 WARNING (MainThread) [homeassistant.components.songpal.media_player] [None(http://192.168.20.42:10000/sony)] Connection reestablished
2024-06-10 11:25:30.944 DEBUG (MainThread) [songpal.service] No notifications available for appControl
2024-06-10 11:25:30.944 DEBUG (MainThread) [songpal.service] switchNotifications version 1.0 got called with args (({'enabled': [{'name': 'notifyVolumeInformation', 'version': '1.0'}]},)) kwargs ({'_consumer': <function Device.listen_notifications.<locals>.handle_notification at 0x7fca7d21ff60>})
2024-06-10 11:25:30.945 DEBUG (MainThread) [songpal.service] switchNotifications version 1.0 got called with args (({'enabled': [{'name': 'notifyAvailablePlaybackFunction', 'version': '1.0'}, {'name': 'notifyPlayingContentInfo', 'version': '1.0'}]},)) kwargs ({'_consumer': <function Device.listen_notifications.<locals>.handle_notification at 0x7fca7d21ff60>})
2024-06-10 11:25:30.946 DEBUG (MainThread) [songpal.service] No notifications available for guide
2024-06-10 11:25:30.946 DEBUG (MainThread) [songpal.service] switchNotifications version 1.0 got called with args (({'enabled': [{'name': 'notifyAlexaRegistrationStatus', 'version': '1.0'}, {'name': 'notifyPowerStatus', 'version': '1.0'}, {'name': 'notifySettingsUpdate', 'version': '1.1'}, {'name': 'notifyStorageStatus', 'version': '1.1'}, {'name': 'notifySWUpdateInfo', 'version': '1.0'}]},)) kwargs ({'_consumer': <function Device.listen_notifications.<locals>.handle_notification at 0x7fca7d21ff60>})
2024-06-10 11:25:31.001 DEBUG (MainThread) [songpal.service] Got notification: <NotificationChange enabled: notifyAvailablePlaybackFunction,notifyPlayingContentInfo disabled: notifyExternalTerminalStatus>
2024-06-10 11:25:31.002 DEBUG (MainThread) [songpal.device] No callbacks defined for <NotificationChange enabled: notifyAvailablePlaybackFunction,notifyPlayingContentInfo disabled: notifyExternalTerminalStatus>
2024-06-10 11:25:31.002 DEBUG (MainThread) [songpal.service] Got notification: <NotificationChange enabled: notifyVolumeInformation disabled: >
2024-06-10 11:25:31.002 DEBUG (MainThread) [songpal.device] No callbacks defined for <NotificationChange enabled: notifyVolumeInformation disabled: >
2024-06-10 11:25:31.002 DEBUG (MainThread) [songpal.service] Got notification: <NotificationChange enabled: notifyAlexaRegistrationStatus,notifyPowerStatus,notifySWUpdateInfo,notifySettingsUpdate,notifyStorageStatus disabled: >
2024-06-10 11:25:31.002 DEBUG (MainThread) [songpal.device] No callbacks defined for <NotificationChange enabled: notifyAlexaRegistrationStatus,notifyPowerStatus,notifySWUpdateInfo,notifySettingsUpdate,notifyStorageStatus disabled: >