diff --git a/modules/proxy/mod_proxy_connect.c b/modules/proxy/mod_proxy_connect.c index 0f7a465..165545f 100644 --- a/modules/proxy/mod_proxy_connect.c +++ b/modules/proxy/mod_proxy_connect.c @@ -16,6 +16,8 @@ /* CONNECT method for Apache proxy */ +#define DEBUGGING 1 + #include "mod_proxy.h" #include "apr_poll.h" @@ -417,39 +419,50 @@ static int proxy_connect_handler(request_rec *r, proxy_worker *worker, if (cur->desc.s == backend.pfd.desc.s) { pollevent = cur->rtnevents; - if (pollevent & (APR_POLLIN | APR_POLLHUP)) { + if (pollevent & (APR_POLLIN | APR_POLLHUP) && !client.c->data_in_output_filters) { #ifdef DEBUGGING ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) "backend was readable"); #endif + apr_socket_timeout_set(client.pfd.desc.s, 10); rv = ap_proxy_transfer_between_connections(r, backend.c, client.c, backend.bb, client.bb, "backend", NULL, CONN_BLKSZ, AP_PROXY_TRANSFER_FLUSH_NEVER); - if (rv == APR_SUCCESS - && client.c->data_in_output_filters) { + apr_socket_timeout_set(client.pfd.desc.s, client.timeout); + if ( rv == APR_SUCCESS && client.c->data_in_output_filters ) { + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "backend->client: Incomplete write. Adding POLLOUT to client pollset"); apr_pollset_remove(pollset, &client.pfd); - client.pfd.reqevents = APR_POLLOUT; + client.pfd.reqevents = APR_POLLOUT | APR_POLLIN | APR_POLLHUP; apr_pollset_add(pollset, &client.pfd); - if (backend.pfd.reqevents & APR_POLLIN) { - apr_pollset_remove(pollset, &backend.pfd); - } } - done |= rv != APR_SUCCESS; + if ( rv != APR_SUCCESS && !APR_STATUS_IS_EAGAIN(rv) ) { + done = 1; + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "POLLIN on backend: failed: done=1: rv=%d", rv); + } } else if (pollevent & APR_POLLOUT) { - rv = client.core_output(client.core_filter, NULL); + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "client->backend: got POLLOUT on backend"); + apr_socket_timeout_set(backend.pfd.desc.s, 10); + rv = backend.core_output(backend.core_filter, NULL); + apr_socket_timeout_set(backend.pfd.desc.s, backend.timeout); if (rv == APR_SUCCESS - && !client.c->data_in_output_filters) { - apr_pollset_remove(pollset, &client.pfd); - client.pfd.reqevents = APR_POLLIN | APR_POLLHUP; - apr_pollset_add(pollset, &client.pfd); - if (backend.pfd.reqevents & APR_POLLIN) { - apr_pollset_add(pollset, &backend.pfd); - } + && !backend.c->data_in_output_filters) { + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "client->backend: backend output filters flushed, restoring normal polling"); + apr_pollset_remove(pollset, &backend.pfd); + backend.pfd.reqevents = APR_POLLIN | APR_POLLHUP; + apr_pollset_add(pollset, &backend.pfd); } - done |= rv != APR_SUCCESS && !APR_STATUS_IS_EAGAIN(rv); + if ( rv != APR_SUCCESS && !APR_STATUS_IS_EAGAIN(rv) ) { + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "POLLOUT on backend: failed: done=1: rv=%d", rv); + done = 1; + } } else if (pollevent & APR_POLLERR) { ap_log_rerror(APLOG_MARK, APLOG_NOTICE, 0, r, APLOGNO(01026) @@ -460,39 +473,50 @@ static int proxy_connect_handler(request_rec *r, proxy_worker *worker, } else if (cur->desc.s == client.pfd.desc.s) { pollevent = cur->rtnevents; - if (pollevent & (APR_POLLIN | APR_POLLHUP)) { + if (pollevent & (APR_POLLIN | APR_POLLHUP) && !backend.c->data_in_output_filters) { #ifdef DEBUGGING ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01027) "client was readable"); #endif + apr_socket_timeout_set(backend.pfd.desc.s, 10); rv = ap_proxy_transfer_between_connections(r, client.c, backend.c, client.bb, backend.bb, "client", NULL, CONN_BLKSZ, AP_PROXY_TRANSFER_FLUSH_NEVER); - if (rv == APR_SUCCESS - && backend.c->data_in_output_filters) { + apr_socket_timeout_set(backend.pfd.desc.s, backend.timeout); + if ( rv == APR_SUCCESS && backend.c->data_in_output_filters) { + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "client->backend: Incomplete write. Adding POLLOUT to backend pollset"); apr_pollset_remove(pollset, &backend.pfd); - backend.pfd.reqevents = APR_POLLOUT; + backend.pfd.reqevents = APR_POLLOUT | APR_POLLIN | APR_POLLHUP; apr_pollset_add(pollset, &backend.pfd); - if (client.pfd.reqevents & APR_POLLIN) { - apr_pollset_remove(pollset, &client.pfd); - } } - done |= rv != APR_SUCCESS; + if ( rv != APR_SUCCESS && !APR_STATUS_IS_EAGAIN(rv) ) { + done = 1; + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "POLLIN on client: failed: done=1: rv=%d", rv); + } } else if (pollevent & APR_POLLOUT) { - rv = backend.core_output(backend.core_filter, NULL); + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "backend->client: got POLLOUT on client"); + apr_socket_timeout_set(client.pfd.desc.s, 10); + rv = client.core_output(client.core_filter, NULL); + apr_socket_timeout_set(client.pfd.desc.s, client.timeout); if (rv == APR_SUCCESS - && !backend.c->data_in_output_filters) { - apr_pollset_remove(pollset, &backend.pfd); - backend.pfd.reqevents = APR_POLLIN | APR_POLLHUP; - apr_pollset_add(pollset, &backend.pfd); - if (client.pfd.reqevents & APR_POLLIN) { - apr_pollset_add(pollset, &client.pfd); - } + && !client.c->data_in_output_filters) { + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "backend->client: client output filters flushed, restoring normal polling"); + apr_pollset_remove(pollset, &client.pfd); + client.pfd.reqevents = APR_POLLIN | APR_POLLHUP; + apr_pollset_add(pollset, &client.pfd); } - done |= rv != APR_SUCCESS && !APR_STATUS_IS_EAGAIN(rv); + if ( rv != APR_SUCCESS && !APR_STATUS_IS_EAGAIN(rv) ) { + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(01025) + "POLLOUT on client: failed: done=1: rv=%d", rv); + done = 1; + } } else if (pollevent & APR_POLLERR) { ap_log_rerror(APLOG_MARK, APLOG_NOTICE, 0, r, APLOGNO(02827) diff --git a/modules/proxy/proxy_util.c b/modules/proxy/proxy_util.c index 33ce9bc..e85afb1 100644 --- a/modules/proxy/proxy_util.c +++ b/modules/proxy/proxy_util.c @@ -3787,6 +3787,9 @@ PROXY_DECLARE(apr_status_t) ap_proxy_transfer_between_connections( APR_NONBLOCK_READ, bsize); if (rv == APR_SUCCESS) { if (c_o->aborted) { + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, APLOGNO(03306) + "ap_proxy_transfer_between_connections: " + "%s is marked as aborted, returning EPIPE", name); return APR_EPIPE; } if (APR_BRIGADE_EMPTY(bb_i)) { diff --git a/server/core_filters.c b/server/core_filters.c index 91d53f1..c4f765a 100644 --- a/server/core_filters.c +++ b/server/core_filters.c @@ -805,6 +805,13 @@ static apr_status_t send_brigade_blocking(apr_socket_t *s, apr_socket_timeout_get(s, &timeout); do { rv = apr_poll(&pollset, 1, &nsds, timeout); + if ( timeout < 1000 && APR_STATUS_IS_TIMEUP(rv) ) { + ap_log_cerror(APLOG_MARK, CORE_LOG_LEVEL_IO, rv, c, + "send_brigade_blocking: TIMEUP on small timeout (%d), returning EAGAIN", + timeout); + rv = APR_INCOMPLETE; + goto out; + } } while (APR_STATUS_IS_EINTR(rv)); if (rv == APR_SUCCESS) { continue; @@ -813,6 +820,7 @@ static apr_status_t send_brigade_blocking(apr_socket_t *s, break; } } +out: return rv; }