Ok, both clients do not provide the server name via the TLS SNI extension. That 
is strange. How did you get the server/h2load installed on your Ubuntu? Default 
Ubuntu comes without mod_http2 AFAIK...(and which Ubuntu is it?) Thanks!

> Am 25.08.2016 um 16:49 schrieb Max Meyer <redeemerofsouls...@web.de>:
> 
> I created a new certificate, now the cert name matches but h2load still falls 
> back to HTTP/1.1
> 
> Here is the error.log after apache restart
> 
> -----------
> 
> [Thu Aug 25 16:38:12.351311 2016] [ssl:info] [pid 3931] AH01887: Init: 
> Initializing (virtual) servers for SSL
> [Thu Aug 25 16:38:12.351381 2016] [ssl:info] [pid 3931] AH01914: Configuring 
> server localhost:443 for SSL protocol
> [Thu Aug 25 16:38:12.351604 2016] [ssl:debug] [pid 3931] 
> ssl_engine_init.c(413): AH01893: Configuring TLS extension handling
> [Thu Aug 25 16:38:12.351843 2016] [ssl:debug] [pid 3931] ssl_util_ssl.c(443): 
> AH02412: [localhost:443] Cert matches for name 'localhost' [subject: 
> CN=localhost,O=Internet Widgits Pty Ltd,ST=Some-State,C=AU / issuer: 
> CN=localhost,O=Internet Widgits Pty Ltd,ST=Some-State,C=AU / serial: 
> A8AC62CFC0533ACA / notbefore: Aug 25 14:07:20 2016 GMT / notafter: Aug 23 
> 14:07:20 2026 GMT]
> [Thu Aug 25 16:38:12.351854 2016] [ssl:info] [pid 3931] AH02568: Certificate 
> and private key localhost:443:0 configured from /etc/ssl/server.crt and 
> /etc/ssl/private.key
> [Thu Aug 25 16:38:12.351948 2016] [ssl:info] [pid 3931] AH01876: 
> mod_ssl/2.4.23 compiled against Server: Apache/2.4.23, Library: OpenSSL/1.0.2h
> [Thu Aug 25 16:38:12.351975 2016] [http2:debug] [pid 3931] mod_http2.c(101): 
> AH03089: initializing post config dry run
> [Thu Aug 25 16:38:12.372115 2016] [ssl:info] [pid 3932] AH01887: Init: 
> Initializing (virtual) servers for SSL
> [Thu Aug 25 16:38:12.372143 2016] [ssl:info] [pid 3932] AH01914: Configuring 
> server localhost:443 for SSL protocol
> [Thu Aug 25 16:38:12.372363 2016] [ssl:debug] [pid 3932] 
> ssl_engine_init.c(413): AH01893: Configuring TLS extension handling
> [Thu Aug 25 16:38:12.372598 2016] [ssl:debug] [pid 3932] ssl_util_ssl.c(443): 
> AH02412: [localhost:443] Cert matches for name 'localhost' [subject: 
> CN=localhost,O=Internet Widgits Pty Ltd,ST=Some-State,C=AU / issuer: 
> CN=localhost,O=Internet Widgits Pty Ltd,ST=Some-State,C=AU / serial: 
> A8AC62CFC0533ACA / notbefore: Aug 25 14:07:20 2016 GMT / notafter: Aug 23 
> 14:07:20 2026 GMT]
> [Thu Aug 25 16:38:12.372609 2016] [ssl:info] [pid 3932] AH02568: Certificate 
> and private key localhost:443:0 configured from /etc/ssl/server.crt and 
> /etc/ssl/private.key
> [Thu Aug 25 16:38:12.372703 2016] [ssl:info] [pid 3932] AH01876: 
> mod_ssl/2.4.23 compiled against Server: Apache/2.4.23, Library: OpenSSL/1.0.2h
> [Thu Aug 25 16:38:12.372738 2016] [http2:info] [pid 3932] AH03090: mod_http2 
> (v1.5.11, feats=CHPRIO+SHA256, nghttp2 1.12.0-DEV), initializing...
> [Thu Aug 25 16:38:12.395339 2016] [mpm_prefork:notice] [pid 3932] AH00163: 
> Apache/2.4.23 (Ubuntu) OpenSSL/1.0.2h PHP/5.5.9-1ubuntu4.19 configured -- 
> resuming normal operations
> [Thu Aug 25 16:38:12.395406 2016] [core:notice] [pid 3932] AH00094: Command 
> line: '/usr/sbin/apache2'
> [Thu Aug 25 16:38:12.395414 2016] [core:debug] [pid 3932] log.c(1546): 
> AH02639: Using SO_REUSEPORT: yes (1)
> ----------
> 
> Then I tried to use h2load
> ---------
> 
> [Thu Aug 25 16:38:26.346029 2016] [ssl:info] [pid 3935] [client 
> 10.0.0.4:52613] AH01964: Connection to child 0 established (server 
> localhost:443)
> [Thu Aug 25 16:38:26.346479 2016] [ssl:debug] [pid 3935] 
> ssl_engine_kernel.c(2143): [client 10.0.0.4:52613] AH02645: Server name not 
> provided via TLS extension (using default/first virtual host)
> [Thu Aug 25 16:38:26.406552 2016] [ssl:debug] [pid 3935] 
> ssl_engine_kernel.c(2042): [client 10.0.0.4:52613] AH02041: Protocol: 
> TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
> [Thu Aug 25 16:38:26.407026 2016] [ssl:debug] [pid 3935] 
> ssl_engine_kernel.c(366): [client 10.0.0.4:52613] AH02034: Initial (No.1) 
> HTTPS request received for child 0 (server localhost:443)
> [Thu Aug 25 16:38:26.407293 2016] [ssl:debug] [pid 3935] 
> ssl_engine_kernel.c(366): [client 10.0.0.4:52613] AH02034: Subsequent (No.2) 
> HTTPS request received for child 0 (server localhost:443)
> [Thu Aug 25 16:38:26.407916 2016] [ssl:debug] [pid 3935] 
> ssl_engine_io.c(1033): [client 10.0.0.4:52613] AH02001: Connection closed to 
> child 0 with standard shutdown (server localhost:443)
> --------
> and finally I used firefox
> -------
> [Thu Aug 25 16:38:29.196386 2016] [ssl:info] [pid 3936] [client 
> 10.0.0.4:52614] AH01964: Connection to child 1 established (server 
> localhost:443)
> [Thu Aug 25 16:38:29.197365 2016] [ssl:debug] [pid 3936] 
> ssl_engine_kernel.c(2143): [client 10.0.0.4:52614] AH02645: Server name not 
> provided via TLS extension (using default/first virtual host)
> [Thu Aug 25 16:38:29.197542 2016] [ssl:debug] [pid 3936] 
> ssl_engine_kernel.c(2143): [client 10.0.0.4:52614] AH02645: Server name not 
> provided via TLS extension (using default/first virtual host)
> [Thu Aug 25 16:38:29.197563 2016] [core:debug] [pid 3936] protocol.c(1893): 
> [client 10.0.0.4:52614] AH03155: select protocol from h2, 
> choices=h2,spdy/3.1,http/1.1 for server localhost
> [Thu Aug 25 16:38:29.197599 2016] [core:debug] [pid 3936] protocol.c(1938): 
> [client 10.0.0.4:52614] AH03156: select protocol, proposals=h2,http/1.1 
> preferences=h2 configured=h2
> [Thu Aug 25 16:38:29.197614 2016] [core:debug] [pid 3936] protocol.c(1956): 
> [client 10.0.0.4:52614] AH03157: selected protocol=h2
> [Thu Aug 25 16:38:29.208965 2016] [ssl:debug] [pid 3936] 
> ssl_engine_kernel.c(2042): [client 10.0.0.4:52614] AH02041: Protocol: 
> TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
> [Thu Aug 25 16:38:29.209126 2016] [http2:debug] [pid 3936] h2_session.c(956): 
> [client 10.0.0.4:52614] AH03200: h2_session(1) created, max_streams=100, 
> stream_mem=65536, workers_limit=4, workers_max=1, push_diary(type=1,N=256)
> [Thu Aug 25 16:38:29.209163 2016] [http2:debug] [pid 3936] 
> h2_session.c(1058): [client 10.0.0.4:52614] AH03201: h2_session(1): start, 
> INITIAL_WINDOW_SIZE=65535, MAX_CONCURRENT_STREAMS=100
> [Thu Aug 25 16:38:29.209185 2016] [http2:debug] [pid 3936] 
> h2_session.c(2081): [client 10.0.0.4:52614] AH03079: h2_session(1): started 
> on localhost:443
> [Thu Aug 25 16:38:29.209200 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [INIT] -- init --> [BUSY]
> [Thu Aug 25 16:38:29.209301 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv 
> FRAME[SETTINGS[length=12, stream=0]], frames=0/0 (r/s)
> [Thu Aug 25 16:38:29.209325 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv 
> FRAME[WINDOW_UPDATE[stream=0, incr=12517377]], frames=1/0 (r/s)
> [Thu Aug 25 16:38:29.209346 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv FRAME[PRIORITY[length=5, 
> flags=0, stream=3]], frames=2/0 (r/s)
> [Thu Aug 25 16:38:29.209364 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv FRAME[PRIORITY[length=5, 
> flags=0, stream=5]], frames=3/0 (r/s)
> [Thu Aug 25 16:38:29.209382 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv FRAME[PRIORITY[length=5, 
> flags=0, stream=7]], frames=4/0 (r/s)
> [Thu Aug 25 16:38:29.209400 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv FRAME[PRIORITY[length=5, 
> flags=0, stream=9]], frames=5/0 (r/s)
> [Thu Aug 25 16:38:29.209417 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv FRAME[PRIORITY[length=5, 
> flags=0, stream=11]], frames=6/0 (r/s)
> [Thu Aug 25 16:38:29.209465 2016] [http2:debug] [pid 3936] h2_stream.c(204): 
> [client 10.0.0.4:52614] AH03082: h2_stream(1-13): opened
> [Thu Aug 25 16:38:29.209546 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv 
> FRAME[HEADERS[length=207, hend=1, stream=13, eos=1]], frames=7/0 (r/s)
> [Thu Aug 25 16:38:29.209601 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv 
> FRAME[WINDOW_UPDATE[stream=13, incr=12451840]], frames=8/0 (r/s)
> [Thu Aug 25 16:38:29.209804 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent FRAME[SETTINGS[length=6, 
> stream=0]], frames=9/0 (r/s)
> [Thu Aug 25 16:38:29.209833 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent FRAME[SETTINGS[ack=1, 
> stream=0]], frames=9/1 (r/s)
> [Thu Aug 25 16:38:29.209851 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent 
> FRAME[WINDOW_UPDATE[stream=0, incr=2147418112]], frames=9/2 (r/s)
> [Thu Aug 25 16:38:29.209987 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.209978 2016] [ssl:debug] [pid 3936] 
> ssl_engine_kernel.c(366): [client 10.0.0.4:52614] AH02034: Initial (No.1) 
> HTTPS request received for child 1 (server localhost:443)
> [Thu Aug 25 16:38:29.210258 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.210321 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv FRAME[SETTINGS[ack=1, 
> stream=0]], frames=9/3 (r/s)
> [Thu Aug 25 16:38:29.210378 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.210505 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.210543 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.210666 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.210702 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.210844 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.210878 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.211059 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.211095 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.211353 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.211388 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.211811 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.211848 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.212072 2016] [http2:debug] [pid 3936] h2_task.c(343): 
> [client 10.0.0.4:52614] AH03348: h2_task(1-13): open response to GET 10.0.0.1 
> /
> [Thu Aug 25 16:38:29.212151 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- data read --> [BUSY]
> [Thu Aug 25 16:38:29.212195 2016] [http2:debug] [pid 3936] 
> h2_session.c(1436): [client 10.0.0.4:52614] AH03073: h2_stream(1-13): submit 
> response 200, REMOTE_WINDOW_SIZE=12582912
> [Thu Aug 25 16:38:29.212261 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent 
> FRAME[HEADERS[length=130, hend=1, stream=13, eos=0]], frames=10/3 (r/s)
> [Thu Aug 25 16:38:29.212301 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent FRAME[DATA[length=3041, 
> flags=1, stream=13, padlen=0]], frames=10/4 (r/s)
> [Thu Aug 25 16:38:29.212357 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io (flow wait) --> [IDLE]
> [Thu Aug 25 16:38:29.254198 2016] [http2:debug] [pid 3936] h2_stream.c(204): 
> [client 10.0.0.4:52614] AH03082: h2_stream(1-15): opened
> [Thu Aug 25 16:38:29.254320 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv FRAME[HEADERS[length=52, 
> hend=1, stream=15, eos=1]], frames=10/5 (r/s)
> [Thu Aug 25 16:38:29.254430 2016] [http2:debug] [pid 3936] h2_session.c(443): 
> [client 10.0.0.4:52614] AH03066: h2_session(1): recv 
> FRAME[WINDOW_UPDATE[stream=15, incr=12451840]], frames=11/5 (r/s)
> [Thu Aug 25 16:38:29.254513 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [IDLE] -- data read --> [BUSY]
> [Thu Aug 25 16:38:29.254576 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.254588 2016] [ssl:debug] [pid 3936] 
> ssl_engine_kernel.c(366): [client 10.0.0.4:52614] AH02034: Subsequent (No.2) 
> HTTPS request received for child 1 (server localhost:443), referer: 
> https://10.0.0.1/
> [Thu Aug 25 16:38:29.254769 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.254839 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io --> [WAIT]
> [Thu Aug 25 16:38:29.254940 2016] [http2:debug] [pid 3936] h2_task.c(343): 
> [client 10.0.0.4:52614] AH03348: h2_task(1-15): open response to GET 10.0.0.1 
> /icons/openlogo-75.png
> [Thu Aug 25 16:38:29.254965 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [WAIT] -- wait cycle --> [BUSY]
> [Thu Aug 25 16:38:29.255012 2016] [http2:debug] [pid 3936] 
> h2_session.c(1436): [client 10.0.0.4:52614] AH03073: h2_stream(1-15): submit 
> response 200, REMOTE_WINDOW_SIZE=12582912
> [Thu Aug 25 16:38:29.255082 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent FRAME[HEADERS[length=62, 
> hend=1, stream=15, eos=0]], frames=12/5 (r/s)
> [Thu Aug 25 16:38:29.255139 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent FRAME[DATA[length=5754, 
> flags=1, stream=15, padlen=0]], frames=12/6 (r/s)
> [Thu Aug 25 16:38:29.255180 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [BUSY] -- no io (flow wait) --> [IDLE]
> [Thu Aug 25 16:38:34.262435 2016] [http2:debug] [pid 3936] h2_session.c(655): 
> [client 10.0.0.4:52614] AH03068: h2_session(1): sent FRAME[GOAWAY[error=0, 
> reason='timeout', last_stream=15]], frames=12/7 (r/s)
> [Thu Aug 25 16:38:34.262672 2016] [http2:debug] [pid 3936] h2_session.c(752): 
> [client 10.0.0.4:52614] AH03069: session(1): sent GOAWAY, err=0, msg=timeout
> [Thu Aug 25 16:38:34.262728 2016] [http2:debug] [pid 3936] 
> h2_session.c(1703): [client 10.0.0.4:52614] AH03078: h2_session(1): transit 
> [IDLE] -- local goaway --> [DONE]
> [Thu Aug 25 16:38:34.262925 2016] [http2:debug] [pid 3936] h2_conn.c(215): 
> (70014)End of file found: [client 10.0.0.4:52614] AH03045: h2_session(1): 
> process, closing conn
> [Thu Aug 25 16:38:34.263055 2016] [ssl:debug] [pid 3936] 
> ssl_engine_io.c(1033): [client 10.0.0.4:52614] AH02001: Connection closed to 
> child 1 with standard shutdown (server localhost:443)
> -------
> 
> 
> Am 25.08.2016 um 15:39 schrieb Stefan Eissing:
>> The following line does not look good:
>> 
>> [Thu Aug 25 15:19:43.851331 2016] [ssl:warn] [pid 4275] AH01909: 
>> localhost:443:0 server certificate does NOT include an ID which matches the 
>> server name
>> 
>> Can you make sure that all names do align? Maybe tweak /etc/hosts to make it 
>> match your localhost?
>> 
>>> Am 25.08.2016 um 15:27 schrieb Max Meyer <redeemerofsouls...@web.de>:
>>> 
>>> [Thu Aug 25 15:19:43.851331 2016] [ssl:warn] [pid 4275] AH01909: 
>>> localhost:443:0 server certificate does NOT include an ID which matches the 
>>> server name
>> 
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscr...@httpd.apache.org
>> For additional commands, e-mail: users-h...@httpd.apache.org
>> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscr...@httpd.apache.org
> For additional commands, e-mail: users-h...@httpd.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@httpd.apache.org
For additional commands, e-mail: users-h...@httpd.apache.org

Reply via email to