`MINISCOPE_IO_LOGS__LEVEL` in `.env` doesn't set log level

[t-sasatani]

It seems like MINISCOPE_IO_LOGS__LEVEL in the .env file doesn't change the stdout/file log levels. Below is the added test function and a GitHub action test run that should explain this. https://github.com/Aharoni-Lab/miniscope-io/actions/runs/11756676032

[t-sasatani]

Adding test for this here too in case.

@pytest.mark.parametrize('level', ['DEBUG', 'INFO', 'WARNING', 'ERROR'])
def test_init_logger_from_dotenv(tmp_path, level):
    """
    Set log levels from dotenv MINISCOPE_IO_LOGS__LEVEL key
    """
    # Feels kind of fragile to hardcode this but I couldn't think of a better way so for now
    level_name_map = {
        'DEBUG': logging.DEBUG,
        'INFO': logging.INFO,
        'WARNING': logging.WARNING,
        'ERROR': logging.ERROR
    }

    tmp_path.mkdir(exist_ok=True,parents=True)
    dotenv = tmp_path / '.env'
    with open(dotenv, 'w') as denvfile:
        denvfile.write(f'MINISCOPE_IO_LOGS__LEVEL="{level}"')

    dotenv_logger = init_logger(name='test_logger', log_dir=tmp_path)

    assert dotenv_logger.level == level_name_map.get(level)

[sneakers-the-rat]

The .env file needs to be in the current working directory, we sort of cheat that in the current test by passing the .env file explicitly: https://github.com/Aharoni-Lab/miniscope-io/blob/fa69f0df8c66dbf9eb4b30690a5c815df98945b0/tests/test_config.py#L46

And I should update that now that ive written better tests elsewhere.

If you monkeypatch the current directory to that tmp dir it should work: https://docs.pytest.org/en/latest/reference/reference.html#pytest.MonkeyPatch.chdir

[sneakers-the-rat]

Ill go ahead and add some stuff I did for linkml to have a user directory where you can set that globally in addition to current directory

https://github.com/linkml/linkml/pull/2335

[t-sasatani]

Thanks I fixed the path stuff in the test. Now, it should initialize the logger after moving to the tmp_path and test each handler separately. I still might have bugs in the test, but it seems like the propagation to the handlers isn't working.

    monkeypatch.chdir(tmp_path)

    dotenv_logger = init_logger(name='test_logger', log_dir=tmp_path)

    # Separating them for readable summary info
    if test_target == 'logger':
        assert dotenv_logger.level == level_name_map.get(level)

    for handler in dotenv_logger.handlers:
        if isinstance(handler, RotatingFileHandler) and test_target == 'RotatingFileHandler':
            assert handler.level == level_name_map.get(level)

        elif isinstance(handler, RichHandler) and test_target == 'RichHandler':
            # Might be better to explicitly set the level in the handler
            assert handler.level == logging.NOTSET

Test summary:

========================== short test summary info ========================== 
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-True-DEBUG] - AssertionError: assert 30 == 10
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-True-INFO] - AssertionError: assert 30 == 20
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-True-WARNING] - AssertionError: assert 10 == 30
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-True-ERROR] - AssertionError: assert 30 == 40
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-False-DEBUG] - AssertionError: assert 30 == 10
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-False-INFO] - AssertionError: assert 30 == 20
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-False-WARNING] - AssertionError: assert 10 == 30
FAILED tests/test_logging.py::test_init_logger_from_dotenv[RotatingFileHandler-False-ERROR] - AssertionError: assert 30 == 40

[t-sasatani]

Here's the github action run https://github.com/Aharoni-Lab/miniscope-io/actions/runs/11777987908

[sneakers-the-rat]

What in tarnation

[sneakers-the-rat]

oh i see the problem - we're actually making new handlers so if i open a debugger and show the handlers its like this:

pprint(dotenv_logger.handlers)
[<RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l0/miniscope_io.test_logger.log (DEBUG)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l1/miniscope_io.test_logger.log (INFO)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l2/miniscope_io.test_logger.log (WARNING)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l3/miniscope_io.test_logger.log (ERROR)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l4/miniscope_io.test_logger.log (DEBUG)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l5/miniscope_io.test_logger.log (INFO)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l6/miniscope_io.test_logger.log (WARNING)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_l7/miniscope_io.test_logger.log (ERROR)>,
 <RichHandler (NOTSET)>,
 <RotatingFileHandler /private/var/folders/b8/28n_6_zn7flgh40028jxd8j80000gn/T/pytest-of-jonny/pytest-33/test_init_logger_from_dotenv_R0/miniscope_io.test_logger.log (DEBUG)>,
 <RichHandler (NOTSET)>]

i actually knew about this problem but had not gotten around to fix it. i'lld ot hat now

[t-sasatani]

Ah interesting. I was confused that the handler level differs when the test fails, but now it makes sense. Also, we have turnarounds for this, so no need to raise priority of this issue for upcoming experiments. (I assume it's not the case, but let me mention it in case you have that in mind.)

[sneakers-the-rat]

oh just seeing this, nah i am in a bugfixing mood so it's done :)