You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by Max Meyer <re...@web.de> on 2016/08/25 12:58:09 UTC
[users@httpd] Apache HTTP2 and benchmarking with h2load
I am trying to do some benchmarking on different HTTP/2 webservers using
"h2load" from nghttp2.org.
I configured Apache with HTTP/2 and in wireshark I can see HTTP/2
traffic when connecting with a browser like firefox.
When I use h2load it falls back to HTTP/1.1 claiming the server does not
support NPN/ALPN.
--------------
Example:
h2load -c1 -n1024 -m1024 myapache
starting benchmark...
spawning thread #0: 1 total client(s). 1024 total requests
TLS Protocol: TLSv1.2
Cipher: ECDHE-RSA-AES128-GCM-SHA256
No protocol negotiated. Fallback behaviour may be activated
Server does not support NPN/ALPN. Falling back to HTTP/1.1.
Application protocol: http/1.1
---------------
I tested h2load with an nginx installation and there it works fine, so
I'm guessing that it is not a problem on the h2load side.
My Apache site configuration looks like this.
<IfModule mod_ssl.c>
<VirtualHost _default_:443>
ServerAdmin webmaster@localhost
DocumentRoot /var/www/html
Protocols h2
H2Push on
ErrorLog ${APACHE_LOG_DIR}/error.log
CustomLog ${APACHE_LOG_DIR}/access.log combined
SSLEngine on
SSLCertificateFile /etc/ssl/server.crt
SSLCertificateKeyFile /etc/ssl/private.key
<FilesMatch "\.(cgi|shtml|phtml|php)$">
SSLOptions +StdEnvVars
</FilesMatch>
<Directory /usr/lib/cgi-bin>
SSLOptions +StdEnvVars
</Directory>
</VirtualHost>
</IfModule>
Apache Version: 2.4.23
Openssl: 1.0.2h
Does anyone have an idea what might be the problem?
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Apache HTTP2 and benchmarking with h2load
Posted by Stefan Eissing <st...@greenbytes.de>.
Ok, the standard ubuntu 14.04 openssl is too old. it does not support openssl. that is why the ppa also unstalls a newer one.
> Am 25.08.2016 um 18:21 schrieb Max Meyer <re...@web.de>:
>
> The webserver is Ubuntu 14.04
>
> I used the ppa from Ondřej Surý for the apache installation.
>
> https://launchpad.net/~ondrej/+archive/ubuntu/apache2
>
> The client is Linux Mint 17.3 (which is basically Ubuntu 14.04).
>
> For h2load I built nghttp2 from source:
>
> git clone https://github.com/tatsuhiro-t/nghttp2.git
> cd nghttp2
> autoreconf -i
> automake
> autoconf
> ./configure
> make
> sudo make install
>
> For testing purposes I just built nghttp2 on the server (the same way I did on the client), started h2load and here it works without falling back to http/1.1
>
>
>> Am 25.08.2016 um 17:08 schrieb Stefan Eissing:
>> 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 <re...@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 <re...@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-unsubscribe@httpd.apache.org
>>>> For additional commands, e-mail: users-help@httpd.apache.org
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
>>> For additional commands, e-mail: users-help@httpd.apache.org
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
>> For additional commands, e-mail: users-help@httpd.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Apache HTTP2 and benchmarking with h2load
Posted by Max Meyer <re...@web.de>.
The webserver is Ubuntu 14.04
I used the ppa from Ond\u0159ej Sur� for the apache installation.
https://launchpad.net/~ondrej/+archive/ubuntu/apache2
The client is Linux Mint 17.3 (which is basically Ubuntu 14.04).
For h2load I built nghttp2 from source:
git clone https://github.com/tatsuhiro-t/nghttp2.git
cd nghttp2
autoreconf -i
automake
autoconf
./configure
make
sudo make install
For testing purposes I just built nghttp2 on the server (the same way I
did on the client), started h2load and here it works without falling
back to http/1.1
Am 25.08.2016 um 17:08 schrieb Stefan Eissing:
> 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 <re...@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 <re...@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-unsubscribe@httpd.apache.org
>>> For additional commands, e-mail: users-help@httpd.apache.org
>>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
>> For additional commands, e-mail: users-help@httpd.apache.org
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Apache HTTP2 and benchmarking with h2load
Posted by Stefan Eissing <st...@greenbytes.de>.
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 <re...@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 <re...@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-unsubscribe@httpd.apache.org
>> For additional commands, e-mail: users-help@httpd.apache.org
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Apache HTTP2 and benchmarking with h2load
Posted by Max Meyer <re...@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 <re...@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-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Apache HTTP2 and benchmarking with h2load
Posted by Stefan Eissing <st...@greenbytes.de>.
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 <re...@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-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Apache HTTP2 and benchmarking with h2load
Posted by Max Meyer <re...@web.de>.
Hi Stefan,
thanks for your answer.
I did what you suggested. Here is the error.log
-------
[Thu Aug 25 15:19:43.850756 2016] [ssl:info] [pid 4275] AH01887: Init:
Initializing (virtual) servers for SSL
[Thu Aug 25 15:19:43.850825 2016] [ssl:info] [pid 4275] AH01914:
Configuring server localhost:443 for SSL protocol
[Thu Aug 25 15:19:43.851048 2016] [ssl:debug] [pid 4275]
ssl_engine_init.c(413): AH01893: Configuring TLS extension handling
[Thu Aug 25 15:19:43.851269 2016] [ssl:warn] [pid 4275] AH01906:
localhost:443:0 server certificate is a CA certificate
(BasicConstraints: CA == TRUE !?)
[Thu Aug 25 15:19:43.851322 2016] [ssl:debug] [pid 4275]
ssl_util_ssl.c(443): AH02412: [localhost:443] Cert does not match for
name 'localhost' [subject: O=Internet Widgits Pty Ltd,ST=Some-State,C=AU
/ issuer: O=Internet Widgits Pty Ltd,ST=Some-State,C=AU / serial:
DF104C2A1DF0EF15 / notbefore: Jun 13 13:48:30 2016 GMT / notafter: Jun
13 13:48:30 2017 GMT]
[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
[Thu Aug 25 15:19:43.851337 2016] [ssl:info] [pid 4275] AH02568:
Certificate and private key localhost:443:0 configured from
/etc/ssl/server.crt and /etc/ssl/private.key
[Thu Aug 25 15:19:43.851433 2016] [ssl:info] [pid 4275] AH01876:
mod_ssl/2.4.23 compiled against Server: Apache/2.4.23, Library:
OpenSSL/1.0.2h
[Thu Aug 25 15:19:43.851458 2016] [http2:debug] [pid 4275]
mod_http2.c(101): AH03089: initializing post config dry run
[Thu Aug 25 15:19:43.872030 2016] [ssl:info] [pid 4276] AH01887: Init:
Initializing (virtual) servers for SSL
[Thu Aug 25 15:19:43.872060 2016] [ssl:info] [pid 4276] AH01914:
Configuring server localhost:443 for SSL protocol
[Thu Aug 25 15:19:43.872306 2016] [ssl:debug] [pid 4276]
ssl_engine_init.c(413): AH01893: Configuring TLS extension handling
[Thu Aug 25 15:19:43.872593 2016] [ssl:warn] [pid 4276] AH01906:
localhost:443:0 server certificate is a CA certificate
(BasicConstraints: CA == TRUE !?)
[Thu Aug 25 15:19:43.872648 2016] [ssl:debug] [pid 4276]
ssl_util_ssl.c(443): AH02412: [localhost:443] Cert does not match for
name 'localhost' [subject: O=Internet Widgits Pty Ltd,ST=Some-State,C=AU
/ issuer: O=Internet Widgits Pty Ltd,ST=Some-State,C=AU / serial:
DF104C2A1DF0EF15 / notbefore: Jun 13 13:48:30 2016 GMT / notafter: Jun
13 13:48:30 2017 GMT]
[Thu Aug 25 15:19:43.872658 2016] [ssl:warn] [pid 4276] AH01909:
localhost:443:0 server certificate does NOT include an ID which matches
the server name
[Thu Aug 25 15:19:43.872664 2016] [ssl:info] [pid 4276] AH02568:
Certificate and private key localhost:443:0 configured from
/etc/ssl/server.crt and /etc/ssl/private.key
[Thu Aug 25 15:19:43.872768 2016] [ssl:info] [pid 4276] AH01876:
mod_ssl/2.4.23 compiled against Server: Apache/2.4.23, Library:
OpenSSL/1.0.2h
[Thu Aug 25 15:19:43.872802 2016] [http2:info] [pid 4276] AH03090:
mod_http2 (v1.5.11, feats=CHPRIO+SHA256, nghttp2 1.12.0-DEV),
initializing...
[Thu Aug 25 15:19:43.895209 2016] [mpm_prefork:notice] [pid 4276]
AH00163: Apache/2.4.23 (Ubuntu) OpenSSL/1.0.2h PHP/5.5.9-1ubuntu4.19
configured -- resuming normal operations
[Thu Aug 25 15:19:43.895278 2016] [core:notice] [pid 4276] AH00094:
Command line: '/usr/sbin/apache2'
[Thu Aug 25 15:19:43.895286 2016] [core:debug] [pid 4276] log.c(1546):
AH02639: Using SO_REUSEPORT: yes (1)
------
Am 25.08.2016 um 15:06 schrieb Stefan Eissing:
> If you add something like
>
> LogLevel http2:debug
> LogLevel ssl:debug
> LogLevel core:debug
>
> you should find information about negotiation in your error.log. Strange
> that Firefox works and h2load does not. I use the later regularly in my tests.
>
> Looking forward to see some log output...
>
>> Am 25.08.2016 um 14:58 schrieb Max Meyer <re...@web.de>:
>>
>> I am trying to do some benchmarking on different HTTP/2 webservers using "h2load" from nghttp2.org.
>>
>> I configured Apache with HTTP/2 and in wireshark I can see HTTP/2 traffic when connecting with a browser like firefox.
>> When I use h2load it falls back to HTTP/1.1 claiming the server does not support NPN/ALPN.
>> --------------
>> Example:
>>
>> h2load -c1 -n1024 -m1024 myapache
>>
>> starting benchmark...
>> spawning thread #0: 1 total client(s). 1024 total requests
>> TLS Protocol: TLSv1.2
>> Cipher: ECDHE-RSA-AES128-GCM-SHA256
>> No protocol negotiated. Fallback behaviour may be activated
>> Server does not support NPN/ALPN. Falling back to HTTP/1.1.
>> Application protocol: http/1.1
>> ---------------
>>
>> I tested h2load with an nginx installation and there it works fine, so I'm guessing that it is not a problem on the h2load side.
>>
>> My Apache site configuration looks like this.
>>
>> <IfModule mod_ssl.c>
>> <VirtualHost _default_:443>
>> ServerAdmin webmaster@localhost
>>
>> DocumentRoot /var/www/html
>> Protocols h2
>> H2Push on
>>
>> ErrorLog ${APACHE_LOG_DIR}/error.log
>> CustomLog ${APACHE_LOG_DIR}/access.log combined
>>
>> SSLEngine on
>>
>> SSLCertificateFile /etc/ssl/server.crt
>> SSLCertificateKeyFile /etc/ssl/private.key
>>
>>
>> <FilesMatch "\.(cgi|shtml|phtml|php)$">
>> SSLOptions +StdEnvVars
>> </FilesMatch>
>> <Directory /usr/lib/cgi-bin>
>> SSLOptions +StdEnvVars
>> </Directory>
>> </VirtualHost>
>> </IfModule>
>>
>> Apache Version: 2.4.23
>> Openssl: 1.0.2h
>>
>> Does anyone have an idea what might be the problem?
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
>> For additional commands, e-mail: users-help@httpd.apache.org
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Apache HTTP2 and benchmarking with h2load
Posted by Stefan Eissing <st...@greenbytes.de>.
If you add something like
LogLevel http2:debug
LogLevel ssl:debug
LogLevel core:debug
you should find information about negotiation in your error.log. Strange
that Firefox works and h2load does not. I use the later regularly in my tests.
Looking forward to see some log output...
> Am 25.08.2016 um 14:58 schrieb Max Meyer <re...@web.de>:
>
> I am trying to do some benchmarking on different HTTP/2 webservers using "h2load" from nghttp2.org.
>
> I configured Apache with HTTP/2 and in wireshark I can see HTTP/2 traffic when connecting with a browser like firefox.
> When I use h2load it falls back to HTTP/1.1 claiming the server does not support NPN/ALPN.
> --------------
> Example:
>
> h2load -c1 -n1024 -m1024 myapache
>
> starting benchmark...
> spawning thread #0: 1 total client(s). 1024 total requests
> TLS Protocol: TLSv1.2
> Cipher: ECDHE-RSA-AES128-GCM-SHA256
> No protocol negotiated. Fallback behaviour may be activated
> Server does not support NPN/ALPN. Falling back to HTTP/1.1.
> Application protocol: http/1.1
> ---------------
>
> I tested h2load with an nginx installation and there it works fine, so I'm guessing that it is not a problem on the h2load side.
>
> My Apache site configuration looks like this.
>
> <IfModule mod_ssl.c>
> <VirtualHost _default_:443>
> ServerAdmin webmaster@localhost
>
> DocumentRoot /var/www/html
> Protocols h2
> H2Push on
>
> ErrorLog ${APACHE_LOG_DIR}/error.log
> CustomLog ${APACHE_LOG_DIR}/access.log combined
>
> SSLEngine on
>
> SSLCertificateFile /etc/ssl/server.crt
> SSLCertificateKeyFile /etc/ssl/private.key
>
>
> <FilesMatch "\.(cgi|shtml|phtml|php)$">
> SSLOptions +StdEnvVars
> </FilesMatch>
> <Directory /usr/lib/cgi-bin>
> SSLOptions +StdEnvVars
> </Directory>
> </VirtualHost>
> </IfModule>
>
> Apache Version: 2.4.23
> Openssl: 1.0.2h
>
> Does anyone have an idea what might be the problem?
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org