From 5103023e85f8880e151ececf44cc81aee28fb040 Mon Sep 17 00:00:00 2001 From: Matthew Stratford Date: Wed, 22 Sep 2021 23:57:50 +0100 Subject: [PATCH] Try non-normalised / redownload file on failure to load. --- helpers/myradio_api.py | 82 +++++++++++++++++++++------------------- helpers/normalisation.py | 21 ++++++++++ player.py | 79 +++++++++++++++++++++++++++----------- 3 files changed, 121 insertions(+), 61 deletions(-) diff --git a/helpers/myradio_api.py b/helpers/myradio_api.py index f1cb32a..2744038 100644 --- a/helpers/myradio_api.py +++ b/helpers/myradio_api.py @@ -60,6 +60,7 @@ class MyRadioAPI: + str(response.status) ) self._logException(str(await response.text())) + return None # Given the output was bad, don't forward it. return await response.read() def call(self, url, method="GET", data=None, timeout=10, json_payload=True): @@ -102,12 +103,12 @@ class MyRadioAPI: request = None if method == "GET": - request = self.async_call(url, method="GET", timeout=timeout) + request = await self.async_call(url, method="GET", timeout=timeout) elif method == "POST": self._log("POST data: {}".format(data)) - request = self.async_call(url, data=data, method="POST", timeout=timeout) + request = await self.async_call(url, data=data, method="POST", timeout=timeout) elif method == "PUT": - request = self.async_call(url, method="PUT", timeout=timeout) + request = await self.async_call(url, method="PUT", timeout=timeout) else: self._logException("Invalid API method. Request not sent.") return None @@ -157,7 +158,7 @@ class MyRadioAPI: self._logException("Failed to get list of show plans.") return None - payload = json.loads(await request)["payload"] + payload = json.loads(request)["payload"] shows = [] if not payload["current"]: @@ -186,7 +187,7 @@ class MyRadioAPI: self._logException("Failed to get show plan.") return None - payload = json.loads(await request)["payload"] + payload = json.loads(request)["payload"] plan = {} @@ -203,7 +204,7 @@ class MyRadioAPI: # Audio Library - async def get_filename(self, item: PlanItem, did_download: bool = False): + async def get_filename(self, item: PlanItem, did_download: bool = False, redownload=False): format = "mp3" # TODO: Maybe we want this customisable? if item.trackid: itemType = "track" @@ -234,28 +235,30 @@ class MyRadioAPI: filename: str = resolve_external_file_path( "/music-tmp/{}-{}.{}".format(itemType, id, format) ) - # Check if we already downloaded the file. If we did, give that. - if os.path.isfile(filename): - self._log("Already got file: " + filename, DEBUG) - return (filename, False) if did_download else filename - # If something else (another channel, the preloader etc) is downloading the track, wait for it. - if os.path.isfile(filename + dl_suffix): - time_waiting_s = 0 - self._log( - "Waiting for download to complete from another worker. " + filename, - DEBUG, - ) - while time_waiting_s < 20: - # TODO: Make something better here. - # If the connectivity is super poor or we're loading reeaaaalllly long files, - # this may be annoying, but this is just in case somehow the other api download gives up. - if os.path.isfile(filename): - # Now the file is downloaded successfully - return (filename, False) if did_download else filename - time_waiting_s += 1 - self._log("Still waiting", DEBUG) - time.sleep(1) + if not redownload: + # Check if we already downloaded the file. If we did, give that, unless we're forcing a redownload. + if os.path.isfile(filename): + self._log("Already got file: " + filename, DEBUG) + return (filename, False) if did_download else filename + + # If something else (another channel, the preloader etc) is downloading the track, wait for it. + if os.path.isfile(filename + dl_suffix): + time_waiting_s = 0 + self._log( + "Waiting for download to complete from another worker. " + filename, + DEBUG, + ) + while time_waiting_s < 20: + # TODO: Make something better here. + # If the connectivity is super poor or we're loading reeaaaalllly long files, + # this may be annoying, but this is just in case somehow the other api download gives up. + if os.path.isfile(filename): + # Now the file is downloaded successfully + return (filename, False) if did_download else filename + time_waiting_s += 1 + self._log("Still waiting", DEBUG) + time.sleep(1) # File doesn't exist, download it. try: @@ -267,17 +270,18 @@ class MyRadioAPI: request = await self.async_api_call(url, api_version="non") - if not request: + if not request or not isinstance(request, (bytes, bytearray)): return (None, False) if did_download else None try: with open(filename + dl_suffix, "wb") as file: - file.write(await request) + file.write(request) os.rename(filename + dl_suffix, filename) except Exception as e: self._logException("Failed to write music file: {}".format(e)) return (None, False) if did_download else None + self._log("Successfully re/downloaded file.", DEBUG) return (filename, True) if did_download else filename # Gets the list of managed music playlists. @@ -285,22 +289,22 @@ class MyRadioAPI: url = "/playlist/allitonesplaylists" request = await self.async_api_call(url) - if not request: + if not request or not isinstance(request, bytes): self._logException("Failed to retrieve music playlists.") return None - return json.loads(await request)["payload"] + return json.loads(request)["payload"] # Gets the list of managed aux playlists (sfx, beds etc.) async def get_playlist_aux(self): url = "/nipswebPlaylist/allmanagedplaylists" request = await self.async_api_call(url) - if not request: + if not request or not isinstance(request, bytes): self._logException("Failed to retrieve music playlists.") return None - return json.loads(await request)["payload"] + return json.loads(request)["payload"] # Loads the playlist items for a certain managed aux playlist async def get_playlist_aux_items(self, library_id: str): @@ -311,13 +315,13 @@ class MyRadioAPI: url = "/nipswebPlaylist/{}/items".format(library_id) request = await self.async_api_call(url) - if not request: + if not request or not isinstance(request, bytes): self._logException( "Failed to retrieve items for aux playlist {}.".format(library_id) ) return None - return json.loads(await request)["payload"] + return json.loads(request)["payload"] # Loads the playlist items for a certain managed playlist @@ -325,13 +329,13 @@ class MyRadioAPI: url = "/playlist/{}/tracks".format(library_id) request = await self.async_api_call(url) - if not request: + if not request or not isinstance(request, bytes): self._logException( "Failed to retrieve items for music playlist {}.".format(library_id) ) return None - return json.loads(await request)["payload"] + return json.loads(request)["payload"] async def get_track_search( self, title: Optional[str], artist: Optional[str], limit: int = 100 @@ -341,11 +345,11 @@ class MyRadioAPI: ) request = await self.async_api_call(url) - if not request: + if not request or not isinstance(request, bytes): self._logException("Failed to search for track.") return None - return json.loads(await request)["payload"] + return json.loads(request)["payload"] def post_tracklist_start(self, item: PlanItem): if item.type != "central": diff --git a/helpers/normalisation.py b/helpers/normalisation.py index c7a8e1e..2168361 100644 --- a/helpers/normalisation.py +++ b/helpers/normalisation.py @@ -44,3 +44,24 @@ def get_normalised_filename_if_available(filename: str): # Else we've not got a normalised verison, just take original. return filename + + +# Returns the original file from the normalised one, useful if the normalised one is borked. +def get_original_filename_from_normalised(filename: str): + if not (isinstance(filename, str) and filename.endswith(".mp3")): + raise ValueError("Invalid filename given.") + + # Already not normalised. + if not filename.endswith("-normalised.mp3"): + if os.path.exists(filename): + return filename + return None + + # Take the filename, remove "-normalised" from it. + original_filename = "{}.mp3".format(filename.rsplit("-", 1)[0]) + + # original version exists + if os.path.exists(original_filename): + return original_filename + + return None diff --git a/player.py b/player.py index da5477d..d622303 100644 --- a/player.py +++ b/player.py @@ -36,7 +36,7 @@ from mutagen.mp3 import MP3 from syncer import sync from threading import Timer -from helpers.normalisation import get_normalised_filename_if_available +from helpers.normalisation import get_normalised_filename_if_available, get_original_filename_from_normalised from helpers.myradio_api import MyRadioAPI from helpers.state_manager import StateManager from helpers.logging_manager import LoggingManager @@ -170,9 +170,10 @@ class Player: # Audio Playout Related Methods def play(self, pos: float = 0): - if not self.isLoaded: - return self.logger.log.info("Playing from pos: " + str(pos)) + if not self.isLoaded: + self.logger.log.warning("Player is not loaded.") + return False try: mixer.music.play(0, pos) self.state.update("pos_offset", pos) @@ -329,7 +330,7 @@ class Player: # Right. So this may be confusing. # So... If the user has just moved the loaded item in the channel (by removing above and readding) # Then we want to re-associate the loaded_item object reference with the new one. - # The loaded item object before this change is now an ophan, which was + # The loaded item object before this change is now an orphan, which was # kept around while the loaded item was potentially moved to another # channel. if loaded_item.timeslotitemid == new_item_obj.timeslotitemid: @@ -406,9 +407,13 @@ class Player: def load(self, weight: int): if not self.isPlaying: - loaded_state = self.state.get() + # If we have something loaded already, unload it first. self.unload() + loaded_state = self.state.get() + + # Sometimes (at least on windows), the pygame player will lose output to the sound output after a while. + # It's odd, but essentially, to stop / recover from this, we de-init the pygame mixer and init it again. self.logger.log.info( "Resetting output (in case of sound output gone silent somehow) to " + str(loaded_state["output"]) @@ -419,16 +424,19 @@ class Player: loaded_item: Optional[PlanItem] = None + # Go find the show plan item of the weight we've been asked to load. for i in range(len(showplan)): if showplan[i].weight == weight: loaded_item = showplan[i] break + # If we didn't find it, exit. if loaded_item is None: self.logger.log.error( "Failed to find weight: {}".format(weight)) return False + # The file_manager helper may have pre-downloaded the file already, or we've played it before. reload = False if loaded_item.filename == "" or loaded_item.filename is None: self.logger.log.info( @@ -440,10 +448,12 @@ class Player: ) reload = True + # Ask the API for the file if we need it. if reload: - loaded_item.filename = sync( - self.api.get_filename(item=loaded_item)) + file = sync(self.api.get_filename(item=loaded_item)) + loaded_item.filename = str(file) if file else None + # If the API still couldn't get the file, RIP. if not loaded_item.filename: return False @@ -452,38 +462,57 @@ class Player: loaded_item.filename ) + # We're comitting to load this item. self.state.update("loaded_item", loaded_item) + # Given we've just messed around with filenames etc, update the item in the show plan too. for i in range(len(showplan)): if showplan[i].weight == weight: self.state.update("show_plan", index=i, value=loaded_item) break - # TODO: Update the show plan filenames??? load_attempt = 0 - if not isinstance(loaded_item.filename, str): - return False - + # Let's have 5 attempts at loading the item audio while load_attempt < 5: load_attempt += 1 + + original_file = None + if load_attempt == 3: + # Ok, we tried twice already to load the file. + # Let's see if we can recover from this. + # Try swapping the normalised version out for the original. + original_file = get_original_filename_from_normalised( + loaded_item.filename + ) + self.logger.log.warning("3rd attempt. Trying the non-normalised file: {}".format(original_file)) + + if load_attempt == 4: + # well, we've got so far that the normalised and original files didn't load. + # Take a last ditch effort to download the original file again. + file = sync(self.api.get_filename(item=loaded_item, redownload=True)) + if file: + original_file = str(file) + self.logger.log.warning("4rd attempt. Trying to redownload the file, got: {}".format(original_file)) + + if original_file: + loaded_item.filename = original_file + try: self.logger.log.info( - "Loading file: " + str(loaded_item.filename)) + "Attempt {} Loading file: {}".format(load_attempt, loaded_item.filename)) mixer.music.load(loaded_item.filename) except Exception: # We couldn't load that file. self.logger.log.exception( "Couldn't load file: " + str(loaded_item.filename) ) - time.sleep(1) continue # Try loading again. if not self.isLoaded: self.logger.log.error( "Pygame loaded file without error, but never actually loaded." ) - time.sleep(1) continue # Try loading again. try: @@ -500,23 +529,25 @@ class Player: except Exception: self.logger.log.exception( "Failed to update the length of item.") - time.sleep(1) continue # Try loading again. # Everything worked, we made it! + # Write the loaded item again once more, to confirm the filename if we've reattempted. + self.state.update("loaded_item", loaded_item) + if loaded_item.cue > 0: self.seek(loaded_item.cue) else: self.seek(0) - if self.state.get()["play_on_load"]: + if loaded_state["play_on_load"]: self.unpause() return True - self.logger.log.error( - "Failed to load track after numerous retries.") - return False + # Even though we failed, make sure state is up to date with latest failure. + # We're comitting to load this item. + self.state.update("loaded_item", loaded_item) return False @@ -546,8 +577,10 @@ class Player: self.logger.log.exception("Failed to quit mixer.") def output(self, name: Optional[str] = None): - wasPlaying = self.state.get()["playing"] - oldPos = self.state.get()["pos_true"] + wasPlaying = self.isPlaying + + state = self.state.get() + oldPos = state["pos_true"] name = None if (not name or name.lower() == "none") else name @@ -564,7 +597,7 @@ class Player: ) return False - loadedItem = self.state.get()["loaded_item"] + loadedItem = state["loaded_item"] if loadedItem: self.logger.log.info("Reloading after output change.") self.load(loadedItem.weight) @@ -799,6 +832,8 @@ class Player: loaded_item.name, loaded_item.weight ) ) + # Just make sure that if we stop and do nothing, we end up at 0. + self.state.update("pos",0) # Repeat 1 # TODO ENUM