Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

Yeah, I tried a 0 len read. Unfortunately, the core input filter is not happy 
about that:

core_filters.c, line 231
AP_DEBUG_ASSERT(readbytes > 0);

> Am 12.10.2015 um 10:25 schrieb Plüm, Rüdiger, Vodafone Group 
> <ruediger.pl...@vodafone.com>:
> 
> How about the following patch?
> 
> This separates the triggering of the SSL Handshake and the possible reading 
> of the 24 bytes:
> 
> Index: h2_h2.c
> ===   
> --- h2_h2.c (revision 1707437)
> +++ h2_h2.c (working copy)
> @@ -154,7 +154,7 @@
> 
> temp = apr_brigade_create(c->pool, c->bucket_alloc);
> status = ap_get_brigade(c->input_filters, temp,
> -AP_MODE_SPECULATIVE, APR_BLOCK_READ, 24);
> +AP_MODE_INIT, APR_BLOCK_READ, 0);
> 
> if (status == APR_SUCCESS) {
> if (h2_ctx_protocol_get(c)
> @@ -171,23 +171,31 @@
> char *s = NULL;
> apr_size_t slen;
> 
> -apr_brigade_pflatten(temp, , , c->pool);
> -if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 24)) {
> -ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
> -  "h2_h2, direct mode detected");
> -h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
> +status = ap_get_brigade(c->input_filters, temp,
> +AP_MODE_SPECULATIVE, 
> APR_BLOCK_READ, 24);
> +if (status == APR_SUCCESS) {
> +apr_brigade_pflatten(temp, , , c->pool);
> +if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 24)) {
> +ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
> +  "h2_h2, direct mode detected");
> +h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
> +}
> +else {
> +ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
> +  "h2_h2, not detected in %d bytes: 
> %s",
> +  (int)slen, s);
> +}
> }
> -else {
> -ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
> -  "h2_h2, not detected in %d bytes: %s",
> -  (int)slen, s);
> -}
> }
> +else {
> +ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
> +  "h2_h2, error reading 24 bytes 
> speculative");
> +}
> }
> }
> else {
> ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
> -  "h2_h2, error reading 24 bytes speculative");
> +  "h2_h2, Failed to init connection");
> }
> apr_brigade_destroy(temp);
> }
> 
> This would still block in the non ssl case if directmode is not set to off 
> explicitly. I would propose to change the default behaviour of directmode 
> here to off as directmode seems to be something very special to me that 
> should be explicitly enabled.
> 
> Regards
> 
> Rüdiger
> 
>> -Original Message-
>> From: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
>> Sent: Sonntag, 11. Oktober 2015 19:54
>> To: dev@httpd.apache.org
>> Subject: Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is
>> loaded
>> 
>> Ok, in ssl_engine_io.c, lines 1426+ I see a hint:
>> 
>>/* XXX: we could actually move ssl_io_filter_handshake to an
>> * ap_hook_process_connection but would still need to call it for
>> * AP_MODE_INIT for protocols that may upgrade the connection
>> * rather than have SSLEngine On configured.
>> */
>>if ((status = ssl_io_filter_handshake(inctx->filter_ctx)) !=
>> APR_SUCCESS) {
>>return ssl_io_filter_error(f, bb, status);
>>}
>> 
>> The handshake handling gets triggered on a filter, so it all happens on
>> READs (or WRITEs), which explains why connection hooks do not see it. This
>> i

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

I am about to change that.

> Am 12.10.2015 um 12:48 schrieb Plüm, Rüdiger, Vodafone Group 
> <ruediger.pl...@vodafone.com>:
> 
> 
> 
>> -Original Message-
>> From: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
>> Sent: Montag, 12. Oktober 2015 10:58
>> To: dev@httpd.apache.org
>> Subject: Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is
>> loaded
>> 
>> The AP_MODE_INIT triggers the handshake nicely. But the protocol switching
>> still happens
>> on the first read. currently looking how to trigger that best.
> 
> Even in the ALPN case the protocol switching happens on the first read after 
> the handshake?
> 
> Regards
> 
> Rüdiger
> 

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

The key here is using AP_MODE_INIT first (where 0 make sense) before
AP_MODE_SPECULATIVE.


On Mon, Oct 12, 2015 at 10:36 AM, Stefan Eissing
<stefan.eiss...@greenbytes.de> wrote:
> Yeah, I tried a 0 len read. Unfortunately, the core input filter is not happy 
> about that:
>
> core_filters.c, line 231
> AP_DEBUG_ASSERT(readbytes > 0);
>
>> Am 12.10.2015 um 10:25 schrieb Plüm, Rüdiger, Vodafone Group 
>> <ruediger.pl...@vodafone.com>:
>>
>> How about the following patch?
>>
>> This separates the triggering of the SSL Handshake and the possible reading 
>> of the 24 bytes:
>>
>> Index: h2_h2.c
>> ===
>> --- h2_h2.c (revision 1707437)
>> +++ h2_h2.c (working copy)
>> @@ -154,7 +154,7 @@
>>
>> temp = apr_brigade_create(c->pool, c->bucket_alloc);
>> status = ap_get_brigade(c->input_filters, temp,
>> -AP_MODE_SPECULATIVE, APR_BLOCK_READ, 24);
>> +AP_MODE_INIT, APR_BLOCK_READ, 0);
>>
>> if (status == APR_SUCCESS) {
>> if (h2_ctx_protocol_get(c)
>> @@ -171,23 +171,31 @@
>> char *s = NULL;
>> apr_size_t slen;
>>
>> -apr_brigade_pflatten(temp, , , c->pool);
>> -if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 24)) {
>> -ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
>> -  "h2_h2, direct mode detected");
>> -h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
>> +status = ap_get_brigade(c->input_filters, temp,
>> +AP_MODE_SPECULATIVE, 
>> APR_BLOCK_READ, 24);
>> +if (status == APR_SUCCESS) {
>> +apr_brigade_pflatten(temp, , , c->pool);
>> +if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 24)) 
>> {
>> +ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
>> +  "h2_h2, direct mode detected");
>> +h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
>> +}
>> +else {
>> +ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
>> +  "h2_h2, not detected in %d bytes: 
>> %s",
>> +  (int)slen, s);
>> +}
>> }
>> -else {
>> -ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
>> -  "h2_h2, not detected in %d bytes: %s",
>> -  (int)slen, s);
>> -}
>> }
>> +else {
>> +ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
>> +  "h2_h2, error reading 24 bytes 
>> speculative");
>> +}
>> }
>> }
>> else {
>> ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
>> -  "h2_h2, error reading 24 bytes speculative");
>> +  "h2_h2, Failed to init connection");
>>     }
>>     apr_brigade_destroy(temp);
>> }
>>
>> This would still block in the non ssl case if directmode is not set to off 
>> explicitly. I would propose to change the default behaviour of directmode 
>> here to off as directmode seems to be something very special to me that 
>> should be explicitly enabled.
>>
>> Regards
>>
>> Rüdiger
>>
>>> -Original Message-
>>> From: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
>>> Sent: Sonntag, 11. Oktober 2015 19:54
>>> To: dev@httpd.apache.org
>>> Subject: Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is
>>> loaded
>>>
>>> Ok, in ssl_engine_io.c, lines 1426+ I see a hint:
>>>
>>>/* XXX: we could actually move ssl_io_filter_handshake to an
>>> * ap_hook_process_connection but would still need to call it for
>>> * AP_MODE_INIT for protocols that may upgrade the connection
>>> * rather than h

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

Also, I wonder if we don't need:

Index: modules/http2/h2_task_input.c
===
--- modules/http2/h2_task_input.c(revision 1707888)
+++ modules/http2/h2_task_input.c(working copy)
@@ -116,7 +116,7 @@ apr_status_t h2_task_input_read(h2_task_input *inp
 }

 if (mode == AP_MODE_INIT) {
-return APR_SUCCESS;
+return ap_get_brigade(f->c->input_filters, bb, mode, block, readbytes);
 }

 if (input->bb) {
--

We shouldn't since h2_task_input_read() is called at NETWORK level
(hence after mod_ssl which "eats" AP_MODE_INIT), but it looks more
correct (as it would be in mod_ssl) since anyway the
core_input_filter() can handle it.


On Mon, Oct 12, 2015 at 10:42 AM, Yann Ylavic <ylavic@gmail.com> wrote:
> The key here is using AP_MODE_INIT first (where 0 make sense) before
> AP_MODE_SPECULATIVE.
>
>
> On Mon, Oct 12, 2015 at 10:36 AM, Stefan Eissing
> <stefan.eiss...@greenbytes.de> wrote:
>> Yeah, I tried a 0 len read. Unfortunately, the core input filter is not 
>> happy about that:
>>
>> core_filters.c, line 231
>> AP_DEBUG_ASSERT(readbytes > 0);
>>
>>> Am 12.10.2015 um 10:25 schrieb Plüm, Rüdiger, Vodafone Group 
>>> <ruediger.pl...@vodafone.com>:
>>>
>>> How about the following patch?
>>>
>>> This separates the triggering of the SSL Handshake and the possible reading 
>>> of the 24 bytes:
>>>
>>> Index: h2_h2.c
>>> ===
>>> --- h2_h2.c (revision 1707437)
>>> +++ h2_h2.c (working copy)
>>> @@ -154,7 +154,7 @@
>>>
>>> temp = apr_brigade_create(c->pool, c->bucket_alloc);
>>> status = ap_get_brigade(c->input_filters, temp,
>>> -AP_MODE_SPECULATIVE, APR_BLOCK_READ, 24);
>>> +AP_MODE_INIT, APR_BLOCK_READ, 0);
>>>
>>> if (status == APR_SUCCESS) {
>>> if (h2_ctx_protocol_get(c)
>>> @@ -171,23 +171,31 @@
>>> char *s = NULL;
>>> apr_size_t slen;
>>>
>>> -apr_brigade_pflatten(temp, , , c->pool);
>>> -if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 24)) {
>>> -ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
>>> -  "h2_h2, direct mode detected");
>>> -h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
>>> +status = ap_get_brigade(c->input_filters, temp,
>>> +AP_MODE_SPECULATIVE, 
>>> APR_BLOCK_READ, 24);
>>> +if (status == APR_SUCCESS) {
>>> +apr_brigade_pflatten(temp, , , c->pool);
>>> +if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 
>>> 24)) {
>>> +ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
>>> +  "h2_h2, direct mode detected");
>>> +h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
>>> +}
>>> +else {
>>> +ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
>>> +  "h2_h2, not detected in %d 
>>> bytes: %s",
>>> +  (int)slen, s);
>>> +}
>>> }
>>> -else {
>>> -ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
>>> -  "h2_h2, not detected in %d bytes: 
>>> %s",
>>> -  (int)slen, s);
>>> -}
>>> }
>>> +else {
>>> +ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
>>> +  "h2_h2, error reading 24 bytes 
>>> speculative");
>>> +}
>>> }
>>> }
>>>     else {
>>>     ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
>>> -  "h2_h2, error reading 24 bytes speculative");
>>

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

On Mon, Oct 12, 2015 at 11:13 AM, Rainer Jung  wrote:
>
> Since I started this thread: IMHO this discussion shouldn't stop/influence
> 2.4.17. mod_http2 is experimental, so even a change of defaults in early
> releases should be OK. And any exotic interop problems are not critical
> enough to roll another release.

+1, not a showstopper from my POV.

RE: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Plüm , Rüdiger , Vodafone Group]

How about the following patch?

This separates the triggering of the SSL Handshake and the possible reading of 
the 24 bytes:

Index: h2_h2.c
===   
--- h2_h2.c (revision 1707437)
+++ h2_h2.c (working copy)
@@ -154,7 +154,7 @@

 temp = apr_brigade_create(c->pool, c->bucket_alloc);
 status = ap_get_brigade(c->input_filters, temp,
-AP_MODE_SPECULATIVE, APR_BLOCK_READ, 24);
+AP_MODE_INIT, APR_BLOCK_READ, 0);

 if (status == APR_SUCCESS) {
 if (h2_ctx_protocol_get(c)
@@ -171,23 +171,31 @@
 char *s = NULL;
 apr_size_t slen;

-apr_brigade_pflatten(temp, , , c->pool);
-if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 24)) {
-ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
-  "h2_h2, direct mode detected");
-h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
+status = ap_get_brigade(c->input_filters, temp,
+AP_MODE_SPECULATIVE, 
APR_BLOCK_READ, 24);
+if (status == APR_SUCCESS) {
+apr_brigade_pflatten(temp, , , c->pool);
+if ((slen >= 24) && !memcmp(H2_MAGIC_TOKEN, s, 24)) {
+ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c,
+  "h2_h2, direct mode detected");
+h2_ctx_protocol_set(ctx, is_tls? "h2" : "h2c");
+}
+else {
+ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
+  "h2_h2, not detected in %d bytes: 
%s",
+  (int)slen, s);
+}
 }
-else {
-ap_log_cerror(APLOG_MARK, APLOG_TRACE2, 0, c,
-  "h2_h2, not detected in %d bytes: %s",
-  (int)slen, s);
-}
 }
+else {
+ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
+  "h2_h2, error reading 24 bytes speculative");
+}
 }
 }
 else {
 ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
-  "h2_h2, error reading 24 bytes speculative");
+  "h2_h2, Failed to init connection");
 }
 apr_brigade_destroy(temp);
 }

This would still block in the non ssl case if directmode is not set to off 
explicitly. I would propose to change the default behaviour of directmode here 
to off as directmode seems to be something very special to me that should be 
explicitly enabled.

Regards

Rüdiger

> -Original Message-----
> From: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
> Sent: Sonntag, 11. Oktober 2015 19:54
> To: dev@httpd.apache.org
> Subject: Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is
> loaded
> 
> Ok, in ssl_engine_io.c, lines 1426+ I see a hint:
> 
> /* XXX: we could actually move ssl_io_filter_handshake to an
>  * ap_hook_process_connection but would still need to call it for
>  * AP_MODE_INIT for protocols that may upgrade the connection
>  * rather than have SSLEngine On configured.
>  */
> if ((status = ssl_io_filter_handshake(inctx->filter_ctx)) !=
> APR_SUCCESS) {
> return ssl_io_filter_error(f, bb, status);
> }
> 
> The handshake handling gets triggered on a filter, so it all happens on
> READs (or WRITEs), which explains why connection hooks do not see it. This
> is quite some code which looks like we do not want to touch for a "quick
> fix". Also, there is no quick fix inside mod_http2 as before handshake,
> the SNI might also not be there yet, thus the vhost cannot be determined.
> etc.
> 
> For the current release, I think we should leave it as it is and advise
> that current mod_http2 is incompatible with things like nntp.
> 
> For the next release, I'd like the server to perform the handshake at a
> defined time, so other modules can rely on protocols being selected and
> correct vhost being known before the first read/write.
> 
> //Stefan
> 

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

 "h2_h2, not detected in %d bytes: 
>>>> %s",
>>>> -  (int)slen, s);
>>>> -}
>>>>}
>>>> +else {
>>>> +    ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
>>>> +  "h2_h2, error reading 24 bytes 
>>>> speculative");
>>>> +}
>>>>}
>>>>}
>>>>else {
>>>>ap_log_cerror(APLOG_MARK, APLOG_DEBUG, status, c,
>>>> -  "h2_h2, error reading 24 bytes speculative");
>>>> +  "h2_h2, Failed to init connection");
>>>>}
>>>>apr_brigade_destroy(temp);
>>>>}
>>>> 
>>>> This would still block in the non ssl case if directmode is not set to off 
>>>> explicitly. I would propose to change the default behaviour of directmode 
>>>> here to off as directmode seems to be something very special to me that 
>>>> should be explicitly enabled.
>>>> 
>>>> Regards
>>>> 
>>>> Rüdiger
>>>> 
>>>>> -Original Message-
>>>>> From: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
>>>>> Sent: Sonntag, 11. Oktober 2015 19:54
>>>>> To: dev@httpd.apache.org
>>>>> Subject: Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is
>>>>> loaded
>>>>> 
>>>>> Ok, in ssl_engine_io.c, lines 1426+ I see a hint:
>>>>> 
>>>>>   /* XXX: we could actually move ssl_io_filter_handshake to an
>>>>>* ap_hook_process_connection but would still need to call it for
>>>>>* AP_MODE_INIT for protocols that may upgrade the connection
>>>>>* rather than have SSLEngine On configured.
>>>>>*/
>>>>>   if ((status = ssl_io_filter_handshake(inctx->filter_ctx)) !=
>>>>> APR_SUCCESS) {
>>>>>   return ssl_io_filter_error(f, bb, status);
>>>>>   }
>>>>> 
>>>>> The handshake handling gets triggered on a filter, so it all happens on
>>>>> READs (or WRITEs), which explains why connection hooks do not see it. This
>>>>> is quite some code which looks like we do not want to touch for a "quick
>>>>> fix". Also, there is no quick fix inside mod_http2 as before handshake,
>>>>> the SNI might also not be there yet, thus the vhost cannot be determined.
>>>>> etc.
>>>>> 
>>>>> For the current release, I think we should leave it as it is and advise
>>>>> that current mod_http2 is incompatible with things like nntp.
>>>>> 
>>>>> For the next release, I'd like the server to perform the handshake at a
>>>>> defined time, so other modules can rely on protocols being selected and
>>>>> correct vhost being known before the first read/write.
>>>>> 
>>>>> //Stefan
>>>>> 
>>> 

RE: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Plüm , Rüdiger , Vodafone Group]

> -Original Message-
> From: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
> Sent: Montag, 12. Oktober 2015 10:58
> To: dev@httpd.apache.org
> Subject: Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is
> loaded
> 
> The AP_MODE_INIT triggers the handshake nicely. But the protocol switching
> still happens
> on the first read. currently looking how to trigger that best.

Even in the ALPN case the protocol switching happens on the first read after 
the handshake?

Regards

Rüdiger

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

It is default for some, others do not do it. 

No browser speaks h2c nowadays. 

I think reading bytes on a connection which is supposed to allow h2c traffic 
should be fine. Then one could argue if 24 bytes can always be expected...

Since we no longer enabled h2c by default in a server, I expect it to be fine. 

//Stefan

> Am 12.10.2015 um 11:12 schrieb Yann Ylavic :
> 
> That would be better, but still the doc says "This mode falls outside
> the RFC 7540 but has become widely implemented as it is very
> convenient for development and testing".
> Is this something used by real world h2 clients?
> 
> On Mon, Oct 12, 2015 at 11:09 AM, Stefan Eissing
>  wrote:
>> I plan to change it to only happen for servers, where h2/h2c is among 
>> configured protocols.
>> 
>>> Am 12.10.2015 um 11:07 schrieb Yann Ylavic :
>>> 
>>> On Sun, Oct 11, 2015 at 7:15 PM, Yann Ylavic  wrote:
 On Sun, Oct 11, 2015 at 7:11 PM, Stefan Eissing
  wrote:
> Don't think so. But loading the module should do no harm, I think. And it 
> does now.
 
 Isn't configuring H2Direct on which harms?
>>> 
>>> Didn't figure out "H2Direct on" was the default for non-TLS.
>>> I don't think it's a good idea, beyond the NNTP case, the admin should
>>> have to enable this by her/his own.
>> 

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Rainer Jung]

Am 12.10.2015 um 11:09 schrieb Stefan Eissing:

I plan to change it to only happen for servers, where h2/h2c is among 
configured protocols.


Am 12.10.2015 um 11:07 schrieb Yann Ylavic :

On Sun, Oct 11, 2015 at 7:15 PM, Yann Ylavic  wrote:

On Sun, Oct 11, 2015 at 7:11 PM, Stefan Eissing
 wrote:

Don't think so. But loading the module should do no harm, I think. And it does 
now.


Isn't configuring H2Direct on which harms?


Didn't figure out "H2Direct on" was the default for non-TLS.
I don't think it's a good idea, beyond the NNTP case, the admin should
have to enable this by her/his own.


Since I started this thread: IMHO this discussion shouldn't 
stop/influence 2.4.17. mod_http2 is experimental, so even a change of 
defaults in early releases should be OK. And any exotic interop problems 
are not critical enough to roll another release.


Regards,

Rainer

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

On Mon, Oct 12, 2015 at 11:12 AM, Yann Ylavic  wrote:
> Is this something used by real world h2 clients?

I meant browers :p

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

I plan to change it to only happen for servers, where h2/h2c is among 
configured protocols.

> Am 12.10.2015 um 11:07 schrieb Yann Ylavic :
> 
> On Sun, Oct 11, 2015 at 7:15 PM, Yann Ylavic  wrote:
>> On Sun, Oct 11, 2015 at 7:11 PM, Stefan Eissing
>>  wrote:
>>> Don't think so. But loading the module should do no harm, I think. And it 
>>> does now.
>> 
>> Isn't configuring H2Direct on which harms?
> 
> Didn't figure out "H2Direct on" was the default for non-TLS.
> I don't think it's a good idea, beyond the NNTP case, the admin should
> have to enable this by her/his own.

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

On Sun, Oct 11, 2015 at 7:15 PM, Yann Ylavic  wrote:
> On Sun, Oct 11, 2015 at 7:11 PM, Stefan Eissing
>  wrote:
>> Don't think so. But loading the module should do no harm, I think. And it 
>> does now.
>
> Isn't configuring H2Direct on which harms?

Didn't figure out "H2Direct on" was the default for non-TLS.
I don't think it's a good idea, beyond the NNTP case, the admin should
have to enable this by her/his own.

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

That would be better, but still the doc says "This mode falls outside
the RFC 7540 but has become widely implemented as it is very
convenient for development and testing".
Is this something used by real world h2 clients?

On Mon, Oct 12, 2015 at 11:09 AM, Stefan Eissing
 wrote:
> I plan to change it to only happen for servers, where h2/h2c is among 
> configured protocols.
>
>> Am 12.10.2015 um 11:07 schrieb Yann Ylavic :
>>
>> On Sun, Oct 11, 2015 at 7:15 PM, Yann Ylavic  wrote:
>>> On Sun, Oct 11, 2015 at 7:11 PM, Stefan Eissing
>>>  wrote:
 Don't think so. But loading the module should do no harm, I think. And it 
 does now.
>>>
>>> Isn't configuring H2Direct on which harms?
>>
>> Didn't figure out "H2Direct on" was the default for non-TLS.
>> I don't think it's a good idea, beyond the NNTP case, the admin should
>> have to enable this by her/his own.
>

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Graham Leggett]

On 11 Oct 2015, at 7:00 PM, Stefan Eissing  wrote:

> Ok, analyzed the code. Here is what seems to be happening:
> 
> - mod_http2, in the connection hook, does a blocking, speculative read to
>  a) make sure the ALPN has been triggered

Looking at the code inside the event MPM that calls 
ap_run_process_connection(), it looks like you can just do a non blocking read, 
and if you haven’t received enough bytes, return DECLINED and expect to be 
called again.

This presupposes that other connection filters aren’t trying to be excessively 
cleaver by stealing your connection away from you and then responding to your 
data (for example by error-ing out), which they may do by doing blocking reads.

Regards,
Graham
—

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

With r1708107 I committed the following changes to /trunk:

mod_ssl:
- calling ap_switch_protocol directly after ap_select protocol from inside the 
SSL ALPN callback. Error in switching will result in a TLS error which seems 
correct. This makes sure that after the ALPN has been triggered, the protocol 
switch is in place.
- alpn_finished check in ssl_engine_io could be removed then. Less flags and 
#ifdefs overall...

mod_http2:
- connection hook triggers handshake by reading in AP_MODE_INIT 0 bytes
- connection hook only every tries to do a blocking read if H2Direct is enabled 
and the connection is still on protocol "http/1.1"
- the default for H2Direct has been changed to "off" for all kinds of 
connections
- documentation xml updated
- ht_task_input passes AP_MODE_INIT calls on to chained filters

I did not test the nntp case (can I? how?), but this should address the issue.

Observations:
- The AP_MODE_INIT read should be done in a connection hook of mod_ssl itself. 
Other modules like mod_http2 should not care about that.
- With SNI, the selected virtual host really is a property of the connection. 
It would be good to get access to it from other modules *without* having a 
request_rec

Thanks for all the good suggestiongs from Yann and Rüdiger!

//Stefan

> Am 12.10.2015 um 14:10 schrieb Graham Leggett :
> 
> On 11 Oct 2015, at 7:00 PM, Stefan Eissing  
> wrote:
> 
>> Ok, analyzed the code. Here is what seems to be happening:
>> 
>> - mod_http2, in the connection hook, does a blocking, speculative read to
>> a) make sure the ALPN has been triggered
> 
> Looking at the code inside the event MPM that calls 
> ap_run_process_connection(), it looks like you can just do a non blocking 
> read, and if you haven’t received enough bytes, return DECLINED and expect to 
> be called again.
> 
> This presupposes that other connection filters aren’t trying to be 
> excessively cleaver by stealing your connection away from you and then 
> responding to your data (for example by error-ing out), which they may do by 
> doing blocking reads.
> 
> Regards,
> Graham
> —
> 

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Jacob Champion]

On 10/12/2015 02:12 AM, Yann Ylavic wrote:

That would be better, but still the doc says "[H2Direct] falls outside
the RFC 7540 but has become widely implemented as it is very
convenient for development and testing".


_Does_ it fall outside the RFC? Section 3.4 covers the establishment of 
(cleartext) HTTP/2 connections via prior knowledge, and seems to 
describe exactly this use case:


> A client MUST send the connection preface (Section 3.5) and then MAY
> immediately send HTTP/2 frames to such a server; servers can identify
> these connections by the presence of the connection preface.

I agree that the method of establishing this prior knowledge is 
undefined, but the h2-direct mode seems to be within the RFC's scope. If 
you agree, I'd suggest removing that line from the docs.


--Jacob

2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Rainer Jung]

I get a test failure for 2.4.17 in the mod_nntp_like_ssl part. Te 
failure happens on Solaris. Note that the nntp tests are disabled by 
default on Linux because of problems with the kernel accept filter, so 
that many of you wont run this test and thus not observe the problem.


The problems is that the test hangs after test 1 when waiting for the 
result of 2. On Solaris 8 the behavior changes a bit, there test 2 
succeeds, but 3-5 receive an empty result. The difference might be due 
to slight perl test differences. I suspect a common root cause.


Maybe the problem is due to some unclean brigade handling in 
mod_nntp_like_ssl (in light of recent dev list discussions)? Or 
mod_http2 is simply incompatible with mod_nntp_like_ssl and we should 
disable that test if mod_http2 is loaded?


Trace 8 log comparison between good runs (without having mod_http2 
loaded) and bad runs (having mod_http2 loaded):


Good run (no mod_http2)

- end of handshake and immediately write 52 bytes

[Sun Oct 11 14:53:47.911105 2015] [ssl:trace3] [pid 23096:tid 27] 
ssl_engine_kernel.c(1810): [client 127.0.0.1:50990] OpenSSL: Handshake: done
[Sun Oct 11 14:53:47.911142 2015] [ssl:debug] [pid 23096:tid 27] 
ssl_engine_kernel.c(1855): [client 127.0.0.1:50990] AH02041: Protocol: 
TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Sun Oct 11 14:53:47.911212 2015] [ssl:trace4] [pid 23096:tid 27] 
ssl_engine_io.c(2088): [client 127.0.0.1:50990] OpenSSL: write 52/52 
bytes to BIO#2861b8 [mem: 2bd45b] (BIO dump follows)



Bad run (including mod_http2)

- end of handshake

[Sun Oct 11 14:54:38.550476 2015] [ssl:trace3] [pid 23133:tid 50] 
ssl_engine_kernel.c(1810): [client 127.0.0.1:50994] OpenSSL: Handshake: done
[Sun Oct 11 14:54:38.550520 2015] [ssl:debug] [pid 23133:tid 50] 
ssl_engine_kernel.c(1855): [client 127.0.0.1:50994] AH02041: Protocol: 
TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Sun Oct 11 14:54:38.550555 2015] [core:trace6] [pid 23133:tid 50] 
core_filters.c(523): [client 127.0.0.1:50994] core_output_filter: 
flushing because of FLUSH bucket


- one minute established connection, but nothing else

[Sun Oct 11 14:54:39.274796 2015] [mpm_event:trace6] [pid 23133:tid 53] 
event.c(1577): connections: 1 (clogged: 0 write-completion: 0 
keep-alive: 0 lingering: 0 suspended: 0)

...

- timeout after one minute and write 52 bytes

[Sun Oct 11 14:55:38.551174 2015] [ssl:trace4] [pid 23133:tid 50] 
ssl_engine_io.c(2099): [client 127.0.0.1:50994] OpenSSL: I/O error, 5 
bytes expected to read on BIO#273480 [mem: 3624e3]
[Sun Oct 11 14:55:38.551253 2015] [ssl:info] [pid 23133:tid 50] 
(70007)The timeout specified has expired: [client 127.0.0.1:50994] 
AH01991: SSL input filter read failed.
[Sun Oct 11 14:55:38.551316 2015] [http2:debug] [pid 23133:tid 50] 
h2_h2.c(189): (70007)The timeout specified has expired: [client 
127.0.0.1:50994] h2_h2, error reading 24 bytes speculative
[Sun Oct 11 14:55:38.551344 2015] [http2:trace1] [pid 23133:tid 50] 
h2_h2.c(205): [client 127.0.0.1:50994] h2_h2, declined
[Sun Oct 11 14:55:38.551433 2015] [ssl:trace4] [pid 23133:tid 50] 
ssl_engine_io.c(2088): [client 127.0.0.1:50994] OpenSSL: write 52/52 
bytes to BIO#282488 [mem: 36a633] (BIO dump follows)


Regards,

Rainer

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Eric Covener]

On Sun, Oct 11, 2015 at 9:32 AM, Rainer Jung  wrote:
> The problems is that the test hangs after test 1 when waiting for the result
> of 2. On Solaris 8 the behavior changes a bit, there test 2 succeeds, but
> 3-5 receive an empty result. The difference might be due to slight perl test
> differences. I suspect a common root cause.


Seen on AIX too, but I am struggling with some non system openssl
1.0.2 issues though (between httpd, framework, and 32-bit perl modules
that use the native code) and can't even re-run at the moment.

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Rainer Jung]

Am 11.10.2015 um 19:08 schrieb Yann Ylavic:

On Sun, Oct 11, 2015 at 7:00 PM, Stefan Eissing
 wrote:

Ok, analyzed the code. Here is what seems to be happening:

- mod_http2, in the connection hook, does a blocking, speculative read to
   a) make sure the ALPN has been triggered
   b) check for the magic 24 bytes h2 preface in case H2Direct is on
   This works fine for HTTP/1.1 or protocols where the client starts sending 
bytes right away.
   If the client waits for something from the server first, it gives a timeout. 
This seems to be the NNTP case.


Does it make any sense to enable h2 on NNTP?


For now I disabled the nntp over ssl test when mod_http2 is loaded 
(disabled in the test file) so that the test suite does not hang.


I guess we don't want to test h2 and NNTP on the same requests, but it 
would be ideal, if the modules would not disturb each other, if they 
serve different vhosts in the same Apache. If that's not possible and 
doesn't actually indicate a bigger problem, I'm personally fine with 
that incompatibility with protocols that show "server sends first" behavior.


Regards,

Rainer

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

> Am 11.10.2015 um 19:19 schrieb Rainer Jung :
> 
> Am 11.10.2015 um 19:08 schrieb Yann Ylavic:
>> On Sun, Oct 11, 2015 at 7:00 PM, Stefan Eissing
>>  wrote:
>>> Ok, analyzed the code. Here is what seems to be happening:
>>> 
>>> - mod_http2, in the connection hook, does a blocking, speculative read to
>>>   a) make sure the ALPN has been triggered
>>>   b) check for the magic 24 bytes h2 preface in case H2Direct is on
>>>   This works fine for HTTP/1.1 or protocols where the client starts sending 
>>> bytes right away.
>>>   If the client waits for something from the server first, it gives a 
>>> timeout. This seems to be the NNTP case.
>> 
>> Does it make any sense to enable h2 on NNTP?
> 
> For now I disabled the nntp over ssl test when mod_http2 is loaded (disabled 
> in the test file) so that the test suite does not hang.
> 
> I guess we don't want to test h2 and NNTP on the same requests, but it would 
> be ideal, if the modules would not disturb each other, if they serve 
> different vhosts in the same Apache. If that's not possible and doesn't 
> actually indicate a bigger problem, I'm personally fine with that 
> incompatibility with protocols that show "server sends first" behavior.

Agreed. What we need is a way to make sure that any ALPN handling is done for 
later connection hooks. Then mod_http2 will only need to sniff when H2Direct is 
enabled.

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

On Sun, Oct 11, 2015 at 7:00 PM, Stefan Eissing
 wrote:
> Ok, analyzed the code. Here is what seems to be happening:
>
> - mod_http2, in the connection hook, does a blocking, speculative read to
>   a) make sure the ALPN has been triggered
>   b) check for the magic 24 bytes h2 preface in case H2Direct is on
>   This works fine for HTTP/1.1 or protocols where the client starts sending 
> bytes right away.
>   If the client waits for something from the server first, it gives a 
> timeout. This seems to be the NNTP case.

Does it make any sense to enable h2 on NNTP?

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Yann Ylavic]

On Sun, Oct 11, 2015 at 7:11 PM, Stefan Eissing
 wrote:
> Don't think so. But loading the module should do no harm, I think. And it 
> does now.

Isn't configuring H2Direct on which harms?

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

Ok, in ssl_engine_io.c, lines 1426+ I see a hint:

/* XXX: we could actually move ssl_io_filter_handshake to an
 * ap_hook_process_connection but would still need to call it for
 * AP_MODE_INIT for protocols that may upgrade the connection
 * rather than have SSLEngine On configured.
 */
if ((status = ssl_io_filter_handshake(inctx->filter_ctx)) != APR_SUCCESS) {
return ssl_io_filter_error(f, bb, status);
}

The handshake handling gets triggered on a filter, so it all happens on READs 
(or WRITEs), which explains why connection hooks do not see it. This is quite 
some code which looks like we do not want to touch for a "quick fix". Also, 
there is no quick fix inside mod_http2 as before handshake, the SNI might also 
not be there yet, thus the vhost cannot be determined. etc.

For the current release, I think we should leave it as it is and advise that 
current mod_http2 is incompatible with things like nntp.

For the next release, I'd like the server to perform the handshake at a defined 
time, so other modules can rely on protocols being selected and correct vhost 
being known before the first read/write.

//Stefan

> Am 11.10.2015 um 19:30 schrieb Stefan Eissing :
> 
> What is the penalty of invoking SSL_do_handshake(ssl) on the server side for 
> a new connection? We do this on renegotiate and upgrade cases...
> 
>> Am 11.10.2015 um 19:23 schrieb Stefan Eissing :
>> 
>> 
>>> Am 11.10.2015 um 19:19 schrieb Rainer Jung :
>>> 
>>> Am 11.10.2015 um 19:08 schrieb Yann Ylavic:
 On Sun, Oct 11, 2015 at 7:00 PM, Stefan Eissing
  wrote:
> Ok, analyzed the code. Here is what seems to be happening:
> 
> - mod_http2, in the connection hook, does a blocking, speculative read to
> a) make sure the ALPN has been triggered
> b) check for the magic 24 bytes h2 preface in case H2Direct is on
> This works fine for HTTP/1.1 or protocols where the client starts sending 
> bytes right away.
> If the client waits for something from the server first, it gives a 
> timeout. This seems to be the NNTP case.
 
 Does it make any sense to enable h2 on NNTP?
>>> 
>>> For now I disabled the nntp over ssl test when mod_http2 is loaded 
>>> (disabled in the test file) so that the test suite does not hang.
>>> 
>>> I guess we don't want to test h2 and NNTP on the same requests, but it 
>>> would be ideal, if the modules would not disturb each other, if they serve 
>>> different vhosts in the same Apache. If that's not possible and doesn't 
>>> actually indicate a bigger problem, I'm personally fine with that 
>>> incompatibility with protocols that show "server sends first" behavior.
>> 
>> Agreed. What we need is a way to make sure that any ALPN handling is done 
>> for later connection hooks. Then mod_http2 will only need to sniff when 
>> H2Direct is enabled.
> 

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

Hmm, will look into this. The module does a speculative non_blocking read on 
the connection. 

That happens only if H2Direct is "on", which I enabled to allow test when the 
client does not have ALPN.

Then it can detect on the first 24 bytes if the client starts talking h2 right 
away. Is doing a speculative read messing up the handshake? 

This is not a usual config. 

//stefan

> Am 11.10.2015 um 15:32 schrieb Rainer Jung :
> 
> I get a test failure for 2.4.17 in the mod_nntp_like_ssl part. Te failure 
> happens on Solaris. Note that the nntp tests are disabled by default on Linux 
> because of problems with the kernel accept filter, so that many of you wont 
> run this test and thus not observe the problem.
> 
> The problems is that the test hangs after test 1 when waiting for the result 
> of 2. On Solaris 8 the behavior changes a bit, there test 2 succeeds, but 3-5 
> receive an empty result. The difference might be due to slight perl test 
> differences. I suspect a common root cause.
> 
> Maybe the problem is due to some unclean brigade handling in 
> mod_nntp_like_ssl (in light of recent dev list discussions)? Or mod_http2 is 
> simply incompatible with mod_nntp_like_ssl and we should disable that test if 
> mod_http2 is loaded?
> 
> Trace 8 log comparison between good runs (without having mod_http2 loaded) 
> and bad runs (having mod_http2 loaded):
> 
> Good run (no mod_http2)
> 
> - end of handshake and immediately write 52 bytes
> 
> [Sun Oct 11 14:53:47.911105 2015] [ssl:trace3] [pid 23096:tid 27] 
> ssl_engine_kernel.c(1810): [client 127.0.0.1:50990] OpenSSL: Handshake: done
> [Sun Oct 11 14:53:47.911142 2015] [ssl:debug] [pid 23096:tid 27] 
> ssl_engine_kernel.c(1855): [client 127.0.0.1:50990] AH02041: Protocol: 
> TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
> [Sun Oct 11 14:53:47.911212 2015] [ssl:trace4] [pid 23096:tid 27] 
> ssl_engine_io.c(2088): [client 127.0.0.1:50990] OpenSSL: write 52/52 bytes to 
> BIO#2861b8 [mem: 2bd45b] (BIO dump follows)
> 
> 
> Bad run (including mod_http2)
> 
> - end of handshake
> 
> [Sun Oct 11 14:54:38.550476 2015] [ssl:trace3] [pid 23133:tid 50] 
> ssl_engine_kernel.c(1810): [client 127.0.0.1:50994] OpenSSL: Handshake: done
> [Sun Oct 11 14:54:38.550520 2015] [ssl:debug] [pid 23133:tid 50] 
> ssl_engine_kernel.c(1855): [client 127.0.0.1:50994] AH02041: Protocol: 
> TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
> [Sun Oct 11 14:54:38.550555 2015] [core:trace6] [pid 23133:tid 50] 
> core_filters.c(523): [client 127.0.0.1:50994] core_output_filter: flushing 
> because of FLUSH bucket
> 
> - one minute established connection, but nothing else
> 
> [Sun Oct 11 14:54:39.274796 2015] [mpm_event:trace6] [pid 23133:tid 53] 
> event.c(1577): connections: 1 (clogged: 0 write-completion: 0 keep-alive: 0 
> lingering: 0 suspended: 0)
> ...
> 
> - timeout after one minute and write 52 bytes
> 
> [Sun Oct 11 14:55:38.551174 2015] [ssl:trace4] [pid 23133:tid 50] 
> ssl_engine_io.c(2099): [client 127.0.0.1:50994] OpenSSL: I/O error, 5 bytes 
> expected to read on BIO#273480 [mem: 3624e3]
> [Sun Oct 11 14:55:38.551253 2015] [ssl:info] [pid 23133:tid 50] (70007)The 
> timeout specified has expired: [client 127.0.0.1:50994] AH01991: SSL input 
> filter read failed.
> [Sun Oct 11 14:55:38.551316 2015] [http2:debug] [pid 23133:tid 50] 
> h2_h2.c(189): (70007)The timeout specified has expired: [client 
> 127.0.0.1:50994] h2_h2, error reading 24 bytes speculative
> [Sun Oct 11 14:55:38.551344 2015] [http2:trace1] [pid 23133:tid 50] 
> h2_h2.c(205): [client 127.0.0.1:50994] h2_h2, declined
> [Sun Oct 11 14:55:38.551433 2015] [ssl:trace4] [pid 23133:tid 50] 
> ssl_engine_io.c(2088): [client 127.0.0.1:50994] OpenSSL: write 52/52 bytes to 
> BIO#282488 [mem: 36a633] (BIO dump follows)
> 
> Regards,
> 
> Rainer

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

Ok, analyzed the code. Here is what seems to be happening:

- mod_http2, in the connection hook, does a blocking, speculative read to
  a) make sure the ALPN has been triggered
  b) check for the magic 24 bytes h2 preface in case H2Direct is on
  This works fine for HTTP/1.1 or protocols where the client starts sending 
bytes right away.
  If the client waits for something from the server first, it gives a timeout. 
This seems to be the NNTP case.

A. The important part is to get the ALPN triggered without a blocking read. Any 
advice from our TLS experts?
B. When that is solved, the check for the 24 bytes can be folder deeper to just 
happen on a H2Direct enabled server/vhost.

The fix for A ideally should be placed into mod_ssl, saving other 
protocol-selection code to mess with it, I think. But for the short term, I'd 
be happy with any advice on how to fix it in mod_http2 alone.

//Stefan


> Am 11.10.2015 um 18:26 schrieb Stefan Eissing :
> 
> Hmm, will look into this. The module does a speculative non_blocking read on 
> the connection. 
> 
> That happens only if H2Direct is "on", which I enabled to allow test when the 
> client does not have ALPN.
> 
> Then it can detect on the first 24 bytes if the client starts talking h2 
> right away. Is doing a speculative read messing up the handshake? 
> 
> This is not a usual config. 
> 
> //stefan
> 
>> Am 11.10.2015 um 15:32 schrieb Rainer Jung :
>> 
>> I get a test failure for 2.4.17 in the mod_nntp_like_ssl part. Te failure 
>> happens on Solaris. Note that the nntp tests are disabled by default on 
>> Linux because of problems with the kernel accept filter, so that many of you 
>> wont run this test and thus not observe the problem.
>> 
>> The problems is that the test hangs after test 1 when waiting for the result 
>> of 2. On Solaris 8 the behavior changes a bit, there test 2 succeeds, but 
>> 3-5 receive an empty result. The difference might be due to slight perl test 
>> differences. I suspect a common root cause.
>> 
>> Maybe the problem is due to some unclean brigade handling in 
>> mod_nntp_like_ssl (in light of recent dev list discussions)? Or mod_http2 is 
>> simply incompatible with mod_nntp_like_ssl and we should disable that test 
>> if mod_http2 is loaded?
>> 
>> Trace 8 log comparison between good runs (without having mod_http2 loaded) 
>> and bad runs (having mod_http2 loaded):
>> 
>> Good run (no mod_http2)
>> 
>> - end of handshake and immediately write 52 bytes
>> 
>> [Sun Oct 11 14:53:47.911105 2015] [ssl:trace3] [pid 23096:tid 27] 
>> ssl_engine_kernel.c(1810): [client 127.0.0.1:50990] OpenSSL: Handshake: done
>> [Sun Oct 11 14:53:47.911142 2015] [ssl:debug] [pid 23096:tid 27] 
>> ssl_engine_kernel.c(1855): [client 127.0.0.1:50990] AH02041: Protocol: 
>> TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
>> [Sun Oct 11 14:53:47.911212 2015] [ssl:trace4] [pid 23096:tid 27] 
>> ssl_engine_io.c(2088): [client 127.0.0.1:50990] OpenSSL: write 52/52 bytes 
>> to BIO#2861b8 [mem: 2bd45b] (BIO dump follows)
>> 
>> 
>> Bad run (including mod_http2)
>> 
>> - end of handshake
>> 
>> [Sun Oct 11 14:54:38.550476 2015] [ssl:trace3] [pid 23133:tid 50] 
>> ssl_engine_kernel.c(1810): [client 127.0.0.1:50994] OpenSSL: Handshake: done
>> [Sun Oct 11 14:54:38.550520 2015] [ssl:debug] [pid 23133:tid 50] 
>> ssl_engine_kernel.c(1855): [client 127.0.0.1:50994] AH02041: Protocol: 
>> TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
>> [Sun Oct 11 14:54:38.550555 2015] [core:trace6] [pid 23133:tid 50] 
>> core_filters.c(523): [client 127.0.0.1:50994] core_output_filter: flushing 
>> because of FLUSH bucket
>> 
>> - one minute established connection, but nothing else
>> 
>> [Sun Oct 11 14:54:39.274796 2015] [mpm_event:trace6] [pid 23133:tid 53] 
>> event.c(1577): connections: 1 (clogged: 0 write-completion: 0 keep-alive: 0 
>> lingering: 0 suspended: 0)
>> ...
>> 
>> - timeout after one minute and write 52 bytes
>> 
>> [Sun Oct 11 14:55:38.551174 2015] [ssl:trace4] [pid 23133:tid 50] 
>> ssl_engine_io.c(2099): [client 127.0.0.1:50994] OpenSSL: I/O error, 5 bytes 
>> expected to read on BIO#273480 [mem: 3624e3]
>> [Sun Oct 11 14:55:38.551253 2015] [ssl:info] [pid 23133:tid 50] (70007)The 
>> timeout specified has expired: [client 127.0.0.1:50994] AH01991: SSL input 
>> filter read failed.
>> [Sun Oct 11 14:55:38.551316 2015] [http2:debug] [pid 23133:tid 50] 
>> h2_h2.c(189): (70007)The timeout specified has expired: [client 
>> 127.0.0.1:50994] h2_h2, error reading 24 bytes speculative
>> [Sun Oct 11 14:55:38.551344 2015] [http2:trace1] [pid 23133:tid 50] 
>> h2_h2.c(205): [client 127.0.0.1:50994] h2_h2, declined
>> [Sun Oct 11 14:55:38.551433 2015] [ssl:trace4] [pid 23133:tid 50] 
>> ssl_engine_io.c(2088): [client 127.0.0.1:50994] OpenSSL: write 52/52 bytes 
>> to BIO#282488 [mem: 36a633] (BIO dump follows)
>> 
>> Regards,
>> 
>> Rainer

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

Don't think so. But loading the module should do no harm, I think. And it does 
now.

I am not familiar with the NNTP use case. Is this always an NNTP-only server 
then?

> Am 11.10.2015 um 19:08 schrieb Yann Ylavic :
> 
> On Sun, Oct 11, 2015 at 7:00 PM, Stefan Eissing
>  wrote:
>> Ok, analyzed the code. Here is what seems to be happening:
>> 
>> - mod_http2, in the connection hook, does a blocking, speculative read to
>>  a) make sure the ALPN has been triggered
>>  b) check for the magic 24 bytes h2 preface in case H2Direct is on
>>  This works fine for HTTP/1.1 or protocols where the client starts sending 
>> bytes right away.
>>  If the client waits for something from the server first, it gives a 
>> timeout. This seems to be the NNTP case.
> 
> Does it make any sense to enable h2 on NNTP?

Re: 2.4.17 test failure for mod_nntp_like_ssl when mod_http2 is loaded

[Stefan Eissing]

What is the penalty of invoking SSL_do_handshake(ssl) on the server side for a 
new connection? We do this on renegotiate and upgrade cases...

> Am 11.10.2015 um 19:23 schrieb Stefan Eissing :
> 
> 
>> Am 11.10.2015 um 19:19 schrieb Rainer Jung :
>> 
>> Am 11.10.2015 um 19:08 schrieb Yann Ylavic:
>>> On Sun, Oct 11, 2015 at 7:00 PM, Stefan Eissing
>>>  wrote:
 Ok, analyzed the code. Here is what seems to be happening:
 
 - mod_http2, in the connection hook, does a blocking, speculative read to
  a) make sure the ALPN has been triggered
  b) check for the magic 24 bytes h2 preface in case H2Direct is on
  This works fine for HTTP/1.1 or protocols where the client starts sending 
 bytes right away.
  If the client waits for something from the server first, it gives a 
 timeout. This seems to be the NNTP case.
>>> 
>>> Does it make any sense to enable h2 on NNTP?
>> 
>> For now I disabled the nntp over ssl test when mod_http2 is loaded (disabled 
>> in the test file) so that the test suite does not hang.
>> 
>> I guess we don't want to test h2 and NNTP on the same requests, but it would 
>> be ideal, if the modules would not disturb each other, if they serve 
>> different vhosts in the same Apache. If that's not possible and doesn't 
>> actually indicate a bigger problem, I'm personally fine with that 
>> incompatibility with protocols that show "server sends first" behavior.
> 
> Agreed. What we need is a way to make sure that any ALPN handling is done for 
> later connection hooks. Then mod_http2 will only need to sniff when H2Direct 
> is enabled.