diff --git a/CHANGES.md b/CHANGES.md index 09c46120..be70cc06 100644 --- a/CHANGES.md +++ b/CHANGES.md @@ -1,6 +1,9 @@ -1.10.1 (2023-05-31) +1.11.0 (2023-08-10) ------------------- - Updated the logging scheme + +1.10.1 (2023-05-31) +------------------- - We now silently fix fits errors that can be repaired automatically 1.10.0 (2023-02-15) diff --git a/banzai/__init__.py b/banzai/__init__.py index e49042e9..d6077d4f 100755 --- a/banzai/__init__.py +++ b/banzai/__init__.py @@ -3,33 +3,10 @@ # Packages may add whatever they like to this file, but # should keep this content at the top. # ---------------------------------------------------------------------------- -from ._astropy_init import * -from banzai.logs import BanzaiLogger -from lcogt_logging import LCOGTFormatter -import logging - +from ._astropy_init import * # noqa +import banzai.logs # noqa: F401 # ---------------------------------------------------------------------------- -# Uncomment to enforce Python version check during package import. -# This is the same check as the one at the top of setup.py -import sys -#class UnsupportedPythonError(Exception): -# pass -#__minimum_python_version__ = '3.5' -#if sys.version_info < tuple((int(val) for val in __minimum_python_version__.split('.'))): -# raise UnsupportedPythonError("{} does not support Python < {}".format(__package__, __minimum_python_version__)) - -if not _ASTROPY_SETUP_: +if not _ASTROPY_SETUP_: # noqa from banzai import utils __all__ = ['utils'] - -logging.setLoggerClass(BanzaiLogger) -logging.captureWarnings(True) -logger = logging.getLogger('banzai') - -handler = logging.StreamHandler(stream=sys.stdout) -handler.setFormatter(LCOGTFormatter()) -logger.addHandler(handler) - -# Default the logger to INFO so that we actually get messages by default. -logger.setLevel('INFO') diff --git a/banzai/astrometry.py b/banzai/astrometry.py index 4b520ac7..b57434a5 100755 --- a/banzai/astrometry.py +++ b/banzai/astrometry.py @@ -1,4 +1,3 @@ -import logging import requests from requests import ConnectionError, HTTPError @@ -8,8 +7,9 @@ import numpy as np from banzai.stages import Stage +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() SOURCE_LIMIT = 50 FAILED_WCS = (4, 'Error status of WCS fit. 0 for no error') diff --git a/banzai/bias.py b/banzai/bias.py index 0d9a7a93..19429727 100755 --- a/banzai/bias.py +++ b/banzai/bias.py @@ -1,11 +1,11 @@ -import logging import numpy as np from banzai.calibrations import CalibrationStacker, CalibrationUser, CalibrationComparer from banzai.stages import Stage from banzai.utils import stats +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class BiasMaker(CalibrationStacker): diff --git a/banzai/bpm.py b/banzai/bpm.py index ff3fc3ab..473f3354 100644 --- a/banzai/bpm.py +++ b/banzai/bpm.py @@ -1,11 +1,10 @@ -import logging import numpy as np from banzai.calibrations import CalibrationUser from banzai.stages import Stage -from banzai.logs import format_exception +from banzai.logs import format_exception, get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class BadPixelMaskLoader(CalibrationUser): diff --git a/banzai/calibrations.py b/banzai/calibrations.py index 20c83664..97105e0f 100644 --- a/banzai/calibrations.py +++ b/banzai/calibrations.py @@ -1,4 +1,3 @@ -import logging import abc from datetime import datetime @@ -8,7 +7,7 @@ from banzai.data import stack from banzai.utils.image_utils import Section -logger = logging.getLogger('banzai') +logger = logs.get_logger() class CalibrationMaker(Stage): diff --git a/banzai/celery.py b/banzai/celery.py index e28c4294..c960af9a 100644 --- a/banzai/celery.py +++ b/banzai/celery.py @@ -1,5 +1,4 @@ import os -import logging from datetime import datetime, timedelta from dateutil.parser import parse @@ -14,16 +13,14 @@ from banzai.utils.date_utils import get_stacking_date_range -logger = logging.getLogger('banzai') +logger = logs.get_logger() RETRY_DELAY = int(os.getenv('RETRY_DELAY', 600)) -# Celery sets up a logger on its own, which messes up the LCOGTFormatter that I want to use. -# Using this disables celery's logging setup. -@setup_logging.connect -def setup_celery_logging(**kwargs): - pass +# Celery sets up a logger on its own, which messes up the LCOGTFormatter that I want to use. Celery logging in general +# is a nightmare. I read this as a reference: +# https://distributedpython.com/posts/three-ideas-to-customise-celery-logging-handlers/ @worker_process_init.connect @@ -36,7 +33,8 @@ def configure_workers(**kwargs): app = Celery('banzai') app.config_from_object('banzai.celeryconfig') -app.conf.update(broker_url=os.getenv('TASK_HOST', 'redis://localhost:6379/0')) +app.conf.update(broker_url=os.getenv('TASK_HOST', 'redis://localhost:6379/0'), + worker_hijack_root_logger=False) celery_task_queue_name = os.getenv('CELERY_TASK_QUEUE_NAME', 'celery') # Set up custom named celery task queue @@ -51,10 +49,8 @@ def configure_workers(**kwargs): # Increase broker timeout to avoid re-scheduling tasks that aren't completed within an hour app.conf.broker_transport_options = {'visibility_timeout': 86400} -logs.set_log_level(os.getenv('BANZAI_WORKER_LOGLEVEL', 'INFO')) -# Calling setup() uses setup_celery_logging. Use redirect to get more celery logs to our logger. app.log.setup() -app.log.redirect_stdouts_to_logger(logger, 'INFO') +logs.set_log_level(os.getenv('BANZAI_WORKER_LOGLEVEL', 'INFO')) @app.task(name='celery.schedule_calibration_stacking', reject_on_worker_lost=True, max_retries=5) diff --git a/banzai/cosmic.py b/banzai/cosmic.py index a7e5a539..0b710608 100644 --- a/banzai/cosmic.py +++ b/banzai/cosmic.py @@ -1,8 +1,8 @@ -import logging from banzai.stages import Stage from cosmic_conn import init_model +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() # initialize a Cosmic-CoNN model cr_model = init_model("ground_imaging") diff --git a/banzai/crosstalk.py b/banzai/crosstalk.py index aae84f6a..86346f70 100644 --- a/banzai/crosstalk.py +++ b/banzai/crosstalk.py @@ -1,10 +1,9 @@ -import logging - import numpy as np from banzai.stages import Stage +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class CrosstalkCorrector(Stage): diff --git a/banzai/dark.py b/banzai/dark.py index dbd18469..f053e8ef 100755 --- a/banzai/dark.py +++ b/banzai/dark.py @@ -1,12 +1,11 @@ -import logging - -import numpy as np - from banzai.stages import Stage from banzai.calibrations import CalibrationStacker, CalibrationUser, CalibrationComparer from banzai.utils import qc +from banzai.logs import get_logger +import numpy as np + -logger = logging.getLogger('banzai') +logger = get_logger() class DarkNormalizer(Stage): diff --git a/banzai/data.py b/banzai/data.py index 340ed8b3..901a72a0 100644 --- a/banzai/data.py +++ b/banzai/data.py @@ -189,7 +189,7 @@ def __isub__(self, value): def __sub__(self, other): uncertainty = np.sqrt(self.uncertainty * self.uncertainty + other.uncertainty * other.uncertainty) - return type(self)(data=self.data - other.data, meta=self.meta, mask=self.mask|other.mask, + return type(self)(data=self.data - other.data, meta=self.meta, mask=self.mask | other.mask, uncertainty=uncertainty) def add_uncertainty(self, readnoise: np.array): diff --git a/banzai/dbs.py b/banzai/dbs.py index 93fde9e2..02e1e113 100755 --- a/banzai/dbs.py +++ b/banzai/dbs.py @@ -8,7 +8,6 @@ October 2015 """ import os.path -import logging import datetime from dateutil.parser import parse import numpy as np @@ -19,10 +18,11 @@ from sqlalchemy.ext.declarative import declarative_base from sqlalchemy.sql.expression import true from contextlib import contextmanager +from banzai.logs import get_logger Base = declarative_base() -logger = logging.getLogger('banzai') +logger = get_logger() @contextmanager diff --git a/banzai/flats.py b/banzai/flats.py index 354240e3..5a6a3cb3 100755 --- a/banzai/flats.py +++ b/banzai/flats.py @@ -1,14 +1,12 @@ import os.path -import logging import numpy as np - from banzai.utils import stats from banzai.stages import Stage from banzai.calibrations import CalibrationStacker, CalibrationUser, CalibrationComparer -import numpy as np +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class FlatSNRChecker(Stage): diff --git a/banzai/frames.py b/banzai/frames.py index e6ba703f..093a5734 100644 --- a/banzai/frames.py +++ b/banzai/frames.py @@ -1,4 +1,3 @@ -import logging from banzai import dbs from banzai.data import HeaderOnly, CCDData from banzai.utils import fits_utils, file_utils @@ -7,8 +6,9 @@ import abc import os from typing import Optional +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class ObservationFrame(metaclass=abc.ABCMeta): diff --git a/banzai/gain.py b/banzai/gain.py index e7a3a361..c73bcc5e 100644 --- a/banzai/gain.py +++ b/banzai/gain.py @@ -1,8 +1,7 @@ -import logging - +from banzai.logs import get_logger from banzai.stages import Stage -logger = logging.getLogger('banzai') +logger = get_logger() class GainNormalizer(Stage): diff --git a/banzai/lco.py b/banzai/lco.py index a769000c..8eb7fb78 100644 --- a/banzai/lco.py +++ b/banzai/lco.py @@ -2,7 +2,6 @@ import os from fnmatch import fnmatch from typing import Optional -from io import BytesIO import numpy as np from astropy.io import fits @@ -222,7 +221,8 @@ def init_master_header(old_header, images): mean_dateobs = date_utils.mean_date(observation_dates) header['DATE-OBS'] = (date_utils.date_obs_to_string(mean_dateobs), '[UTC] Mean observation start time') - header['DAY-OBS'] = (max(images, key=lambda x: datetime.datetime.strptime(x.epoch, '%Y%m%d')).epoch, '[UTC] Date at start of local observing night') + header['DAY-OBS'] = (max(images, key=lambda x: datetime.datetime.strptime(x.epoch, '%Y%m%d')).epoch, + '[UTC] Date at start of local observing night') header['ISMASTER'] = (True, 'Is this a master calibration frame') header.add_history("Images combined to create master calibration image:") @@ -435,13 +435,13 @@ def open(self, file_info, runtime_context) -> Optional[ObservationFrame]: for extension_name_to_condense in runtime_context.EXTENSION_NAMES_TO_CONDENSE: condensed_name = condensed_name.replace(extension_name_to_condense, '') for associated_extension in self.associated_extensions: - associated_fits_extension_name = condensed_name + associated_extension['FITS_NAME'] - if associated_fits_extension_name in fits_hdu_list: + associated_extension_name = condensed_name + associated_extension['FITS_NAME'] + if associated_extension_name in fits_hdu_list: if hdu.header.get('EXTVER') == 0: extension_version = None else: extension_version = hdu.header.get('EXTVER') - associated_data[associated_extension['NAME']] = fits_hdu_list[associated_fits_extension_name, + associated_data[associated_extension['NAME']] = fits_hdu_list[associated_extension_name, extension_version].data else: associated_data[associated_extension['NAME']] = None @@ -561,10 +561,12 @@ def _init_detector_sections(image): if hdu.meta.get('DETSEC', 'UNKNOWN') in ['UNKNOWN', 'N/A']: # DETSEC missing? binning = hdu.meta.get('CCDSUM', image.primary_hdu.meta.get('CCDSUM', '1 1')) + x_binning = int(binning[0]) + y_binning = int(binning[2]) if hdu.data_section is not None: # use binning from FITS header, bin_x is index 0, bin_y is index 2. - detector_section = Section(1, max(hdu.data_section.x_start, hdu.data_section.x_stop) * int(binning[0]), - 1, max(hdu.data_section.y_start, hdu.data_section.y_stop) * int(binning[2])) + detector_section = Section(1, max(hdu.data_section.x_start, hdu.data_section.x_stop) * x_binning, + 1, max(hdu.data_section.y_start, hdu.data_section.y_stop) * y_binning) hdu.detector_section = detector_section else: logger.warning("Data and detector sections are both undefined for image.", image=image) diff --git a/banzai/logs.py b/banzai/logs.py index 091383c2..dcd593e7 100755 --- a/banzai/logs.py +++ b/banzai/logs.py @@ -3,17 +3,23 @@ import traceback import sys import multiprocessing +from lcogt_logging import LCOGTFormatter from banzai.utils import date_utils +logging.captureWarnings(True) +logging.basicConfig() +logger = logging.getLogger() +logger.handlers[0].setFormatter(LCOGTFormatter()) -class BanzaiLogger(logging.getLoggerClass()): - def __init__(self, name, level='NOTSET'): - super(BanzaiLogger, self).__init__(name, level) +# Default the logger to INFO so that we actually get messages by default. +logger.setLevel('INFO') - def _log(self, level, msg, *args, **kwargs): + +class BanzaiLogger(logging.LoggerAdapter): + def process(self, msg, kwargs): kwargs = _create_logging_tags_dictionary(kwargs) - super(BanzaiLogger, self)._log(level, msg, *args, **kwargs) + return msg, kwargs def _create_logging_tags_dictionary(kwargs): @@ -47,10 +53,13 @@ def _image_to_tags(image): def set_log_level(log_level='INFO'): - root_logger = logging.getLogger('banzai') - root_logger.setLevel(log_level.upper()) + logger.setLevel(log_level.upper()) def format_exception(): exc_type, exc_value, exc_tb = sys.exc_info() return traceback.format_exception(exc_type, exc_value, exc_tb) + + +def get_logger(): + return BanzaiLogger(logging.getLogger('banzai'), extra=None) diff --git a/banzai/main.py b/banzai/main.py index 90fdbd1f..4f2dfa5a 100755 --- a/banzai/main.py +++ b/banzai/main.py @@ -8,8 +8,8 @@ October 2015 """ import argparse -import logging import os.path +import logging from kombu import Exchange, Connection, Queue from kombu.mixins import ConsumerMixin @@ -26,7 +26,7 @@ import celery.bin.beat import requests -logger = logging.getLogger('banzai') +logger = logs.get_logger() class RealtimeModeListener(ConsumerMixin): @@ -95,7 +95,8 @@ def parse_args(settings, extra_console_arguments=None, parser_description='Proce parser.add_argument('--no-bpm', dest='no_bpm', default=False, action='store_true', help='Do not use a bad pixel mask to reduce data (BPM contains all zeros)') parser.add_argument('--use-only-older-calibrations', dest='use_only_older_calibrations', default=False, - action='store_true', help='Only use calibrations that were created before the start of the block') + action='store_true', + help='Only use calibrations that were created before the start of the block') parser.add_argument('--preview-mode', dest='preview_mode', default=False, action='store_true', help='Save the reductions to the preview directory') parser.add_argument('--max-tries', dest='max_tries', default=5, @@ -185,7 +186,7 @@ def run_realtime_pipeline(): def start_listener(runtime_context): # Need to keep the amqp logger level at least as high as INFO, # or else it send heartbeat check messages every second - logging.getLogger('amqp').setLevel(max(logger.level, getattr(logging, 'INFO'))) + logging.getLogger('amqp').setLevel(max(logging.getLogger().level, getattr(logging, 'INFO'))) logger.info('Starting pipeline listener') fits_exchange = Exchange(runtime_context.FITS_EXCHANGE, type='fanout') @@ -301,7 +302,8 @@ def add_super_calibration(): try: cal_image = frame_factory.open({'path': args.filepath}, args) except Exception: - logger.error(f"Calibration file not able to be opened by BANZAI. Aborting... {logs.format_exception()}", extra_tags={'filename': args.filepath}) + logger.error(f"Calibration file not able to be opened by BANZAI. Aborting... {logs.format_exception()}", + extra_tags={'filename': args.filepath}) cal_image = None # upload calibration file via ingester @@ -310,7 +312,8 @@ def add_super_calibration(): logger.debug("Posting calibration file to s3 archive") ingester_response = file_utils.post_to_ingester(f, cal_image, args.filepath) - logger.debug("File posted to s3 archive. Saving to database.", extra_tags={'frameid': ingester_response['frameid']}) + logger.debug("File posted to s3 archive. Saving to database.", + extra_tags={'frameid': ingester_response['frameid']}) cal_image.frame_id = ingester_response['frameid'] cal_image.is_bad = False cal_image.is_master = True @@ -345,7 +348,8 @@ def add_bpms_from_archive(): filepath=None)), args.db_address) except Exception: - logger.error(f"BPM not added to database: {logs.format_exception()}", extra_tags={'filename': frame.get('filename')}) + logger.error(f"BPM not added to database: {logs.format_exception()}", + extra_tags={'filename': frame.get('filename')}) def create_db(): diff --git a/banzai/mosaic.py b/banzai/mosaic.py index c4b0a962..253ed7e9 100644 --- a/banzai/mosaic.py +++ b/banzai/mosaic.py @@ -1,11 +1,11 @@ -import logging import numpy as np from banzai.stages import Stage from banzai.utils.image_utils import Section from banzai.data import CCDData +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class MosaicCreator(Stage): diff --git a/banzai/photometry.py b/banzai/photometry.py index c89f0491..afb4eaec 100755 --- a/banzai/photometry.py +++ b/banzai/photometry.py @@ -1,4 +1,3 @@ -import logging from urllib.parse import urljoin import numpy as np @@ -14,7 +13,7 @@ from skimage import measure -logger = logging.getLogger('banzai') +logger = logs.get_logger() sep.set_sub_object_limit(int(1e6)) diff --git a/banzai/qc/__init__.py b/banzai/qc/__init__.py index 1d1b3661..184864bc 100644 --- a/banzai/qc/__init__.py +++ b/banzai/qc/__init__.py @@ -2,7 +2,9 @@ from banzai.qc.pointing import PointingTest from banzai.qc.sinistro_1000s import ThousandsTest from banzai.qc.pattern_noise import PatternNoiseDetector -from banzai.qc.header_checker import HeaderSanity +from banzai.qc.header_checker import HeaderChecker -__all__ = ['SaturationTest', 'PointingTest', 'ThousandsTest', - 'PatternNoiseDetector', 'HeaderSanity'] +__all__ = [ + 'SaturationTest', 'PointingTest', 'ThousandsTest', 'PatternNoiseDetector', + 'HeaderChecker' +] diff --git a/banzai/qc/header_checker.py b/banzai/qc/header_checker.py index 16470a39..3f14be6a 100644 --- a/banzai/qc/header_checker.py +++ b/banzai/qc/header_checker.py @@ -3,15 +3,13 @@ format and validates their values. @author:ebachelet """ -import logging from banzai.stages import Stage from banzai.utils import qc +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() -class HeaderSanity: - pass class HeaderChecker(Stage): """ diff --git a/banzai/qc/pattern_noise.py b/banzai/qc/pattern_noise.py index 37f3059f..03e2c972 100644 --- a/banzai/qc/pattern_noise.py +++ b/banzai/qc/pattern_noise.py @@ -1,5 +1,3 @@ -import logging - import numpy as np from scipy.ndimage.filters import median_filter from itertools import groupby @@ -8,8 +6,9 @@ from banzai.stages import Stage from banzai.utils import qc from banzai.utils.stats import robust_standard_deviation +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class PatternNoiseDetector(Stage): diff --git a/banzai/qc/pointing.py b/banzai/qc/pointing.py index 727cdcf0..d6eaa25a 100644 --- a/banzai/qc/pointing.py +++ b/banzai/qc/pointing.py @@ -1,12 +1,11 @@ -import logging - import astropy.units as u from astropy.coordinates import SkyCoord from banzai.stages import Stage from banzai.utils import qc +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class PointingTest(Stage): diff --git a/banzai/qc/saturation.py b/banzai/qc/saturation.py index 23b30f4a..223d2c05 100644 --- a/banzai/qc/saturation.py +++ b/banzai/qc/saturation.py @@ -1,10 +1,8 @@ -import logging - from banzai.stages import Stage from banzai.utils import qc +from banzai.logs import get_logger -logger = logging.getLogger('banzai') - +logger = get_logger() class SaturationTest(Stage): """ diff --git a/banzai/qc/sinistro_1000s.py b/banzai/qc/sinistro_1000s.py index 856c91bd..2e5e8201 100644 --- a/banzai/qc/sinistro_1000s.py +++ b/banzai/qc/sinistro_1000s.py @@ -1,11 +1,10 @@ -import logging - import numpy as np from banzai.stages import Stage from banzai.utils import qc +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class ThousandsTest(Stage): diff --git a/banzai/readnoise.py b/banzai/readnoise.py index 20c51ace..ba11ab69 100644 --- a/banzai/readnoise.py +++ b/banzai/readnoise.py @@ -1,9 +1,7 @@ -import logging - from banzai.calibrations import CalibrationUser -from banzai.logs import format_exception +from banzai.logs import format_exception, get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class ReadNoiseLoader(CalibrationUser): diff --git a/banzai/stages.py b/banzai/stages.py index ee774205..fe8aff1d 100755 --- a/banzai/stages.py +++ b/banzai/stages.py @@ -1,4 +1,3 @@ -import logging import abc import itertools from collections.abc import Iterable @@ -6,7 +5,7 @@ from banzai import logs from banzai.frames import ObservationFrame -logger = logging.getLogger('banzai') +logger = logs.get_logger() class Stage(abc.ABC): diff --git a/banzai/tests/test_end_to_end.py b/banzai/tests/test_end_to_end.py index fd223560..33357930 100644 --- a/banzai/tests/test_end_to_end.py +++ b/banzai/tests/test_end_to_end.py @@ -19,13 +19,12 @@ from banzai.tests.utils import FakeResponse, get_min_and_max_dates, FakeContext from astropy.io import fits import pkg_resources - -import logging +from banzai.logs import get_logger # TODO: Mock out AWS calls here # TODO: Mock out archived fits queue structure as well -logger = logging.getLogger('banzai') +logger = get_logger() app.conf.update(CELERY_TASK_ALWAYS_EAGER=True) diff --git a/banzai/tests/test_header_checker.py b/banzai/tests/test_header_checker.py index bc5a40de..d5155df5 100644 --- a/banzai/tests/test_header_checker.py +++ b/banzai/tests/test_header_checker.py @@ -1,11 +1,10 @@ -import logging -import mock import pytest from banzai.tests.utils import FakeLCOObservationFrame, FakeContext from banzai.qc.header_checker import HeaderChecker +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() pytestmark = pytest.mark.header_checker @@ -53,61 +52,53 @@ def test_one_keyword_missing_and_one_na(): assert set(bad_keywords) == set(tester.expected_header_keywords[0:2]) -def test_ra_outside_range(): - logger.error = mock.MagicMock() +def test_ra_outside_range(caplog): tester = HeaderChecker(FakeContext()) tester.check_ra_range(FakeHeaderImage({'CRVAL1': 360.1})) - assert logger.error.called + assert any(record.levelname == 'ERROR' for record in caplog.records) -def test_ra_within_range(): - logger.error = mock.MagicMock() +def test_ra_within_range(caplog): tester = HeaderChecker(FakeContext()) tester.check_ra_range(FakeHeaderImage({'CRVAL1': 359.9})) tester.check_ra_range(FakeHeaderImage({'CRVAL1': 0.1})) - assert not logger.error.called + assert not any(record.levelname == 'INFO' for record in caplog.records) -def test_dec_outside_range(): - logger.error = mock.MagicMock() +def test_dec_outside_range(caplog): tester = HeaderChecker(FakeContext()) tester.check_dec_range(FakeHeaderImage({'CRVAL2': -90.1})) - assert logger.error.called + assert any(record.levelname == 'ERROR' for record in caplog.records) -def test_dec_within_range(): - logger.error = mock.MagicMock() +def test_dec_within_range(caplog): tester = HeaderChecker(FakeContext()) tester.check_dec_range(FakeHeaderImage({'CRVAL2': -89.9})) tester.check_dec_range(FakeHeaderImage({'CRVAL2': 89.9})) tester.check_dec_range(FakeHeaderImage({'CRVAL2': 0.0})) - assert not logger.error.called + assert not any(record.levelname == 'ERROR' for record in caplog.records) -def test_null_exptime_value(): - logger.error = mock.MagicMock() +def test_null_exptime_value(caplog): tester = HeaderChecker(FakeContext()) tester.check_exptime_value(FakeHeaderImage({'EXPTIME': 0.0, 'OBSTYPE': 'test'})) - assert logger.error.called + assert any(record.levelname == 'ERROR' for record in caplog.records) -def test_negative_exptime_value(): - logger.error = mock.MagicMock() +def test_negative_exptime_value(caplog): tester = HeaderChecker(FakeContext()) tester.check_exptime_value(FakeHeaderImage({'EXPTIME': -0.1, 'OBSTYPE': 'test'})) - assert logger.error.called + assert any(record.levelname == 'ERROR' for record in caplog.records) -def test_null_or_negative_exptime_value_for_bias(): - logger.error = mock.MagicMock() +def test_null_or_negative_exptime_value_for_bias(caplog): tester = HeaderChecker(FakeContext()) tester.check_exptime_value(FakeHeaderImage({'EXPTIME': 0.0, 'OBSTYPE': 'BIAS'})) tester.check_exptime_value(FakeHeaderImage({'EXPTIME': -0.1, 'OBSTYPE': 'BIAS'})) - assert not logger.error.called + assert not any(record.levelname == 'ERROR' for record in caplog.records) -def test_postive_exptime_value(): - logger.error = mock.MagicMock() +def test_postive_exptime_value(caplog): tester = HeaderChecker(FakeContext()) tester.check_exptime_value(FakeHeaderImage({'EXPTIME': 0.1, 'OBSTYPE': 'test'})) - assert not logger.error.called + assert not any(record.levelname == 'ERROR' for record in caplog.records) diff --git a/banzai/tests/test_pattern_noise_qc.py b/banzai/tests/test_pattern_noise_qc.py index cb3b059e..3e1cc954 100644 --- a/banzai/tests/test_pattern_noise_qc.py +++ b/banzai/tests/test_pattern_noise_qc.py @@ -1,13 +1,11 @@ -import logging - import pytest -import mock import numpy as np from banzai.qc import pattern_noise from banzai.tests.utils import gaussian2d, FakeCCDData, FakeLCOObservationFrame +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() pytestmark = pytest.mark.pattern_noise_qc @@ -45,7 +43,7 @@ def test_pattern_noise_detects_noise_when_it_should(set_random_seed): def test_pattern_noise_does_not_detect_white_noise(set_random_seed): data = generate_data() detector = pattern_noise.PatternNoiseDetector(None) - assert detector.check_for_pattern_noise(data)[0] == False + assert not detector.check_for_pattern_noise(data)[0] def test_pattern_noise_does_not_detect_stars(set_random_seed): @@ -59,13 +57,12 @@ def test_pattern_noise_does_not_detect_stars(set_random_seed): assert detector.check_for_pattern_noise(data)[0] == False -def test_pattern_noise_on_2d_image(set_random_seed): +def test_pattern_noise_on_2d_image(set_random_seed, caplog): image = FakeLCOObservationFrame(hdu_list=[FakeCCDData(data=generate_data(has_pattern_noise=True))]) detector = pattern_noise.PatternNoiseDetector(None) - logger.error = mock.MagicMock() detector.do_stage(image) - assert logger.error.called + assert any(record.levelname == 'ERROR' for record in caplog.records) def test_trim_edges(): diff --git a/banzai/tests/utils.py b/banzai/tests/utils.py index 04995b81..faae200a 100644 --- a/banzai/tests/utils.py +++ b/banzai/tests/utils.py @@ -11,9 +11,9 @@ from banzai.utils.image_utils import Section from banzai.data import HeaderOnly, CCDData from banzai.utils.date_utils import TIMESTAMP_FORMAT -import logging +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() class FakeCCDData(CCDData): diff --git a/banzai/trim.py b/banzai/trim.py index 43335058..92513ea1 100755 --- a/banzai/trim.py +++ b/banzai/trim.py @@ -1,7 +1,7 @@ -import logging +from banzai.logs import get_logger from banzai.stages import Stage -logger = logging.getLogger('banzai') +logger = get_logger() class Trimmer(Stage): diff --git a/banzai/utils/db_migration.py b/banzai/utils/db_migration.py index 6628b229..b378824d 100644 --- a/banzai/utils/db_migration.py +++ b/banzai/utils/db_migration.py @@ -1,13 +1,12 @@ import argparse -import logging from sqlalchemy import create_engine from sqlalchemy import Column, Integer, String, Date, ForeignKey, Boolean, CHAR from sqlalchemy.ext.declarative import declarative_base -from banzai import dbs, logs, main +from banzai import dbs, logs -logger = logging.getLogger('banzai') +logger = logs.get_logger() Base = declarative_base() @@ -120,7 +119,7 @@ def migrate_db(): row['type'] = 'BPM' row['is_master'] = True row['attributes'] = {'ccdsum': row.pop('ccdsum')} - del(row['id']) + del row['id'] change_key_name(bpms, 'creation_date', 'dateobs') change_key_name(bpms, 'telescope_id', 'instrument_id') # BPMs have some duplicates, remove them @@ -140,7 +139,7 @@ def migrate_db(): for row in calibrations: row['is_master'] = True row['attributes'] = {'filter': row.pop('filter_name'), 'ccdsum': row.pop('ccdsum')} - del(row['id']) + del row['id'] change_key_name(calibrations, 'dayobs', 'dateobs') change_key_name(calibrations, 'telescope_id', 'instrument_id') logger.info("Adding {n} rows from the old CalibrationImage table to the new CalibrationImage table".format( diff --git a/banzai/utils/file_utils.py b/banzai/utils/file_utils.py index fb61f465..610a5196 100755 --- a/banzai/utils/file_utils.py +++ b/banzai/utils/file_utils.py @@ -1,5 +1,4 @@ import hashlib -import logging from time import sleep from ocs_ingester import ingester @@ -7,8 +6,9 @@ from kombu import Connection, Exchange from banzai.utils import import_utils +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() def post_to_archive_queue(image_path, broker_url, exchange_name='fits_files'): @@ -20,7 +20,7 @@ def post_to_archive_queue(image_path, broker_url, exchange_name='fits_files'): def post_to_ingester(file_object, image, output_filename, meta=None): - logger.info(f'Posting file to the archive', image=image) + logger.info('Posting file to the archive', image=image) retry = True try_counter = 1 ingester_response = {} diff --git a/banzai/utils/fits_utils.py b/banzai/utils/fits_utils.py index e69a4fca..9fba5a77 100755 --- a/banzai/utils/fits_utils.py +++ b/banzai/utils/fits_utils.py @@ -1,5 +1,4 @@ import datetime -import logging from typing import Optional import requests from collections.abc import Iterable @@ -15,7 +14,7 @@ import io import os -logger = logging.getLogger('banzai') +logger = logs.get_logger() FITS_MANDATORY_KEYWORDS = ['SIMPLE', 'BITPIX', 'NAXIS', 'EXTEND', 'COMMENT', 'CHECKSUM', 'DATASUM'] diff --git a/banzai/utils/image_utils.py b/banzai/utils/image_utils.py index d6ce5bd0..8a0c2f74 100644 --- a/banzai/utils/image_utils.py +++ b/banzai/utils/image_utils.py @@ -1,15 +1,14 @@ -import logging - +from banzai.logs import get_logger import numpy as np from banzai.utils.instrument_utils import instrument_passes_criteria -logger = logging.getLogger('banzai') +logger = get_logger() def get_reduction_level(header): - reduction_level = header.get('RLEVEL', '00') + reduction_level = header.get('RLEVEL', '00') # return a correctly-formatted RLEVEL string - 00 or 91 return '{:02d}'.format(int(reduction_level)) diff --git a/banzai/utils/observation_utils.py b/banzai/utils/observation_utils.py index 5a5442c0..6ca8c8e3 100644 --- a/banzai/utils/observation_utils.py +++ b/banzai/utils/observation_utils.py @@ -1,10 +1,9 @@ import requests -import logging import copy -from datetime import datetime from dateutil.parser import parse +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() def get_calibration_blocks_for_time_range(site, start_before, start_after, context): diff --git a/banzai/utils/qc.py b/banzai/utils/qc.py index a22f5fe9..0823ddac 100644 --- a/banzai/utils/qc.py +++ b/banzai/utils/qc.py @@ -1,11 +1,9 @@ -import logging - import numpy as np from opensearchpy import OpenSearch from banzai import logs -logger = logging.getLogger('banzai') +logger = logs.get_logger() def format_qc_results(qc_results, image): @@ -48,7 +46,8 @@ def save_qc_results(runtime_context, qc_results, image, **kwargs): opensearch_client = OpenSearch(runtime_context.opensearch_url, timeout=60) try: opensearch_output = opensearch_client.update(index=runtime_context.opensearch_qc_index, - id=filename, body={'doc': results_to_save, 'doc_as_upsert': True}, + id=filename, + body={'doc': results_to_save, 'doc_as_upsert': True}, retry_on_conflict=5, **kwargs) except Exception: error_message = 'Cannot update opensearch index to URL \"{url}\": {exception}' diff --git a/banzai/utils/realtime_utils.py b/banzai/utils/realtime_utils.py index 612a1498..9908f9dd 100644 --- a/banzai/utils/realtime_utils.py +++ b/banzai/utils/realtime_utils.py @@ -1,11 +1,10 @@ -import logging - import os from banzai import dbs from banzai.utils import file_utils, import_utils, image_utils from banzai.data import HeaderOnly from banzai import logs -logger = logging.getLogger('banzai') + +logger = logs.get_logger() def set_file_as_processed(path, db_address): @@ -85,7 +84,8 @@ def need_to_process_image(file_info, context): if 'frameid' in file_info: try: factory = import_utils.import_attribute(context.FRAME_FACTORY)() - test_image = factory.observation_frame_class(hdu_list=[HeaderOnly(file_info)], file_path=file_info['filename']) + test_image = factory.observation_frame_class(hdu_list=[HeaderOnly(file_info)], + file_path=file_info['filename']) test_image.instrument = factory.get_instrument_from_header(file_info, db_address=context.db_address) if image_utils.get_reduction_level(test_image.meta) != '00': logger.error('Image has nonzero reduction level. Aborting.', extra_tags={'filename': filename}) @@ -95,8 +95,8 @@ def need_to_process_image(file_info, context): extra_tags={'filename': filename}) need_to_process = False elif not image_utils.image_can_be_processed(test_image, context): - logger.error('The header in this queue message appears to not be complete enough to make a Frame object', - extra_tags={'filename': filename}) + msg = 'The header in this queue message appears to not be complete enough to make a Frame object' + logger.error(msg, extra_tags={'filename': filename}) need_to_process = False except Exception: logger.error('Issue creating Image object with given queue message', extra_tags={"filename": filename}) diff --git a/banzai/utils/stage_utils.py b/banzai/utils/stage_utils.py index 9b9aa428..5400c4ed 100644 --- a/banzai/utils/stage_utils.py +++ b/banzai/utils/stage_utils.py @@ -1,8 +1,8 @@ from banzai.utils import import_utils -import logging from banzai.context import Context +from banzai.logs import get_logger -logger = logging.getLogger('banzai') +logger = get_logger() def get_stages_for_individual_frame(ordered_stages, last_stage=None, extra_stages=None): @@ -56,7 +56,7 @@ def run_pipeline_stages(image_paths: list, runtime_context: Context, calibration stage = stage_constructor(runtime_context) images = stage.run(images) - if not images : + if not images: logger.error('Reduction stopped', extra_tags={'filename': image_paths}) return diff --git a/docs/index.rst b/docs/index.rst index ddbb830f..ac03b777 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -239,8 +239,8 @@ Quality Control --------------- -Header Sanity -============= +Header Checker +============== The header sanity test first checks if any of the following principal FITS header keywords are either missing or set to ``'N/A'``: ``RA``, ``DEC``, ``CAT-RA``, ``CAT-DEC``,