Hi folks,
right away, I don't know whether it is us (Tomcat) or curl. I'd lke to
narrow down the cause.
I am trying to enable HTTP/2 for some upload services via Tomcat
directly (HTTPd is currently out of scope here).
I am running off:
Server version: Apache Tomcat/8.5.38
> Server built: Feb 5 2019 11:42:42 UTC
> Server number: 8.5.38.0
> OS Name: FreeBSD
> OS Version: 12.0-STABLE
> Architecture: amd64
> Java Home: /usr/local/openjdk8/jre
> JVM Version: 1.8.0_202-b08
> JVM Vendor: Oracle Corporation
>
> Loaded APR based Apache Tomcat Native library [1.2.21] using APR
version [1.6.5].
> capabilities: IPv6 [true], sendfile [true], accept filters [true],
random [true].
> APR/OpenSSL configuration: useAprConnector [true], useOpenSSL [true]
> OpenSSL successfully initialized [OpenSSL 1.1.1a-freebsd 20 Nov 2018]
>
> <Connector address="147.54.64.55" port="8445" connectionTimeout="20000"
> maxHttpHeaderSize="24576" maxThreads="250"
> SSLEnabled="true" scheme="https" secure="true"
> defaultSSLHostConfigName="sitex-ldadw.ad001.siemens.net">
> <UpgradeProtocol className="org.apache.coyote.http2.Http2Protocol" />
> <SSLHostConfig hostName="sitex-ldadw.ad001.siemens.net"
protocols="TLSv1.2+TLSv1.3"
> honorCipherOrder="true"
ciphers="HIGH:!aNULL:!eNULL:!EXPORT:!DES:!RC4:!3DES:!MD5:!PSK:!DSS">
> <Certificate
certificateFile="/etc/ssl/sitex-ldadw.ad001.siemens.net/cert/public.pem"
>
certificateKeyFile="/etc/ssl/sitex-ldadw.ad001.siemens.net/key/private.pem"
> certificateKeyPassword="..."
> type="RSA" />
> </SSLHostConfig>
> </Connector>
>
> $ curl --version
> curl 7.64.0 (amd64-portbld-freebsd12.0) libcurl/7.64.0 OpenSSL/1.1.1b
zlib/1.2.11 nghttp2/1.37.0
> Release-Date: 2019-02-06
> Protocols: file http https rtsp smtp smtps
> Features: AsynchDNS Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB
SSL libz HTTP2 UnixSockets HTTPS-proxy
Now trying to upload a WAR file to the manager, with curl for example, fails
(while it works with HTTP/1.1 flawlessly for years):
> $ time curl --verbose -H 'Expect: 100-continue' --negotiate -u :
--upload-file target/lda-docgen-webapp-0.1-SNAPSHOT-backend-dev.war -o
manager-response.txt
'https://sitex-ldadw.ad001.siemens.net:8445/backend-dev/manager-1/text/deploy?path=/backend-dev&update=false&version=003'
> * Expire in 0 ms for 6 (transfer 0x800d65000)
> * Uses proxy env variable NO_PROXY == 'localhost .siemens.net
.siemens.com .siemens.de'
> * Expire in 1 ms for 1 (transfer 0x800d65000)
> % Total % Received % Xferd Average Speed Time Time
Time Current
> Dload Upload Total Spent
Left Speed
> 0 0 0 0 0 0 0 0 --:--:-- --:--:--
--:--:-- 0* Expire in 0 ms for 1 (transfer 0x800d65000)
> * Expire in 1 ms for 1 (transfer 0x800d65000)
> ...
> * Trying 147.54.64.55...
> * TCP_NODELAY set
> * Expire in 200 ms for 4 (transfer 0x800d65000)
> * Connected to sitex-ldadw.ad001.siemens.net (147.54.64.55) port 8445
(#0)
> * ALPN, offering h2
> * ALPN, offering http/1.1
> * successfully set certificate verify locations:
> * CAfile: /usr/local/etc/ssl/cert.pem
> CApath: none
> } [5 bytes data]
> * TLSv1.3 (OUT), TLS handshake, Client hello (1):
> } [512 bytes data]
> * TLSv1.3 (IN), TLS handshake, Server hello (2):
> { [122 bytes data]
> * TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
> { [19 bytes data]
> * TLSv1.3 (IN), TLS handshake, Certificate (11):
> { [6195 bytes data]
> * TLSv1.3 (IN), TLS handshake, CERT verify (15):
> { [520 bytes data]
> * TLSv1.3 (IN), TLS handshake, Finished (20):
> { [52 bytes data]
> * TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
> } [1 bytes data]
> * TLSv1.3 (OUT), TLS handshake, Finished (20):
> } [52 bytes data]
> * SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
> * ALPN, server accepted to use h2
> * Server certificate:
> * subject: C=DE; O=Siemens; OU=LDA DW; CN=sitex-ldadw.ad001.siemens.net
> * start date: Mar 19 13:10:13 2019 GMT
> * expire date: Mar 19 13:10:13 2020 GMT
> * subjectAltName: host "sitex-ldadw.ad001.siemens.net" matched
cert's "sitex-ldadw.ad001.siemens.net"
> * issuer: C=DE; ST=Bayern; L=Muenchen; O=Siemens;
serialNumber=ZZZZZZB7; OU=Siemens Trust Center; CN=Siemens Issuing CA
Intranet Server 2017
> * SSL certificate verify ok.
> * Using HTTP2, server supports multi-use
> * Connection state changed (HTTP/2 confirmed)
> * Copying HTTP/2 data in stream buffer to connection buffer after
upgrade: len=0
> } [5 bytes data]
> * Using Stream ID: 1 (easy handle 0x800d65000)
> } [5 bytes data]
> > PUT
/backend-dev/manager-1/text/deploy?path=/backend-dev&update=false&version=003
HTTP/2
> > Host: sitex-ldadw.ad001.siemens.net:8445
> > User-Agent: curl/7.64.0
> > Accept: */*
> > Expect: 100-continue
> > Content-Length: 6502195
> >
> { [5 bytes data]
> * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
> { [281 bytes data]
> * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
> { [281 bytes data]
> * old SSL session ID is stale, removing
> } [5 bytes data]
> * Connection state changed (MAX_CONCURRENT_STREAMS == 200)!
> } [5 bytes data]
> < HTTP/2 401
> < cache-control: private
> < expires: Thu, 01 Jan 1970 00:00:00 GMT
> < www-authenticate: Negotiate
> < content-type: text/html;charset=utf-8
> < content-language: en
> < content-length: 802
> < date: Thu, 28 Mar 2019 13:48:19 GMT
> * HTTP error before end of send, stop sending
> <
> { [5 bytes data]
> * Ignoring the response-body
> { [802 bytes data]
> 1 6349k 0 0 1 65535 0 1185k 0:00:05 --:--:--
0:00:05 1185k
> * Connection #0 to host sitex-ldadw.ad001.siemens.net left intact
> * Issue another request to this URL:
'https://sitex-ldadw.ad001.siemens.net:8445/backend-dev/manager-1/text/deploy?path=/backend-dev&update=false&version=003'
> * Uses proxy env variable NO_PROXY == 'localhost .siemens.net
.siemens.com .siemens.de'
> * Found bundle for host sitex-ldadw.ad001.siemens.net: 0x800cd5270
[can multiplex]
> * Re-using existing connection! (#0) with host
sitex-ldadw.ad001.siemens.net
> * Connected to sitex-ldadw.ad001.siemens.net (147.54.64.55) port 8445
(#0)
> * Server auth using Negotiate with user ''
> * Using Stream ID: 3 (easy handle 0x800d65000)
> } [5 bytes data]
> > PUT
/backend-dev/manager-1/text/deploy?path=/backend-dev&update=false&version=003
HTTP/2
> > Host: sitex-ldadw.ad001.siemens.net:8445
> > Authorization: Negotiate YIISIwYGKwY...
> > User-Agent: curl/7.64.0
> > Accept: */*
> > Expect: 100-continue
> > Content-Length: 6502195
> >
> } [0 bytes data]
> 0 6349k 0 0 0 0 0 0 --:--:-- --:--:--
--:--:-- 0< HTTP/2 100
> } [0 bytes data]
> 0 6349k 0 0 0 0 0 0 --:--:-- 0:00:20
--:--:-- 0< HTTP/2 200
> < cache-control: private
> < expires: Thu, 01 Jan 1970 00:00:00 GMT
> < www-authenticate: Negotiate oYHzMIHwo...
> < x-content-type-options: nosniff
> < content-type: text/plain;charset=utf-8
> < date: Thu, 28 Mar 2019 13:48:39 GMT
> <
> } [0 bytes data]
> * HTTP/2 stream 0 was not closed cleanly: ENHANCE_YOUR_CALM (err 11)
> * stopped the pause stream!
> 0 6349k 0 161 0 0 7 0 --:--:-- 0:00:21
--:--:-- 33
> * Connection #0 to host sitex-ldadw.ad001.siemens.net left intact
> curl: (92) HTTP/2 stream 0 was not closed cleanly: ENHANCE_YOUR_CALM
(err 11)
>
> real 0m21,019s
> user 0m9,054s
> sys 0m11,950s
> $ less manager-response.txt
> FAIL - Encountered exception
[org.apache.catalina.connector.ClientAbortException:
org.apache.coyote.CloseNowException: Timeout waiting to read data from
client]
and Tomcat says:
> 2019-03-28T14:48:19.976 INFO
[https-openssl-apr-147.54.64.55-8445-exec-9]
org.apache.catalina.core.ApplicationContext.log Manager: deploy:
Deploying web application '/backend-dev##003'
> 2019-03-28T14:48:19.976 INFO
[https-openssl-apr-147.54.64.55-8445-exec-9]
org.apache.catalina.core.ApplicationContext.log Manager: Uploading WAR
file to /usr/local/ldadocgen/backend-dev/tomcat-1/webapps/backend-
> 2019-03-28T14:48:39.979 SEVERE
[https-openssl-apr-147.54.64.55-8445-exec-9]
org.apache.catalina.core.ApplicationContext.log Manager:
managerServlet.check[/backend-dev##003]
> org.apache.catalina.connector.ClientAbortException:
org.apache.coyote.CloseNowException: Timeout waiting to read data from
client
> at
org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:348)
> at
org.apache.catalina.connector.InputBuffer.checkByteBufferEof(InputBuffer.java:663)
> at
org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:370)
> at
org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:152)
> at
org.apache.catalina.manager.ManagerServlet.uploadWar(ManagerServlet.java:1668)
> at
org.apache.catalina.manager.ManagerServlet.deploy(ManagerServlet.java:798)
> at
org.apache.catalina.manager.ManagerServlet.doPut(ManagerServlet.java:448)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:664)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
> at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
> at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
> at
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
> at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
> at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
> at
org.apache.catalina.filters.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:109)
> at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
> at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
> at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
> at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
> at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:610)
> at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
> at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
> at
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
> at
org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:679)
> at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
> at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
> at
org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:317)
> at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
> at
org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:69)
> at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: org.apache.coyote.CloseNowException: Timeout waiting to
read data from client
> at
org.apache.coyote.http2.Stream$StreamInputBuffer.doRead(Stream.java:1086)
> at org.apache.coyote.Request.doRead(Request.java:581)
> at
org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:344)
> ... 33 more
> Caused by: org.apache.coyote.http2.StreamException: Timeout waiting
to read data from client
> at
org.apache.coyote.http2.Stream$StreamInputBuffer.doRead(Stream.java:1081)
> ... 35 more
Removing "Expect: 100-continue" makes no difference here.
Doing the same with HTTPd 2.4.38 with mod_cgid and a Python script:
> $ less upload.py
> #!/usr/bin/env python3
>
> import cgi
> import cgitb; cgitb.enable()
> import os
> import sys
> import shutil
>
> if os.environ['REQUEST_METHOD'] == 'PUT':
> print("Status: 204")
> print()
> data = sys.stdin.buffer.read()
> with open('/tmp/upload.bin', 'wb+') as outfile:
> outfile.write(data)
> else:
> print("Status: 405")
> print()
> $ time curl --verbose --negotiate -u : --upload-file
target/lda-docgen-webapp-0.1-SNAPSHOT-backend-dev.war
'https://sitex-ldadw.ad001.siemens.net/webhooks/upload.py' -H "Expect:
100-continue"
> * Expire in 0 ms for 6 (transfer 0x800d65000)
> * Uses proxy env variable NO_PROXY == 'localhost .siemens.net
.siemens.com .siemens.de'
> * Expire in 1 ms for 1 (transfer 0x800d65000)
> % Total % Received % Xferd Average Speed Time Time
Time Current
> Dload Upload Total Spent
Left Speed
> 0 0 0 0 0 0 0 0 --:--:-- --:--:--
--:--:-- 0* Expire in 0 ms for 1 (transfer 0x800d65000)
> * Expire in 1 ms for 1 (transfer 0x800d65000)
> ...
> * Trying 147.54.64.55...
> * TCP_NODELAY set
> * Expire in 200 ms for 4 (transfer 0x800d65000)
> * Connected to sitex-ldadw.ad001.siemens.net (147.54.64.55) port 443 (#0)
> * ALPN, offering h2
> * ALPN, offering http/1.1
> * successfully set certificate verify locations:
> * CAfile: /usr/local/etc/ssl/cert.pem
> CApath: none
> } [5 bytes data]
> * TLSv1.3 (OUT), TLS handshake, Client hello (1):
> } [512 bytes data]
> * TLSv1.3 (IN), TLS handshake, Server hello (2):
> { [122 bytes data]
> * TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
> { [19 bytes data]
> * TLSv1.3 (IN), TLS handshake, Certificate (11):
> { [6195 bytes data]
> * TLSv1.3 (IN), TLS handshake, CERT verify (15):
> { [520 bytes data]
> * TLSv1.3 (IN), TLS handshake, Finished (20):
> { [52 bytes data]
> * TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
> } [1 bytes data]
> * TLSv1.3 (OUT), TLS handshake, Finished (20):
> } [52 bytes data]
> * SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
> * ALPN, server accepted to use h2
> * Server certificate:
> * subject: C=DE; O=Siemens; OU=LDA DW; CN=sitex-ldadw.ad001.siemens.net
> * start date: Mar 19 13:10:13 2019 GMT
> * expire date: Mar 19 13:10:13 2020 GMT
> * subjectAltName: host "sitex-ldadw.ad001.siemens.net" matched
cert's "sitex-ldadw.ad001.siemens.net"
> * issuer: C=DE; ST=Bayern; L=Muenchen; O=Siemens;
serialNumber=ZZZZZZB7; OU=Siemens Trust Center; CN=Siemens Issuing CA
Intranet Server 2017
> * SSL certificate verify ok.
> * Using HTTP2, server supports multi-use
> * Connection state changed (HTTP/2 confirmed)
> * Copying HTTP/2 data in stream buffer to connection buffer after
upgrade: len=0
> } [5 bytes data]
> * Using Stream ID: 1 (easy handle 0x800d65000)
> } [5 bytes data]
> > PUT /webhooks/upload.py HTTP/2
> > Host: sitex-ldadw.ad001.siemens.net
> > User-Agent: curl/7.64.0
> > Accept: */*
> > Expect: 100-continue
> > Content-Length: 6502195
> >
> { [5 bytes data]
> * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
> { [297 bytes data]
> * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
> { [297 bytes data]
> * old SSL session ID is stale, removing
> { [5 bytes data]
> * Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
> } [5 bytes data]
> < HTTP/2 401
> < date: Thu, 28 Mar 2019 14:36:56 GMT
> < server: Apache/2.4.38 (FreeBSD) OpenSSL/1.1.1a-freebsd
mod_auth_gssapi/1.6.1
> < x-frame-options: SAMEORIGIN
> < www-authenticate: Negotiate
> < content-length: 523
> < content-type: text/html; charset=iso-8859-1
> * HTTP error before end of send, stop sending
> <
> * Ignoring the response-body
> { [523 bytes data]
> 1 6349k 0 0 1 65535 0 1230k 0:00:05 --:--:--
0:00:05 1254k
> * Connection #0 to host sitex-ldadw.ad001.siemens.net left intact
> * Issue another request to this URL:
'https://sitex-ldadw.ad001.siemens.net/webhooks/upload.py'
> * Uses proxy env variable NO_PROXY == 'localhost .siemens.net
.siemens.com .siemens.de'
> * Found bundle for host sitex-ldadw.ad001.siemens.net: 0x800cd5390
[can multiplex]
> * Re-using existing connection! (#0) with host
sitex-ldadw.ad001.siemens.net
> * Connected to sitex-ldadw.ad001.siemens.net (147.54.64.55) port 443 (#0)
> * Server auth using Negotiate with user ''
> * Using Stream ID: 3 (easy handle 0x800d65000)
> } [5 bytes data]
> > PUT /webhooks/upload.py HTTP/2
> > Host: sitex-ldadw.ad001.siemens.net
> > Authorization: Negotiate YIISJQYGKwYBBQUCoI...
> > User-Agent: curl/7.64.0
> > Accept: */*
> > Expect: 100-continue
> > Content-Length: 6502195
> >
> } [5 bytes data]
> < HTTP/2 100
> } [5 bytes data]
> 3 6349k 0 0 3 191k 0 1432k 0:00:04 --:--:--
0:00:04 1432k* We are completely uploaded and fine
> { [5 bytes data]
> < HTTP/2 204
> < date: Thu, 28 Mar 2019 14:36:56 GMT
> < server: Apache/2.4.38 (FreeBSD) OpenSSL/1.1.1a-freebsd
mod_auth_gssapi/1.6.1
> < www-authenticate: Negotiate oYG3MIG0oAMKA...
> < x-frame-options: SAMEORIGIN
> <
> { [5 bytes data]
> 100 6349k 0 0 100 6349k 0 15.3M --:--:-- --:--:--
--:--:-- 22.2M
> * Connection #0 to host sitex-ldadw.ad001.siemens.net left intact
>
> real 0m0,420s
> user 0m0,212s
> sys 0m0,169s
It works, even without "Expect: 100-continue".
As far as I understand the HTTP/2 spec, the header is not necessary
anymore and this is builtin into the protocol.
Any ideas?
Michael
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
