You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@httpd.apache.org by Ruediger Pluem <rp...@apache.org> on 2020/05/27 10:40:59 UTC
Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
I try to understand the logic of mod_proxy_http2 with respect to timeouts. I am currently stuck at this piece of code in
h2_proxy_session_process in h2_proxy_session.c
case H2_PROXYS_ST_BUSY:
case H2_PROXYS_ST_LOCAL_SHUTDOWN:
case H2_PROXYS_ST_REMOTE_SHUTDOWN:
have_written = send_loop(session);
if (nghttp2_session_want_read(session->ngh2)) {
status = h2_proxy_session_read(session, 0, 0);
if (status == APR_SUCCESS) {
have_read = 1;
}
}
if (!have_written && !have_read
&& !nghttp2_session_want_write(session->ngh2)) {
dispatch_event(session, H2_PROXYS_EV_NO_IO, 0, NULL);
goto run_loop;
}
break;
case H2_PROXYS_ST_WAIT:
if (check_suspended(session) == APR_EAGAIN) {
/* no stream has become resumed. Do a blocking read with
* ever increasing timeouts... */
if (session->wait_timeout < 25) {
session->wait_timeout = 25;
}
else {
session->wait_timeout = H2MIN(apr_time_from_msec(100),
2*session->wait_timeout);
}
status = h2_proxy_session_read(session, 1, session->wait_timeout);
ap_log_cerror(APLOG_MARK, APLOG_TRACE3, status, session->c,
APLOGNO(03365)
"h2_proxy_session(%s): WAIT read, timeout=%fms",
session->id, session->wait_timeout/1000.0);
if (status == APR_SUCCESS) {
have_read = 1;
dispatch_event(session, H2_PROXYS_EV_DATA_READ, 0, NULL);
}
else if (APR_STATUS_IS_TIMEUP(status)
|| APR_STATUS_IS_EAGAIN(status)) {
/* go back to checking all inputs again */
transit(session, "wait cycle", H2_PROXYS_ST_BUSY);
}
Doesn't that loop forever with in the end 100ms blocking reads from the backend if the backend never replies?
The state of the session seems to switch between H2_PROXYS_ST_BUSY (set in line 1454) and H2_PROXYS_ST_WAIT set
by ev_no_io. Do I miss the exit?
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Ruediger Pluem <rp...@apache.org>.
On 6/3/20 4:09 PM, Stefan Eissing wrote:
> Made some adjustments to have it work for all the "we wait for sth from backend" and added as r1878433 in trunk.
Looks very nice. Thank you very much.
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
Made some adjustments to have it work for all the "we wait for sth from backend" and added as r1878433 in trunk.
> Am 02.06.2020 um 09:37 schrieb Stefan Eissing <st...@greenbytes.de>:
>
> Looks good!
>
>> Am 29.05.2020 um 21:14 schrieb Ruediger Pluem <rp...@apache.org>:
>>
>>
>>
>> On 5/29/20 11:41 AM, Stefan Eissing wrote:
>>>
>>>
>>>> Am 29.05.2020 um 11:23 schrieb Ruediger Pluem <rp...@apache.org>:
>>>>
>>>>
>>>>
>>>> On 5/29/20 10:09 AM, Stefan Eissing wrote:
>>>>> Looks good. Now I learned about the "ping" parameter...
>>>>
>>>> Committed as r1878264 with a tweaked comment to make clear what I do.
>>
>> Thanks for backporting both
>>
>>>>
>>>> Getting me to the next possible enhancement. I already had a patch but when putting it to the mail I got doubts that it could work
>>>> due to the fact, that in most use cases HTTP/2 is encrypted.
>>>> In AJP a set ping parameter on the worker will also cause an AJP ping to be sent as the first thing even on fresh connections and
>>>> we only wait for the timeout set in the parameter for a reply. The idea behind this is that the backend might be able to deal with
>>>> a TCP handshake, but not with processing a request, because maybe all processing threads / processes on the backend application
>>>> are busy. This way this can be detected quickly and early and we can sent our request to a different backend in case of a load
>>>> balancing scenario.
>>>> With HTTP/2 we will likely have a TLS handshake first which likely already requires a responding backend application. So it would
>>>> not work to wait only for ping timeout time on a ping reply as we will already wait for the timeout set on the socket to get an
>>>> answer to our TLS client Hello. So the idea would be to already lower the socket timeout to ping timeout before the TLS handshake
>>>> starts and reset it back after we received the ping from the backend. Opinions?
>>>
>>> HTTP/2 also has an initial SETTINGS frame handshake. We could use the ping timeout on the socket until the first NGHTTP2_SETTINGS frame from the backend arrives on a new connection.
>>
>> And now I learned about the HTTP/2 handshake :-). I haven't though about the SETTINGS frame. So the high level idea would be:
>>
>> 1. If a fresh session in h2_proxy_session_setup is created and the ping parameter is set on the worker change the socket timeout
>> to the one in ping, but tuck away the current socket timeout.
>> 2. In on_frame_recv in the NGHTTP2_SETTINGS restore the old timeout (if it was changed) and continue.
>>
>> So something like the below?
>>
>> Index: modules/http2/h2_proxy_session.c
>> ===================================================================
>> --- modules/http2/h2_proxy_session.c (revision 1878265)
>> +++ modules/http2/h2_proxy_session.c (working copy)
>> @@ -203,6 +203,21 @@
>> case NGHTTP2_PUSH_PROMISE:
>> break;
>> case NGHTTP2_SETTINGS:
>> + /*
>> + * Check if we have saved a socket timeout before sending the
>> + * SETTINGS frame in h2_proxy_session_setup to perform a quick
>> + * "ping" on the backend. If yes, restore the saved timeout to
>> + * the socket.
>> + */
>> + if (session->save_timeout != -1) {
>> + apr_socket_t *socket = NULL;
>> +
>> + socket = ap_get_conn_socket(session->c);
>> + if (socket) {
>> + apr_socket_timeout_set(socket, session->save_timeout);
>> + session->save_timeout = -1;
>> + }
>> + }
>> if (frame->settings.niv > 0) {
>> n = nghttp2_session_get_remote_settings(ngh2, NGHTTP2_SETTINGS_MAX_CONCURRENT_STREAMS);
>> if (n > 0) {
>> @@ -634,6 +649,8 @@
>> session->input = apr_brigade_create(session->pool, session->c->bucket_alloc);
>> session->output = apr_brigade_create(session->pool, session->c->bucket_alloc);
>>
>> + session->save_timeout = -1;
>> +
>> nghttp2_session_callbacks_new(&cbs);
>> nghttp2_session_callbacks_set_on_frame_recv_callback(cbs, on_frame_recv);
>> nghttp2_session_callbacks_set_on_data_chunk_recv_callback(cbs, stream_response_data);
>> @@ -654,6 +671,22 @@
>> nghttp2_option_del(option);
>> nghttp2_session_callbacks_del(cbs);
>>
>> + /*
>> + * If a ping parameter is set on the worker set the socket timeout to
>> + * it to "use" the possible TLS handshake and the initial SETTINGS
>> + * frame as kind of ping. Tuck away the old timeout to restore it, once
>> + * the SETTING frame arrived from the backend.
>> + */
>> + if (p_conn->worker->s->ping_timeout_set) {
>> + apr_socket_t *socket = NULL;
>> +
>> + socket = ap_get_conn_socket(session->c);
>> + if (socket) {
>> + apr_socket_timeout_get(socket, &session->save_timeout);
>> + apr_socket_timeout_set(socket, p_conn->worker->s->ping_timeout);
>> + }
>> + }
>> +
>> ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c, APLOGNO(03362)
>> "setup session for %s", p_conn->hostname);
>> }
>> Index: modules/http2/h2_proxy_session.h
>> ===================================================================
>> --- modules/http2/h2_proxy_session.h (revision 1878265)
>> +++ modules/http2/h2_proxy_session.h (working copy)
>> @@ -94,6 +94,8 @@
>>
>> apr_bucket_brigade *input;
>> apr_bucket_brigade *output;
>> +
>> + apr_time_t save_timeout;
>> };
>>
>> h2_proxy_session *h2_proxy_session_setup(const char *id, proxy_conn_rec *p_conn,
>>
>>
>> Regards
>>
>> Rüdiger
>
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
Looks good!
> Am 29.05.2020 um 21:14 schrieb Ruediger Pluem <rp...@apache.org>:
>
>
>
> On 5/29/20 11:41 AM, Stefan Eissing wrote:
>>
>>
>>> Am 29.05.2020 um 11:23 schrieb Ruediger Pluem <rp...@apache.org>:
>>>
>>>
>>>
>>> On 5/29/20 10:09 AM, Stefan Eissing wrote:
>>>> Looks good. Now I learned about the "ping" parameter...
>>>
>>> Committed as r1878264 with a tweaked comment to make clear what I do.
>
> Thanks for backporting both
>
>>>
>>> Getting me to the next possible enhancement. I already had a patch but when putting it to the mail I got doubts that it could work
>>> due to the fact, that in most use cases HTTP/2 is encrypted.
>>> In AJP a set ping parameter on the worker will also cause an AJP ping to be sent as the first thing even on fresh connections and
>>> we only wait for the timeout set in the parameter for a reply. The idea behind this is that the backend might be able to deal with
>>> a TCP handshake, but not with processing a request, because maybe all processing threads / processes on the backend application
>>> are busy. This way this can be detected quickly and early and we can sent our request to a different backend in case of a load
>>> balancing scenario.
>>> With HTTP/2 we will likely have a TLS handshake first which likely already requires a responding backend application. So it would
>>> not work to wait only for ping timeout time on a ping reply as we will already wait for the timeout set on the socket to get an
>>> answer to our TLS client Hello. So the idea would be to already lower the socket timeout to ping timeout before the TLS handshake
>>> starts and reset it back after we received the ping from the backend. Opinions?
>>
>> HTTP/2 also has an initial SETTINGS frame handshake. We could use the ping timeout on the socket until the first NGHTTP2_SETTINGS frame from the backend arrives on a new connection.
>
> And now I learned about the HTTP/2 handshake :-). I haven't though about the SETTINGS frame. So the high level idea would be:
>
> 1. If a fresh session in h2_proxy_session_setup is created and the ping parameter is set on the worker change the socket timeout
> to the one in ping, but tuck away the current socket timeout.
> 2. In on_frame_recv in the NGHTTP2_SETTINGS restore the old timeout (if it was changed) and continue.
>
> So something like the below?
>
> Index: modules/http2/h2_proxy_session.c
> ===================================================================
> --- modules/http2/h2_proxy_session.c (revision 1878265)
> +++ modules/http2/h2_proxy_session.c (working copy)
> @@ -203,6 +203,21 @@
> case NGHTTP2_PUSH_PROMISE:
> break;
> case NGHTTP2_SETTINGS:
> + /*
> + * Check if we have saved a socket timeout before sending the
> + * SETTINGS frame in h2_proxy_session_setup to perform a quick
> + * "ping" on the backend. If yes, restore the saved timeout to
> + * the socket.
> + */
> + if (session->save_timeout != -1) {
> + apr_socket_t *socket = NULL;
> +
> + socket = ap_get_conn_socket(session->c);
> + if (socket) {
> + apr_socket_timeout_set(socket, session->save_timeout);
> + session->save_timeout = -1;
> + }
> + }
> if (frame->settings.niv > 0) {
> n = nghttp2_session_get_remote_settings(ngh2, NGHTTP2_SETTINGS_MAX_CONCURRENT_STREAMS);
> if (n > 0) {
> @@ -634,6 +649,8 @@
> session->input = apr_brigade_create(session->pool, session->c->bucket_alloc);
> session->output = apr_brigade_create(session->pool, session->c->bucket_alloc);
>
> + session->save_timeout = -1;
> +
> nghttp2_session_callbacks_new(&cbs);
> nghttp2_session_callbacks_set_on_frame_recv_callback(cbs, on_frame_recv);
> nghttp2_session_callbacks_set_on_data_chunk_recv_callback(cbs, stream_response_data);
> @@ -654,6 +671,22 @@
> nghttp2_option_del(option);
> nghttp2_session_callbacks_del(cbs);
>
> + /*
> + * If a ping parameter is set on the worker set the socket timeout to
> + * it to "use" the possible TLS handshake and the initial SETTINGS
> + * frame as kind of ping. Tuck away the old timeout to restore it, once
> + * the SETTING frame arrived from the backend.
> + */
> + if (p_conn->worker->s->ping_timeout_set) {
> + apr_socket_t *socket = NULL;
> +
> + socket = ap_get_conn_socket(session->c);
> + if (socket) {
> + apr_socket_timeout_get(socket, &session->save_timeout);
> + apr_socket_timeout_set(socket, p_conn->worker->s->ping_timeout);
> + }
> + }
> +
> ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c, APLOGNO(03362)
> "setup session for %s", p_conn->hostname);
> }
> Index: modules/http2/h2_proxy_session.h
> ===================================================================
> --- modules/http2/h2_proxy_session.h (revision 1878265)
> +++ modules/http2/h2_proxy_session.h (working copy)
> @@ -94,6 +94,8 @@
>
> apr_bucket_brigade *input;
> apr_bucket_brigade *output;
> +
> + apr_time_t save_timeout;
> };
>
> h2_proxy_session *h2_proxy_session_setup(const char *id, proxy_conn_rec *p_conn,
>
>
> Regards
>
> Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Ruediger Pluem <rp...@apache.org>.
On 5/29/20 11:41 AM, Stefan Eissing wrote:
>
>
>> Am 29.05.2020 um 11:23 schrieb Ruediger Pluem <rp...@apache.org>:
>>
>>
>>
>> On 5/29/20 10:09 AM, Stefan Eissing wrote:
>>> Looks good. Now I learned about the "ping" parameter...
>>
>> Committed as r1878264 with a tweaked comment to make clear what I do.
Thanks for backporting both
>>
>> Getting me to the next possible enhancement. I already had a patch but when putting it to the mail I got doubts that it could work
>> due to the fact, that in most use cases HTTP/2 is encrypted.
>> In AJP a set ping parameter on the worker will also cause an AJP ping to be sent as the first thing even on fresh connections and
>> we only wait for the timeout set in the parameter for a reply. The idea behind this is that the backend might be able to deal with
>> a TCP handshake, but not with processing a request, because maybe all processing threads / processes on the backend application
>> are busy. This way this can be detected quickly and early and we can sent our request to a different backend in case of a load
>> balancing scenario.
>> With HTTP/2 we will likely have a TLS handshake first which likely already requires a responding backend application. So it would
>> not work to wait only for ping timeout time on a ping reply as we will already wait for the timeout set on the socket to get an
>> answer to our TLS client Hello. So the idea would be to already lower the socket timeout to ping timeout before the TLS handshake
>> starts and reset it back after we received the ping from the backend. Opinions?
>
> HTTP/2 also has an initial SETTINGS frame handshake. We could use the ping timeout on the socket until the first NGHTTP2_SETTINGS frame from the backend arrives on a new connection.
And now I learned about the HTTP/2 handshake :-). I haven't though about the SETTINGS frame. So the high level idea would be:
1. If a fresh session in h2_proxy_session_setup is created and the ping parameter is set on the worker change the socket timeout
to the one in ping, but tuck away the current socket timeout.
2. In on_frame_recv in the NGHTTP2_SETTINGS restore the old timeout (if it was changed) and continue.
So something like the below?
Index: modules/http2/h2_proxy_session.c
===================================================================
--- modules/http2/h2_proxy_session.c (revision 1878265)
+++ modules/http2/h2_proxy_session.c (working copy)
@@ -203,6 +203,21 @@
case NGHTTP2_PUSH_PROMISE:
break;
case NGHTTP2_SETTINGS:
+ /*
+ * Check if we have saved a socket timeout before sending the
+ * SETTINGS frame in h2_proxy_session_setup to perform a quick
+ * "ping" on the backend. If yes, restore the saved timeout to
+ * the socket.
+ */
+ if (session->save_timeout != -1) {
+ apr_socket_t *socket = NULL;
+
+ socket = ap_get_conn_socket(session->c);
+ if (socket) {
+ apr_socket_timeout_set(socket, session->save_timeout);
+ session->save_timeout = -1;
+ }
+ }
if (frame->settings.niv > 0) {
n = nghttp2_session_get_remote_settings(ngh2, NGHTTP2_SETTINGS_MAX_CONCURRENT_STREAMS);
if (n > 0) {
@@ -634,6 +649,8 @@
session->input = apr_brigade_create(session->pool, session->c->bucket_alloc);
session->output = apr_brigade_create(session->pool, session->c->bucket_alloc);
+ session->save_timeout = -1;
+
nghttp2_session_callbacks_new(&cbs);
nghttp2_session_callbacks_set_on_frame_recv_callback(cbs, on_frame_recv);
nghttp2_session_callbacks_set_on_data_chunk_recv_callback(cbs, stream_response_data);
@@ -654,6 +671,22 @@
nghttp2_option_del(option);
nghttp2_session_callbacks_del(cbs);
+ /*
+ * If a ping parameter is set on the worker set the socket timeout to
+ * it to "use" the possible TLS handshake and the initial SETTINGS
+ * frame as kind of ping. Tuck away the old timeout to restore it, once
+ * the SETTING frame arrived from the backend.
+ */
+ if (p_conn->worker->s->ping_timeout_set) {
+ apr_socket_t *socket = NULL;
+
+ socket = ap_get_conn_socket(session->c);
+ if (socket) {
+ apr_socket_timeout_get(socket, &session->save_timeout);
+ apr_socket_timeout_set(socket, p_conn->worker->s->ping_timeout);
+ }
+ }
+
ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, session->c, APLOGNO(03362)
"setup session for %s", p_conn->hostname);
}
Index: modules/http2/h2_proxy_session.h
===================================================================
--- modules/http2/h2_proxy_session.h (revision 1878265)
+++ modules/http2/h2_proxy_session.h (working copy)
@@ -94,6 +94,8 @@
apr_bucket_brigade *input;
apr_bucket_brigade *output;
+
+ apr_time_t save_timeout;
};
h2_proxy_session *h2_proxy_session_setup(const char *id, proxy_conn_rec *p_conn,
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
> Am 29.05.2020 um 11:23 schrieb Ruediger Pluem <rp...@apache.org>:
>
>
>
> On 5/29/20 10:09 AM, Stefan Eissing wrote:
>> Looks good. Now I learned about the "ping" parameter...
>
> Committed as r1878264 with a tweaked comment to make clear what I do.
>
> Getting me to the next possible enhancement. I already had a patch but when putting it to the mail I got doubts that it could work
> due to the fact, that in most use cases HTTP/2 is encrypted.
> In AJP a set ping parameter on the worker will also cause an AJP ping to be sent as the first thing even on fresh connections and
> we only wait for the timeout set in the parameter for a reply. The idea behind this is that the backend might be able to deal with
> a TCP handshake, but not with processing a request, because maybe all processing threads / processes on the backend application
> are busy. This way this can be detected quickly and early and we can sent our request to a different backend in case of a load
> balancing scenario.
> With HTTP/2 we will likely have a TLS handshake first which likely already requires a responding backend application. So it would
> not work to wait only for ping timeout time on a ping reply as we will already wait for the timeout set on the socket to get an
> answer to our TLS client Hello. So the idea would be to already lower the socket timeout to ping timeout before the TLS handshake
> starts and reset it back after we received the ping from the backend. Opinions?
HTTP/2 also has an initial SETTINGS frame handshake. We could use the ping timeout on the socket until the first NGHTTP2_SETTINGS frame from the backend arrives on a new connection.
- Stefan
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Ruediger Pluem <rp...@apache.org>.
On 5/29/20 10:09 AM, Stefan Eissing wrote:
> Looks good. Now I learned about the "ping" parameter...
Committed as r1878264 with a tweaked comment to make clear what I do.
Getting me to the next possible enhancement. I already had a patch but when putting it to the mail I got doubts that it could work
due to the fact, that in most use cases HTTP/2 is encrypted.
In AJP a set ping parameter on the worker will also cause an AJP ping to be sent as the first thing even on fresh connections and
we only wait for the timeout set in the parameter for a reply. The idea behind this is that the backend might be able to deal with
a TCP handshake, but not with processing a request, because maybe all processing threads / processes on the backend application
are busy. This way this can be detected quickly and early and we can sent our request to a different backend in case of a load
balancing scenario.
With HTTP/2 we will likely have a TLS handshake first which likely already requires a responding backend application. So it would
not work to wait only for ping timeout time on a ping reply as we will already wait for the timeout set on the socket to get an
answer to our TLS client Hello. So the idea would be to already lower the socket timeout to ping timeout before the TLS handshake
starts and reset it back after we received the ping from the backend. Opinions?
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
Looks good. Now I learned about the "ping" parameter...
> Am 28.05.2020 um 21:30 schrieb Ruediger Pluem <rp...@apache.org>:
>
>
>
> On 5/28/20 12:06 PM, Stefan Eissing wrote:
>>
>>> Am 28.05.2020 um 12:05 schrieb Ruediger Pluem <rp...@apache.org>:
>>>
>>>
>>>
>>> On 5/28/20 11:36 AM, Stefan Eissing wrote:
>>>
>>>>
>>>> You are correct. I made a v2 of the patch:
>>>
>>> Thanks. This one looks good.
>>
>> Thanks for reviewing this.
>
> Thanks for commiting as r1878233. One further enhancement on top of this:
>
> Index: modules/http2/h2_proxy_session.c
> ===================================================================
> --- modules/http2/h2_proxy_session.c (revision 1878243)
> +++ modules/http2/h2_proxy_session.c (working copy)
> @@ -1399,6 +1399,7 @@
> {
> apr_status_t status;
> int have_written = 0, have_read = 0;
> + apr_interval_time_t timeout;
>
> ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, session->c,
> "h2_proxy_session(%s): process", session->id);
> @@ -1441,7 +1442,14 @@
> * configured via ProxyTimeout in our socket. There is
> * nothing we want to send or check until we get more data
> * from the backend. */
> - status = h2_proxy_session_read(session, 1, 0);
> + if (session->check_ping
> + && session->p_conn->worker->s->ping_timeout_set) {
> + timeout = session->p_conn->worker->s->ping_timeout;
> + }
> + else {
> + timeout = 0;
> + }
> + status = h2_proxy_session_read(session, 1, timeout);
> if (status == APR_SUCCESS) {
> have_read = 1;
> dispatch_event(session, H2_PROXYS_EV_DATA_READ, 0, NULL);
>
>
> This would make use of the worker ping parameter if we wait for a ping and the ping parameter was specified.
> Opinions (and yes if this is fine I would adjust the comment above regarding ProxyTimeout)?
>
> Regards
>
> Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Ruediger Pluem <rp...@apache.org>.
On 5/28/20 12:06 PM, Stefan Eissing wrote:
>
>> Am 28.05.2020 um 12:05 schrieb Ruediger Pluem <rp...@apache.org>:
>>
>>
>>
>> On 5/28/20 11:36 AM, Stefan Eissing wrote:
>>
>>>
>>> You are correct. I made a v2 of the patch:
>>
>> Thanks. This one looks good.
>
> Thanks for reviewing this.
Thanks for commiting as r1878233. One further enhancement on top of this:
Index: modules/http2/h2_proxy_session.c
===================================================================
--- modules/http2/h2_proxy_session.c (revision 1878243)
+++ modules/http2/h2_proxy_session.c (working copy)
@@ -1399,6 +1399,7 @@
{
apr_status_t status;
int have_written = 0, have_read = 0;
+ apr_interval_time_t timeout;
ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, session->c,
"h2_proxy_session(%s): process", session->id);
@@ -1441,7 +1442,14 @@
* configured via ProxyTimeout in our socket. There is
* nothing we want to send or check until we get more data
* from the backend. */
- status = h2_proxy_session_read(session, 1, 0);
+ if (session->check_ping
+ && session->p_conn->worker->s->ping_timeout_set) {
+ timeout = session->p_conn->worker->s->ping_timeout;
+ }
+ else {
+ timeout = 0;
+ }
+ status = h2_proxy_session_read(session, 1, timeout);
if (status == APR_SUCCESS) {
have_read = 1;
dispatch_event(session, H2_PROXYS_EV_DATA_READ, 0, NULL);
This would make use of the worker ping parameter if we wait for a ping and the ping parameter was specified.
Opinions (and yes if this is fine I would adjust the comment above regarding ProxyTimeout)?
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
> Am 28.05.2020 um 12:05 schrieb Ruediger Pluem <rp...@apache.org>:
>
>
>
> On 5/28/20 11:36 AM, Stefan Eissing wrote:
>
>>
>> You are correct. I made a v2 of the patch:
>
> Thanks. This one looks good.
Thanks for reviewing this.
>
> Regards
>
> Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Ruediger Pluem <rp...@apache.org>.
On 5/28/20 11:36 AM, Stefan Eissing wrote:
>
> You are correct. I made a v2 of the patch:
Thanks. This one looks good.
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
> Am 27.05.2020 um 17:58 schrieb Ruediger Pluem <rp...@apache.org>:
>
>
>
> On 5/27/20 5:25 PM, Stefan Eissing wrote:
>> Maybe this can work? It goes into blocking read with default timeout when there is definitely nothing to send from our end.
>>
>>
>> h2-proxy-timeout.patch
>>
>> Index: modules/http2/h2_proxy_session.c
>> ===================================================================
>> --- modules/http2/h2_proxy_session.c (Revision 1878161)
>> +++ modules/http2/h2_proxy_session.c (Arbeitskopie)
>> @@ -556,11 +556,14 @@
>> "h2_proxy_stream(%d): request DATA %ld, %ld"
>> " total, flags=%d", stream->id, (long)readlen, (long)stream->data_sent,
>> (int)*data_flags);
>> - if ((*data_flags & NGHTTP2_DATA_FLAG_EOF) && !apr_is_empty_table(stream->r->trailers_in)) {
>> - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, status, stream->r, APLOGNO(10179)
>> - "h2_proxy_stream(%d): submit trailers", stream->id);
>> - *data_flags |= NGHTTP2_DATA_FLAG_NO_END_STREAM;
>> - submit_trailers(stream);
>> + if (*data_flags & NGHTTP2_DATA_FLAG_EOF) {
>> + if (!apr_is_empty_table(stream->r->trailers_in)) {
>> + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, status, stream->r, APLOGNO(10179)
>> + "h2_proxy_stream(%d): submit trailers", stream->id);
>> + *data_flags |= NGHTTP2_DATA_FLAG_NO_END_STREAM;
>> + submit_trailers(stream);
>> + }
>> + stream->state = H2_STREAM_ST_CLOSED_INPUT;
>
> Where is this state processed? Looks to me as if this state would fall into the default case of the switch in
> h2_proxy_session_process and thus cause an error messages. But as far as I understand this only indicates that the front does not
> want to sent more data which is no error.
I removed this again. mod_http2 tracks stream states more closely that proxy_http2 and I thought it would help. But we can do without, I think.
>> }
>> return readlen;
>> }
>> @@ -902,7 +905,7 @@
>> apr_socket_t *socket = NULL;
>> apr_time_t save_timeout = -1;
>>
>> - if (block) {
>> + if (block && timeout > 0) {
>> socket = ap_get_conn_socket(session->c);
>> if (socket) {
>> apr_socket_timeout_get(socket, &save_timeout);
>> @@ -974,6 +977,11 @@
>> dispatch_event(session, H2_PROXYS_EV_STREAM_RESUMED, 0, NULL);
>> }
>>
>> +static int has_suspended_streams(h2_proxy_session *session)
>> +{
>> + return (session->suspended->nelts > 0);
>> +}
>> +
>> static apr_status_t check_suspended(h2_proxy_session *session)
>> {
>> h2_proxy_stream *stream;
>> @@ -1428,7 +1436,20 @@
>> break;
>>
>> case H2_PROXYS_ST_WAIT:
>> - if (check_suspended(session) == APR_EAGAIN) {
>> + if (!has_suspended_streams(session)
>> + && !nghttp2_session_want_write(session->ngh2)
>> + && nghttp2_session_want_read(session->ngh2)) {
>> + status = h2_proxy_session_read(session, 1, 0);
>> + if (status == APR_SUCCESS) {
>> + have_read = 1;
>> + dispatch_event(session, H2_PROXYS_EV_DATA_READ, 0, NULL);
>> + }
>> + else {
>> + dispatch_event(session, H2_PROXYS_EV_CONN_ERROR, status, NULL);
>> + return status;
>> + }
>> + }
>
> Hm. I think this does not catch the case where we sent a PING to the backend and are waiting for the reply because we might have
> suspended streams in this case?
> So maybe instead of
>
> !has_suspended_streams(session)
>
> we need to check for
>
> (!has_suspended_streams(session) || session->check_ping)
>
> ?
You are correct. I made a v2 of the patch:
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Ruediger Pluem <rp...@apache.org>.
On 5/27/20 5:25 PM, Stefan Eissing wrote:
> Maybe this can work? It goes into blocking read with default timeout when there is definitely nothing to send from our end.
>
>
> h2-proxy-timeout.patch
>
> Index: modules/http2/h2_proxy_session.c
> ===================================================================
> --- modules/http2/h2_proxy_session.c (Revision 1878161)
> +++ modules/http2/h2_proxy_session.c (Arbeitskopie)
> @@ -556,11 +556,14 @@
> "h2_proxy_stream(%d): request DATA %ld, %ld"
> " total, flags=%d", stream->id, (long)readlen, (long)stream->data_sent,
> (int)*data_flags);
> - if ((*data_flags & NGHTTP2_DATA_FLAG_EOF) && !apr_is_empty_table(stream->r->trailers_in)) {
> - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, status, stream->r, APLOGNO(10179)
> - "h2_proxy_stream(%d): submit trailers", stream->id);
> - *data_flags |= NGHTTP2_DATA_FLAG_NO_END_STREAM;
> - submit_trailers(stream);
> + if (*data_flags & NGHTTP2_DATA_FLAG_EOF) {
> + if (!apr_is_empty_table(stream->r->trailers_in)) {
> + ap_log_rerror(APLOG_MARK, APLOG_DEBUG, status, stream->r, APLOGNO(10179)
> + "h2_proxy_stream(%d): submit trailers", stream->id);
> + *data_flags |= NGHTTP2_DATA_FLAG_NO_END_STREAM;
> + submit_trailers(stream);
> + }
> + stream->state = H2_STREAM_ST_CLOSED_INPUT;
Where is this state processed? Looks to me as if this state would fall into the default case of the switch in
h2_proxy_session_process and thus cause an error messages. But as far as I understand this only indicates that the front does not
want to sent more data which is no error.
> }
> return readlen;
> }
> @@ -902,7 +905,7 @@
> apr_socket_t *socket = NULL;
> apr_time_t save_timeout = -1;
>
> - if (block) {
> + if (block && timeout > 0) {
> socket = ap_get_conn_socket(session->c);
> if (socket) {
> apr_socket_timeout_get(socket, &save_timeout);
> @@ -974,6 +977,11 @@
> dispatch_event(session, H2_PROXYS_EV_STREAM_RESUMED, 0, NULL);
> }
>
> +static int has_suspended_streams(h2_proxy_session *session)
> +{
> + return (session->suspended->nelts > 0);
> +}
> +
> static apr_status_t check_suspended(h2_proxy_session *session)
> {
> h2_proxy_stream *stream;
> @@ -1428,7 +1436,20 @@
> break;
>
> case H2_PROXYS_ST_WAIT:
> - if (check_suspended(session) == APR_EAGAIN) {
> + if (!has_suspended_streams(session)
> + && !nghttp2_session_want_write(session->ngh2)
> + && nghttp2_session_want_read(session->ngh2)) {
> + status = h2_proxy_session_read(session, 1, 0);
> + if (status == APR_SUCCESS) {
> + have_read = 1;
> + dispatch_event(session, H2_PROXYS_EV_DATA_READ, 0, NULL);
> + }
> + else {
> + dispatch_event(session, H2_PROXYS_EV_CONN_ERROR, status, NULL);
> + return status;
> + }
> + }
Hm. I think this does not catch the case where we sent a PING to the backend and are waiting for the reply because we might have
suspended streams in this case?
So maybe instead of
!has_suspended_streams(session)
we need to check for
(!has_suspended_streams(session) || session->check_ping)
?
> + else if (check_suspended(session) == APR_EAGAIN) {
> /* no stream has become resumed. Do a blocking read with
> * ever increasing timeouts... */
> if (session->wait_timeout < 25) {
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
Maybe this can work? It goes into blocking read with default timeout when there is definitely nothing to send from our end.
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
Is this a new stupid feature that apple mail inserts a sig in front of quoted text? Sorry about that...
> Am 27.05.2020 um 15:35 schrieb Stefan Eissing <st...@greenbytes.de>:
>
>
> Stefan Eissing
>
> <green/>bytes GmbH
> Hafenweg 16
> 48155 Münster
> www.greenbytes.de
>
>> Am 27.05.2020 um 15:05 schrieb Ruediger Pluem <rp...@apache.org>:
>>
>>
>>
>> On 5/27/20 1:10 PM, Stefan Eissing wrote:
>>> The whole thing initially handled processing of several streams in parallel. That is why it has more states than currently necessary.
>>>
>>> h2_proxy_session_process() returns from H2_PROXYS_ST_WAIT state to the caller in mod_proxy_http2.c#255. That one checks the aborted state of the "master" connection. So, when our frontend connection goes away, mod_proxy_http2 processing also aborts. (Which raises the question if c->aborted can ever be set on a HTTP/1.1 connection during this, uhmm.)
>>
>> If you don't write to the frontend I doubt that c->aborted will be set.
>>
>>>
>>> But, as I reread it now, the h2_proxy_session_process() will not timeout when the frontend connection stays and the backend just does not send anything back at all. So, any "ProxyTimeout" seems to be ignored atm.
>>
>> So I seem to read this correct. This gets me to the next question: Is this the desired behavior? I would expect it to obey
>> ProxyTimeout or timeout worker settings. Any particular reason why we have that timeout starting with 25ms and increasing up to
>> 100ms and not just using the current timeout set on the socket? I mean even in case it would process several streams in parallel
>> it could block reading from the socket until ProxyTimeout and give up if nothing was delivered until then. Or does it need to wake
>> up quicker in the multi stream scenario as a request for a new stream by the proxy_handler needs to be processed by the blocking
>> thread?
>
> I think respecting ProxyTimeout is the correct behaviour, now that we one handle one request at a time. However, due to the nature of h2, we cannot always do a blocking read with that timeout. For example, while a request body needs to be send, we might be in the same processing loop and need to check regularly for new data arriving on the frontend connection.
>
> But we can track how long we have neither sent nor received and compare that to ProxyTimeout. And that includes writing and reading to the frontend connection (or slave connection when the fronend is h2 itself).
>
>>
>> OTOH I understand that in the multiple stream scenario which we currently don't use users might expect that the ProxyTimeout
>> applies to each single stream and hence doing a blocking socket read with a ProxyTimeout could lead to streams waiting for much
>> longer than ProxyTimeout if there are active streams on the connection. I guess this would require a stream specific
>> last_frame_received that would need to checked on a regular basis.
>>
>> Having said this any proposal how to move on? Should we do a blocking read with ProxyTimeout and bail out if it times out for now?
>>
>> Regards
>>
>> Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
Stefan Eissing
<green/>bytes GmbH
Hafenweg 16
48155 Münster
www.greenbytes.de
> Am 27.05.2020 um 15:05 schrieb Ruediger Pluem <rp...@apache.org>:
>
>
>
> On 5/27/20 1:10 PM, Stefan Eissing wrote:
>> The whole thing initially handled processing of several streams in parallel. That is why it has more states than currently necessary.
>>
>> h2_proxy_session_process() returns from H2_PROXYS_ST_WAIT state to the caller in mod_proxy_http2.c#255. That one checks the aborted state of the "master" connection. So, when our frontend connection goes away, mod_proxy_http2 processing also aborts. (Which raises the question if c->aborted can ever be set on a HTTP/1.1 connection during this, uhmm.)
>
> If you don't write to the frontend I doubt that c->aborted will be set.
>
>>
>> But, as I reread it now, the h2_proxy_session_process() will not timeout when the frontend connection stays and the backend just does not send anything back at all. So, any "ProxyTimeout" seems to be ignored atm.
>
> So I seem to read this correct. This gets me to the next question: Is this the desired behavior? I would expect it to obey
> ProxyTimeout or timeout worker settings. Any particular reason why we have that timeout starting with 25ms and increasing up to
> 100ms and not just using the current timeout set on the socket? I mean even in case it would process several streams in parallel
> it could block reading from the socket until ProxyTimeout and give up if nothing was delivered until then. Or does it need to wake
> up quicker in the multi stream scenario as a request for a new stream by the proxy_handler needs to be processed by the blocking
> thread?
I think respecting ProxyTimeout is the correct behaviour, now that we one handle one request at a time. However, due to the nature of h2, we cannot always do a blocking read with that timeout. For example, while a request body needs to be send, we might be in the same processing loop and need to check regularly for new data arriving on the frontend connection.
But we can track how long we have neither sent nor received and compare that to ProxyTimeout. And that includes writing and reading to the frontend connection (or slave connection when the fronend is h2 itself).
>
> OTOH I understand that in the multiple stream scenario which we currently don't use users might expect that the ProxyTimeout
> applies to each single stream and hence doing a blocking socket read with a ProxyTimeout could lead to streams waiting for much
> longer than ProxyTimeout if there are active streams on the connection. I guess this would require a stream specific
> last_frame_received that would need to checked on a regular basis.
>
> Having said this any proposal how to move on? Should we do a blocking read with ProxyTimeout and bail out if it times out for now?
>
> Regards
>
> Rüdiger
>
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Ruediger Pluem <rp...@apache.org>.
On 5/27/20 1:10 PM, Stefan Eissing wrote:
> The whole thing initially handled processing of several streams in parallel. That is why it has more states than currently necessary.
>
> h2_proxy_session_process() returns from H2_PROXYS_ST_WAIT state to the caller in mod_proxy_http2.c#255. That one checks the aborted state of the "master" connection. So, when our frontend connection goes away, mod_proxy_http2 processing also aborts. (Which raises the question if c->aborted can ever be set on a HTTP/1.1 connection during this, uhmm.)
If you don't write to the frontend I doubt that c->aborted will be set.
>
> But, as I reread it now, the h2_proxy_session_process() will not timeout when the frontend connection stays and the backend just does not send anything back at all. So, any "ProxyTimeout" seems to be ignored atm.
So I seem to read this correct. This gets me to the next question: Is this the desired behavior? I would expect it to obey
ProxyTimeout or timeout worker settings. Any particular reason why we have that timeout starting with 25ms and increasing up to
100ms and not just using the current timeout set on the socket? I mean even in case it would process several streams in parallel
it could block reading from the socket until ProxyTimeout and give up if nothing was delivered until then. Or does it need to wake
up quicker in the multi stream scenario as a request for a new stream by the proxy_handler needs to be processed by the blocking
thread?
OTOH I understand that in the multiple stream scenario which we currently don't use users might expect that the ProxyTimeout
applies to each single stream and hence doing a blocking socket read with a ProxyTimeout could lead to streams waiting for much
longer than ProxyTimeout if there are active streams on the connection. I guess this would require a stream specific
last_frame_received that would need to checked on a regular basis.
Having said this any proposal how to move on? Should we do a blocking read with ProxyTimeout and bail out if it times out for now?
Regards
Rüdiger
Re: Trying to understand the logic of mod_proxy_http2 with regards to
timeouts
Posted by Stefan Eissing <st...@greenbytes.de>.
The whole thing initially handled processing of several streams in parallel. That is why it has more states than currently necessary.
h2_proxy_session_process() returns from H2_PROXYS_ST_WAIT state to the caller in mod_proxy_http2.c#255. That one checks the aborted state of the "master" connection. So, when our frontend connection goes away, mod_proxy_http2 processing also aborts. (Which raises the question if c->aborted can ever be set on a HTTP/1.1 connection during this, uhmm.)
But, as I reread it now, the h2_proxy_session_process() will not timeout when the frontend connection stays and the backend just does not send anything back at all. So, any "ProxyTimeout" seems to be ignored atm.
- Stefan
> Am 27.05.2020 um 12:40 schrieb Ruediger Pluem <rp...@apache.org>:
>
> I try to understand the logic of mod_proxy_http2 with respect to timeouts. I am currently stuck at this piece of code in
> h2_proxy_session_process in h2_proxy_session.c
>
> case H2_PROXYS_ST_BUSY:
> case H2_PROXYS_ST_LOCAL_SHUTDOWN:
> case H2_PROXYS_ST_REMOTE_SHUTDOWN:
> have_written = send_loop(session);
>
> if (nghttp2_session_want_read(session->ngh2)) {
> status = h2_proxy_session_read(session, 0, 0);
> if (status == APR_SUCCESS) {
> have_read = 1;
> }
> }
>
> if (!have_written && !have_read
> && !nghttp2_session_want_write(session->ngh2)) {
> dispatch_event(session, H2_PROXYS_EV_NO_IO, 0, NULL);
> goto run_loop;
> }
> break;
>
> case H2_PROXYS_ST_WAIT:
> if (check_suspended(session) == APR_EAGAIN) {
> /* no stream has become resumed. Do a blocking read with
> * ever increasing timeouts... */
> if (session->wait_timeout < 25) {
> session->wait_timeout = 25;
> }
> else {
> session->wait_timeout = H2MIN(apr_time_from_msec(100),
> 2*session->wait_timeout);
> }
>
> status = h2_proxy_session_read(session, 1, session->wait_timeout);
> ap_log_cerror(APLOG_MARK, APLOG_TRACE3, status, session->c,
> APLOGNO(03365)
> "h2_proxy_session(%s): WAIT read, timeout=%fms",
> session->id, session->wait_timeout/1000.0);
> if (status == APR_SUCCESS) {
> have_read = 1;
> dispatch_event(session, H2_PROXYS_EV_DATA_READ, 0, NULL);
> }
> else if (APR_STATUS_IS_TIMEUP(status)
> || APR_STATUS_IS_EAGAIN(status)) {
> /* go back to checking all inputs again */
> transit(session, "wait cycle", H2_PROXYS_ST_BUSY);
> }
>
>
> Doesn't that loop forever with in the end 100ms blocking reads from the backend if the backend never replies?
> The state of the session seems to switch between H2_PROXYS_ST_BUSY (set in line 1454) and H2_PROXYS_ST_WAIT set
> by ev_no_io. Do I miss the exit?
>
>
> Regards
>
> Rüdiger