Possible cause and solution of 100% cpu and massive log file in Windows

[Ricardo V G]

Hi,

Recently one of my employer's products (Trend Micro) that includes
nginx Windows binary had an issue similar to [1] where the error
message "[alert] 2548#2552: WaitForMultipleObjects() failed (6: The
handle is invalid)" is generated indefinitely hence creating a massive
log file. This wasn't new. Previously a change was done to the
configuration and it seemed that the issue was fixed. But it
reappeared and I was asked to look into it. Here's what I think could
be the problem along with the solution (patch) at the end of this
email.

When creating threads in a Windows system the following calls are made
(using release 1.2.2):

main() ->
    ngx_master_process_cycle() ->
        ngx_start_worker_processes() ->
            ngx_start_worker_processes() ->
                ngx_spawn_process()

The issue appears in one documented case when
ngx_start_worker_processes() fails to create a thread and the
following error message is generated:

    [alert] 2548#2552: the event "ngx_master_2548" was not signaled for 5s

When this message is generated, the execution jumps to the failed
label using a goto in os/win32/ngx_process.c at line 150. From there
on, the function attempts to close all opened handles and returns an
error in the form of an invalid process/thread ID. It's important to
note that the thread handle is closed if necessary but the global
variable that holds it is not cleared (i.e. the global array
ngx_processes[] defined in os/win32/ngx_process.c at line 17 keeps all
handles).


    ngx_pid_t ngx_spawn_process(ngx_cycle_t *cycle, char *name,
ngx_int_t respawn)
    {
    [...]
        rc = WaitForMultipleObjects(2, events, 0, 5000);
    [...]
        switch (rc) {
    [...]
        case WAIT_FAILED:
            ngx_log_error(NGX_LOG_ALERT, cycle->log, ngx_errno,
                          "WaitForSingleObject(\"%s\") failed",
                          ngx_master_process_event_name);

            goto failed;
        }
    [...]
    failed:
    [...]
        if (ngx_processes[s].handle) {
            ngx_close_handle(ngx_processes[s].handle);
        }

        return NGX_INVALID_PID;
    }


With the error in hand, ngx_start_worker_processes() in
os/win32/ngx_process_cycle.c breaks the loop and returns with the
number of threads that were successfully started.

    static ngx_int_t ngx_start_worker_processes(ngx_cycle_t *cycle,
ngx_int_t type)
    {
    [...]
        for (n = 0; n < ccf->worker_processes; n++) {
            if (ngx_spawn_process(cycle, "worker", type) == NGX_INVALID_PID) {
                break;
            }
        }

        return n;
    }


Finally ngx_master_process_cycle(), defined in
os/win32/ngx_process_cycle.c, checks if there are any threads and
exits if none has started. But if there are any threads that were
successfully started then it continues.

At this point, ngx_master_process_cycle() enters a forever loop where
a call is made to WaitForMultipleObjects() using all the handles
obtained from ngx_processes[] including the handle that was already
closed by ngx_start_worker_processes().

    void ngx_master_process_cycle(ngx_cycle_t *cycle)
    {
    [...]
        if (ngx_start_worker_processes(cycle, NGX_PROCESS_RESPAWN) == 0) {
            exit(2);
        }
    [...]
        for ( ;; ) {
    [...]
            for (n = 0; n < ngx_last_process; n++) {
                if (ngx_processes[n].handle) {
                    events[nev++] = ngx_processes[n].handle;
                }
            }
    [...]
            ev = WaitForMultipleObjects(nev, events, 0, timeout);
    [...]
            if (ev == WAIT_FAILED) {
                ngx_log_error(NGX_LOG_ALERT, cycle->log, err,
                              "WaitForMultipleObjects() failed");

                continue;
            }
    [...]
        }
    }


Because the handle is invalid, WaitForMultipleObjects() returns
immediately with WAIT_FAILED triggering the first error shown in this
email followed by a "continue" statement which goes back at the start
of the loop again still with the invalid handle. This will be repeated
forever since the handle is always invalid.

I believe that the simplest fix that doesn't modify the logic of the
program is to clear the thread handle in ngx_process.c failed section
once they have been closed by setting the variable zero as shown
below.

What do you think?

/ricardo

[1] nginx windows freezes with 100% CPU and massive error log
http://forum.nginx.org/read.php?2,27839,27839



--- a/src/os/win32/ngx_process.c
+++ b/src/os/win32/ngx_process.c
@@ -196,6 +196,7 @@ failed:

     if (ngx_processes[s].handle) {
         ngx_close_handle(ngx_processes[s].handle);
+        ngx_processes[s].handle = 0;
     }

     return NGX_INVALID_PID;