From 6abc9a0c64493ef151ac09e07abacf50a2efec81 Mon Sep 17 00:00:00 2001 From: ekzyis Date: Thu, 4 Nov 2021 00:29:54 +0100 Subject: [PATCH 1/4] Add logging --- .env.template | 2 ++ src/bot.py | 29 +++++++++++++++------ src/error.py | 5 +++- src/log.py | 66 ++++++++++++++++++++++++++++++++++++++++++++++++ test/conftest.py | 10 ++++++++ 5 files changed, 103 insertions(+), 9 deletions(-) create mode 100644 src/log.py diff --git a/.env.template b/.env.template index 8b33c29..525cbe4 100644 --- a/.env.template +++ b/.env.template @@ -1,3 +1,5 @@ DISCORD_BOT_TOKEN= DISCORD_CMD_PREFIX= +DISCORD_LOG_CHANNEL_ID= +DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP=False YOUTUBE_COOKIES=youtube.com_cookies.txt \ No newline at end of file diff --git a/src/bot.py b/src/bot.py index 532fabd..1f07080 100644 --- a/src/bot.py +++ b/src/bot.py @@ -2,6 +2,8 @@ import os import sys import asyncio from dataclasses import dataclass +from distutils.util import strtobool +import logging import discord from discord.ext import commands, tasks @@ -10,6 +12,7 @@ import youtube_dl from error import ErrorHandler from message import NowPlayingMessage, QueuedMessage, ErrorMessage +from log import create_logger, DiscordLogger load_dotenv() @@ -25,7 +28,7 @@ class Song: class Music(commands.Cog): - def __init__(self, bot): + def __init__(self, bot: commands.Bot, logger: logging.Logger): self._bot = bot self._queue = asyncio.Queue() self._queue_lock = asyncio.Lock() @@ -52,6 +55,15 @@ class Music(commands.Cog): # pylint: disable=no-member self._handle_playback.start() + self.logger = logger + if log_channel_id := os.environ.get("DISCORD_LOG_CHANNEL_ID", None): + clear_on_startup = os.environ.get("DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP", False) + if clear_on_startup == "": + clear_on_startup = False + if isinstance(clear_on_startup, str): + clear_on_startup = bool(strtobool(clear_on_startup)) + self.logger.addHandler(DiscordLogger(self._bot, channel_id=log_channel_id, clear_on_startup=clear_on_startup)) + def cog_unload(self): # pylint: disable=no-member self._handle_playback.cancel() @@ -79,7 +91,7 @@ class Music(commands.Cog): def after(err): if err: - print(f"Player error: {err}") + self.logger.error(f"Player error: {err}") self._next() ctx.voice_client.play(audio, after=after) embed = NowPlayingMessage(title=song.title, url=song.webpage_url) @@ -87,7 +99,7 @@ class Music(commands.Cog): await self._add_skip_button(msg) # pylint: disable=broad-except except Exception as err: - print(f"Error during playback: {err}") + self.logger.error(f"Error during playback: {err}") if ctx: embed = ErrorMessage(str(err)) await ctx.send(embed=embed) @@ -154,20 +166,21 @@ class Music(commands.Cog): if __name__ == "__main__": prefix = os.environ.get("DISCORD_CMD_PREFIX", "!") + logger = create_logger("bot") bot = commands.Bot(command_prefix=commands.when_mentioned_or(prefix), description='Relatively simple music bot example') @bot.event async def on_ready(): - print(f"Logged in as {bot.user} ({bot.user.id})") - print('------') + logger.info(f"Logged in as {bot.user} ({bot.user.id})") + logger.info('------') - bot.add_cog(Music(bot)) - bot.add_cog(ErrorHandler(bot)) + bot.add_cog(Music(bot, logger=logger)) + bot.add_cog(ErrorHandler(bot, logger=logger)) token = os.environ.get("DISCORD_BOT_TOKEN", None) if not token: - print("Discord bot token not found") + logger.warning("Discord bot token not found") sys.exit(1) bot.run(token) diff --git a/src/error.py b/src/error.py index 5bf9470..8f6526a 100644 --- a/src/error.py +++ b/src/error.py @@ -1,3 +1,5 @@ +import logging + from discord.ext import commands from message import ErrorMessage @@ -6,8 +8,9 @@ from message import ErrorMessage class ErrorHandler(commands.Cog): """A cog for global error handling.""" - def __init__(self, bot: commands.Bot): + def __init__(self, bot: commands.Bot, logger: logging.Logger): self.bot = bot + self.logger = logger @commands.Cog.listener() async def on_command_error(self, ctx: commands.Context, error: commands.CommandError): diff --git a/src/log.py b/src/log.py new file mode 100644 index 0000000..f64ab58 --- /dev/null +++ b/src/log.py @@ -0,0 +1,66 @@ +import asyncio +import logging +from logging import LogRecord +import sys +import os +from datetime import datetime + +from discord import TextChannel +from discord.ext.commands import Bot as DiscordBot + + +__LOG_FORMAT__ = '%(asctime)s %(name)-5s %(levelname)-8s %(message)s' +__DATE_FORMAT__ = '%Y-%m-%d %H:%M:%S' + + +def create_logger(name: str) -> logging.Logger: + """Create logger with some sane defaults.""" + logger = logging.getLogger(name) + logger.setLevel(logging.DEBUG) + + stream_handler = logging.StreamHandler(stream=sys.stdout) + + COMMIT = os.getenv('GIT_COMMIT') or 'no-commit' + timestamp = datetime.now().strftime("%Y-%m-%dT%H:%M:%S") + log_path = "%s_%s.log" % (COMMIT, timestamp) + + file_handler = logging.FileHandler(log_path) + + formatter = logging.Formatter( + fmt='%(asctime)s %(name)-5s %(levelname)-8s %(message)s', datefmt='%Y-%m-%d %H:%M:%S') + stream_handler.setFormatter(formatter) + file_handler.setFormatter(formatter) + + logger.addHandler(stream_handler) + logger.addHandler(file_handler) + + return logger + + +class DiscordLogger(logging.Handler): + """Logging handler which sends logs to the specified discord channel.""" + + def __init__(self, bot: DiscordBot, channel_id=None, clear_on_startup=False): + super().__init__() + self._bot = bot + self._channel_id = channel_id + self._channel: TextChannel = None + self._channel_cleared = False + self._clear_on_startup = clear_on_startup + self._formatter = logging.Formatter(fmt='%(asctime)s %(name)-5s %(levelname)-8s %(message)s', datefmt='%Y-%m-%d %H:%M:%S') + + def emit(self, record: LogRecord) -> None: + if self._channel_id is not None: + msg = self._formatter.format(record) + + async def _emit_to_channel() -> None: + if self._channel is None: + self._channel = await self._bot.fetch_channel(self._channel_id) + if self._clear_on_startup: + async for log in self._channel.history(limit=None): + await log.delete() + + if self._channel is not None: + await self._channel.send(msg) + + asyncio.create_task(_emit_to_channel()) diff --git a/test/conftest.py b/test/conftest.py index 6902468..6da72fa 100644 --- a/test/conftest.py +++ b/test/conftest.py @@ -2,6 +2,8 @@ import asyncio import sys from pathlib import Path from unittest.mock import Mock +import glob +import os import pytest from pytest_mock import MockerFixture @@ -13,6 +15,14 @@ sys.path.insert(0, SRC_PATH) from bot import Music +@pytest.fixture(scope="session", autouse=True) +def start_xvfb_server(request): + yield + logs = glob.glob('*.log') + for log in logs: + os.remove(log) + + @pytest.fixture def bot(mocker: MockerFixture): bot_mock = mocker.patch('discord.ext.commands.Bot', autospec=True) From 85ec8c95a54425a10a2a9d3ac49afc6ca7ee6598 Mon Sep 17 00:00:00 2001 From: ekzyis Date: Thu, 4 Nov 2021 00:59:52 +0100 Subject: [PATCH 2/4] Add env vars to docker image --- Dockerfile | 3 +++ Makefile | 2 ++ 2 files changed, 5 insertions(+) diff --git a/Dockerfile b/Dockerfile index d43e2c1..be0b175 100644 --- a/Dockerfile +++ b/Dockerfile @@ -12,6 +12,9 @@ RUN pip install -r requirements.txt ARG GIT_COMMIT=unset ARG DISCORD_BOT_TOKEN=unset ARG YOUTUBE_COOKIES=unset +ARG DISCORD_LOG_CHANNEL_ID=unset +ARG DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP=unset ENV DISCORD_BOT_TOKEN=${DISCORD_BOT_TOKEN} YOUTUBE_COOKIES=${YOUTUBE_COOKIES} GIT_COMMIT=${GIT_COMMIT} +ENV DISCORD_LOG_CHANNEL_ID=${DISCORD_LOG_CHANNEL_ID} DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP=${DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP} CMD ["python", "src/bot.py"] diff --git a/Makefile b/Makefile index a74f4fe..7df08b4 100644 --- a/Makefile +++ b/Makefile @@ -10,5 +10,7 @@ build: --build-arg DISCORD_BOT_TOKEN=${DISCORD_BOT_TOKEN} \ --build-arg YOUTUBE_COOKIES=${YOUTUBE_COOKIES} \ --build-arg GIT_COMMIT=${GIT_COMMIT} \ + --build-arg DISCORD_LOG_CHANNEL_ID=${DISCORD_LOG_CHANNEL_ID} \ + --build-arg DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP=${DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP} \ -t musicube:${GIT_COMMIT} -t musicube:latest \ . From a26de66f08f3a20d096b7922856a9578303cc1e5 Mon Sep 17 00:00:00 2001 From: ekzyis Date: Thu, 4 Nov 2021 01:07:34 +0100 Subject: [PATCH 3/4] Fix pytest --- src/bot.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/bot.py b/src/bot.py index 1f07080..0692a1c 100644 --- a/src/bot.py +++ b/src/bot.py @@ -28,7 +28,7 @@ class Song: class Music(commands.Cog): - def __init__(self, bot: commands.Bot, logger: logging.Logger): + def __init__(self, bot: commands.Bot, logger: logging.Logger = None): self._bot = bot self._queue = asyncio.Queue() self._queue_lock = asyncio.Lock() @@ -55,7 +55,7 @@ class Music(commands.Cog): # pylint: disable=no-member self._handle_playback.start() - self.logger = logger + self.logger = logger if logger else create_logger("bot") if log_channel_id := os.environ.get("DISCORD_LOG_CHANNEL_ID", None): clear_on_startup = os.environ.get("DISCORD_LOG_CHANNEL_CLEAR_ON_STARTUP", False) if clear_on_startup == "": From 1277e6d00b4d8800c4bfb6bf9134774c5374e9b5 Mon Sep 17 00:00:00 2001 From: ekzyis Date: Thu, 4 Nov 2021 01:07:42 +0100 Subject: [PATCH 4/4] Fix pylint --- .pylintrc | 3 ++- src/bot.py | 6 +++--- src/log.py | 2 +- test/conftest.py | 2 +- 4 files changed, 7 insertions(+), 6 deletions(-) diff --git a/.pylintrc b/.pylintrc index 6df1145..78b6d2c 100644 --- a/.pylintrc +++ b/.pylintrc @@ -12,7 +12,8 @@ disable= wrong-import-position, redefined-outer-name, invalid-name, - no-self-use + no-self-use, + too-many-instance-attributes [FORMAT] indent-string=' ' diff --git a/src/bot.py b/src/bot.py index 0692a1c..16e1320 100644 --- a/src/bot.py +++ b/src/bot.py @@ -91,7 +91,7 @@ class Music(commands.Cog): def after(err): if err: - self.logger.error(f"Player error: {err}") + self.logger.error("Player error: %s", err) self._next() ctx.voice_client.play(audio, after=after) embed = NowPlayingMessage(title=song.title, url=song.webpage_url) @@ -99,7 +99,7 @@ class Music(commands.Cog): await self._add_skip_button(msg) # pylint: disable=broad-except except Exception as err: - self.logger.error(f"Error during playback: {err}") + self.logger.error("Error during playback: %s", err) if ctx: embed = ErrorMessage(str(err)) await ctx.send(embed=embed) @@ -172,7 +172,7 @@ if __name__ == "__main__": @bot.event async def on_ready(): - logger.info(f"Logged in as {bot.user} ({bot.user.id})") + logger.info("Logged in as %s (%s)", bot.user, bot.user.id) logger.info('------') bot.add_cog(Music(bot, logger=logger)) diff --git a/src/log.py b/src/log.py index f64ab58..21cb5f3 100644 --- a/src/log.py +++ b/src/log.py @@ -22,7 +22,7 @@ def create_logger(name: str) -> logging.Logger: COMMIT = os.getenv('GIT_COMMIT') or 'no-commit' timestamp = datetime.now().strftime("%Y-%m-%dT%H:%M:%S") - log_path = "%s_%s.log" % (COMMIT, timestamp) + log_path = f"{COMMIT}_{timestamp}.log" file_handler = logging.FileHandler(log_path) diff --git a/test/conftest.py b/test/conftest.py index 6da72fa..5413a8f 100644 --- a/test/conftest.py +++ b/test/conftest.py @@ -16,7 +16,7 @@ from bot import Music @pytest.fixture(scope="session", autouse=True) -def start_xvfb_server(request): +def global_teardown(): yield logs = glob.glob('*.log') for log in logs: