diff --git a/dkist/__init__.py b/dkist/__init__.py index 941f90ed..108cbbe3 100644 --- a/dkist/__init__.py +++ b/dkist/__init__.py @@ -1,19 +1,19 @@ """ The DKIST package aims to help you search, obtain and use DKIST data as part of your Python software. """ -from pkg_resources import DistributionNotFound, get_distribution +from importlib.metadata import PackageNotFoundError +from importlib.metadata import version as _version -import astropy.config as _config +from .logger import setup_default_dkist_logger as _setup_log -from .dataset import Dataset, TiledDataset, load_dataset # noqa -from .utils.sysinfo import system_info # noqa +log = _setup_log(__name__) try: - __version__ = get_distribution(__name__).version -except DistributionNotFound: - # package is not installed + __version__ = _version(__name__) +except PackageNotFoundError: __version__ = "unknown" + __all__ = ['TiledDataset', 'Dataset', 'load_dataset', 'system_info'] @@ -25,4 +25,10 @@ def write_default_config(overwrite=False): config file already exits this will write a config file appended with the version number, to facilitate comparison of changes. """ + import astropy.config as _config return _config.create_config_file("dkist", "dkist", overwrite=overwrite) + + +# Do internal imports last (so logger etc is initialised) +from dkist.dataset import Dataset, TiledDataset, load_dataset # noqa +from dkist.utils.sysinfo import system_info # noqa diff --git a/dkist/conftest.py b/dkist/conftest.py index 799edbd9..5bbced56 100644 --- a/dkist/conftest.py +++ b/dkist/conftest.py @@ -16,7 +16,7 @@ from astropy.time import Time from sunpy.coordinates.frames import Helioprojective -from dkist import load_dataset +from dkist import load_dataset, log from dkist.data.test import rootdir from dkist.dataset import Dataset from dkist.dataset.tiled_dataset import TiledDataset @@ -24,6 +24,15 @@ from dkist.io.loaders import AstropyFITSLoader +@pytest.fixture +def caplog_dkist(caplog): + """ + A `dkist.log` specifc equivalent to caplog. + """ + log.addHandler(caplog.handler) + return caplog + + @pytest.fixture def array(): shape = 2**np.random.randint(2, 7, size=2) diff --git a/dkist/io/loaders.py b/dkist/io/loaders.py index da7376e4..540ee310 100644 --- a/dkist/io/loaders.py +++ b/dkist/io/loaders.py @@ -4,7 +4,6 @@ """ import abc -import logging from pathlib import Path import numpy as np @@ -12,7 +11,7 @@ from astropy.io import fits from sunpy.util.decorators import add_common_docstring -_LOGGER = logging.getLogger(__name__) +from dkist import log __all__ = ['BaseFITSLoader', 'AstropyFITSLoader'] @@ -91,7 +90,7 @@ class AstropyFITSLoader(BaseFITSLoader): def __getitem__(self, slc): if not self.absolute_uri.exists(): - _LOGGER.debug("File %s does not exist.", self.absolute_uri) + log.debug("File %s does not exist.", self.absolute_uri) # Use np.broadcast_to to generate an array of the correct size, but # which only uses memory for one value. return np.broadcast_to(np.nan, self.shape) * np.nan @@ -100,7 +99,7 @@ def __getitem__(self, slc): memmap=False, # memmap is redundant with dask and delayed loading do_not_scale_image_data=True, # don't scale as we shouldn't need to mode="denywrite") as hdul: - _LOGGER.debug("Accessing slice %s from file %s", slc, self.absolute_uri) + log.debug("Accessing slice %s from file %s", slc, self.absolute_uri) hdu = hdul[self.target] if hasattr(hdu, "section"): diff --git a/dkist/logger.py b/dkist/logger.py new file mode 100644 index 00000000..1f90ac46 --- /dev/null +++ b/dkist/logger.py @@ -0,0 +1,118 @@ +""" +This module contains helpers to use the Python logger to show messages to users. + +It is heavily insipired by Astropy's logger, but implemented independantly +because Astropy warn you against directly using theirs. + +This module sets up the following things: + +* A `logging.Logger` subclass which: + - Tracks the module which triggered the log call. + - Overrides warnings.showwarnings so that subclasses of given warning classes are displayed using the logger. +* Sets up a ``log`` instance which uses the Astropy StreamHandler class to log to stdout and colourise the output. +""" +import os +import sys +import logging +import warnings + +from astropy.logger import StreamHandler as AstropyStreamHandler +from astropy.utils.introspection import find_current_module + +from dkist.utils.exceptions import DKISTWarning + + +class DKISTLogger(logging.Logger): + """ + A knock off AstropyLogger. + """ + _showwarning_orig = None + + def __init__(self, name, level=logging.NOTSET, *, capture_warning_classes=None): + super().__init__(name, level=level) + self.capture_warning_classes = tuple(capture_warning_classes) if capture_warning_classes is not None else tuple() + + self.enable_warnings_capture() + + def enable_warnings_capture(self): + if self._showwarning_orig is None: + self._showwarning_orig = warnings.showwarning + warnings.showwarning = self._showwarning + + def disable_warnings_capture(self): + if self._showwarning_orig is not None: + warnings.showwarning = self._showwarning_orig + self._showwarning_orig = None + + def makeRecord( + self, + name, + level, + pathname, + lineno, + msg, + args, + exc_info, + func=None, + extra=None, + sinfo=None, + ): + if extra is None: + extra = {} + + if "origin" not in extra: + current_module = find_current_module(1, finddiff=[True, "logging"]) + if current_module is not None: + extra["origin"] = current_module.__name__ + else: + extra["origin"] = "unknown" + + return super().makeRecord( + name, + level, + pathname, + lineno, + msg, + args, + exc_info, + func=func, + extra=extra, + sinfo=sinfo, + ) + + def _showwarning(self, *args, **kwargs): + # Bail out if we are not catching a warning from one of the given + # classes (or subclasses) + if not isinstance(args[0], self.capture_warning_classes): + return self._showwarning_orig(*args, **kwargs) + + warning = args[0] + message = f"{warning.__class__.__name__}: {args[0]}" + + mod_path = args[2] + # Now that we have the module's path, we look through sys.modules to + # find the module object and thus the fully-package-specified module + # name. The module.__file__ is the original source file name. + mod_name = None + mod_path, ext = os.path.splitext(mod_path) + for name, mod in list(sys.modules.items()): + try: + # Believe it or not this can fail in some cases: + # https://github.com/astropy/astropy/issues/2671 + path = os.path.splitext(getattr(mod, "__file__", ""))[0] + except Exception: + continue + if path == mod_path: + mod_name = mod.__name__ + break + + if mod_name is not None: + self.warning(message, extra={"origin": mod_name}) + else: + self.warning(message) + + +def setup_default_dkist_logger(name): + log = DKISTLogger(name, level=logging.INFO, capture_warning_classes=[DKISTWarning]) + log.addHandler(AstropyStreamHandler()) + return log diff --git a/dkist/tests/test_logger.py b/dkist/tests/test_logger.py new file mode 100644 index 00000000..f8771913 --- /dev/null +++ b/dkist/tests/test_logger.py @@ -0,0 +1,95 @@ +import logging +import warnings + +import pytest + +from dkist import log +from dkist.utils.exceptions import DKISTUserWarning, DKISTWarning + + +def test_debug_log(caplog_dkist): + # By default the level is set to INFO so we shouldn't get anything here. + log.debug("test_debug_log") + assert caplog_dkist.record_tuples == [] + + +def test_info_log(caplog_dkist, capsys): + log.info("test_info_log") + assert caplog_dkist.record_tuples == [("dkist", logging.INFO, "test_info_log")] + + captured = capsys.readouterr() + assert "INFO: test_info_log [dkist.tests.test_logger]" in captured.out + + +def test_warning_log(caplog_dkist, capsys): + log.warning("test_warning_log") + + assert caplog_dkist.record_tuples == [("dkist", logging.WARNING, "test_warning_log")] + captured = capsys.readouterr() + assert "WARNING: test_warning_log [dkist.tests.test_logger]" in captured.err + + +def test_error_log(caplog_dkist, capsys): + log.error("test_error_log") + + assert caplog_dkist.record_tuples == [("dkist", logging.ERROR, "test_error_log")] + captured = capsys.readouterr() + assert "ERROR: test_error_log [dkist.tests.test_logger]" in captured.err + + +def test_warning_capture(caplog_dkist, capsys): + log.disable_warnings_capture() + log.enable_warnings_capture() + + with warnings.catch_warnings(): + warnings.simplefilter("always") + warnings.warn("Test warning", DKISTWarning) + assert caplog_dkist.record_tuples == [("dkist", logging.WARNING, "DKISTWarning: Test warning")] + + captured = capsys.readouterr() + assert "WARNING: DKISTWarning: Test warning [dkist.tests.test_logger]" in captured.err + + +def test_subclass_warning_capture(caplog_dkist, capsys): + log.disable_warnings_capture() + log.enable_warnings_capture() + + with warnings.catch_warnings(): + warnings.simplefilter("always") + warnings.warn("Test warning", DKISTUserWarning) + assert caplog_dkist.record_tuples == [("dkist", logging.WARNING, "DKISTUserWarning: Test warning")] + + captured = capsys.readouterr() + assert "WARNING: DKISTUserWarning: Test warning [dkist.tests.test_logger]" in captured.err + + +def test_no_warning_capture(caplog_dkist, capsys): + log.disable_warnings_capture() + + with pytest.warns(match="Test warning"): + with warnings.catch_warnings(): + # To ensure that disable works, we enable it and then disable it + # again after pytest is done with all it's stuff + log.enable_warnings_capture() + log.disable_warnings_capture() + warnings.simplefilter("always") + warnings.warn("Test warning", DKISTWarning) + assert caplog_dkist.record_tuples == [] + + captured = capsys.readouterr() + assert captured.err == "" + + +def test_not_class_warning_capture(caplog_dkist, capsys): + log.disable_warnings_capture() + + with pytest.warns(match="Test warning"): + with warnings.catch_warnings(): + # We must re-enable capture in the context manager + log.enable_warnings_capture() + warnings.simplefilter("always") + warnings.warn("Test warning", Warning) + assert caplog_dkist.record_tuples == [] + + captured = capsys.readouterr() + assert captured.err == "" diff --git a/dkist/utils/exceptions.py b/dkist/utils/exceptions.py index 4305521a..55177d1b 100644 --- a/dkist/utils/exceptions.py +++ b/dkist/utils/exceptions.py @@ -1,2 +1,16 @@ -class DKISTDeprecationWarning(DeprecationWarning): - pass +class DKISTWarning(Warning): + """ + The base warning class from which all dkist warnings should inherit. + """ + +class DKISTUserWarning(UserWarning, DKISTWarning): + """ + The primary warning class for dkist. + + Use this if you do not need a specific type of warning. + """ + +class DKISTDeprecationWarning(DeprecationWarning, DKISTWarning): + """ + A warning class to use when functionality will be changed or removed in a future version. + """