From 79dda66e10d913a2f397a9d88db2fa844ac72c9c Mon Sep 17 00:00:00 2001 From: Marcel van der Veldt Date: Tue, 27 Feb 2024 09:26:58 +0100 Subject: [PATCH] Make the logging less verbose for errors (#1118) Only print stack traces if debug level enabled --- music_assistant/server/controllers/cache.py | 7 ++++++- music_assistant/server/controllers/metadata.py | 6 +++++- music_assistant/server/controllers/music.py | 2 +- music_assistant/server/controllers/players.py | 2 +- music_assistant/server/controllers/webserver.py | 8 ++++++-- music_assistant/server/providers/dlna/__init__.py | 5 ++++- music_assistant/server/providers/fanarttv/__init__.py | 2 +- .../server/providers/filesystem_local/base.py | 9 +++++++-- music_assistant/server/providers/qobuz/__init__.py | 4 ++-- music_assistant/server/providers/sonos/__init__.py | 5 ++++- music_assistant/server/providers/sonos/player.py | 2 +- music_assistant/server/providers/spotify/__init__.py | 2 +- music_assistant/server/providers/theaudiodb/__init__.py | 2 +- music_assistant/server/server.py | 2 +- pyproject.toml | 1 + 15 files changed, 42 insertions(+), 17 deletions(-) diff --git a/music_assistant/server/controllers/cache.py b/music_assistant/server/controllers/cache.py index 3523ebaa..a375ec65 100644 --- a/music_assistant/server/controllers/cache.py +++ b/music_assistant/server/controllers/cache.py @@ -104,7 +104,12 @@ class CacheController(CoreController): try: data = await asyncio.to_thread(json_loads, db_row["data"]) except Exception as exc: # pylint: disable=broad-except - LOGGER.exception("Error parsing cache data for %s", cache_key, exc_info=exc) + LOGGER.error( + "Error parsing cache data for %s: %s", + cache_key, + str(exc), + exc_info=exc if self.logger.isEnabledFor(10) else None, + ) else: # also store in memory cache for faster access self._mem_cache[cache_key] = ( diff --git a/music_assistant/server/controllers/metadata.py b/music_assistant/server/controllers/metadata.py index 0e8bc06c..42e52046 100644 --- a/music_assistant/server/controllers/metadata.py +++ b/music_assistant/server/controllers/metadata.py @@ -226,7 +226,11 @@ class MetaDataController(CoreController): MediaItemImage(type=ImageType.THUMB, path=img_path, provider="file") ] except Exception as err: - LOGGER.debug("Error while creating playlist image", exc_info=err) + LOGGER.warning( + "Error while creating playlist image: %s", + str(err), + exc_info=err if self.logger.isEnabledFor(10) else None, + ) # set timestamp, used to determine when this function was last called playlist.metadata.last_refresh = int(time()) diff --git a/music_assistant/server/controllers/music.py b/music_assistant/server/controllers/music.py index 5dc0f304..41394853 100644 --- a/music_assistant/server/controllers/music.py +++ b/music_assistant/server/controllers/music.py @@ -601,7 +601,7 @@ class MusicController(CoreController): self.logger.warning( "Sync task for %s completed with errors", provider.name, - exc_info=task_err, + exc_info=task_err if self.logger.isEnabledFor(10) else None, ) else: self.logger.info("Sync task for %s completed", provider.name) diff --git a/music_assistant/server/controllers/players.py b/music_assistant/server/controllers/players.py index 748a05b9..58171ae6 100644 --- a/music_assistant/server/controllers/players.py +++ b/music_assistant/server/controllers/players.py @@ -875,7 +875,7 @@ class PlayerController(CoreController): "Error while requesting latest state from player %s: %s", player.display_name, str(err), - exc_info=err, + exc_info=err if self.logger.isEnabledFor(10) else None, ) finally: # always update player state diff --git a/music_assistant/server/controllers/webserver.py b/music_assistant/server/controllers/webserver.py index 10cbf285..507f42d5 100644 --- a/music_assistant/server/controllers/webserver.py +++ b/music_assistant/server/controllers/webserver.py @@ -248,6 +248,7 @@ class WebsocketClientHandler: self._to_write: asyncio.Queue = asyncio.Queue(maxsize=MAX_PENDING_MSG) self._handle_task: asyncio.Task | None = None self._writer_task: asyncio.Task | None = None + self.log_level = webserver.log_level self._logger = WebSocketLogAdapter(webserver.logger, {"connid": id(self)}) async def disconnect(self) -> None: @@ -374,7 +375,10 @@ class WebsocketClientHandler: result = await result self._send_message(SuccessResultMessage(msg.message_id, result)) except Exception as err: # pylint: disable=broad-except - self._logger.exception("Error handling message: %s", msg) + if self.log_level == "VERBOSE": + self._logger.exception("Error handling message: %s", msg) + else: + self._logger.error("Error handling message: %s: %s", msg.command, str(err)) self._send_message( ErrorResultMessage(msg.message_id, getattr(err, "error_code", 999), str(err)) ) @@ -407,7 +411,7 @@ class WebsocketClientHandler: try: self._to_write.put_nowait(_message) except asyncio.QueueFull: - self._logger.exception("Client exceeded max pending messages: %s", MAX_PENDING_MSG) + self._logger.error("Client exceeded max pending messages: %s", MAX_PENDING_MSG) self._cancel() diff --git a/music_assistant/server/providers/dlna/__init__.py b/music_assistant/server/providers/dlna/__init__.py index b5c8b6a7..d0b6ade9 100644 --- a/music_assistant/server/providers/dlna/__init__.py +++ b/music_assistant/server/providers/dlna/__init__.py @@ -167,7 +167,10 @@ def catch_request_errors( return await func(self, *args, **kwargs) except UpnpError as err: dlna_player.force_poll = True - self.logger.exception("Error during call %s: %r", func.__name__, err) + if self.log_level == "VERBOSE": + self.logger.exception("Error during call %s: %r", func.__name__, err) + else: + self.logger.error("Error during call %s: %r", func.__name__, str(err)) return None return wrapper diff --git a/music_assistant/server/providers/fanarttv/__init__.py b/music_assistant/server/providers/fanarttv/__init__.py index c6455e29..7540c38b 100644 --- a/music_assistant/server/providers/fanarttv/__init__.py +++ b/music_assistant/server/providers/fanarttv/__init__.py @@ -133,7 +133,7 @@ class FanartTvMetadataProvider(MetadataProvider): aiohttp.client_exceptions.ContentTypeError, JSONDecodeError, ): - self.logger.exception("Failed to retrieve %s", endpoint) + self.logger.error("Failed to retrieve %s", endpoint) text_result = await response.text() self.logger.debug(text_result) return None diff --git a/music_assistant/server/providers/filesystem_local/base.py b/music_assistant/server/providers/filesystem_local/base.py index a764a193..c9152fe2 100644 --- a/music_assistant/server/providers/filesystem_local/base.py +++ b/music_assistant/server/providers/filesystem_local/base.py @@ -356,7 +356,7 @@ class FileSystemProviderBase(MusicProvider): ) except Exception as err: # pylint: disable=broad-except # we don't want the whole sync to crash on one file so we catch all exceptions here - self.logger.exception("Error processing %s - %s", item.path, str(err)) + self.logger.error("Error processing %s - %s", item.path, str(err)) async def _process_deletions(self, deleted_files: set[str]) -> None: """Process all deletions.""" @@ -504,7 +504,12 @@ class FileSystemProviderBase(MusicProvider): yield media_item except Exception as err: # pylint: disable=broad-except - self.logger.warning("Error while parsing playlist %s", prov_playlist_id, exc_info=err) + self.logger.warning( + "Error while parsing playlist %s: %s", + prov_playlist_id, + str(err), + exc_info=err if self.logger.isEnabledFor(10) else None, + ) async def _parse_playlist_line( self, line: str, playlist_path: str, position: int diff --git a/music_assistant/server/providers/qobuz/__init__.py b/music_assistant/server/providers/qobuz/__init__.py index b0a12cea..b0d2b1e5 100644 --- a/music_assistant/server/providers/qobuz/__init__.py +++ b/music_assistant/server/providers/qobuz/__init__.py @@ -760,9 +760,9 @@ class QobuzProvider(MusicProvider): JSONDecodeError, AssertionError, ValueError, - ) as err: + ): text = await response.text() - self.logger.exception("Error while processing %s: %s", endpoint, text, exc_info=err) + self.logger.error("Error while processing %s: %s", endpoint, text) return None return result diff --git a/music_assistant/server/providers/sonos/__init__.py b/music_assistant/server/providers/sonos/__init__.py index 33f33450..01a677b0 100644 --- a/music_assistant/server/providers/sonos/__init__.py +++ b/music_assistant/server/providers/sonos/__init__.py @@ -482,7 +482,10 @@ class SonosPlayerProvider(PlayerProvider): self.logger.debug("Failed to add SonosPlayer %s: %s", soco, err) except Exception as err: self.logger.warning( - "Failed to add SonosPlayer %s: %s", soco, err, exc_info=err + "Failed to add SonosPlayer %s: %s", + soco, + err, + exc_info=err if self.logger.isEnabledFor(10) else None, ) finally: self._discovery_running = False diff --git a/music_assistant/server/providers/sonos/player.py b/music_assistant/server/providers/sonos/player.py index ec542e25..857575d3 100644 --- a/music_assistant/server/providers/sonos/player.py +++ b/music_assistant/server/providers/sonos/player.py @@ -238,7 +238,7 @@ class SonosPlayer: event, self.zone_name, message, - exc_info=exc_info, + exc_info=exc_info if self.logger.isEnabledFor(10) else None, ) async def subscribe(self) -> None: diff --git a/music_assistant/server/providers/spotify/__init__.py b/music_assistant/server/providers/spotify/__init__.py index 5e5cd8ac..4c3152fb 100644 --- a/music_assistant/server/providers/spotify/__init__.py +++ b/music_assistant/server/providers/spotify/__init__.py @@ -752,7 +752,7 @@ class SpotifyProvider(MusicProvider): aiohttp.ContentTypeError, JSONDecodeError, ): - self.logger.exception("Error while processing %s: %s", endpoint, result) + self.logger.error("Error while processing %s: %s", endpoint, result) return None self.logger.debug( "Processing GET/%s took %s seconds", diff --git a/music_assistant/server/providers/theaudiodb/__init__.py b/music_assistant/server/providers/theaudiodb/__init__.py index 68d19bc5..12713ef3 100644 --- a/music_assistant/server/providers/theaudiodb/__init__.py +++ b/music_assistant/server/providers/theaudiodb/__init__.py @@ -279,7 +279,7 @@ class AudioDbMetadataProvider(MetadataProvider): aiohttp.client_exceptions.ContentTypeError, JSONDecodeError, ): - self.logger.exception("Failed to retrieve %s", endpoint) + self.logger.error("Failed to retrieve %s", endpoint) text_result = await response.text() self.logger.debug(text_result) return None diff --git a/music_assistant/server/server.py b/music_assistant/server/server.py index 3e8654c5..65d92921 100644 --- a/music_assistant/server/server.py +++ b/music_assistant/server/server.py @@ -603,7 +603,7 @@ class MusicAssistant: await self.aiozc.async_register_service(info) self.mass_zc_service_set = True except NonUniqueNameException: - LOGGER.exception( + LOGGER.error( "Music Assistant instance with identical name present in the local network!" ) diff --git a/pyproject.toml b/pyproject.toml index 458ab3b7..83dcc393 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -198,6 +198,7 @@ ignore = [ "TD003", # Just annoying, not really useful "TD004", # Just annoying, not really useful "TRY003", # Just annoying, not really useful + "TRY400", # Just annoying, not really useful "COM812", # Conflicts with the Ruff formatter "ISC001", # TEMPORARY DISABLED rules # The below rules must be enabled later one-by-one ! "BLE001", -- 2.34.1