While trying to figure out why the May 17 patch in my case does not behave as expected, I was adding some extra debug output to server_fcgi_read, server_fcgi_header and server_fcgi_writechunk and started a httpd debug session during which I was signing in and out of a WordPress site's admin interface. Both actions were delayed by 30 seconds which corresponds to the request timeout specified in the httpd configuration. Please find attached the session transcript and my additions to server_fcgi.c.
The two places of importance are lines 314 and 2195 where the patch forces fcgi.chunked to be 0 assuming there is no content because server_fcgi_header was called in the course of an FCGI_END_REQUEST. Is it possible this was not correct here as we actually did have content?
void
server_fcgi_read(struct bufferevent *bev, void *arg)
{
uint8_t buf[FCGI_RECORD_SIZE];
struct client *clt = (struct client *) arg;
struct fcgi_record_header *h;
size_t len;
char *ptr;
do {
len = bufferevent_read(bev, buf, clt->clt_fcgi.toread);
if (evbuffer_add(clt->clt_srvevb, buf, len) == -1) {
server_abort_http(clt, 500, "short write");
return;
}
clt->clt_fcgi.toread -= len;
DPRINTF("%s: len: %lu toread: %d state: %d type: %d",
__func__, len, clt->clt_fcgi.toread,
clt->clt_fcgi.state, clt->clt_fcgi.type);
if (clt->clt_fcgi.toread != 0)
return;
switch (clt->clt_fcgi.state) {
case FCGI_READ_HEADER:
clt->clt_fcgi.state = FCGI_READ_CONTENT;
h = (struct fcgi_record_header *)
EVBUFFER_DATA(clt->clt_srvevb);
DPRINTF("%s: record header: version %d type %d id %d "
"content len %d padding %d", __func__,
h->version, h->type, ntohs(h->id),
ntohs(h->content_len), h->padding_len);
clt->clt_fcgi.type = h->type;
clt->clt_fcgi.toread = ntohs(h->content_len);
clt->clt_fcgi.padding_len = h->padding_len;
evbuffer_drain(clt->clt_srvevb,
EVBUFFER_LENGTH(clt->clt_srvevb));
if (clt->clt_fcgi.toread != 0)
break;
else if (clt->clt_fcgi.type == FCGI_STDOUT &&
!clt->clt_chunk) {
server_abort_http(clt, 500, "empty stdout");
return;
}
/* fallthrough if content_len == 0 */
case FCGI_READ_CONTENT:
switch (clt->clt_fcgi.type) {
case FCGI_STDERR:
if (EVBUFFER_LENGTH(clt->clt_srvevb) > 0 &&
(ptr = get_string(
EVBUFFER_DATA(clt->clt_srvevb),
EVBUFFER_LENGTH(clt->clt_srvevb)))
!= NULL) {
server_sendlog(clt->clt_srv_conf,
IMSG_LOG_ERROR, "%s", ptr);
free(ptr);
}
break;
case FCGI_STDOUT:
++clt->clt_chunk;
DPRINTF("*** STDOUT: chunk=%d headersdone=%d",
clt->clt_chunk, clt->clt_fcgi.headersdone);
if (!clt->clt_fcgi.headersdone) {
clt->clt_fcgi.headersdone =
server_fcgi_getheaders(clt);
if (!EVBUFFER_LENGTH(clt->clt_srvevb)) {
DPRINTF("*** NO MORE DATA");
break;
}
}
/* FALLTHROUGH */
case FCGI_END_REQUEST:
if (clt->clt_fcgi.type != FCGI_END_REQUEST)
DPRINTF("*** FALLTHROUGH from STDOUT: "
"type=%d headerssent=%d",
clt->clt_fcgi.type,
clt->clt_fcgi.headerssent);
else
DPRINTF("*** END_REQUEST: "
"headerssent=%d",
clt->clt_fcgi.headerssent);
if (clt->clt_fcgi.headersdone &&
!clt->clt_fcgi.headerssent) {
if (server_fcgi_header(clt,
clt->clt_fcgi.status) == -1) {
server_abort_http(clt, 500,
"malformed fcgi headers");
return;
}
}
if (server_fcgi_writechunk(clt) == -1) {
server_abort_http(clt, 500,
"encoding error");
return;
}
break;
}
evbuffer_drain(clt->clt_srvevb,
EVBUFFER_LENGTH(clt->clt_srvevb));
if (!clt->clt_fcgi.padding_len) {
clt->clt_fcgi.state = FCGI_READ_HEADER;
clt->clt_fcgi.toread =
sizeof(struct fcgi_record_header);
} else {
clt->clt_fcgi.state = FCGI_READ_PADDING;
clt->clt_fcgi.toread =
clt->clt_fcgi.padding_len;
}
break;
case FCGI_READ_PADDING:
evbuffer_drain(clt->clt_srvevb,
EVBUFFER_LENGTH(clt->clt_srvevb));
clt->clt_fcgi.state = FCGI_READ_HEADER;
clt->clt_fcgi.toread =
sizeof(struct fcgi_record_header);
break;
}
} while (len > 0);
}
int
server_fcgi_header(struct client *clt, unsigned int code)
{
struct server_config *srv_conf = clt->clt_srv_conf;
struct http_descriptor *desc = clt->clt_descreq;
struct http_descriptor *resp = clt->clt_descresp;
const char *error;
char tmbuf[32];
struct kv *kv, *cl, key;
clt->clt_fcgi.headerssent = 1;
DPRINTF("*** SENDING HEADERS: fcgi.chunked=%d", clt->clt_fcgi.chunked);
if (desc == NULL || (error = server_httperror_byid(code)) == NULL)
return (-1);
if (server_log_http(clt, code, 0) == -1)
return (-1);
/* Add error codes */
if (kv_setkey(&resp->http_pathquery, "%u", code) == -1 ||
kv_set(&resp->http_pathquery, "%s", error) == -1)
return (-1);
/* Add headers */
if (kv_add(&resp->http_headers, "Server", HTTPD_SERVERNAME) == NULL)
return (-1);
if (clt->clt_fcgi.type == FCGI_END_REQUEST ||
EVBUFFER_LENGTH(clt->clt_srvevb) == 0) {
DPRINTF("*** FORCING CHUNKED=0: fcgi.type=%d evblen=%zu",
clt->clt_fcgi.type, EVBUFFER_LENGTH(clt->clt_srvevb));
/* Can't chunk encode an empty body. */
clt->clt_fcgi.chunked = 0;
}
/* Set chunked encoding */
if (clt->clt_fcgi.chunked) {
/* XXX Should we keep and handle Content-Length instead? */
key.kv_key = "Content-Length";
if ((kv = kv_find(&resp->http_headers, &key)) != NULL)
kv_delete(&resp->http_headers, kv);
/*
* XXX What if the FastCGI added some kind of Transfer-Encoding?
* XXX like gzip, deflate or even "chunked"?
*/
if (kv_add(&resp->http_headers,
"Transfer-Encoding", "chunked") == NULL)
return (-1);
}
/* Is it a persistent connection? */
if (clt->clt_persist) {
if (kv_add(&resp->http_headers,
"Connection", "keep-alive") == NULL)
return (-1);
} else if (kv_add(&resp->http_headers, "Connection", "close") == NULL)
return (-1);
/* HSTS header */
if (srv_conf->flags & SRVFLAG_SERVER_HSTS &&
srv_conf->flags & SRVFLAG_TLS) {
if ((cl =
kv_add(&resp->http_headers, "Strict-Transport-Security",
NULL)) == NULL ||
kv_set(cl, "max-age=%d%s%s", srv_conf->hsts_max_age,
srv_conf->hsts_flags & HSTSFLAG_SUBDOMAINS ?
"; includeSubDomains" : "",
srv_conf->hsts_flags & HSTSFLAG_PRELOAD ?
"; preload" : "") == -1)
return (-1);
}
/* Date header is mandatory and should be added as late as possible */
key.kv_key = "Date";
if (kv_find(&resp->http_headers, &key) == NULL &&
(server_http_time(time(NULL), tmbuf, sizeof(tmbuf)) <= 0 ||
kv_add(&resp->http_headers, "Date", tmbuf) == NULL))
return (-1);
if (server_writeresponse_http(clt) == -1 ||
server_bufferevent_print(clt, "\r\n") == -1 ||
server_headers(clt, resp, server_writeheader_http, NULL) == -1 ||
server_bufferevent_print(clt, "\r\n") == -1)
return (-1);
return (0);
}
int
server_fcgi_writechunk(struct client *clt)
{
struct evbuffer *evb = clt->clt_srvevb;
size_t len;
if (clt->clt_fcgi.type == FCGI_END_REQUEST) {
len = 0;
} else
len = EVBUFFER_LENGTH(evb);
DPRINTF("*** WRITING CHUNK: fcgi.type=%d fcgi.chunked=%d fcgi.end=%d",
clt->clt_fcgi.type, clt->clt_fcgi.chunked, clt->clt_fcgi.end);
if (clt->clt_fcgi.chunked) {
/* If len is 0, make sure to write the end marker only once */
if (len == 0 && clt->clt_fcgi.end++)
return (0);
if (server_bufferevent_printf(clt, "%zx\r\n", len) == -1 ||
server_bufferevent_write_chunk(clt, evb, len) == -1 ||
server_bufferevent_print(clt, "\r\n") == -1)
return (-1);
} else if (len)
return (server_bufferevent_write_buffer(clt, evb));
return (0);
}
httpd_debug.out.gz
Description: GNU Zip compressed data
