Improve logging

pyproject.toml

@@ -31,12 +31,13 @@ httpx = "^0.23.0"
 beautifulsoup4 = "^4.12.1"
 lxml = "^4.9.3"
 pyyaml = "^6.0.1"
-more-itertools = "^9.0"
+more-itertools = "^10.1.0"
 tqdm = "^4.66.1"
 
 synphot = "^1.2.1"
 skycalc_ipy = "^0.3.0"
 anisocado = "^0.3.0"
+astar-utils = {version = "^0.2.0b0", allow-prereleases = true}
 
 [tool.poetry.group.dev]
 optional = true

scopesim/__init__.py

@@ -1,8 +1,8 @@
-"""The Instrument data simulator for MICADO on the E-ELT"""
+"Generalised telescope observation simulator."
 
-################################################################################
-#                            TURN OFF WARNINGS                                 #
-################################################################################
+###############################################################################
+#                            TURN OFF WARNINGS                                #
+###############################################################################
 import sys
 import logging
 import warnings
@@ -12,43 +12,48 @@
 
 warnings.simplefilter('ignore', UserWarning)
 warnings.simplefilter('ignore', FutureWarning)
-warnings.simplefilter('ignore', RuntimeWarning)     # warnings for the developer
+warnings.simplefilter('ignore', RuntimeWarning)    # warnings for the developer
 warnings.simplefilter('ignore', category=AstropyWarning)
 yaml.warnings({'YAMLLoadWarning': False})
 
-################################################################################
-#                         PACKAGE GLOBAL VARIABLES                             #
-################################################################################
+###############################################################################
+#                         PACKAGE GLOBAL VARIABLES                            #
+###############################################################################
 
 from . import rc
 
-################################################################################
-#                         SET BASIC LOGGING LEVEL                              #
-################################################################################
+###############################################################################
+#                         SET BASIC LOGGING LEVEL                             #
+###############################################################################
 
-root = logging.getLogger()
-root.setLevel("DEBUG")            # DEBUG
+# TODO: this should be replaced with YAML-based config!! see prepipy
 
-if rc.__config__["!SIM.logging.log_to_file"] is True:
-    file_path = rc.__config__["!SIM.logging.file_path"]
-    write_mode = rc.__config__["!SIM.logging.file_open_mode"]
-    file_handler = logging.FileHandler(file_path, write_mode)
-    file_handler.setLevel(rc.__config__["!SIM.logging.file_level"])  # DEBUG
-    formatter = logging.Formatter('%(levelname)s - %(message)s')
+# This should be part of ScopeSim (the app) and not scopesim_core eventually
+
+top_logger = logging.getLogger("astar")
+top_logger.setLevel(logging.WARNING)
+sim_logger = top_logger.getChild(__package__)
+sim_logger.setLevel(logging.DEBUG)
+formatter = logging.Formatter("%(name)s - %(levelname)s: %(message)s")
+
+log_dict = rc.__config__["!SIM.logging"]
+if log_dict["log_to_file"]:
+    file_handler = logging.FileHandler(log_dict["file_path"],
+                                       log_dict["file_open_mode"])
+    file_handler.setLevel(log_dict["file_level"])  # DEBUG
     file_handler.setFormatter(formatter)
-    root.addHandler(file_handler)
+    top_logger.addHandler(file_handler)
 
-if rc.__config__["!SIM.logging.log_to_console"] is True:
+if log_dict["log_to_console"]:
     stdout_handler = logging.StreamHandler(sys.stdout)
-    stdout_handler.setLevel(rc.__config__["!SIM.logging.console_level"])  # WARNING
-    formatter = logging.Formatter('%(levelname)s - %(message)s')
+    stdout_handler.setLevel(log_dict["console_level"])  # INFO
     stdout_handler.setFormatter(formatter)
-    root.addHandler(stdout_handler)
+    top_logger.addHandler(stdout_handler)
 
 
-################################################################################
-#                         IMPORT PACKAGE MODULES                               #
-################################################################################
+###############################################################################
+#                         IMPORT PACKAGE MODULES                              #
+###############################################################################
 
 # Import all the modules to go under ScopeSim
 
@@ -72,8 +77,8 @@
 
 from .tests.mocks.load_basic_instrument import load_example_optical_train
 
-################################################################################
-#                          VERSION INFORMATION                                 #
-################################################################################
+###############################################################################
+#                          VERSION INFORMATION                                #
+###############################################################################
 
 __version__ = metadata.version(__package__)

scopesim/commands/user_commands.py

@@ -1,14 +1,15 @@
 import os
-import logging
 import copy
 from pathlib import Path
 
-import numpy as np
 import yaml
 import httpx
 
 from .. import rc
-from ..utils import find_file, top_level_catch
+from ..utils import find_file, top_level_catch, get_logger
+
+
+logger = get_logger(__name__)
 
 __all__ = ["UserCommands"]
 
@@ -181,7 +182,7 @@
                         if yaml_input == "default.yaml":
                             self.default_yamls = yaml_dict
                     else:
-                        logging.warning("%s could not be found", yaml_input)
+                        logger.warning("%s could not be found", yaml_input)
 
                 elif isinstance(yaml_input, dict):
                     self.cmds.update(yaml_input)
@@ -232,7 +233,7 @@
                     if mode in self.modes_dict:
                         defyam["properties"]["modes"].append(mode)
                         if "deprecate" in self.modes_dict[mode]:
-                            logging.warning(self.modes_dict[mode]["deprecate"])
+                            logger.warning(self.modes_dict[mode]["deprecate"])
                     else:
                         raise ValueError(f"mode '{mode}' was not recognised")
 
@@ -362,7 +363,7 @@
         if not pkg_dir.exists():
             # todo: keep here, but add test for this by downloading test_package
             # raise ValueError("Package could not be found: {}".format(pkg_dir))
-            logging.warning("Package could not be found: %s", pkg_dir)
+            logger.warning("Package could not be found: %s", pkg_dir)
 
         rc.__search_path__.append_first(pkg_dir)
 

scopesim/defaults.yaml

@@ -57,7 +57,7 @@ properties :
     file_path: ".scopesim.log"
     file_open_mode: "w"   # w - overwrite, a - append
     file_level:    "DEBUG"      # DEBUG INFO WARNING ERROR CRITICAL
-    console_level: "WARNING"    # DEBUG INFO WARNING ERROR CRITICAL
+    console_level: "INFO"       # DEBUG INFO WARNING ERROR CRITICAL
 
   tests :
     # overridden in tests/__init__.py

scopesim/detector/detector.py

@@ -1,14 +1,16 @@
-import logging
 import numpy as np
 
 from ..base_classes import ImagePlaneBase, DetectorBase
 from ..optics import image_plane_utils as imp_utils
-from .. import utils
+from ..utils import get_logger, from_currsys, stringify_dict
 
 from astropy.io import fits
 from astropy.wcs import WCS
 
 
+logger = get_logger(__name__)
+
+
 class Detector(DetectorBase):
     def __init__(self, header, **kwargs):
         image = np.zeros((header["NAXIS2"], header["NAXIS1"]))
@@ -33,13 +35,13 @@ def reset(self):
 
     @property
     def hdu(self):
-        new_meta = utils.stringify_dict(self.meta)
+        new_meta = stringify_dict(self.meta)
         self._hdu.header.update(new_meta)
 
-        pixel_scale = utils.from_currsys("!INST.pixel_scale")
-        plate_scale = utils.from_currsys("!INST.plate_scale")
+        pixel_scale = from_currsys("!INST.pixel_scale")
+        plate_scale = from_currsys("!INST.plate_scale")
         if pixel_scale == 0 or plate_scale == 0:
-            logging.warning("Could not create sky WCS.")
+            logger.warning("Could not create sky WCS.")
         else:
             sky_wcs, _ = imp_utils.sky_wcs_from_det_wcs(
                 WCS(self._hdu.header, key="D"), pixel_scale, plate_scale)

scopesim/detector/detector_array.py

@@ -1,13 +1,13 @@
 # -*- coding: utf-8 -*-
 """Contains DetectorArray and aux functions."""
 
-import logging
-
 from astropy.io import fits
 
 from .detector import Detector
+from ..utils import stringify_dict, get_logger
+
 
-from .. import utils
+logger = get_logger(__name__)
 
 
 class DetectorArray:
@@ -86,7 +86,7 @@ def readout(self, image_planes, array_effects=None, dtcr_effects=None,
                           for hdr in self._detector_list.detector_headers()]
 
         # 4. iterate through all Detectors, extract image from image_plane
-        logging.info("Extracting from %d detectors...", len(self.detectors))
+        logger.info("Extracting from %d detectors...", len(self.detectors))
         for detector in self.detectors:
             detector.extract_from(image_plane)
 
@@ -133,7 +133,7 @@ def _repr_pretty_(self, p, cycle):
 def make_primary_hdu(meta):
     """Create the primary header from meta data."""
     prihdu = fits.PrimaryHDU()
-    prihdu.header.update(utils.stringify_dict(meta))
+    prihdu.header.update(stringify_dict(meta))
     return prihdu
 
 

scopesim/effects/apertures.py

@@ -1,7 +1,5 @@
 """Effects related to field masks, including spectroscopic slits."""
 
-from pathlib import Path
-import logging
 import yaml
 
 import numpy as np
@@ -14,8 +12,11 @@
 from ..optics import image_plane_utils as imp_utils
 from ..base_classes import FOVSetupBase
 
-from ..utils import quantify, quantity_from_table, from_currsys, check_keys, \
-    figure_factory
+from ..utils import (quantify, quantity_from_table, from_currsys, check_keys,
+                     figure_factory, get_logger)
+
+
+logger = get_logger(__name__)
 
 
 class ApertureMask(Effect):
@@ -126,7 +127,7 @@ def apply_to(self, obj, **kwargs):
     # Outdated. Remove when removing all old FOVManager code from effects
     def fov_grid(self, which="edges", **kwargs):
         """Return a header with the sky coordinates."""
-        logging.warning("DetectorList.fov_grid will be depreciated in v1.0")
+        logger.warning("DetectorList.fov_grid will be depreciated in v1.0")
         if which == "edges":
             self.meta.update(kwargs)
             return self.header

scopesim/effects/detector_list.py

@@ -1,17 +1,17 @@
 """TBA."""
 
-import logging
-
 import numpy as np
 from astropy import units as u
 from astropy.table import Table
 
 from ..base_classes import FOVSetupBase
 from .effects import Effect
 from .apertures import ApertureMask
-from .. import utils
-from ..utils import close_loop, figure_factory
 from ..optics.image_plane_utils import header_from_list_of_xy, calc_footprint
+from ..utils import (from_currsys, close_loop, figure_factory,
+                     quantity_from_table, unit_from_table, get_logger)
+
+logger = get_logger(__name__)
 
 __all__ = ["DetectorList", "DetectorWindow"]
 
@@ -141,7 +141,7 @@ def apply_to(self, obj, **kwargs):
             xy_mm = calc_footprint(hdr, "D")
             pixel_size = hdr["CDELT1D"]              # mm
             pixel_scale = kwargs.get("pixel_scale", self.meta["pixel_scale"])   # ["]
-            pixel_scale = utils.from_currsys(pixel_scale)
+            pixel_scale = from_currsys(pixel_scale)
 
             # x["] = x[mm] * ["] / [mm]
             xy_sky = xy_mm * pixel_scale / pixel_size
@@ -158,11 +158,11 @@ def apply_to(self, obj, **kwargs):
 
     def fov_grid(self, which="edges", **kwargs):
         """Return an ApertureMask object. kwargs are "pixel_scale" [arcsec]."""
-        logging.warning("DetectorList.fov_grid will be depreciated in v1.0")
+        logger.warning("DetectorList.fov_grid will be depreciated in v1.0")
         aperture_mask = None
         if which == "edges":
             self.meta.update(kwargs)
-            self.meta = utils.from_currsys(self.meta)
+            self.meta = from_currsys(self.meta)
 
             hdr = self.image_plane_header
             xy_mm = calc_footprint(hdr, "D")
@@ -181,9 +181,9 @@ def fov_grid(self, which="edges", **kwargs):
     @property
     def image_plane_header(self):
         tbl = self.active_table
-        pixel_size = np.min(utils.quantity_from_table("pixel_size", tbl, u.mm))
-        x_unit = utils.unit_from_table("x_size", tbl, u.mm)
-        y_unit = utils.unit_from_table("y_size", tbl, u.mm)
+        pixel_size = np.min(quantity_from_table("pixel_size", tbl, u.mm))
+        x_unit = unit_from_table("x_size", tbl, u.mm)
+        y_unit = unit_from_table("y_size", tbl, u.mm)
 
         xcen = tbl["x_cen"].data.astype(float)
         ycen = tbl["y_cen"].data.astype(float)
@@ -221,15 +221,15 @@ def active_table(self):
         else:
             raise ValueError("Could not determine which detectors are active: "
                              f"{self.meta['active_detectors']}, {self.table},")
-        tbl = utils.from_currsys(tbl)
+        tbl = from_currsys(tbl)
 
         return tbl
 
     def detector_headers(self, ids=None):
         if ids is not None and all(isinstance(ii, int) for ii in ids):
             self.meta["active_detectors"] = list(ids)
 
-        tbl = utils.from_currsys(self.active_table)
+        tbl = from_currsys(self.active_table)
         hdrs = []
         for row in tbl:
             pixel_size = row["pixel_size"]