#!/usr/bin/env python # # logs_utils.py - Tools for logging. # # Author: Paul McCarthy <pauldmccarthy@gmail.com> # Author: Fidel Alfaro Almagro <fidel.alfaroalmagro@ndcn.ox.ac.uk> # Author: Michiel Cottaar <michiel.cottaar@ndcn.ox.ac.uk> # # pylint: disable=C0103,E0602,C0114,C0115,C0116,R0913,R0914,R0915 # pylint: disable=W0613 # import os import os.path as op import socket import shutil import inspect import logging import traceback import contextlib import functools as ft from subprocess import check_output from fsl import wrappers def run_command(logger, command, **kwargs): try: logger.info('COMMAND TO RUN: \t' + command.strip()) job_output = check_output(command,shell=True,**kawargs).decode('UTF-8') logger.info('COMMAND OUTPUT: \t' + job_output.strip()) except Exception as e: logger.error('Exception raised during: \t' + command.strip()) logger.error('Exception type: \t' + str(type(e))) logger.error('Exception args: \t' + str(e.args)) logger.error('Exception message: \t' + str(e)) job_output = "" return job_output.strip() def create_formatter(): """Create a logging.Formatter. """ return logging.Formatter('%(asctime)s ' '%(filename)s ' '%(lineno)4d: ' '%(funcName)s - ' '%(message)s', datefmt='%m/%d/%Y %H:%M:%S') def setup_logging(fname, level=logging.INFO): """Set up BIP logging. Intended to be called once from main at application startup. """ log = logging.getLogger('bip') handler = logging.FileHandler(fname) formatter = create_formatter() # Add handler/formatter references # to the top level logger so the # redirect_logging function can # manipulate them. log.formatter = formatter log.handler = handler handler.setFormatter(formatter) log.addHandler(handler) log.setLevel(level) def log_bip(logobj, level, msg): """Log a message, associating it with the nearest line in the bip python codebase in the call stack. """ frames = inspect.stack()[1:] for i, frame in enumerate(frames): if 'bip' in frame[1]: break logobj.log(level, msg.strip(), stacklevel=i + 2) @contextlib.contextmanager def redirect_logging(name, outdir='.', level=logging.INFO): """Context manager which temporarily redirects logging. The following log files are created: - outdir/name.log: contains log messages, commands that are executed through fsl.wrappers functions, and standard output/error of those commands. """ fname = op.join(outdir, name) with open(f'{fname}.log', 'wt', buffering=1, encoding="utf-8") as stdout: log = logging.getLogger('bip') handler = logging.StreamHandler(stdout) handler.setFormatter(create_formatter()) log.addHandler(handler) log.setLevel(level) # If running within a single process, we # want to temporarily suppress log messages # from the main log file (assumed to have # been configured with setup_logging). if getattr(log, 'handler', None): log.removeHandler(log.handler) # Log all fsl.wrappers calls via log_bip logcmd = ft.partial(log_bip, log, level) # Redirect fsl.wrappers stdout/stderr to # the same with wrappers.wrapperconfig(log={'tee' : False, 'stdout' : stdout, 'stderr' : stdout, 'cmd' : logcmd}): try: log.info(f'Started {name}') log.info(f'Host {socket.gethostname()}') yield except Exception as e: traceback.print_exception(type(e), e, e.__traceback__, file=stdout) raise e finally: log.info(f'Finished {name}') log.removeHandler(handler) # Restore main log handler if getattr(log, 'handler', None): log.addHandler(log.handler) @contextlib.contextmanager def tempdir(dir_name): os.makedirs(dir_name, exist_ok=True) yield dir_name for file_name in os.listdir(dir_name): file_path = os.path.join(dir_name, file_name) try: shutil.rmtree(file_path) except OSError: os.remove(file_path)