Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-25832

(8.0.z) UNDERTOW-2332 - Requesting deployment overlay may results in ConnectionClosedException

XMLWordPrintable

      If we overlay deployment content, sometimes Content-Length is miscalculated or content seem to be cached.

      Here is a Jenkins run: https://jenkins.eapqe.psi.redhat.com/job/eap-8.x-undertow-integration-tests-rhel/1336/testReport/

      The test that reproduces this issue is OverlayIT#modifiedFileInOverlayTest 2 out of 12.

      I have attached two output files from mvn command. Search for:

      ConnectionClosedException occurred during reading http response entity!

      Errors are not the same. In the first case it is miscalculated content-length (content is as expected) and in another content is not changed (seems like the file isn't invalidated) and content-length is also wrong:

      First case:

      2023-10-10 13:32:04.013 DEBUG o.a.h.impl.execchain.MainClientExec: Executing request GET /overlay/modified.txt HTTP/1.1
2023-10-10 13:32:04.013 DEBUG o.a.h.impl.execchain.MainClientExec: Target auth state: UNCHALLENGED
2023-10-10 13:32:04.013 DEBUG o.a.h.impl.execchain.MainClientExec: Proxy auth state: UNCHALLENGED
2023-10-10 13:32:04.013 DEBUG org.apache.http.headers: http-outgoing-4573 >> GET /overlay/modified.txt HTTP/1.1
2023-10-10 13:32:04.013 DEBUG org.apache.http.headers: http-outgoing-4573 >> Host: 127.0.0.1:8080
2023-10-10 13:32:04.013 DEBUG org.apache.http.headers: http-outgoing-4573 >> Connection: Keep-Alive
2023-10-10 13:32:04.013 DEBUG org.apache.http.headers: http-outgoing-4573 >> User-Agent: Apache-HttpClient/4.5.6 (Java/11.0.19)
2023-10-10 13:32:04.013 DEBUG org.apache.http.headers: http-outgoing-4573 >> Accept-Encoding: gzip,deflate
2023-10-10 13:32:04.013 DEBUG org.apache.http.wire: http-outgoing-4573 >> "GET /overlay/modified.txt HTTP/1.1[\r][\n]"
2023-10-10 13:32:04.013 DEBUG org.apache.http.wire: http-outgoing-4573 >> "Host: 127.0.0.1:8080[\r][\n]"
2023-10-10 13:32:04.013 DEBUG org.apache.http.wire: http-outgoing-4573 >> "Connection: Keep-Alive[\r][\n]"
2023-10-10 13:32:04.013 DEBUG org.apache.http.wire: http-outgoing-4573 >> "User-Agent: Apache-HttpClient/4.5.6 (Java/11.0.19)[\r][\n]"
2023-10-10 13:32:04.013 DEBUG org.apache.http.wire: http-outgoing-4573 >> "Accept-Encoding: gzip,deflate[\r][\n]"
2023-10-10 13:32:04.013 DEBUG org.apache.http.wire: http-outgoing-4573 >> "[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "HTTP/1.1 200 OK[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "Connection: keep-alive[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "Last-Modified: Tue, 10 Oct 2023 13:32:04 GMT[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "Content-Type: text/plain[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "Content-Length: 28[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "Accept-Ranges: bytes[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "Date: Tue, 10 Oct 2023 13:15:19 GMT[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "[\r][\n]"
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "modified value some new"
2023-10-10 13:32:04.014 DEBUG org.apache.http.headers: http-outgoing-4573 << HTTP/1.1 200 OK
2023-10-10 13:32:04.014 DEBUG org.apache.http.headers: http-outgoing-4573 << Connection: keep-alive
2023-10-10 13:32:04.014 DEBUG org.apache.http.headers: http-outgoing-4573 << Last-Modified: Tue, 10 Oct 2023 13:32:04 GMT
2023-10-10 13:32:04.014 DEBUG org.apache.http.headers: http-outgoing-4573 << Content-Type: text/plain
2023-10-10 13:32:04.014 DEBUG org.apache.http.headers: http-outgoing-4573 << Content-Length: 28
2023-10-10 13:32:04.014 DEBUG org.apache.http.headers: http-outgoing-4573 << Accept-Ranges: bytes
2023-10-10 13:32:04.014 DEBUG org.apache.http.headers: http-outgoing-4573 << Date: Tue, 10 Oct 2023 13:15:19 GMT
2023-10-10 13:32:04.014 DEBUG o.a.h.impl.execchain.MainClientExec: Connection can be kept alive indefinitely
2023-10-10 13:32:04.014 DEBUG org.apache.http.wire: http-outgoing-4573 << "end of stream"
2023-10-10 13:32:04.014 DEBUG o.a.h.i.c.DefaultManagedHttpClientConnection: http-outgoing-4573: Close connection
2023-10-10 13:32:04.014 DEBUG o.a.h.impl.execchain.MainClientExec: Connection discarded
2023-10-10 13:32:04.014 DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager: Connection released: [id: 4573][route: {}->http://127.0.0.1:8080][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
2023-10-10 13:32:04.014 ERROR o.jboss.qa.management.web.OverlayIT: ConnectionClosedException occurred during reading http response entity!
org.apache.http.ConnectionClosedException: Premature end of Content-Length delimited message body (expected: 28; received: 23)
	at org.apache.http.impl.io.ContentLengthInputStream.read(ContentLengthInputStream.java:178)
	at org.apache.http.conn.EofSensorInputStream.read(EofSensorInputStream.java:135)
	at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
	at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
	at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
	at java.base/java.io.InputStreamReader.read(InputStreamReader.java:181)
	at java.base/java.io.Reader.read(Reader.java:229)
	at org.apache.http.util.EntityUtils.toString(EntityUtils.java:227)
	at org.apache.http.util.EntityUtils.toString(EntityUtils.java:308)
	at org.jboss.qa.management.web.OverlayIT.retrieveAndCheck(OverlayIT.java:211)
	at org.jboss.qa.management.web.OverlayIT.modifiedFileInOverlayTest(OverlayIT.java:190)

      Second case:

      2023-10-10 13:30:08.229 DEBUG org.apache.http.headers: http-outgoing-4305 >> GET /overlay/modified.txt HTTP/1.1
2023-10-10 13:30:08.229 DEBUG org.apache.http.headers: http-outgoing-4305 >> Host: 127.0.0.1:8080
2023-10-10 13:30:08.229 DEBUG org.apache.http.headers: http-outgoing-4305 >> Connection: Keep-Alive
2023-10-10 13:30:08.229 DEBUG org.apache.http.headers: http-outgoing-4305 >> User-Agent: Apache-HttpClient/4.5.6 (Java/17.0.7)
2023-10-10 13:30:08.229 DEBUG org.apache.http.headers: http-outgoing-4305 >> Accept-Encoding: gzip,deflate
2023-10-10 13:30:08.229 DEBUG org.apache.http.wire: http-outgoing-4305 >> "GET /overlay/modified.txt HTTP/1.1[\r][\n]"
2023-10-10 13:30:08.229 DEBUG org.apache.http.wire: http-outgoing-4305 >> "Host: 127.0.0.1:8080[\r][\n]"
2023-10-10 13:30:08.229 DEBUG org.apache.http.wire: http-outgoing-4305 >> "Connection: Keep-Alive[\r][\n]"
2023-10-10 13:30:08.229 DEBUG org.apache.http.wire: http-outgoing-4305 >> "User-Agent: Apache-HttpClient/4.5.6 (Java/17.0.7)[\r][\n]"
2023-10-10 13:30:08.229 DEBUG org.apache.http.wire: http-outgoing-4305 >> "Accept-Encoding: gzip,deflate[\r][\n]"
2023-10-10 13:30:08.229 DEBUG org.apache.http.wire: http-outgoing-4305 >> "[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "HTTP/1.1 200 OK[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "Connection: keep-alive[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "Last-Modified: Tue, 10 Oct 2023 13:30:08 GMT[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "Content-Type: text/plain[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "Content-Length: 28[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "Accept-Ranges: bytes[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "Date: Tue, 10 Oct 2023 13:14:39 GMT[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "[\r][\n]"
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "modified value"
2023-10-10 13:30:08.230 DEBUG org.apache.http.headers: http-outgoing-4305 << HTTP/1.1 200 OK
2023-10-10 13:30:08.230 DEBUG org.apache.http.headers: http-outgoing-4305 << Connection: keep-alive
2023-10-10 13:30:08.230 DEBUG org.apache.http.headers: http-outgoing-4305 << Last-Modified: Tue, 10 Oct 2023 13:30:08 GMT
2023-10-10 13:30:08.230 DEBUG org.apache.http.headers: http-outgoing-4305 << Content-Type: text/plain
2023-10-10 13:30:08.230 DEBUG org.apache.http.headers: http-outgoing-4305 << Content-Length: 28
2023-10-10 13:30:08.230 DEBUG org.apache.http.headers: http-outgoing-4305 << Accept-Ranges: bytes
2023-10-10 13:30:08.230 DEBUG org.apache.http.headers: http-outgoing-4305 << Date: Tue, 10 Oct 2023 13:14:39 GMT
2023-10-10 13:30:08.230 DEBUG o.a.h.impl.execchain.MainClientExec: Connection can be kept alive indefinitely
2023-10-10 13:30:08.230 DEBUG org.apache.http.wire: http-outgoing-4305 << "end of stream"
2023-10-10 13:30:08.230 DEBUG o.a.h.i.c.DefaultManagedHttpClientConnection: http-outgoing-4305: Close connection
2023-10-10 13:30:08.230 DEBUG o.a.h.impl.execchain.MainClientExec: Connection discarded
2023-10-10 13:30:08.230 DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager: Connection released: [id: 4305][route: {}->http://127.0.0.1:8080][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
2023-10-10 13:30:08.230 ERROR o.jboss.qa.management.web.OverlayIT: ConnectionClosedException occurred during reading http response entity!
org.apache.http.ConnectionClosedException: Premature end of Content-Length delimited message body (expected: 28; received: 14)
	at org.apache.http.impl.io.ContentLengthInputStream.read(ContentLengthInputStream.java:178)
	at org.apache.http.conn.EofSensorInputStream.read(EofSensorInputStream.java:135)
	at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:270)
	at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:313)
	at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:188)
	at java.base/java.io.InputStreamReader.read(InputStreamReader.java:177)
	at java.base/java.io.Reader.read(Reader.java:250)
	at org.apache.http.util.EntityUtils.toString(EntityUtils.java:227)
	at org.apache.http.util.EntityUtils.toString(EntityUtils.java:308)
	at org.jboss.qa.management.web.OverlayIT.retrieveAndCheck(OverlayIT.java:211)
	at org.jboss.qa.management.web.OverlayIT.modifiedFileInOverlayTest(OverlayIT.java:190)

      The test: https://gitlab.hosts.mwqe.eng.bos.redhat.com/jbossqe-eap/tests-management/-/blob/master/integration-tests/src/test/java/org/jboss/qa/management/web/OverlayIT.java#L159

      Note, time to live is set to 0.

        1. 8.0.0.GA.CR1_jdk=oracle-java-11,label_exp=RHEL8&&dynamic&&xlarge.log
          69.21 MB
        2. 8.0.0.GA.CR1_jdk=oracle-java-17,label_exp=RHEL9&&dynamic&&xlarge.log
          69.28 MB
        3. jbeap_25832_eap8_reproducer.patch
          11 kB
        4. undertow_sod.patch
          7 kB

              rhn-cservice-bbaranow Bartosz Baranowski
              istraka@redhat.com Ivan Straka
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

                Created:
                Updated:
                Resolved: