功能记录器在 Pytest 中引发 FileNotFoundError

Question

意图

我想创建一个 python 类，它在初始化时创建一个日志，并在该类的实例工作时添加到日志中。我的代码在实践中有效，但在编写测试时我得到了FileNotFoundError。

代码

# code.py

""""A class that creates a logger during initialization"""

import datetime
import logging
import sys

from os import makedirs, path


class Worker(object):
    def __init__(self):
        job_name = path.splitext(sys.argv[0])[0]
        here = path.dirname(path.abspath(__file__))
        log_dir = ''.join([here, '/logs/jobs/', job_name])
        makedirs(log_dir, exist_ok=True)
        
        self.logger = logging.getLogger('.'.join(['jobs', job_name]))
        self.logger.setLevel(logging.DEBUG)
        
        log_formatter = logging.Formatter('%(name)s,%(levelname)-8s,%(asctime)s,%(message)s')
        stream_handler = logging.StreamHandler()
        stream_handler.setLevel(logging.WARN)
        stream_handler.setFormatter(log_formatter)
        self.logger.addHandler(stream_handler)
        
        now = datetime.datetime.now().strftime('%H%M%S')
        log_file = ''.join([log_dir, '/', job_name, '_', now, '.log'])
        file_handler = logging.FileHandler(log_file)
        file_handler.setLevel(logging.DEBUG)
        file_handler.setFormatter(log_formatter)
        self.logger.addHandler(file_handler)
        stream_handler.setLevel(logging.INFO)

    def do_something(self):
        """A job that needs to be done"""
        self.logger.info('I did something.')
        return True

# test_code.py
import unittest

from workers.code import Worker


class CodeTest(unittest.TestCase):
    def test__init__(self):
        worker = Worker()
        assert worker.logger.handlers  # this fails with FileNotFound Error

    def test_do_something(self):
        worker = Worker()  # this also fails even when delay=True on FileHandler
        assert worker.do_something()

追溯

$ pytest
===================================== test session starts =====================================
platform linux -- Python 3.8.5, pytest-6.0.1, py-1.9.0, pluggy-0.13.1
rootdir: /home/laptop/Documents/Repositories/pytest-logging-test
collected 2 items                                                                             

tests/test_code.py FF                                                                   [100%]

========================================== FAILURES ===========================================
____________________________________ CodeTest.test__init__ ____________________________________

self = <tests.test_code.CodeTest testMethod=test__init__>

    def test__init__(self):
>       worker = Worker()

tests/test_code.py:8: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
workers/code.py:28: in __init__
    file_handler = logging.FileHandler(log_file)
/usr/lib/python3.8/logging/__init__.py:1143: in __init__
    StreamHandler.__init__(self, self._open())
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <[AttributeError("'FileHandler' object has no attribute 'level'") raised in repr()] FileHandler object at 0x7fc8ff05a820>

    def _open(self):
        """
        Open the current base file with the (original) mode and encoding.
        Return the resulting stream.
        """
>       return open(self.baseFilename, self.mode, encoding=self.encoding)
E       FileNotFoundError: [Errno 2] No such file or directory: '/home/laptop/Documents/Repositories/pytest-logging-test/workers/logs/jobs/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest_172529.log'

/usr/lib/python3.8/logging/__init__.py:1172: FileNotFoundError
_________________________________ CodeTest.test_do_something __________________________________

self = <tests.test_code.CodeTest testMethod=test_do_something>

    def test_do_something(self):
>       worker = Worker()  # this also fails even when delay=True on FileHandler

tests/test_code.py:12: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
workers/code.py:28: in __init__
    file_handler = logging.FileHandler(log_file)
/usr/lib/python3.8/logging/__init__.py:1143: in __init__
    StreamHandler.__init__(self, self._open())
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <[AttributeError("'FileHandler' object has no attribute 'level'") raised in repr()] FileHandler object at 0x7fc8ff0140d0>

    def _open(self):
        """
        Open the current base file with the (original) mode and encoding.
        Return the resulting stream.
        """
>       return open(self.baseFilename, self.mode, encoding=self.encoding)
E       FileNotFoundError: [Errno 2] No such file or directory: '/home/laptop/Documents/Repositories/pytest-logging-test/workers/logs/jobs/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest_172529.log'

/usr/lib/python3.8/logging/__init__.py:1172: FileNotFoundError
=================================== short test summary info ===================================
FAILED tests/test_code.py::CodeTest::test__init__ - FileNotFoundError: [Errno 2] No such fil...
FAILED tests/test_code.py::CodeTest::test_do_something - FileNotFoundError: [Errno 2] No suc...
====================================== 2 failed in 0.26s ======================================

失败的解决方案

看起来 pytest 正在尝试在文件创建之前打开它。此代码在实践中完全按预期工作。我只在使用 pytest 时收到此错误。

此外，在我的测试目录中，pytest 创建了一堆文件夹，这从追溯中的/home/laptop/Documents/Repositories/pytest-logging-test/workers/logs/jobs/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/ 可以看出。我不知道为什么它没有生成文件。

当我在Worker 类中调用FileHandler 时设置delay=True 时，test__init__ 通过但test_do_something 失败。这是回溯：

$ pytest
===================================== test session starts =====================================
platform linux -- Python 3.8.5, pytest-6.0.1, py-1.9.0, pluggy-0.13.1
rootdir: /home/laptop/Documents/Repositories/pytest-logging-test
collected 2 items                                                                             

tests/test_code.py .F                                                                   [100%]

========================================== FAILURES ===========================================
_________________________________ CodeTest.test_do_something __________________________________

self = <tests.test_code.CodeTest testMethod=test_do_something>

    def test_do_something(self):
        worker = Worker()  # this also fails even when delay=True on FileHandler
>       assert worker.do_something()

tests/test_code.py:13: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
workers/code.py:36: in do_something
    self.logger.info('I did something.')
/usr/lib/python3.8/logging/__init__.py:1434: in info
    self._log(INFO, msg, args, **kwargs)
/usr/lib/python3.8/logging/__init__.py:1577: in _log
    self.handle(record)
/usr/lib/python3.8/logging/__init__.py:1587: in handle
    self.callHandlers(record)
/usr/lib/python3.8/logging/__init__.py:1649: in callHandlers
    hdlr.handle(record)
/usr/lib/python3.8/logging/__init__.py:950: in handle
    self.emit(record)
/usr/lib/python3.8/logging/__init__.py:1182: in emit
    self.stream = self._open()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <FileHandler /home/laptop/Documents/Repositories/pytest-logging-test/workers/logs/jobs/home/laptop/Documents/Repos...gging-test/venv/bin/pytest/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest_172946.log (DEBUG)>

    def _open(self):
        """
        Open the current base file with the (original) mode and encoding.
        Return the resulting stream.
        """
>       return open(self.baseFilename, self.mode, encoding=self.encoding)
E       FileNotFoundError: [Errno 2] No such file or directory: '/home/laptopy/Documents/Repositories/pytest-logging-test/workers/logs/jobs/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest/home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest_172946.log'

/usr/lib/python3.8/logging/__init__.py:1172: FileNotFoundError
------------------------------------ Captured stderr call -------------------------------------
jobs./home/laptop/Documents/Repositories/pytest-logging-test/venv/bin/pytest,INFO    ,2020-09-02 17:29:46,569,I did something.
=================================== short test summary info ===================================
FAILED tests/test_code.py::CodeTest::test_do_something - FileNotFoundError: [Errno 2] No suc...
================================= 1 failed, 1 passed in 0.28s =================================

在 python 控制台中，上面的代码完全按照预期工作：

>>> from workers.code import Worker
>>> w = Worker()
>>> w.do_something()
True

相应的日志文件也已制作，因此这是 pytest 的问题。 pytest 正在捕获logger.info() 调用，这在回溯中很明显，但由于某种原因，该文件没有被制作。我无法弄清楚为什么会这样。有人可以解释一下吗？

Answer 1

正如@blues 在对原始问题的评论中指出的那样，job_name 是从sys.argv 中提取的（该脚本通常称为$ python code.py some_file.txt），并且仅使用pytest 运行测试。因此，没有创建日志文件，而是创建了一个空目录。以下是一种解决方法。我不会将此标记为答案，因为它实际上并没有回答原始问题。如果有人有更好的解决方案，请发布！

# code.py
""""A class that creates a logger during initialization"""

import datetime
import logging
import sys

from os import makedirs, path


class Worker(object):
    def __init__(self):
        job_name = path.splitext(sys.argv[0])[0]
        if '/' or '\\' in job_name:  # path.isfile() and path.isdir() don't work as expected for some reason
            job_name = path.splitext(job_name)[-1] or 'no_job_name'
        here = path.dirname(path.abspath(__file__))
        log_dir = ''.join([here, '/logs/jobs/', job_name])
        makedirs(log_dir, exist_ok=True)

        self.logger = logging.getLogger('.'.join(['jobs', job_name]))
        self.logger.setLevel(logging.DEBUG)

        log_formatter = logging.Formatter('%(name)s,%(levelname)-8s,%(asctime)s,%(message)s')
        stream_handler = logging.StreamHandler()
        stream_handler.setLevel(logging.WARN)
        stream_handler.setFormatter(log_formatter)
        self.logger.addHandler(stream_handler)

        now = datetime.datetime.now().strftime('%H%M%S')
        log_file = ''.join([log_dir, '/', job_name, '_', now, '.log'])
        file_handler = logging.FileHandler(log_file)
        file_handler.setLevel(logging.DEBUG)
        file_handler.setFormatter(log_formatter)
        self.logger.addHandler(file_handler)
        stream_handler.setLevel(logging.INFO)

    def do_something(self):
        """A job that needs to be done"""
        self.logger.info('I did something.')
        return True