App restart delay (5s) / shutdown-timeout should be shortcutted if daemon process is idle (no requests)

[QuadrupleA]

I've been digging into some slow restart problems on one of our VMs using bpftrace (sometimes 60+ seconds for a full httpd restart). Along the way I noticed a possible performance issue (or at least possible improvement) with the restart of individual WSGI apps / daemon processes.

The shutdown-timeout option (default 5 seconds) on WSGIDaemonProcess seems to be a mandatory wait, rather than "wait up to N seconds until idle". The behavior is roughly:

1. touch the WSGI script (application.py)
2. make a request to the app, triggering a daemon process restart; apache holds connection open and browser starts waiting for response
3. from tracing, I see the old daemon process PID makes a 5 second nanosleep() syscall during which nothing happens (the app is idle and receiving no requests besides the pending test request)
4. the nanosleep period ends, the old daemon process shuts down, and the new one is cloned and started up
5. the new daemon process handles the request

It would be nice, during #3, if the daemon process is idle (no requests), to restart immediately, rather than requiring waiting the full shutdown-timeout each time. It would be less delays for users when apps need a quick patch, less chance of secondary bugs and issues happening due to the delayed requests, etc.

Happy to share more details if it sounds like something particular to our Apache configuration.

Side note, thanks to Graham for his longtime, dedicated support (both documentation / assistance, and coding) on this excellent module. It's been sitting reliably at the foundation of our applications for years, and when I've needed it I've nearly always found the documentation, expert StackOverflow answer from him, etc. to help.

[GrahamDumpleton]

The five second sleep you see is a fail safe to force exit if it the process hasn't shutdown.

In other words, a background thread is created which sleeps 5 seconds and if that completes, calls exit().

static void *wsgi_reaper_thread(apr_thread_t *thd, void *data)
{
    WSGIDaemonProcess *daemon = data;

    sleep(daemon->group->shutdown_timeout);

    ap_log_error(APLOG_MARK, APLOG_INFO, 0, wsgi_server,
                 "mod_wsgi (pid=%d): Aborting process '%s'.",
                 getpid(), daemon->group->name);

    wsgi_exit_daemon_process(-1);

    return NULL;
}

While this is running the main thread should start the shutdown if everything is idle, at least that is my memory of how should work.

    if (daemon->group->shutdown_timeout) {
        rv = apr_thread_create(&reaper, thread_attr, wsgi_reaper_thread,
                               daemon, p);

        if (rv != APR_SUCCESS) {
            ap_log_error(APLOG_MARK, APLOG_ALERT, rv, wsgi_server,
                         "mod_wsgi (pid=%d): Couldn't create reaper "
                         "thread in daemon process '%s'.", getpid(),
                         daemon->group->name);
        }
    }

    /*
     * If shutting down process due to reaching request time
     * limit, then try and dump out stack traces of any threads
     * which are running as a debugging aid.
     */

    wsgi_publish_process_stopping(wsgi_shutdown_reason);

#if (PY_MAJOR_VERSION >= 3) || (PY_MAJOR_VERSION == 2 && PY_MINOR_VERSION >= 5)
    if (wsgi_dump_stack_traces)
        wsgi_log_stack_traces();
#endif

    /*
     * Attempt a graceful shutdown by waiting for any
     * threads which were processing a request at the time
     * of shutdown. In some respects this is a bit pointless
     * as even though we allow the requests to be completed,
     * the Apache child process which proxied the request
     * through to this daemon process could get killed off
     * before the daemon process and so the response gets
     * cut off or lost.
     */

    wsgi_worker_shutdown();

    for (i=0; i<daemon->group->threads; i++) {
        if (wsgi_worker_threads[i].thread && wsgi_worker_threads[i].running) {
            rv = apr_thread_join(&thread_rv, wsgi_worker_threads[i].thread);
            if (rv != APR_SUCCESS) {
                ap_log_error(APLOG_MARK, APLOG_CRIT, rv, wsgi_server,
                             "mod_wsgi (pid=%d): Couldn't join with "
                             "worker thread %d in daemon process '%s'.",
                             getpid(), i, daemon->group->name);
            }
        }
    }

Where waiting for request thread shutdown is:

static apr_status_t wsgi_worker_shutdown(void)
{
    int i;
    apr_status_t rv;
    WSGIThreadStack *stack = wsgi_worker_stack;

    while (1) {
        apr_uint32_t state = stack->state;
        if (apr_atomic_cas32(&(stack->state), state | WSGI_STACK_TERMINATED,
                           state) == state) {
            break;
        }
    }
    for (i = 0; i < wsgi_daemon_process->group->threads; i++) {
        if ((rv = wsgi_worker_release()) != APR_SUCCESS) {
            return rv;
        }
    }
    return APR_SUCCESS;
}

So it should only reach 5 seconds if there requests still running.

One thing to try is set:

WSGIDestroyInterpreter Off

Since about Python 3.9 (or maybe 3.10), core Python behaviour changed such that it will try also waiting on daemon threads (not just non daemon threads) when shutting down a process. If an application uses daemon threads and doesn't have a way of cleanly terminating on interpreter destruction via atexit() callback, it will hold up process shutdown and 5 seconds would expire.

So try disabling destruction of the Python interpreter on process shutdown. You may find the issue goes away.

If it does go away, but still need to trigger actions on process shutdown, you can use:

import mod_wsgi

def shutdown_handler(event, **kwargs):
    print('SHUTDOWN-HANDLER', event, kwargs)

mod_wsgi.subscribe_shutdown(shutdown_handler)

to have mod_wsgi call a shutdown handler in independent of atexit() mechanism, since atexit() will not be trigged when interpreter is not destroyed.

[QuadrupleA]

Thanks Graham, interesting - adding WSGIDestroyInterpreter Off to the server config indeed resolves the delay for app restarts. So that's an acceptible fix for my purposes, as I'm not using any atexit handlers or mod_wsgi module shutdown callbacks (good to know those exist). The grace period for request threads to finish is generally enough cleanup-wise.

So I can understand it better - the app I was tracing / experimenting on uses bottle.py, and neither it nor the app spawn any daemon threads directly. This is on python 3.11.6. But I guess at least one daemon thread must be spawned indirectly in the standard library internals? And the interpreter destruction by mod_wsgi is held up while those daemon threads time out?

Tricky, would be nice to have app restarts be as instant as possible for everyone with the default configuration, but obviously don't want to break apps that rely on atexit etc. for cleanup.

[GrahamDumpleton]

If know is configured this way, you could always have the mod_wsgi shutdown callback call atexit._run_exitfuncs().

Although I have to check whether I may even do that if know situation. Can't remember.

[QuadrupleA]

Interestingly, when I tried registering an atexit handler on app startup, it never fired at all on restarts, whether WSGIDestroyInterpreter was Off or On:

import atexit
def at_exit_handler():
    with open(os.path.join(app_base_path, 'log.txt'), 'a') as file:
        file.write('fired at_exit_handler().\n')
atexit.register(at_exit_handler)

But the mod_wsgi shutdown handler fired on both:

import mod_wsgi
def shutdown_handler(event, **kwargs):
    with open(os.path.join(app_base_path, 'log.txt'), 'a') as file:
        file.write('fired shutdown_handler().\n')
mod_wsgi.subscribe_shutdown(shutdown_handler)

So maybe WSGIDestroyInterpreter Off could safely be the default? Not sure if there are other compatibility implications. It's helped make app restarts snappy on our systems (though I'm still troubleshooting the slowness for full-httpd restarts).

[GrahamDumpleton]

This may be the part of the stupidity of the changes they made to Python to wait for daemon threads. They may well do that before atexit() handlers are called, or as a side effect of one, so if that hangs it will never get to run the others. There is a lot of stupid history around calling of atexit() handlers by Python and have had to adjust to two or three different ways they tried to do things over the years with workarounds as they didn't do it in a place that would allow threads to be shutdown properly. Maybe they changed it again and I didn't realise and it is the reason for all the problems. I guess when I get a chance some time I will need to go and look at what they are up to again.

[GrahamDumpleton]

BTW, do you use:

WSGIApplicationGroup %{GLOBAL}

or the application-group=%{GLOBAL} option to WSGIScriptAlias?

Want to work out if using are using Python sub interpreter or main interpreter context, which is what options above force.

These issues with shutdown may affect sub interpreters specifically.

[QuadrupleA]

Interesting about all the atexit / daemon thread inconsistency. Glad mod_wsgi.subscribe_shutdown() is available if I need it.

Re: application group, I set an explicit process group, but not application group, so looks like it'd use the default %{RESOURCE}. My app configurations are usually like below, with a distinct process group per app:

<VirtualHost *:443>
    # ...
    WSGIDaemonProcess lukerissacher display-name=%{GROUP} lang=en_US.UTF-8 locale=en_US.UTF-8 threads=4 stack-size=1048576
    WSGIScriptAlias / "/var/www/wsgi/LukeRissacher/application.py" process-group=lukerissacher
</VirtualHost>

[GrahamDumpleton]

If you only ever have the one web application per mod_wsgi daemon process group, it is recommended to force use of the main interpreter context. Thus:

WSGIScriptAlias / "/var/www/wsgi/LukeRissacher/application.py" process-group=lukerissacher application-group=%{GLOBAL}

This avoids various problems with third party Python packages, and even some corner cases in Python standard packages, where they do not work in sub interpreters.

So try that, and remove WSGIDestroyInterpreter and see if that also solves the issue. It may not, but still recommended to set the application to the main interpreter context if just the one web application per mod_wsgi daemon process group.

[QuadrupleA]

Thanks! So yes, setting WSGIScriptAlias ... application-group=%{GLOBAL} (and reverting WSGIDestroyInterpreter to its default) fixes the 5-second app restart delay, nearly instant now when my application.py files are touched. The full-httpd restarts are still sometimes 60+ seconds, but not sure that has anything to do with mod_wsgi.

Didn't realize the default spawned an extra sub-interpreter per daemon process. I'll try and reread the mod_wsgi docs & maybe source code a bit when I get some time, it's been a few years.

I tested atexit and mod_wsgi.subscribe_shutdown() also, atexit still doesn't fire on restarts with the app in the main interpreter (with either WSGIDestroyInterpreter setting) but subscribe_shutdown() handlers still do.

One bonus, this seems to have saved about 10mb memory per daemon process - with 20+ apps on some of my VMs that's actually pretty significant. The apps are CPU- and RAM-efficient but the OS and python RAM overhead has been steadily bloating over the years and reducing how much I can do on a particular VM. So that's a nice win.

[QuadrupleA]

Feel free close this issue if you like BTW - for my purposes, adding WSGIScriptAlias ... application-group=%{GLOBAL} to all our apps solved the individual app-restart delay, as did adding WSGIDestroyInterpreter Off in the prior configuration.

For others with daemon process sub-interpreters and the default WSGIDestroyInterpreter setting, it might be good to avoid the delay somehow, but not sure the time/effort required.