From 77fbadb65f3b2319803faf1a6bef3b4b4ed2231e Mon Sep 17 00:00:00 2001 From: Marcel van der Veldt Date: Mon, 10 Jul 2023 22:57:50 +0200 Subject: [PATCH] Fix reloading of the airplay provider (#767) * Fix some weird flipflop when reloading airplay provider * adjust logger --- .../server/providers/airplay/__init__.py | 23 ++++++++++++++----- .../server/providers/slimproto/__init__.py | 9 ++++++-- .../server/providers/slimproto/cli.py | 2 ++ 3 files changed, 26 insertions(+), 8 deletions(-) diff --git a/music_assistant/server/providers/airplay/__init__.py b/music_assistant/server/providers/airplay/__init__.py index 7254e5fa..1ee21e12 100644 --- a/music_assistant/server/providers/airplay/__init__.py +++ b/music_assistant/server/providers/airplay/__init__.py @@ -23,7 +23,7 @@ from music_assistant.common.models.config_entries import ( from music_assistant.common.models.enums import ConfigEntryType from music_assistant.common.models.player import DeviceInfo, Player from music_assistant.common.models.queue_item import QueueItem -from music_assistant.constants import CONF_PLAYERS +from music_assistant.constants import CONF_LOG_LEVEL, CONF_PLAYERS from music_assistant.server.models.player_provider import PlayerProvider if TYPE_CHECKING: @@ -116,6 +116,7 @@ class AirplayProvider(PlayerProvider): _timer_handle: asyncio.TimerHandle | None = None _closing: bool = False _config_file: str | None = None + _log_reader_task: asyncio.Task | None = None async def handle_setup(self) -> None: """Handle async initialization of the provider.""" @@ -349,6 +350,8 @@ class AirplayProvider(PlayerProvider): "Starting Airplay bridge using config file %s", self._config_file, ) + conf_log_level = self.config.get_value(CONF_LOG_LEVEL) + enable_debug_log = conf_log_level == "DEBUG" args = [ self._bridge_bin, "-s", @@ -358,21 +361,20 @@ class AirplayProvider(PlayerProvider): "-I", "-Z", "-d", - "all=warn", + f'all={"debug" if enable_debug_log else "warn"}', # filter out apple tv's for now until we fix auth "-m", "apple-tv,appletv", - # enable terminate on exit otherwise exists are soooo slooooowwww - "-k", ] start_success = False while True: try: self._bridge_proc = await asyncio.create_subprocess_shell( " ".join(args), - stdout=asyncio.subprocess.DEVNULL, - stderr=asyncio.subprocess.DEVNULL, + stdout=asyncio.subprocess.PIPE, + stderr=asyncio.subprocess.STDOUT, ) + self._log_reader_task = asyncio.create_task(self._log_reader()) await self._bridge_proc.wait() except Exception as err: if not start_success: @@ -394,6 +396,8 @@ class AirplayProvider(PlayerProvider): self.logger.debug("Bridge process stopped.") except ProcessLookupError: pass + if self._log_reader_task and not self._log_reader_task.done(): + self._log_reader_task.cancel() async def _check_config_xml(self, recreate: bool = False) -> None: """Check the bridge config XML file.""" @@ -476,6 +480,13 @@ class AirplayProvider(PlayerProvider): async with aiofiles.open(self._config_file, "w") as _file: await _file.write(ET.tostring(xml_root).decode()) + async def _log_reader(self) -> None: + """Read log output from bridge process.""" + bridge_logger = self.logger.getChild("squeeze2raop") + while self._bridge_proc.returncode is None: + async for line in self._bridge_proc.stdout: + bridge_logger.debug(line.decode().strip()) + def restart_bridge(self) -> None: """Schedule restart of bridge process.""" if self._timer_handle is not None: diff --git a/music_assistant/server/providers/slimproto/__init__.py b/music_assistant/server/providers/slimproto/__init__.py index 4e499463..3d8e3a5d 100644 --- a/music_assistant/server/providers/slimproto/__init__.py +++ b/music_assistant/server/providers/slimproto/__init__.py @@ -224,9 +224,13 @@ class SlimprotoProvider(PlayerProvider): async def unload(self) -> None: """Handle close/cleanup of the provider.""" + if getattr(self, "_virtual_providers", None): + raise RuntimeError("Virtual providers loaded") if hasattr(self, "_socket_clients"): for client in list(self._socket_clients.values()): - client.disconnect() + with suppress(RuntimeError): + # this may fail due to a race condition sometimes + client.disconnect() self._socket_clients = {} if hasattr(self, "_socket_servers"): for _server in self._socket_servers: @@ -772,7 +776,8 @@ class SlimprotoProvider(PlayerProvider): if existing := self._socket_clients.pop(player_id, None): # race condition: new socket client connected while # the old one has not yet been cleaned up - existing.disconnect() + with suppress(RuntimeError): + existing.disconnect() self._socket_clients[player_id] = client # update all attributes diff --git a/music_assistant/server/providers/slimproto/cli.py b/music_assistant/server/providers/slimproto/cli.py index ca2841f9..84bec41f 100644 --- a/music_assistant/server/providers/slimproto/cli.py +++ b/music_assistant/server/providers/slimproto/cli.py @@ -183,6 +183,8 @@ class LmsCli: while True: raw_request = await reader.readline() raw_request = raw_request.strip().decode("utf-8") + if not raw_request: + break # request comes in as url encoded strings, separated by space raw_params = [urllib.parse.unquote(x) for x in raw_request.split(" ")] # the first param is either a macaddress or a command -- 2.34.1