Simplified Version of Current Kilosort Logging and interplay with module level logging

console_output.log

outer_logger - DEBUG - This is a debug message from the outer logger before calling run_kilosort.
outer_logger - INFO - This is an info message from the outer logger before calling run_kilosort.
test_logging: Kilosort version 4
test_logging: Sorting None
test_logging: ----------------------------------------
test_logging: Encountered error in `run_kilosort`:
Traceback (most recent call last):
  File "/Users/ct5868/test_logging.py", line 22, in run_kilosort
    will_fail()
  File "/Users/ct5868/test_logging.py", line 30, in will_fail
    0/0
    ~^~
ZeroDivisionError: division by zero
outer_logger - ERROR - Kilosort4 failed
Traceback (most recent call last):
  File "/Users/ct5868/testing_logging_levels.py", line 35, in <module>
    run_kilosort(settings={}, results_dir='.')
  File "/Users/ct5868/test_logging.py", line 27, in run_kilosort
    raise e
  File "/Users/ct5868/test_logging.py", line 22, in run_kilosort
    will_fail()
  File "/Users/ct5868/test_logging.py", line 30, in will_fail
    0/0
    ~^~
ZeroDivisionError: division by zero
NOTE: See ./kilosort4.log for detailed info.
outer_logger: Kilosort4 failed
Traceback (most recent call last):
  File "/Users/ct5868/testing_logging_levels.py", line 35, in <module>
    run_kilosort(settings={}, results_dir='.')
  File "/Users/ct5868/test_logging.py", line 27, in run_kilosort
    raise e
  File "/Users/ct5868/test_logging.py", line 22, in run_kilosort
    will_fail()
  File "/Users/ct5868/test_logging.py", line 30, in will_fail
    0/0
    ~^~
ZeroDivisionError: division by zero
NOTE: See ./kilosort4.log for detailed info.
outer_logger - DEBUG - This is a debug message from the outer logger after calling run_kilosort.
outer_logger - INFO - This is an info message from the outer logger after calling run_kilosort.
outer_logger: This is an info message from the outer logger after calling run_kilosort.

kilosort4.log

09-13 12:57 test_logging DEBUG    Debug message
09-13 12:57 test_logging INFO     Kilosort version 4
09-13 12:57 test_logging INFO     Sorting None
09-13 12:57 test_logging INFO     ----------------------------------------
09-13 12:57 test_logging ERROR    Encountered error in `run_kilosort`:
Traceback (most recent call last):
  File "/Users/ct5868/test_logging.py", line 22, in run_kilosort
    will_fail()
  File "/Users/ct5868/test_logging.py", line 30, in will_fail
    0/0
    ~^~
ZeroDivisionError: division by zero
09-13 12:57 outer_logger ERROR    Kilosort4 failed
Traceback (most recent call last):
  File "/Users/ct5868/testing_logging_levels.py", line 35, in <module>
    run_kilosort(settings={}, results_dir='.')
  File "/Users/ct5868/test_logging.py", line 27, in run_kilosort
    raise e
  File "/Users/ct5868/test_logging.py", line 22, in run_kilosort
    will_fail()
  File "/Users/ct5868/test_logging.py", line 30, in will_fail
    0/0
    ~^~
ZeroDivisionError: division by zero
NOTE: See ./kilosort4.log for detailed info.
09-13 12:57 outer_logger DEBUG    This is a debug message from the outer logger after calling run_kilosort.
09-13 12:57 outer_logger INFO     This is an info message from the outer logger after calling run_kilosort.

my_custom.log

outer_logger - INFO - This is an info message from the outer logger before calling run_kilosort.
outer_logger - ERROR - Kilosort4 failed
Traceback (most recent call last):
  File "/Users/ct5868/testing_logging_levels.py", line 35, in <module>
    run_kilosort(settings={}, results_dir='.')
  File "/Users/ct5868/test_logging.py", line 27, in run_kilosort
    raise e
  File "/Users/ct5868/test_logging.py", line 22, in run_kilosort
    will_fail()
  File "/Users/ct5868/test_logging.py", line 30, in will_fail
    0/0
    ~^~
ZeroDivisionError: division by zero
NOTE: See ./kilosort4.log for detailed info.
outer_logger - INFO - This is an info message from the outer logger after calling run_kilosort.

test_logging.py

# test_logging.py

import time
from pathlib import Path
import pprint
import logging
import warnings
logger = logging.getLogger(__name__)


def run_kilosort(settings, results_dir=None, filename=None):

    results_dir = Path(results_dir)
    setup_logger_current(results_dir)
    # setup_logger_proposed(results_dir)
    try:
        logger.debug("Debug message")
        logger.info(f"Kilosort version 4")
        logger.info(f"Sorting {filename}")
        logger.info('-'*40)
        will_fail()
    except Exception as e:
        # This makes sure the full traceback is written to log file.
        logger.exception('Encountered error in `run_kilosort`:')
        e.add_note(f'NOTE: See {results_dir}/kilosort4.log for detailed info.')
        raise e

def will_fail():
    0/0

def setup_logger_current(results_dir):
    # Adapted from
    # https://docs.python.org/2/howto/logging-cookbook.html#logging-to-multiple-destinations
    # In summary: only send logging.debug statements to log file, not console.

    # set up logging to file for root logger
    logging.basicConfig(level=logging.DEBUG,
                        format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',
                        datefmt='%m-%d %H:%M',
                        filename=results_dir/'kilosort4.log',
                        filemode='w')

    # define a Handler which writes INFO messages or higher to the sys.stderr
    console = logging.StreamHandler()
    console.setLevel(logging.INFO)
    # set a format which is simpler for console use
    console_formatter = logging.Formatter('%(name)-12s: %(message)s')
    console.setFormatter(console_formatter)
    # add the console handler to the root logger
    logging.getLogger('').addHandler(console)

    # Set 3rd party loggers to INFO or above only,
    # so that it doesn't spam the log file
    numba_log = logging.getLogger('numba')
    numba_log.setLevel(logging.INFO)

    mpl_log = logging.getLogger('matplotlib')
    mpl_log.setLevel(logging.INFO)

testing_logging_levels.py

# testing_logging_levels.py

import logging
import logging.config
from test_logging import run_kilosort

# Define the logging configuration
logging_config = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'default': {
            'format': '%(name)s - %(levelname)s - %(message)s',
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'level': 'DEBUG',
            'formatter': 'default',
        },
        'file': {
            'class': 'logging.FileHandler',
            'filename': 'my_custom.log',
            'mode': 'w',
            'level': 'INFO',
            'formatter': 'default',
        },
    },
    'root': {
        'level': 'DEBUG',
        'handlers': ['console', 'file'],
    },
}

# Apply the logging configuration
logging.config.dictConfig(logging_config)

# Get the outer logger
outer_logger = logging.getLogger('outer_logger')
outer_logger.setLevel(logging.DEBUG)

# Set logging levels
test_logging_logger = logging.getLogger('test_logging')
test_logging_logger.propagate = False # Set to True by default


# Log a message before calling run_kilosort
outer_logger.debug('This is a debug message from the outer logger before calling run_kilosort.')
outer_logger.info('This is an info message from the outer logger before calling run_kilosort.')

# Call the function from test_logging.py
try:
    run_kilosort(settings={}, results_dir='.')
except:
    outer_logger.exception("Kilosort4 failed")

# Log a message after calling run_kilosort
outer_logger.debug('This is a debug message from the outer logger after calling run_kilosort.')
outer_logger.info('This is an info message from the outer logger after calling run_kilosort.')