From 176fb9e533fbecc979f5afd5172ba290b1d8be82 Mon Sep 17 00:00:00 2001 From: Marcel van der Veldt Date: Mon, 2 Aug 2021 10:35:28 +0200 Subject: [PATCH] fix logging --- music_assistant/__main__.py | 23 ++----- music_assistant/constants.py | 2 +- music_assistant/helpers/audio.py | 50 ++++++++++++++ music_assistant/helpers/logger.py | 78 +++++++++++++++++++++ music_assistant/helpers/util.py | 99 ++++++++++++++------------- music_assistant/managers/events.py | 7 +- music_assistant/managers/players.py | 2 +- music_assistant/managers/tasks.py | 4 ++ music_assistant/mass.py | 4 +- music_assistant/models/media_types.py | 4 ++ music_assistant/models/player.py | 4 ++ music_assistant/web/__init__.py | 4 +- music_assistant/web/api.py | 9 +++ 13 files changed, 213 insertions(+), 77 deletions(-) create mode 100644 music_assistant/helpers/logger.py diff --git a/music_assistant/__main__.py b/music_assistant/__main__.py index b33253fc..65befb74 100755 --- a/music_assistant/__main__.py +++ b/music_assistant/__main__.py @@ -1,9 +1,9 @@ """Start Music Assistant.""" import argparse -import logging import os from aiorun import run +from music_assistant.helpers.logger import setup_logger from music_assistant.mass import MusicAssistant @@ -41,30 +41,19 @@ def get_arguments(): def main(): """Start MusicAssistant.""" - # setup logger - logger = logging.getLogger() - logformat = logging.Formatter( - "%(asctime)-15s %(levelname)-5s %(name)s -- %(message)s" - ) - consolehandler = logging.StreamHandler() - consolehandler.setFormatter(logformat) - logger.addHandler(consolehandler) - # parse arguments args = get_arguments() data_dir = args.config if not os.path.isdir(data_dir): os.makedirs(data_dir) + # setup logger + logger = setup_logger(data_dir) # config debug settings if needed if args.debug or bool(os.environ.get("DEBUG")): - logger.setLevel(logging.DEBUG) + debug = True else: - logger.setLevel(logging.INFO) - # cool down logging for asyncio and aiosqlite - logging.getLogger("asyncio").setLevel(logging.WARNING) - logging.getLogger("aiosqlite").setLevel(logging.INFO) - - mass = MusicAssistant(data_dir, args.debug, int(args.port)) + debug = False + mass = MusicAssistant(data_dir, debug, int(args.port)) def on_shutdown(loop): logger.info("shutdown requested!") diff --git a/music_assistant/constants.py b/music_assistant/constants.py index 165d9d1c..430aac4c 100755 --- a/music_assistant/constants.py +++ b/music_assistant/constants.py @@ -1,6 +1,6 @@ """All constants for Music Assistant.""" -__version__ = "0.2.0" +__version__ = "0.2.1" REQUIRED_PYTHON_VER = "3.8" # configuration keys/attributes diff --git a/music_assistant/helpers/audio.py b/music_assistant/helpers/audio.py index 80283eb9..d54b6e3e 100644 --- a/music_assistant/helpers/audio.py +++ b/music_assistant/helpers/audio.py @@ -2,6 +2,8 @@ import asyncio import logging +import struct +from io import BytesIO from typing import List, Tuple from music_assistant.helpers.process import AsyncProcess @@ -205,3 +207,51 @@ async def get_gain_correct( gain_correct = target_gain - track_loudness gain_correct = round(gain_correct, 2) return (track_loudness, gain_correct) + + +def create_wave_header(samplerate=44100, channels=2, bitspersample=16, duration=3600): + """Generate a wave header from given params.""" + # pylint: disable=no-member + file = BytesIO() + numsamples = samplerate * duration + + # Generate format chunk + format_chunk_spec = b"<4sLHHLLHH" + format_chunk = struct.pack( + format_chunk_spec, + b"fmt ", # Chunk id + 16, # Size of this chunk (excluding chunk id and this field) + 1, # Audio format, 1 for PCM + channels, # Number of channels + int(samplerate), # Samplerate, 44100, 48000, etc. + int(samplerate * channels * (bitspersample / 8)), # Byterate + int(channels * (bitspersample / 8)), # Blockalign + bitspersample, # 16 bits for two byte samples, etc. + ) + # Generate data chunk + data_chunk_spec = b"<4sL" + datasize = int(numsamples * channels * (bitspersample / 8)) + data_chunk = struct.pack( + data_chunk_spec, + b"data", # Chunk id + int(datasize), # Chunk size (excluding chunk id and this field) + ) + sum_items = [ + # "WAVE" string following size field + 4, + # "fmt " + chunk size field + chunk size + struct.calcsize(format_chunk_spec), + # Size of data chunk spec + data size + struct.calcsize(data_chunk_spec) + datasize, + ] + # Generate main header + all_chunks_size = int(sum(sum_items)) + main_header_spec = b"<4sL4s" + main_header = struct.pack(main_header_spec, b"RIFF", all_chunks_size, b"WAVE") + # Write all the contents in + file.write(main_header) + file.write(format_chunk) + file.write(data_chunk) + + # return file.getvalue(), all_chunks_size + 8 + return file.getvalue() diff --git a/music_assistant/helpers/logger.py b/music_assistant/helpers/logger.py new file mode 100644 index 00000000..c695666f --- /dev/null +++ b/music_assistant/helpers/logger.py @@ -0,0 +1,78 @@ +"""Initialize logger.""" +import logging +import os +import random +from logging.handlers import TimedRotatingFileHandler + +from .util import LimitedList + + +def setup_logger(data_path): + """Initialize logger.""" + logs_dir = os.path.join(data_path, "logs") + if not os.path.isdir(logs_dir): + os.mkdir(logs_dir) + logger = logging.getLogger() + log_formatter = logging.Formatter( + "%(asctime)-15s %(levelname)-5s %(name)s -- %(message)s" + ) + consolehandler = logging.StreamHandler() + consolehandler.setFormatter(log_formatter) + consolehandler.setLevel(logging.DEBUG) + logger.addHandler(consolehandler) + log_filename = os.path.join(logs_dir, "musicassistant.log") + file_handler = TimedRotatingFileHandler( + log_filename, when="midnight", interval=1, backupCount=10 + ) + file_handler.setLevel(logging.INFO) + file_handler.setFormatter(log_formatter) + logger.addHandler(file_handler) + + html_handler = HistoryLogHandler() + html_handler.setLevel(logging.DEBUG) + html_handler.setFormatter(log_formatter) + logger.addHandler(html_handler) + + # global level is debug + logger.setLevel(logging.DEBUG) + + # silence some loggers + logging.getLogger("asyncio").setLevel(logging.WARNING) + logging.getLogger("aiosqlite").setLevel(logging.WARNING) + logging.getLogger("databases").setLevel(logging.WARNING) + logging.getLogger("multipart.multipart").setLevel(logging.WARNING) + logging.getLogger("passlib.handlers.bcrypt").setLevel(logging.WARNING) + + return logger + + +class HistoryLogHandler(logging.Handler): + """A logging handler that keeps the last X records in memory.""" + + def __init__(self, max_len: int = 200): + """Initialize instance.""" + logging.Handler.__init__(self) + # Our custom argument + self._history = LimitedList(max_len=max_len) + self._max_len = max_len + + @property + def max_len(self) -> int: + """Return the max size of the log list.""" + return self._max_len + + def emit(self, record): + """Emit log record.""" + self._history.append( + { + "id": f"{record.asctime}.{random.randint(0, 9)}", + "time": record.asctime, + "name": record.name, + "level": record.levelname, + "message": record.message, + } + ) + + def get_history(self): + """Get all log lines in history.""" + return self._history diff --git a/music_assistant/helpers/util.py b/music_assistant/helpers/util.py index 682144f4..38a3b763 100755 --- a/music_assistant/helpers/util.py +++ b/music_assistant/helpers/util.py @@ -5,13 +5,11 @@ import logging import os import platform import socket -import struct import tempfile import threading import urllib.request from asyncio.events import AbstractEventLoop -from io import BytesIO -from typing import Any, Callable, Dict, Optional, Set, TypeVar, Union +from typing import Any, Callable, Dict, List, Optional, Set, TypeVar, Union import memory_tempfile import ujson @@ -225,7 +223,7 @@ def get_version_substitute(version_str): def get_ip(): """Get primary IP-address for this host.""" - # pylint: disable=broad-except + # pylint: disable=broad-except,no-member sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) try: # doesn't even have to be reachable @@ -240,6 +238,7 @@ def get_ip(): def get_ip_pton(): """Return socket pton for local ip.""" + # pylint:disable=no-member try: return socket.inet_pton(socket.AF_INET, get_ip()) except OSError: @@ -251,6 +250,7 @@ def get_ip_pton(): def get_hostname(): """Get hostname for this machine.""" + # pylint:disable=no-member return socket.gethostname() @@ -343,48 +343,49 @@ def create_uri(media_type: MediaType, provider: str, item_id: str): return f"{provider}://{media_type.value}/{item_id}" -def create_wave_header(samplerate=44100, channels=2, bitspersample=16, duration=3600): - """Generate a wave header from given params.""" - file = BytesIO() - numsamples = samplerate * duration - - # Generate format chunk - format_chunk_spec = b"<4sLHHLLHH" - format_chunk = struct.pack( - format_chunk_spec, - b"fmt ", # Chunk id - 16, # Size of this chunk (excluding chunk id and this field) - 1, # Audio format, 1 for PCM - channels, # Number of channels - int(samplerate), # Samplerate, 44100, 48000, etc. - int(samplerate * channels * (bitspersample / 8)), # Byterate - int(channels * (bitspersample / 8)), # Blockalign - bitspersample, # 16 bits for two byte samples, etc. - ) - # Generate data chunk - data_chunk_spec = b"<4sL" - datasize = int(numsamples * channels * (bitspersample / 8)) - data_chunk = struct.pack( - data_chunk_spec, - b"data", # Chunk id - int(datasize), # Chunk size (excluding chunk id and this field) - ) - sum_items = [ - # "WAVE" string following size field - 4, - # "fmt " + chunk size field + chunk size - struct.calcsize(format_chunk_spec), - # Size of data chunk spec + data size - struct.calcsize(data_chunk_spec) + datasize, - ] - # Generate main header - all_chunks_size = int(sum(sum_items)) - main_header_spec = b"<4sL4s" - main_header = struct.pack(main_header_spec, b"RIFF", all_chunks_size, b"WAVE") - # Write all the contents in - file.write(main_header) - file.write(format_chunk) - file.write(data_chunk) - - # return file.getvalue(), all_chunks_size + 8 - return file.getvalue() +class LimitedList(list): + """Implementation of a size limited list.""" + + @property + def max_len(self): + """Return list's max length.""" + return self._max_len + + def __init__(self, lst: Optional[List] = None, max_len=500): + """Initialize instance.""" + self._max_len = max_len + if lst is not None: + super().__init__(lst) + else: + super().__init__() + + def _truncate(self): + """Call by various methods to reinforce the maximum length.""" + dif = len(self) - self._max_len + if dif > 0: + self[:dif] = [] + + def append(self, x): + """Append item x to the list.""" + super().append(x) + self._truncate() + + def insert(self, *args): + """Insert items at position x to the list.""" + super().insert(*args) + self._truncate() + + def extend(self, x): + """Extend the list.""" + super().extend(x) + self._truncate() + + def __setitem__(self, *args): + """Internally set.""" + super().__setitem__(*args) + self._truncate() + + # def __setslice__(self, *args): + # """Internally set slice.""" + # super().__setslice__(*args) + # self._truncate() diff --git a/music_assistant/managers/events.py b/music_assistant/managers/events.py index 2c07da4b..71407d9b 100644 --- a/music_assistant/managers/events.py +++ b/music_assistant/managers/events.py @@ -26,11 +26,8 @@ class EventBus: :param event_msg: the eventmessage to signal :param event_details: optional details to send with the event. """ - if LOGGER.isEnabledFor(logging.DEBUG): - log_details = getattr( - event_details, "name", getattr(event_details, "id", event_details) - ) - LOGGER.debug("%s: %s", event_msg, log_details) + if self.mass.debug: + LOGGER.debug("%s: %s", event_msg, str(event_details)) for cb_func, event_filter in self._listeners: if not event_filter or event_msg in event_filter: create_task(cb_func, event_msg, event_details) diff --git a/music_assistant/managers/players.py b/music_assistant/managers/players.py index 36f180d0..f4adf112 100755 --- a/music_assistant/managers/players.py +++ b/music_assistant/managers/players.py @@ -205,7 +205,7 @@ class PlayerManager: player.provider_id, player.name, ) - self.mass.eventbus.signal(EVENT_PLAYER_ADDED, player) + self.mass.eventbus.signal(EVENT_PLAYER_ADDED, player.calculated_state) async def remove_player(self, player_id: str): """Remove a player from the registry.""" diff --git a/music_assistant/managers/tasks.py b/music_assistant/managers/tasks.py index 85b12788..acbefb33 100644 --- a/music_assistant/managers/tasks.py +++ b/music_assistant/managers/tasks.py @@ -52,6 +52,10 @@ class TaskInfo: self.execution_time = 0 # time in seconds it took to process self.id = str(uuid4()) + def __str__(self): + """Return string representation, used for logging.""" + return f"{self.name} ({id})" + def to_dict(self) -> Dict[str, Any]: """Return serializable dict.""" return { diff --git a/music_assistant/mass.py b/music_assistant/mass.py index 4b3ddaa3..0c764518 100644 --- a/music_assistant/mass.py +++ b/music_assistant/mass.py @@ -53,7 +53,7 @@ class MusicAssistant: self._exit = False self._loop = None - self._debug = debug + self.debug = debug self._http_session = None self._providers = {} @@ -78,7 +78,7 @@ class MusicAssistant: self._loop = asyncio.get_event_loop() util.DEFAULT_LOOP = self._loop self._loop.set_exception_handler(global_exception_handler) - self._loop.set_debug(self._debug) + self._loop.set_debug(self.debug) # create shared aiohttp ClientSession self._http_session = aiohttp.ClientSession( loop=self.loop, diff --git a/music_assistant/models/media_types.py b/music_assistant/models/media_types.py index 2acea7bf..96c7cf4f 100755 --- a/music_assistant/models/media_types.py +++ b/music_assistant/models/media_types.py @@ -133,6 +133,10 @@ class MediaItem(DataClassDictMixin): """Return custom hash.""" return hash((self.media_type, self.provider, self.item_id)) + def __str__(self): + """Return string representation, used for logging.""" + return f"{self.name} ({self.uri})" + @dataclass class Artist(MediaItem): diff --git a/music_assistant/models/player.py b/music_assistant/models/player.py index 24f89e73..d922e798 100755 --- a/music_assistant/models/player.py +++ b/music_assistant/models/player.py @@ -105,6 +105,10 @@ class CalculatedPlayerState(DataClassDictMixin): """Return custom hash.""" return hash((self.provider_id, self.player_id)) + def __str__(self): + """Return string representation, used for logging.""" + return f"{self.name} ({self.provider_id}/{self.player_id})" + def update(self, new_obj: "PlayerState") -> Set[str]: """Update state from other PlayerState instance and return changed keys.""" changed_keys = set() diff --git a/music_assistant/web/__init__.py b/music_assistant/web/__init__.py index 006bdb55..998139dd 100755 --- a/music_assistant/web/__init__.py +++ b/music_assistant/web/__init__.py @@ -152,8 +152,8 @@ class WebServer: @property def address(self) -> str: - """Return the API connect address for this Music Assistant instance.""" - return f"ws://{self.hostname}:{self.port}/ws" + """Return the base HTTP address for this Music Assistant instance.""" + return f"http://{self.hostname}:{self.port}" @property def server_id(self) -> str: diff --git a/music_assistant/web/api.py b/music_assistant/web/api.py index 92196a7c..51cdc7ba 100644 --- a/music_assistant/web/api.py +++ b/music_assistant/web/api.py @@ -13,6 +13,7 @@ from aiohttp import WSMsgType, web from aiohttp.http_websocket import WSMessage from music_assistant.helpers.errors import AuthenticationError from music_assistant.helpers.images import get_image_url, get_thumb_file +from music_assistant.helpers.logger import HistoryLogHandler from music_assistant.helpers.typing import MusicAssistant from music_assistant.helpers.web import ( api_route, @@ -25,6 +26,14 @@ from music_assistant.models.media_types import MediaType LOGGER = logging.getLogger("api") +@api_route("log") +async def get_log(tail: int = 200) -> str: + """Return current application log.""" + for handler in logging.getLogger().handlers: + if isinstance(handler, HistoryLogHandler): + return handler.get_history()[-tail:] + + @api_route("images/{media_type}/{provider}/{item_id}") async def get_media_item_image_url( mass: MusicAssistant, media_type: MediaType, provider: str, item_id: str -- 2.34.1