jetty.project icon indicating copy to clipboard operation
jetty.project copied to clipboard

Published 20 hours ago • verified publisher icon jetty

Flaky Test: MultiPartRequestContentTest.testFileFromInputStream([2] HTTPS)

Open joakime opened this issue 3 years ago • 1 comments

Jetty version(s) Jetty 12

Description

Experienced this as a flaky test twice.

Running org.eclipse.jetty.client.util.MultiPartRequestContentTest.testFileFromInputStream([2] HTTPS)
2022-08-16 13:59:44.858:INFO :oejs.Server:main: jetty-12.0.0-SNAPSHOT; built: 2022-08-16T18:50:19.198Z; git: 37bc52f0ff0004c4ec20de6a367c8aaf3cb03bad; jvm 17.0.3+7
[2022-08-16T13:59:44.948-0500][info][gc] GC(44) Pause Young (Normal) (G1 Evacuation Pause) 1239M->14M(2048M) 3.100ms
2022-08-16 13:59:44.911:INFO :oejus.SslContextFactory:main: x509=X509@3b18009f(mykey,h=[localhost],a=[/127.0.0.1, /0:0:0:0:0:0:0:1],w=[]) for Server@77aeba9b[provider=null,keyStore=file:///home/joakim/code/jetty/jetty.project-12.0.x/jetty-core/jetty-client/src/test/resources/keystore.p12,trustStore=null]
2022-08-16 13:59:44.931:INFO :oejs.AbstractConnector:main: Started ServerConnector@501b296a{SSL, (ssl, http/1.1)}{0.0.0.0:39757}
2022-08-16 13:59:44.931:INFO :oejs.Server:main: Started oejs.Server@34588991{STARTING}[12.0.0-SNAPSHOT,sto=0] @184041ms
2022-08-16 13:59:44.975:INFO :oejus.SslContextFactory:main: x509=X509@3220833f(mykey,h=[localhost],a=[/127.0.0.1, /0:0:0:0:0:0:0:1],w=[]) for Client@2e5c245d[provider=null,keyStore=file:///home/joakim/code/jetty/jetty.project-12.0.x/jetty-core/jetty-client/src/test/resources/keystore.p12,trustStore=null]
2022-08-16 13:59:44.988:WARN :oejusS.config:main: No Client EndPointIdentificationAlgorithm configured for Client@2e5c245d[provider=null,keyStore=file:///home/joakim/code/jetty/jetty.project-12.0.x/jetty-core/jetty-client/src/test/resources/keystore.p12,trustStore=null]
2022-08-16 13:59:45.007:WARN :oejs.Response:server-62574: writeError: status=500, message=org.opentest4j.AssertionFailedError: expected: <512> but was: <511>, response=org.eclipse.jetty.server.internal.HttpChannelState$ErrorResponse@73395631
org.opentest4j.AssertionFailedError: expected: <512> but was: <511>
	at org.junit.jupiter.api.AssertionFailureBuilder.build(AssertionFailureBuilder.java:151)
	at org.junit.jupiter.api.AssertionFailureBuilder.buildAndThrow(AssertionFailureBuilder.java:132)
	at org.junit.jupiter.api.AssertEquals.failNotEqual(AssertEquals.java:197)
	at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:166)
	at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:161)
	at org.junit.jupiter.api.Assertions.assertEquals(Assertions.java:628)
	at [email protected]/org.eclipse.jetty.client.util.MultiPartRequestContentTest$5.process(MultiPartRequestContentTest.java:219)
	at [email protected]/org.eclipse.jetty.client.util.MultiPartRequestContentTest$AbstractMultiPartHandler.process(MultiPartRequestContentTest.java:431)
	at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:660)
	at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:444)
	at [email protected]/org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
	at [email protected]/org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at [email protected]/org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:559)
	at [email protected]/org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:380)
	at [email protected]/org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:147)
	at [email protected]/org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at [email protected]/org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at [email protected]/org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421)
	at [email protected]/org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390)
	at [email protected]/org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277)
	at [email protected]/org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.lambda$new$0(AdaptiveExecutionStrategy.java:139)
	at [email protected]/org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:410)
	at [email protected]/org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:932)
	at [email protected]/org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1076)
	at java.base/java.lang.Thread.run(Thread.java:833)
2022-08-16 13:59:45.010:INFO :oejs.Server:main: Stopped oejs.Server@34588991{STOPPING}[12.0.0-SNAPSHOT,sto=0]
2022-08-16 13:59:45.010:INFO :oejs.AbstractConnector:main: Stopped ServerConnector@501b296a{SSL, (ssl, http/1.1)}{0.0.0.0:0}

[ERROR] Failures: 
[ERROR]   MultiPartRequestContentTest.testFileFromInputStream:246 expected: <200> but was: <500>

joakime avatar Aug 16 '22 19:08 joakime

Just experienced another variation of this ...

Running org.eclipse.jetty.client.util.MultiPartRequestContentTest.testFieldDeferredAndFileDeferred([1] HTTP)
2022-08-16 14:11:46.150:INFO :oejs.Server:main: jetty-12.0.0-SNAPSHOT; built: 2022-08-16T18:50:19.198Z; git: 37bc52f0ff0004c4ec20de6a367c8aaf3cb03bad; jvm 17.0.3+7
2022-08-16 14:11:46.158:INFO :oejs.AbstractConnector:main: Started ServerConnector@1f6d3a81{HTTP/1.1, (http/1.1)}{0.0.0.0:44525}
2022-08-16 14:11:46.158:INFO :oejs.Server:main: Started oejs.Server@52667676{STARTING}[12.0.0-SNAPSHOT,sto=0] @180309ms
2022-08-16 14:11:46.169:WARN :oejs.Response:server-64981: writeError: status=500, message=org.opentest4j.AssertionFailedError: array lengths differ, expected: <1024> but was: <1023>, response=org.eclipse.jetty.server.internal.HttpChannelState$ErrorResponse@4aafa549
org.opentest4j.AssertionFailedError: array lengths differ, expected: <1024> but was: <1023>
	at org.junit.jupiter.api.AssertionFailureBuilder.build(AssertionFailureBuilder.java:151)
	at org.junit.jupiter.api.AssertionFailureBuilder.buildAndThrow(AssertionFailureBuilder.java:132)
	at org.junit.jupiter.api.AssertArrayEquals.assertArraysHaveSameLength(AssertArrayEquals.java:428)
	at org.junit.jupiter.api.AssertArrayEquals.assertArrayEquals(AssertArrayEquals.java:205)
	at org.junit.jupiter.api.AssertArrayEquals.assertArrayEquals(AssertArrayEquals.java:63)
	at org.junit.jupiter.api.AssertArrayEquals.assertArrayEquals(AssertArrayEquals.java:59)
	at org.junit.jupiter.api.Assertions.assertArrayEquals(Assertions.java:1225)
	at [email protected]/org.eclipse.jetty.client.util.MultiPartRequestContentTest$9.process(MultiPartRequestContentTest.java:377)
	at [email protected]/org.eclipse.jetty.client.util.MultiPartRequestContentTest$AbstractMultiPartHandler.process(MultiPartRequestContentTest.java:431)
	at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:660)
	at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:444)
	at [email protected]/org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
	at [email protected]/org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at [email protected]/org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at [email protected]/org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:932)
	at [email protected]/org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1076)
	at java.base/java.lang.Thread.run(Thread.java:833)
2022-08-16 14:11:46.170:INFO :oejc.ResponseNotifier:client-64940: Exception while notifying listener org.eclipse.jetty.client.util.MultiPartRequestContentTest$$Lambda$1138/0x00000007c042c640@3ed4a27
org.opentest4j.AssertionFailedError: expected: <200> but was: <500>
	at org.junit.jupiter.api.AssertionFailureBuilder.build(AssertionFailureBuilder.java:151)
	at org.junit.jupiter.api.AssertionFailureBuilder.buildAndThrow(AssertionFailureBuilder.java:132)
	at org.junit.jupiter.api.AssertEquals.failNotEqual(AssertEquals.java:197)
	at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:150)
	at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:145)
	at org.junit.jupiter.api.Assertions.assertEquals(Assertions.java:527)
	at [email protected]/org.eclipse.jetty.client.util.MultiPartRequestContentTest.lambda$testFieldDeferredAndFileDeferred$3(MultiPartRequestContentTest.java:398)
	at [email protected]/org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:213)
	at [email protected]/org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:205)
	at [email protected]/org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:471)
	at [email protected]/org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:451)
	at [email protected]/org.eclipse.jetty.client.HttpReceiver.responseSuccess(HttpReceiver.java:414)
	at [email protected]/org.eclipse.jetty.client.http.HttpReceiverOverHTTP.messageComplete(HttpReceiverOverHTTP.java:385)
	at [email protected]/org.eclipse.jetty.http.HttpParser.handleContentMessage(HttpParser.java:585)
	at [email protected]/org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1692)
	at [email protected]/org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1521)
	at [email protected]/org.eclipse.jetty.client.http.HttpReceiverOverHTTP.parse(HttpReceiverOverHTTP.java:221)
	at [email protected]/org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:160)
	at [email protected]/org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:91)
	at [email protected]/org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:91)
	at [email protected]/org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:194)
	at [email protected]/org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
	at [email protected]/org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at [email protected]/org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at [email protected]/org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:932)
	at [email protected]/org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1076)
	at java.base/java.lang.Thread.run(Thread.java:833)
[2022-08-16T14:11:46.543-0500][info][gc] GC(48) Pause Young (Normal) (G1 Evacuation Pause) 1240M->13M(2048M) 2.658ms
[2022-08-16T14:11:46.756-0500][info][gc] GC(49) Pause Young (Normal) (G1 Evacuation Pause) 1239M->13M(2048M) 2.455ms
[2022-08-16T14:11:47.024-0500][info][gc] GC(50) Pause Young (Normal) (G1 Evacuation Pause) 1239M->13M(2048M) 2.357ms
[2022-08-16T14:11:47.295-0500][info][gc] GC(51) Pause Young (Normal) (G1 Evacuation Pause) 1239M->13M(2048M) 2.541ms
[2022-08-16T14:11:47.504-0500][info][gc] GC(52) Pause Young (Normal) (G1 Evacuation Pause) 1239M->13M(2048M) 2.723ms
[2022-08-16T14:11:47.717-0500][info][gc] GC(53) Pause Young (Normal) (G1 Evacuation Pause) 1239M->14M(2048M) 2.636ms
[2022-08-16T14:11:47.927-0500][info][gc] GC(54) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.521ms
[2022-08-16T14:11:48.199-0500][info][gc] GC(55) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.483ms
[2022-08-16T14:11:48.411-0500][info][gc] GC(56) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.674ms
[2022-08-16T14:11:48.621-0500][info][gc] GC(57) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.674ms
[2022-08-16T14:11:48.833-0500][info][gc] GC(58) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.517ms
[2022-08-16T14:11:49.043-0500][info][gc] GC(59) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.373ms
[2022-08-16T14:11:49.310-0500][info][gc] GC(60) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.520ms
[2022-08-16T14:11:49.523-0500][info][gc] GC(61) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.573ms
[2022-08-16T14:11:49.788-0500][info][gc] GC(62) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.090ms
[2022-08-16T14:11:50.002-0500][info][gc] GC(63) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 1.789ms
[2022-08-16T14:11:50.270-0500][info][gc] GC(64) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 1.873ms
[2022-08-16T14:11:50.482-0500][info][gc] GC(65) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.112ms
[2022-08-16T14:11:50.750-0500][info][gc] GC(66) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 1.876ms
[2022-08-16T14:11:50.959-0500][info][gc] GC(67) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.126ms
[2022-08-16T14:11:51.170-0500][info][gc] GC(68) Pause Young (Normal) (G1 Evacuation Pause) 1240M->14M(2048M) 2.459ms
2022-08-16 14:11:51.165:INFO :oejs.Server:main: Stopped oejs.Server@52667676{STOPPING}[12.0.0-SNAPSHOT,sto=0]

joakime avatar Aug 16 '22 19:08 joakime

Not seeing this recently.

sbordet avatar Sep 24 '22 15:09 sbordet