diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index cb5441398..74af76aa5 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -1,43 +1,111 @@ # Getting Started -If you are unsure about a possible contribution to the project contact the project owners about your idea. +If you are unsure about a possible contribution to the project contact the project owners about +your idea. -Please see the [code of conduct](https://github.com/panoptes/POCS/blob/develop/CODE_OF_CONDUCT.md) for our +Please see the [code of conduct](https://github.com/panoptes/POCS/blob/develop/CODE_OF_CONDUCT.md) +for our playground rules and follow them during all your contributions. # Pull Request Process * Pre-requisites - Ensure you have [github account](https://github.com/join) - - If the change you wish to make is not already an Issue in the project please create one specifying the need. + - If the change you wish to make is not already an Issue in the project please create one + specifying the need. * Process - Create a fork of the repository and use a topic branch within your fork to make changes. - - All of our repositories have a default branch of `develop` when you first clone them, but your work should be in a separate branch. + - All of our repositories have a default branch of `develop` when you first clone them, but + your work should be in a separate branch. - Create a branch with a descriptive name, e.g.: - `git checkout -b new-camera-simulator` - `git checkout -b issue-28` - Ensure that your code meets this project's standards (see Testing and Code Formatting below). - Run `python setup.py test` from the `$POCS` directory before pushing to github - Squash your commits so they only reflect meaningful changes. - - Submit a pull request to the repository, be sure to reference the issue number it addresses. + - Submit a pull request to the repository, be sure to reference the issue number it + addresses. # Setting up Local Environment - - Follow instructions on the [Coding in PANOPTES](https://github.com/panoptes/POCS/wiki/Coding-in-PANOPTES). + - Follow instructions in the [README](https://github.com/panoptes/POCS/blob/develop/README.md) + as well as the [Coding in PANOPTES](https://github.com/panoptes/POCS/wiki/Coding-in-PANOPTES) + document. # Testing - - All changes should have corresponding tests and existing tests should pass after your changes. - - For more on testing see the [Coding in PANOPTES](https://github.com/panoptes/POCS/wiki/Coding-in-PANOPTES) page. + - All changes should have corresponding tests and existing tests should pass after + your changes. + - For more on testing see the + [Coding in PANOPTES](https://github.com/panoptes/POCS/wiki/Coding-in-PANOPTES) page. # Code Formatting - All Python should use [PEP 8 Standards](https://www.python.org/dev/peps/pep-0008/) - - Use a tool such as [yapf](https://github.com/google/yapf) to format your - files; we'd rather spend time developing PANOPTES and not arguing about - style. + - Line length is set at 100 characters instead of 80. + - It is recommended to have your editor auto-format code whenever you save a file + rather than attempt to go back and change an entire file all at once. - Do not leave in commented-out code or unnecessary whitespace. -- Variable/function/class and file names should be meaningful and descriptive -- File names should be lower case and underscored, not contain spaces. For - example, `my_file.py` instead of `My File.py` -- Define any project specific terminology or abbreviations you use in the file you use them +- Variable/function/class and file names should be meaningful and descriptive. +- File names should be lower case and underscored, not contain spaces. For example, `my_file.py` +instead of `My File.py`. +- Define any project specific terminology or abbreviations you use in the file you use them. + +# Log Messages + +Use appropriate logging: +- Log level: + - DEBUG (i.e. `self.logger.debug()`) should attempt to capture all run-time + information. + - INFO (i.e. `self.logger.info()`) should be used sparingly and meant to convey + information to a person actively watching a running unit. + - WARNING (i.e. `self.logger.warning()`) should alert when something does not + go as expected but operation of unit can continue. + - ERROR (i.e. `self.logger.error()`) should be used at critical levels when + operation cannot continue. +- The logger supports variable information without the use of the `format` method. +- There is a `say` method available on the main `POCS` class that is meant to be +used in friendly manner to convey information to a user. This should be used only +for personable output and is typically displayed in the "chat box"of the PAWS +website. These messages are also sent to the INFO level logger. + +#### Logging examples: + +_Note: These are meant to illustrate the logging calls and are not necessarily indicative of real +operation_ + +``` +self.logger.info("PANOPTES unit initialized: {}", self.config['name']) + +self.say("I'm all ready to go, first checking the weather") + +self.logger.debug("Setting up weather station") + +self.logger.warning('Problem getting wind safety: {}'.format(e)) + +self.logger.debug("Rain: {} Clouds: {} Dark: {} Temp: {:.02f}", + is_raining, + is_cloudy, + is_dark, + temp_celsius +) + +self.logger.error('Unable to connect to AAG Cloud Sensor, cannot continue') +``` + +#### Viewing log files + +- You typically want to follow an active log file by using `tail -f` on the command line. +- The [`grc`](https://github.com/garabik/grc) (generic colouriser) can be used with +`tail` to get pretty log files. + +``` +(panoptes-env) $ grc tail -f $PANDIR/logs/pocs_shell.log +``` + +The following screenshot shows commands entered into a `jupyter-console` in the top +panel and the log file in the bottom panel. + +

+ +

\ No newline at end of file diff --git a/Changelog.md b/Changelog.md index 1c6c4dd6b..d08f89b98 100644 --- a/Changelog.md +++ b/Changelog.md @@ -1,6 +1,8 @@ ## [Unreleased] +======= ### Added - Merge PACE into POCS +- Logs: separate files for each level and new naming scheme ## [0.5.1] - 2017-12-02 ### Added diff --git a/conf_files/log.yaml b/conf_files/log.yaml index 1d6e8f6d5..0ac0bff80 100644 --- a/conf_files/log.yaml +++ b/conf_files/log.yaml @@ -13,9 +13,15 @@ logger: all: handlers: [all] propagate: true + info: + handlers: [info] + propagate: true warn: handlers: [warn] propagate: true + error: + handlers: [error] + propagate: true handlers: all: @@ -24,12 +30,24 @@ logger: formatter: detail when: W6 backupCount: 4 + info: + class: logging.handlers.TimedRotatingFileHandler + level: INFO + formatter: detail + when: W6 + backupCount: 4 warn: class: logging.handlers.TimedRotatingFileHandler level: WARNING formatter: detail when: W6 backupCount: 4 + error: + class: logging.handlers.TimedRotatingFileHandler + level: ERROR + formatter: detail + when: W6 + backupCount: 4 root: level: DEBUG diff --git a/pocs/core.py b/pocs/core.py index 8a169281c..693b1868d 100644 --- a/pocs/core.py +++ b/pocs/core.py @@ -25,7 +25,8 @@ class POCS(PanStateMachine, PanBase): the `get_ready()` method the transition that is responsible for moving to the initial state. Args: - state_machine_file(str): Filename of the state machine to use, defaults to 'simple_state_table' + state_machine_file(str): Filename of the state machine to use, defaults to + 'simple_state_table' messaging(bool): If messaging should be included, defaults to False simulator(list): A list of the different modules that can run in simulator mode. Possible modules include: all, mount, camera, weather, night. Defaults to an empty list. @@ -42,7 +43,11 @@ def __init__(self, state_machine_file='simple_state_table', messaging=False, **k # Explicitly call the base classes in the order we want PanBase.__init__(self, **kwargs) - self.logger.info('Initializing PANOPTES unit') + self.name = self.config.get('name', 'Generic PANOPTES Unit') + self.logger.info('Initializing PANOPTES unit - {} - {}', + self.name, + self.config['location']['name'] + ) self._processes = {} @@ -67,8 +72,6 @@ def __init__(self, state_machine_file='simple_state_table', messaging=False, **k self.status() - self.name = self.config.get('name', 'Generic PANOPTES Unit') - self.logger.info('Welcome {}!'.format(self.name)) self.say("Hi there!") @property @@ -377,7 +380,8 @@ def sleep(self, delay=2.5, with_status=True): Keyword Arguments: delay {float} -- Number of seconds to sleep (default: 2.5) - with_status {bool} -- Show system status while sleeping (default: {True if delay > 2.0}) + with_status {bool} -- Show system status while sleeping + (default: {True if delay > 2.0}) """ if delay is None: delay = self._sleep_delay @@ -482,7 +486,8 @@ def check_message_loop(cmd_queue): # Poll for messages sockets = dict(poller.poll(500)) # 500 ms timeout - if cmd_subscriber.socket in sockets and sockets[cmd_subscriber.socket] == zmq.POLLIN: + if cmd_subscriber.socket in sockets and \ + sockets[cmd_subscriber.socket] == zmq.POLLIN: msg_type, msg_obj = cmd_subscriber.receive_message(flags=zmq.NOBLOCK) diff --git a/pocs/images.py b/pocs/images.py index 246640a87..03f756c8e 100644 --- a/pocs/images.py +++ b/pocs/images.py @@ -31,7 +31,8 @@ def __init__(self, fits_file, wcs_file=None, location=None): if fits_file.endswith('.fz'): fits_file = img_utils.fpack(fits_file, unpack=True) - assert fits_file.lower().endswith(('.fits')), self.logger.warning('File must end with .fits') + assert fits_file.lower().endswith(('.fits')), \ + self.logger.warning('File must end with .fits') self.wcs = None self._wcs_file = None @@ -115,7 +116,8 @@ def pointing_error(self): namedtuple: Pointing error information """ if self._pointing_error is None: - assert self.pointing is not None, self.logger.warn("No WCS, can't get pointing_error") + assert self.pointing is not None, self.logger.warning( + "No world coordinate system (WCS), can't get pointing_error") assert self.header_pointing is not None if self.wcs is None: diff --git a/pocs/mount/bisque.py b/pocs/mount/bisque.py index 8be4a7b33..616fbb22c 100644 --- a/pocs/mount/bisque.py +++ b/pocs/mount/bisque.py @@ -124,7 +124,7 @@ def set_target_coordinates(self, coords): target_set = False if self.is_parked: - self.logger.warning("Mount is parked") + self.logger.info("Mount is parked") else: # Save the skycoord coordinates self.logger.debug("Setting target coordinates: {}".format(coords)) @@ -173,9 +173,9 @@ def slew_to_target(self): success = False if self.is_parked: - self.logger.warning("Mount is parked") + self.logger.info("Mount is parked") elif self._target_coordinates is None: - self.logger.warning("Target Coordinates not set") + self.logger.info("Target Coordinates not set") else: # Get coordinate format from mount specific class mount_coords = self._skycoord_to_mount_coord(self._target_coordinates) diff --git a/pocs/mount/mount.py b/pocs/mount/mount.py index c5fde06ca..cb1bfb3f9 100644 --- a/pocs/mount/mount.py +++ b/pocs/mount/mount.py @@ -358,9 +358,9 @@ def slew_to_target(self): success = False if self.is_parked: - self.logger.warning("Mount is parked") + self.logger.info("Mount is parked") elif not self.has_target: - self.logger.warning("Target Coordinates not set") + self.logger.info("Target Coordinates not set") else: success = self.query('slew_to_target') diff --git a/pocs/utils/logger.py b/pocs/utils/logger.py index 8f64111fc..7a4a77b69 100644 --- a/pocs/utils/logger.py +++ b/pocs/utils/logger.py @@ -1,16 +1,49 @@ +import os +import sys +import time import datetime import logging import logging.config -import os -import time - +from tempfile import gettempdir from .config import load_config +class PanLogger(object): + """ Logger for PANOPTES with format style strings """ + + def __init__(self, logger): + super(PanLogger, self).__init__() + self.logger = logger + + def _process_str(self, fmt, *args, **kwargs): + """ Pre-process the log string + + This allows for `format` style specifiers, e.g. `{:02f}` and + `{:40s}`, which otherwise aren't supported by python's default + log formatting. + """ + log_str = fmt + if len(args) > 0 or len(kwargs) > 0: + log_str = fmt.format(*args, **kwargs) + + return log_str + + def debug(self, fmt, *args, **kwargs): + self.logger.debug(self._process_str(fmt, *args, **kwargs)) + + def info(self, fmt, *args, **kwargs): + self.logger.info(self._process_str(fmt, *args, **kwargs)) + + def warning(self, fmt, *args, **kwargs): + self.logger.warning(self._process_str(fmt, *args, **kwargs)) + + def error(self, fmt, *args, **kwargs): + self.logger.error(self._process_str(fmt, *args, **kwargs)) + + def get_root_logger(profile='panoptes', log_config=None): """ Creates a root logger for PANOPTES used by the PanBase object - Returns: logger(logging.logger): A configured instance of the logger """ @@ -23,16 +56,33 @@ def get_root_logger(profile='panoptes', log_config=None): for name, formatter in log_config['formatters'].items(): log_config['formatters'][name].setdefault('()', _UTCFormatter) - log_file_lookup = { - 'all': "{}/logs/panoptes.log".format(os.getenv('PANDIR', '/var/panoptes')), - 'warn': "{}/logs/warnings.log".format(os.getenv('PANDIR', '/var/panoptes')), - } + log_fname_datetime = datetime.datetime.utcnow().strftime('%Y%m%dT%H%M%SZ') + else: + log_fname_datetime = datetime.datetime.now().strftime('%Y%m%dT%H%M%SZ') + + # Setup log file names + invoked_script = os.path.basename(sys.argv[0]) + log_dir = '{}/logs'.format(os.getenv('PANDIR', gettempdir())) + log_fname = '{}-{}-{}'.format(invoked_script, os.getpid(), log_fname_datetime) + log_symlink = '{}/{}.log'.format(log_dir, invoked_script) - # Setup the TimeedRotatingFileHandler to backup in middle of day intead of middle of night + # Set log filename and rotation for handler in log_config.get('handlers', []): - log_config['handlers'][handler].setdefault('filename', log_file_lookup[handler]) - if handler in ['all', 'warn']: - log_config['handlers'][handler].setdefault('atTime', datetime.time(hour=11, minute=30)) + # Set the filename + full_log_fname = '{}/{}-{}.log'.format(log_dir, log_fname, handler) + log_config['handlers'][handler].setdefault('filename', full_log_fname) + + # Setup the TimeedRotatingFileHandler for middle of day + log_config['handlers'][handler].setdefault('atTime', datetime.time(hour=11, minute=30)) + + if handler == 'all': + # Symlink the log file to $PANDIR/logs/panoptes.log + try: + os.unlink(log_symlink) + except FileNotFoundError: + pass + finally: + os.symlink(full_log_fname, log_symlink) # Configure the logger logging.config.dictConfig(log_config) @@ -40,6 +90,8 @@ def get_root_logger(profile='panoptes', log_config=None): # Get the logger and set as attribute to class logger = logging.getLogger(profile) + # Don't want log messages from state machine library, it is very noisy and + # we have our own way of logging state transitions logging.getLogger('transitions.core').setLevel(logging.WARNING) try: @@ -48,7 +100,7 @@ def get_root_logger(profile='panoptes', log_config=None): except Exception: # pragma: no cover pass - return logger + return PanLogger(logger) class _UTCFormatter(logging.Formatter):