Broken Pipe in Server of Manager in multiprocessing when finalizing, sometimes

[mutax]

BPO	44614
Nosy	@markshannon, @mutax
Files	race2.py

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = None
created_at = <Date 2021-07-12.22:07:45.419>
labels = ['type-bug', 'library', '3.9']
title = 'Broken Pipe in Server of Manager in multiprocessing when finalizing, sometimes'
updated_at = <Date 2021-07-13.13:25:37.945>
user = 'https://github.com/mutax'

bugs.python.org fields:

activity = <Date 2021-07-13.13:25:37.945>
actor = 'Mark.Shannon'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['Library (Lib)']
creation = <Date 2021-07-12.22:07:45.419>
creator = 'mutax'
dependencies = []
files = ['50145']
hgrepos = []
issue_num = 44614
keywords = ['patch']
message_count = 1.0
messages = ['397358']
nosy_count = 2.0
nosy_names = ['Mark.Shannon', 'mutax']
pr_nums = []
priority = 'normal'
resolution = None
stage = 'patch review'
status = 'open'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue44614'
versions = ['Python 3.9']

[mutax]

It seems that the shutdown() method of the Server in in managers.py is already sending the result of its execution directly into the connection, and then the handle_request() method is trying to send ('#RETURN', None) yet again after returning from the call to shutdown() which sometimes yields a Broken Pipe Exception.

with the following line in handle_request():
    result = func(c, *args, **kwds)
a call to shutown() is made, and in shutdown() I see:
    c.send(('#RETURN', None))

and back in handle_request():
msg = ('#RETURN', result)
…
c.send(msg)

attached you find a minimal example that shows this behaviour sometimes, if logging is set to not more than DEBUG. I am guessing that the Broken Pipe depends on a race with the other side being closed.

Although the race condition does not look like having an impact, it is highly confusing when debugging.

log:
INFO MainProcess util.py:54 sending shutdown message to manager
DEBUG BaseManager-12 util.py:50 manager received shutdown message
INFO BaseManager-12 util.py:54 Failure to send message: ('#RETURN', None)
INFO BaseManager-12 util.py:54 process shutting down
INFO BaseManager-12 util.py:54 ... request was (None, 'shutdown', (), {})
DEBUG BaseManager-12 util.py:50 running all "atexit" finalizers with priority >= 0
INFO BaseManager-12 util.py:54 ... exception was BrokenPipeError(32, 'Broken pipe')
DEBUG BaseManager-12 util.py:50 running the remaining "atexit" finalizers
INFO BaseManager-12 util.py:54 process exiting with exitcode 0