From 4e16e3ee7aaec300ddbeeeb522915ca6a397b309 Mon Sep 17 00:00:00 2001 From: Stefano Pigozzi Date: Sun, 24 Nov 2019 16:02:32 +0100 Subject: [PATCH] Better colored logging --- .idea/vcs.xml | 1 - royalnet/__main__.py | 10 ++-- royalnet/backpack/commands/__init__.py | 10 ++++ royalnet/backpack/commands/exception.py | 11 +++++ royalnet/backpack/commands/excevent.py | 12 +++++ royalnet/backpack/commands/version.py | 8 ++- royalnet/backpack/events/__init__.py | 6 ++- royalnet/backpack/events/exception.py | 8 +++ royalnet/constellation/constellation.py | 10 ++-- royalnet/herald/server.py | 26 +++++++++- royalnet/serf/serf.py | 65 +++++++++++++++---------- 11 files changed, 127 insertions(+), 40 deletions(-) create mode 100644 royalnet/backpack/commands/exception.py create mode 100644 royalnet/backpack/commands/excevent.py create mode 100644 royalnet/backpack/events/exception.py diff --git a/.idea/vcs.xml b/.idea/vcs.xml index bf9b0443..94a25f7f 100644 --- a/.idea/vcs.xml +++ b/.idea/vcs.xml @@ -2,6 +2,5 @@ - \ No newline at end of file diff --git a/royalnet/__main__.py b/royalnet/__main__.py index ad2541b0..f939050a 100644 --- a/royalnet/__main__.py +++ b/royalnet/__main__.py @@ -53,10 +53,10 @@ def run(telegram: typing.Optional[bool], royalnet_log.setLevel(log_level) stream_handler = StreamHandler() if coloredlogs is not None: - stream_handler.formatter = coloredlogs.ColoredFormatter("{asctime}\t| {processName}\t| {levelname}\t| {name}\t|" - " {message}", style="{") + stream_handler.formatter = coloredlogs.ColoredFormatter("{asctime}\t| {processName}\t| {name}\t| {message}", + style="{") else: - stream_handler.formatter = Formatter("{asctime}\t| {processName}\t| {levelname}\t| {name}\t| {message}", + stream_handler.formatter = Formatter("{asctime}\t| {processName}\t| {name}\t| {message}", style="{") royalnet_log.addHandler(stream_handler) royalnet_log.debug("Logging: ready") @@ -96,8 +96,12 @@ def run(telegram: typing.Optional[bool], secret=get_secret("herald"), secure=False, path="/") + herald_kwargs = { + "log_level": log_level + } herald_process = multiprocessing.Process(name="Herald Server", target=r.herald.Server(config=herald_config).run_blocking, + kwargs=herald_kwargs, daemon=True) herald_process.start() else: diff --git a/royalnet/backpack/commands/__init__.py b/royalnet/backpack/commands/__init__.py index 50c1aa68..1ae94c97 100644 --- a/royalnet/backpack/commands/__init__.py +++ b/royalnet/backpack/commands/__init__.py @@ -1,10 +1,20 @@ # Imports go here! from .version import VersionCommand +from .exception import ExceptionCommand +from .excevent import ExceventCommand # Enter the commands of your Pack here! available_commands = [ VersionCommand, ] +# noinspection PyUnreachableCode +if __debug__: + available_commands = [ + *available_commands, + ExceptionCommand, + ExceventCommand, + ] + # Don't change this, it should automatically generate __all__ __all__ = [command.__name__ for command in available_commands] diff --git a/royalnet/backpack/commands/exception.py b/royalnet/backpack/commands/exception.py new file mode 100644 index 00000000..5419b0b3 --- /dev/null +++ b/royalnet/backpack/commands/exception.py @@ -0,0 +1,11 @@ +import royalnet +from royalnet.commands import * + + +class ExceptionCommand(Command): + name: str = "exception" + + description: str = "Raise an exception in the command." + + async def run(self, args: CommandArgs, data: CommandData) -> None: + raise Exception(f"{self.interface.prefix}{self.name} was called") diff --git a/royalnet/backpack/commands/excevent.py b/royalnet/backpack/commands/excevent.py new file mode 100644 index 00000000..38220942 --- /dev/null +++ b/royalnet/backpack/commands/excevent.py @@ -0,0 +1,12 @@ +import royalnet +from royalnet.commands import * + + +class ExceventCommand(Command): + name: str = "excevent" + + description: str = "Call an event that raises an exception." + + async def run(self, args: CommandArgs, data: CommandData) -> None: + await self.interface.call_herald_event(self.interface.name, "exception") + await data.reply("✅ Event called!") diff --git a/royalnet/backpack/commands/version.py b/royalnet/backpack/commands/version.py index 7d7cf56b..fee185a2 100644 --- a/royalnet/backpack/commands/version.py +++ b/royalnet/backpack/commands/version.py @@ -5,10 +5,14 @@ from royalnet.commands import * class VersionCommand(Command): name: str = "version" - description: str = "Get the current Royalnet version." + description: str = "Display the current Royalnet version." async def run(self, args: CommandArgs, data: CommandData) -> None: - message = f"ℹ️ Royalnet {royalnet.__version__}\n" + # noinspection PyUnreachableCode + if __debug__: + message = f"ℹ️ Royalnet {royalnet.__version__} (debug)\n" + else: + message = f"ℹ️ Royalnet {royalnet.__version__}\n" if "69" in message: message += "(Nice.)" await data.reply(message) diff --git a/royalnet/backpack/events/__init__.py b/royalnet/backpack/events/__init__.py index 0c59d789..eac5e669 100644 --- a/royalnet/backpack/events/__init__.py +++ b/royalnet/backpack/events/__init__.py @@ -1,10 +1,14 @@ # Imports go here! - +from .exception import ExceptionEvent # Enter the commands of your Pack here! available_events = [ ] +# noinspection PyUnreachableCode +if __debug__: + available_events.append(ExceptionEvent) + # Don't change this, it should automatically generate __all__ __all__ = [command.__name__ for command in available_events] diff --git a/royalnet/backpack/events/exception.py b/royalnet/backpack/events/exception.py new file mode 100644 index 00000000..15440f1e --- /dev/null +++ b/royalnet/backpack/events/exception.py @@ -0,0 +1,8 @@ +from royalnet.commands import * + + +class ExceptionEvent(Event): + name = "exception" + + def run(self, **kwargs): + raise Exception(f"{self.name} event was called") diff --git a/royalnet/constellation/constellation.py b/royalnet/constellation/constellation.py index 0be322f3..9ecdf3d5 100644 --- a/royalnet/constellation/constellation.py +++ b/royalnet/constellation/constellation.py @@ -142,14 +142,14 @@ class Constellation: royalnet_log.setLevel(log_level) stream_handler = logging.StreamHandler() if coloredlogs is not None: - stream_handler.formatter = coloredlogs.ColoredFormatter("{asctime}\t| {processName}\t| {levelname}\t|" - " {name}\t| {message}", style="{") + stream_handler.formatter = coloredlogs.ColoredFormatter("{asctime}\t| {processName}\t| {name}\t| {message}", + style="{") else: - stream_handler.formatter = logging.Formatter("{asctime}\t| {processName}\t| {levelname}\t| {name}\t| {message}", + stream_handler.formatter = logging.Formatter("{asctime}\t| {processName}\t| {name}\t| {message}", style="{") if len(royalnet_log.handlers) < 1: royalnet_log.addHandler(stream_handler) - royalnet_log.debug("Logging: ready") + log.debug("Logging: ready") # Initialize Sentry on the process if sentry_sdk is None: @@ -172,7 +172,7 @@ class Constellation: release=release) log.info(f"Sentry: enabled (Royalnet {release})") # Run the server - log.info(f"Running Constellation on https://{address}:{port}/ ...") + log.info(f"Running Constellation on https://{address}:{port}/...") constellation.running = True try: uvicorn.run(constellation.starlette, host=address, port=port, log_config=UVICORN_LOGGING_CONFIG) diff --git a/royalnet/herald/server.py b/royalnet/herald/server.py index 34da2efe..4f027d4c 100644 --- a/royalnet/herald/server.py +++ b/royalnet/herald/server.py @@ -1,3 +1,4 @@ +import logging import typing import re import datetime @@ -7,6 +8,11 @@ import logging as _logging from .package import Package from .config import Config +try: + import coloredlogs +except ImportError: + coloredlogs = None + try: import websockets except ImportError: @@ -144,7 +150,10 @@ class Server: if self.config.secure: raise Exception("Secure servers aren't supported yet") log.debug(f"Serving on {self.config.url}") - self.loop.run_until_complete(self.run()) + try: + self.loop.run_until_complete(self.run()) + except OSError as e: + log.fatal(f"OSError: {e}") self.loop.run_forever() async def run(self): @@ -153,7 +162,20 @@ class Server: port=self.config.port, loop=self.loop) - def run_blocking(self): + def run_blocking(self, log_level): + # Initialize logging, as Windows doesn't have fork + royalnet_log: logging.Logger = logging.getLogger("royalnet") + royalnet_log.setLevel(log_level) + stream_handler = logging.StreamHandler() + if coloredlogs is not None: + stream_handler.formatter = coloredlogs.ColoredFormatter("{asctime}\t| {processName}\t| {name}\t| {message}", + style="{") + else: + stream_handler.formatter = logging.Formatter("{asctime}\t| {processName}\t| {name}\t| {message}", + style="{") + if len(royalnet_log.handlers) < 1: + royalnet_log.addHandler(stream_handler) + log.debug("Logging: ready") if self.loop is None: self.loop = asyncio.get_event_loop() self.serve() diff --git a/royalnet/serf/serf.py b/royalnet/serf/serf.py index bd66e18e..6a906e43 100644 --- a/royalnet/serf/serf.py +++ b/royalnet/serf/serf.py @@ -1,4 +1,6 @@ import logging +import sys +import traceback from asyncio import Task, AbstractEventLoop, get_event_loop from typing import Type, Optional, Awaitable, Dict, List, Any, Callable, Union, Set from keyring import get_password @@ -161,22 +163,25 @@ class Serf: request: Request = Request(handler=event_name, data=kwargs) response: Response = await self.herald.request(destination=destination, request=request) if isinstance(response, ResponseFailure): - # TODO: pretty sure there's a better way to do this - if response.extra_info["type"] == "CommandError": - raise CommandError(response.extra_info["message"]) - elif response.extra_info["type"] == "UserError": - raise UserError(response.extra_info["message"]) - elif response.extra_info["type"] == "InvalidInputError": - raise InvalidInputError(response.extra_info["message"]) - elif response.extra_info["type"] == "UnsupportedError": - raise UnsupportedError(response.extra_info["message"]) - elif response.extra_info["type"] == "ConfigurationError": - raise ConfigurationError(response.extra_info["message"]) - elif response.extra_info["type"] == "ExternalError": - raise ExternalError(response.extra_info["message"]) - else: - raise TypeError(f"Herald action call returned invalid error:\n" - f"[p]{response}[/p]") + if response.name == "no_event": + raise CommandError(f"There is no event named {event_name} in {destination}.") + elif response.name == "exception_in_event": + # TODO: pretty sure there's a better way to do this + if response.extra_info["type"] == "CommandError": + raise CommandError(response.extra_info["message"]) + elif response.extra_info["type"] == "UserError": + raise UserError(response.extra_info["message"]) + elif response.extra_info["type"] == "InvalidInputError": + raise InvalidInputError(response.extra_info["message"]) + elif response.extra_info["type"] == "UnsupportedError": + raise UnsupportedError(response.extra_info["message"]) + elif response.extra_info["type"] == "ConfigurationError": + raise ConfigurationError(response.extra_info["message"]) + elif response.extra_info["type"] == "ExternalError": + raise ExternalError(response.extra_info["message"]) + else: + raise TypeError(f"Herald action call returned invalid error:\n" + f"[p]{response}[/p]") elif isinstance(response, ResponseSuccess): return response.data else: @@ -249,6 +254,7 @@ class Serf: response_data = await event.run(**message.data) return ResponseSuccess(data=response_data) except Exception as e: + self.sentry_exc(e) return ResponseFailure("exception_in_event", f"An exception was raised in the event for '{message.handler}'.", extra_info={ @@ -273,11 +279,19 @@ class Serf: release=release) log.info(f"Sentry: enabled (Royalnet {release})") + # noinspection PyUnreachableCode @staticmethod - def sentry_exc(exc: Exception): + def sentry_exc(exc: Exception, + level: str = "error"): if sentry_sdk is not None: - sentry_sdk.capture_exception(exc) - log.error(f"Captured error: {exc}") + with sentry_sdk.configure_scope() as scope: + scope.set_level(level) + sentry_sdk.capture_exception(exc) + log.log(level, f"Captured {level}: {exc}") + # If started in debug mode (without -O), raise the exception, allowing you to see its source + if __debug__: + exc_type, exc_value, exc_traceback = sys.exc_info() + traceback.print_exception(exc_type, exc_value, exc_traceback) def get_secret(self, username: str): """Get a Royalnet secret from the keyring. @@ -325,14 +339,14 @@ class Serf: royalnet_log.setLevel(log_level) stream_handler = logging.StreamHandler() if coloredlogs is not None: - stream_handler.formatter = coloredlogs.ColoredFormatter("{asctime}\t| {processName}\t| {levelname}\t| {name}\t|" - " {message}", style="{") + stream_handler.formatter = coloredlogs.ColoredFormatter("{asctime}\t| {processName}\t| {name}\t| {message}", + style="{") else: - stream_handler.formatter = Formatter("{asctime}\t| {processName}\t| {levelname}\t| {name}\t| {message}", - style="{") + stream_handler.formatter = logging.Formatter("{asctime}\t| {processName}\t| {name}\t| {message}", + style="{") if len(royalnet_log.handlers) < 1: royalnet_log.addHandler(stream_handler) - royalnet_log.debug("Logging: ready") + log.debug("Logging: ready") if sentry_sdk is None: log.info("Sentry: not installed") @@ -347,5 +361,4 @@ class Serf: try: serf.loop.run_until_complete(serf.run()) except Exception as e: - log.error(f"Uncaught exception: {e}") - serf.sentry_exc(e) + serf.sentry_exc(e, level="fatal")