multiprocessing logger get bad %(filename)s

[xu-song]

Bug report

Bug description:

util.info and util.debug get bad %(filename)s in multiprocessing logger.

cpython/Lib/multiprocessing/pool.py

Line 116 in c3f92f6

util.debug('worker got EOFError or OSError -- exiting')

Reproducible example

test_logger.py

import logging
import multiprocessing

logger = multiprocessing.get_logger()
logger.setLevel(logging.DEBUG)
handler = logging.StreamHandler()
handler.setFormatter(
    logging.Formatter('[%(levelname)s] [%(processName)s] [%(filename)s:%(lineno)d:%(funcName)s] %(message)s'))
logger.addHandler(handler)


def add1(x):
    return x + 1


logger.info("print info")
logger.debug("print debug")

with multiprocessing.Pool(3) as p:
    result = p.map(add1, range(10))

It gets bad %(filename)s as follows

$ python test_logger.py
[INFO] [MainProcess] [test_logger.py:16:<module>] print info
[DEBUG] [MainProcess] [test_logger.py:17:<module>] print debug
[DEBUG] [MainProcess] [util.py:50:debug] created semlock with handle 140232166834176
[DEBUG] [MainProcess] [util.py:50:debug] created semlock with handle 140232166830080
[DEBUG] [MainProcess] [util.py:50:debug] created semlock with handle 140232157552640
[DEBUG] [MainProcess] [util.py:50:debug] created semlock with handle 140232157548544
[DEBUG] [MainProcess] [util.py:50:debug] created semlock with handle 140232157544448
[DEBUG] [MainProcess] [util.py:50:debug] created semlock with handle 140232157540352
[DEBUG] [MainProcess] [util.py:50:debug] added worker
[DEBUG] [MainProcess] [util.py:50:debug] added worker
[INFO] [ForkPoolWorker-1] [util.py:54:info] child process calling self.run()
[INFO] [ForkPoolWorker-2] [util.py:54:info] child process calling self.run()
[DEBUG] [MainProcess] [util.py:50:debug] added worker
[INFO] [ForkPoolWorker-3] [util.py:54:info] child process calling self.run()
...

After apply pull request #113423

$ python test_logger.py
[INFO] [MainProcess] [test_logger.py:16:<module>] print info
[DEBUG] [MainProcess] [test_logger.py:17:<module>] print debug
[DEBUG] [MainProcess] [synchronize.py:67:__init__] created semlock with handle 139963328901120
[DEBUG] [MainProcess] [synchronize.py:67:__init__] created semlock with handle 139963328897024
[DEBUG] [MainProcess] [synchronize.py:67:__init__] created semlock with handle 139963319619584
[DEBUG] [MainProcess] [synchronize.py:67:__init__] created semlock with handle 139963319615488
[DEBUG] [MainProcess] [synchronize.py:67:__init__] created semlock with handle 139963319611392
[DEBUG] [MainProcess] [synchronize.py:67:__init__] created semlock with handle 139963319607296
[DEBUG] [MainProcess] [pool.py:331:_repopulate_pool_static] added worker
[INFO] [ForkPoolWorker-1] [process.py:312:_bootstrap] child process calling self.run()
[DEBUG] [MainProcess] [pool.py:331:_repopulate_pool_static] added worker
[INFO] [ForkPoolWorker-2] [process.py:312:_bootstrap] child process calling self.run()
[DEBUG] [MainProcess] [pool.py:331:_repopulate_pool_static] added worker
[INFO] [ForkPoolWorker-3] [process.py:312:_bootstrap] child process calling self.run()
[DEBUG] [MainProcess] [pool.py:655:terminate] terminating pool
[DEBUG] [MainProcess] [pool.py:684:_terminate_pool] finalizing pool
[DEBUG] [MainProcess] [pool.py:694:_terminate_pool] helping task handler/workers to finish
[DEBUG] [MainProcess] [pool.py:525:_handle_workers] worker handler exiting
[DEBUG] [MainProcess] [pool.py:674:_help_stuff_finish] removing tasks from inqueue until task handler finished
[DEBUG] [MainProcess] [pool.py:557:_handle_tasks] task handler got sentinel
[DEBUG] [MainProcess] [pool.py:561:_handle_tasks] task handler sending sentinel to result handler
[DEBUG] [MainProcess] [pool.py:565:_handle_tasks] task handler sending sentinel to workers
[DEBUG] [MainProcess] [pool.py:590:_handle_results] result handler got sentinel
[DEBUG] [ForkPoolWorker-2] [pool.py:120:worker] worker got sentinel -- exiting
[DEBUG] [MainProcess] [pool.py:618:_handle_results] ensuring that outqueue is not full
[DEBUG] [ForkPoolWorker-2] [pool.py:140:worker] worker exiting after 3 tasks
...

CPython versions tested on:

CPython main branch

Operating systems tested on:

Linux

Linked PRs

• GH-113421: Fix multiprocessing logger #113423
• [3.12] gh-113421: Fix multiprocessing logger for "%(filename)s" (GH-113423) #113450
• [3.11] gh-113421: Fix multiprocessing logger for "%(filename)s" (GH-113423) #113451