Fix #1978: Support Python 3.7's new pre- and post-fork handlers

[nickwilliams-eventbrite]

This change addresses #1978 by ensuring that, in Python 3.7 and newer versions, the following always happens:

• PyOS_BeforeFork() is called before the parent process calls fork()
• PyOS_AfterFork_Parent() is called in the master process after the parent process calls fork()
• PyOS_AfterFork_Child() is called in all worker processes after the parent process calls fork()

This new behavior ignores the value of the py-call-osafterfork setting (only in Python 3.7 and newer), because not calling the before- and after-fork hooks is invalid behavior for CPython extensions in Python 3.7 and newer.

I tested this by compiling, installing, and using in our new Python 3.7 systems:

mkdir /usr/lib/uwsgi
mkdir /usr/lib/uwsgi/plugins
cd /usr/local/src
git clone https://github.com/nickwilliams-eventbrite/uwsgi.git
cd uwsgi
git checkout fix-py37-errors
python uwsgiconfig.py --build core
python uwsgiconfig.py --plugin plugins/rsyslog core rsyslog
python uwsgiconfig.py --plugin plugins/python core python3
UWSGI_PLUGINS_BUILDER_CFLAGS= python uwsgiconfig.py --extra-plugin https://github.com/Datadog/uwsgi-dogstatsd dogstatsd
cp -v ./uwsgi /usr/bin/uwsgi-core
cp -v ./dogstatsd_plugin.so ./python3_plugin.so ./rsyslog_plugin.so /usr/lib/uwsgi/plugins/

This also adds a Python 3.7 build to the Travis build (I won't know if that works until posting this PR).

[nickwilliams-eventbrite]

[bump] Could I get some 👀 on this? Thanks!

[xrmx]

The changes looks fine to me but there's a bit that puzzles me. We are adding a new callback for the plugins to set when we have a uwsgi hook just one line above below which would be very cool to reuse if possible.

[nickwilliams-eventbrite]

The changes looks fine to me but there's a bit that puzzles me. We are adding a new callback for the plugins to set when we have a uwsgi hook just one line above which would be very cool to reuse if possible.

I'm not sure I understand what bit puzzles you. Could you elaborate more? It sounds like you're saying that it would be very cool to re-use the new master_start callback I'm adding. Anyone is free to re-use this new callback.

[xrmx]

What I mean is that it would be cool to reuse, if possible, the hook at master.c:643 https://github.com/unbit/uwsgi/pull/1995/files#diff-d752b2bf332e435717f74037eb981f1fL642 instead of adding the master_start callback in the uwsgi_plugin struct.

[nickwilliams-eventbrite]

Oh, so you're talking about this line, which is already there?

uwsgi_hooks_run(uwsgi.hook_master_start, "master-start", 1);

I thought about that at first, but I couldn't figure out how to detect hook_master_start in a plugin. Could you explain a bit more about how I could attach to hook_master_start within a plugin? AFAICT, the pattern of lopping over the list of plugins and calling a hook on each plugin is the pattern used everywhere else for all plugin hooks.

[nickwilliams-eventbrite]

@xrmx: Per my most recent comment about two weeks ago, could you advise on how I can change this to work as you suggest? I can't figure out how to make what you suggest work.

[xrmx]

@nickwilliams-eventbrite AFAIK there's no interface for internal callers to use the hook system. Maybe @unbit can chime in to sort out if it's a good idea or not?

[xrmx]

without master this will print the warning, we should probably check uwsgi.master_process

spawned uWSGI worker 1 (and the only) (pid: 16127, cores: 1)
*** WARNING: post_fork called for masterpid (pid: 16127)! ***

[nickwilliams-eventbrite]

So do you think this is correct?

    if (getpid() == masterpid) {
        if (uwsgi.master_process) {
            uwsgi_log("*** WARNING: post_fork called for masterpid (pid: %d)! ***\n", uwsgi.mypid);
        }
    } else {
        // debug log if enabled
        PyOS_AfterFork_Child();
    }

Or should I do this (doesn't seem right to me, but just checking)?

    if (getpid() == masterpid && uwsgi.master_process) {
        uwsgi_log("*** WARNING: post_fork called for masterpid (pid: %d)! ***\n", uwsgi.mypid);
    } else {
        // debug log if enabled
        PyOS_AfterFork_Child();
    }

[xrmx]

I'd add just the (ignored in Python 3.7) bits. Eventually we can add a more detailed explanation if it has been called with --py-call-osafterfork.

[nickwilliams-eventbrite]

Ok, I can remove the extra verbiage.

[edufelipe]

@nickwilliams-eventbrite

Hi there! Thanks for this code, it really helped our issue. I have a few quick questions if you don't mind my asking:

1. Are you guys using this patch in production?
2. Do you guys run the master branch on production, instead of the latest tag from the uwsgi-2.0 branch?
3. Could I backport it to 2.0.18 and open a pull request against the uwsgi-2.0 branch? I'll mark you as the author and just be the committer.

Thanks again for all this work :D

[awelzel]

Hey @nickwilliams-eventbrite ,

thanks for taking a stab at that issue. I've looked through your changes and attempted to run them with the test app from #1978 - some thoughts as follows.

1. The exception shown in RuntimeError at startup in Python 3.7.1+ when using --py-call-osafterfork option and logging module #1978 does happen (again) when a worker is respawned after hitting max-requests. E.g starting with the following and sending enough requests should reproduce:

./uwsgi --master --workers 2 --max-requests 5 --min-worker-lifetime 1  --http-socket :9090  --plugin ./python37_plugin.so --wsgi-file ./tests/testosafterfork.py
...
...The work of process 27456 is done (max requests reached (5 >= 5)). Seeya!
worker 1 killed successfully (pid: 27456)
Respawned uWSGI worker 1 (new pid: 27474)
Exception ignored in: <function _releaseLock at 0x7fa63364af28>
Traceback (most recent call last):
  File "/usr/lib/python3.7/logging/__init__.py", line 226, in _releaseLock
    _lock.release()
RuntimeError: cannot release un-acquired lock
Ignoring exception from logging atfork Exception ignored in: <function _after_at_fork_weak_calls at 0x7fa63364c268>                                                                     
Traceback (most recent call last):
  File "/usr/lib/python3.7/logging/__init__.py", line 269, in _after_at_fork_weak_calls
    _at_fork_weak_calls('release')
  File "/usr/lib/python3.7/logging/__init__.py", line 261, in _at_fork_weak_calls
    method_name, "method:", err, file=sys.stderr)
  File "/usr/lib/python3.7/logging/__init__.py", line 1066, in __repr__
    name += ' '
TypeError: unsupported operand type(s) for +=: 'int' and 'str'

2. Using master_fixup() for the PyOS_BeforeFork() does seem a bit off. master_fixup(0) is called before spawning the initial set of workers (with or without an actual master), but only once. And then master_fixup(1) is called in every worker after spawning it, too. I'm somewhat thinking that the master part in the name doesn't actually describe that it'll be executed only in the master, but means something else. IMO calling the hooks should actually be within uwsgi_respawn_worker() where the actual fork is happening.

3. IIUC, the idea is to call PyOS_BeforeFork() and the PyOS_AfterFork_Parent() for every fork() call. I don't think that this is given with your changes, but the flow of execution is a bit hard to follow.

Almost certainly 3) and 2) somehow lead to 1).

Hmm, hmm. I stared at it for quite a while and dabbled around a bit - see branch below. The only real solution I came up with involved adding two plugin hooks pre_fork() and post_fork_parent(). It does survive the simple and respawned test-case, though and maybe it's possible to fold master_fixup() in one...

https://github.com/awelzel/uwsgi/tree/before-after-fork

Thoughts? @xrmx - happy to open that as a separate request if that could be useful?

[zaheerabbas-prodigal]

Is there any update on this PR getting merged and released?

Has anyone found a solution that fixes the Runtime Exceptions, would appreciate any help here. Thanks

[edufelipe]

@zaheerabbas-prodigal They already did something similar in d80f9d9

My company does not use this fix because we found that it is not fully working for mules that fork, but we haven't got the time to port this to Python 3.11 so we are still running this branch under Python 3.8.

[zaheerabbas-prodigal]

@edufelipe - thanks for a quick response. Do you use this branch nickwilliams-eventbrite:fix-py37-errors or the PR branch #2388. We used uWSGI version 2.0.21, the PR #2388 was merged in to the versions we have. But running with flag py-call-uwsgi-fork-hooks raises the weird Runtime lock exception.

[edufelipe]

@zaheerabbas-prodigal we actually use our own branch based on uWSGI 2.0.20: https://github.com/onsigntv/uwsgi/tree/lts