Why does 'import dataclasses' cause logging to stop working?

Question

I have the follow bit of code:

import logging
# import dataclasses

logging.basicConfig(
    filename="logfile.log",
    level=logging.DEBUG,
)

def main():
    logging.info("This is an info message")
    logging.error("This is an error message")

if __name__ == "__main__":
    main()

If I comment out import dataclasses the logs are outputted properly. But if I include import dataclasses it stops outputting completely.

Does anyone know why this is? Perhaps a bug?

Python version: 3.9.16

Answer 1

So here's what seems to be causing my issue. I have the following simplified project layout:

project/
  script_one/
    script_one.py
  script_two/
    script_two.py

script_one.py:

import logging

logging.basicConfig(
    filename="script_one.log",
    level=logging.DEBUG,
)

def main() -> None:
    logging.info("Starting script...")

if __name__ == "__main__":
    main()

script_two.py:

import logging
import dataclasses

logging.basicConfig(
    filename="logfile.log",
    level=logging.DEBUG,
)

def main():
    logging.info("This is an info message")
    logging.error("This is an error message")

if __name__ == "__main__":
    main()

The problem is that script_one.py also contains logging.basicConfig outside of the main function. Apparently this caused the logs in script_two.py to be output to script_one.log, despite only running script_two.py (these scripts don't import each other).

I am curious why Python works this way... And also why import dataclasses triggers this issue...

Anyway, the solution is to just use a separate logger function and initialize from main:

script_one.py:

import logging

def logger():
    logging.basicConfig(
        filename="script_one.log",
        level=logging.DEBUG,
    )

def main() -> None:
    logger()
    logging.info("Starting script...")

if __name__ == "__main__":
    main()

script_two.py:

import logging
import dataclasses

def logger():
    logging.basicConfig(
        filename="logfile.log",
        level=logging.DEBUG,
    )

def main():
    logger()
    logging.info("This is an info message")
    logging.error("This is an error message")

if __name__ == "__main__":
    main()

----------------------EDIT----------------------

I now fully understand what was happening after placing import traceback; traceback.print_stack() in script_one.py as suggested by @user2357112:

File "/home/user/project/script_two/script_two.py", line 5, in <module>
    from dataclasses import dataclass
File "<frozen importlib._bootstrap>", line 1007, in _find_and_load
File "<frozen importlib._bootstrap>", line 986, in _find_and_load_unlocked
File "<frozen importlib._bootstrap>", line 680, in _load_unlocked
File "<frozen importlib._bootstrap_external>", line 850, in exec_module
File "<frozen importlib._bootstrap>", line 228, in _call_with_frames_removed
File "/usr/lib/python3.9/dataclasses.py", line 3, in <module>
    import copy
File "<frozen importlib._bootstrap>", line 1007, in _find_and_load
File "<frozen importlib._bootstrap>", line 986, in _find_and_load_unlocked
File "<frozen importlib._bootstrap>", line 680, in _load_unlocked
File "<frozen importlib._bootstrap_external>", line 850, in exec_module
File "<frozen importlib._bootstrap>", line 228, in _call_with_frames_removed
File "/home/user/project/copy/copy.py", line 8, in <module>
    traceback.print_stack()

As it so happens, my script_one.py that I used in the example was actually called copy.py. Since dataclasses imports the copy module, it instead imports my copy.py which then runs the logging statement, outputting to the other file.

Mystery solved!