[Koha-bugs] [Bug 26128] Proxy Error while importing a large number of patrons (e.g. 6000 patrons) with Plack

[bugzilla-daemon at bugs.koha-community.org]

https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=26128

--- Comment #21 from David Cook <dcook at prosentient.com.au> ---
I'm reading through the httpd source code for 2.4.25 (the Apache httpd used in
koha-testing-docker) from https://github.com/apache/httpd, and it's not clear
why Apache didn't return the 504 until after 10 minutes (600 seconds).

Looking at "modules/generators/mod_cgi.c", I can see the "cgi_handler"...

It calls "run_cgi_child", and it sets a timeout
"apr_file_pipe_timeout_set(*script_out, r->server->timeout);"

The "cgi_handler" calls "apr_bucket_read" which should map to
"cgi_bucket_read". That runs "rv = apr_pollset_poll(data->pollset, timeout,
&num, &results);" in a loop, which runs the following:

if (APR_STATUS_IS_TIMEUP(rv)) {
    if (timeout) {
        ap_log_rerror(APLOG_MARK, APLOG_WARNING, 0, data->r, APLOGNO(01220)
                      "Timeout waiting for output from CGI script %s",
                      data->r->filename);
        return rv;
    }
    else {
        return APR_EAGAIN;
    }
}

Based on the Koha Apache logs, we did get this after the first 5 minutes (300
seconds). 

But then we got the message "Script timed out before returning headers"...

So if we keep going down the "cgi_handler", we get to
"ap_scan_script_header_err_brigade_ex", which ultimately maps to
"ap_scan_script_header_err_core_ex" in "server/util_script.c". We can see the
following code there:

ap_log_rerror(SCRIPT_LOG_MARK, APLOG_ERR|APLOG_TOCLIENT, 0, r,
              "Script timed out before returning headers: %s",
              apr_filepath_name_get(r->filename));
return HTTP_GATEWAY_TIME_OUT;

Now that should've been when we got our 504 from Apache httpd... but it's not.
As per the Koha Apache logs, there was a "Timeout waiting for output from CGI
script" timeout followed by "Script timed out before returning headers", but
the CGI script kept running after that and unless I got my timing wrong (which
is possible) then Apache kept running too... since we got a 2nd "Timeout
waiting for output from CGI script" timeout.

It's almost like it tried to gracefully stop/close the CGI script... but then
after getting another timeout it just killed it. 

It does look like after "ap_scan_script_header_err_brigade_ex" returns then
"log_script" is run... and that runs "discard_script_output" and that does
another "apr_bucket_read" although I think that's for a different bucket...

-- 
You are receiving this mail because:
You are watching all bug changes.