Am 2016-12-28 um 06:05 schrieb Dan Tran:
i still see the same timeout error on the jetty8 branch. No issue at master
[ERROR] Failed to execute goal
org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test
(default-test) on project wagon-http: There was a timeout or other
error in the fork -> [Help
1]org.apache.maven.lifecycle.LifecycleExecutionException: Failed to
execute goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test
(default-test) on project wagon-http: There was a timeout or other
error in the fork
at
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:212)
I still would like to see your Surefire XML. Please provide! Can you
raise forkedProcessTimeoutInSeconds?
This could also be a race condition where one thread does not wait for
another. Please also note:
https://mail-archives.apache.org/mod_mbox/maven-dev/201612.mbox/%3C81e68f7b-b68f-ce5d-2529-12d604d42c98%40apache.org%3E
Can you set up a job on Jenkins for this branch? I'd like to see wether
the Ubuntu slave fails too.
> It is your call now. since I cant release it
Do you want me to roll the release?
On Tue, Dec 27, 2016 at 5:05 PM, Michael Osipov <micha...@apache.org> wrote:
Hi Dan,
Am 2016-12-25 um 19:51 schrieb Dan Tran:
Just want to confirm, your FreeBSD and build.apache.org's ubuntu see the
same test failure??
Do you think we should cancel the vote and wait for your fix?
I was finally able to complete my coding and testings. After several hours
of testing and debugging, I've found the reasons why several tests were
failing sporadically, some were bad test conditions (testSecuredGet(),
testSecuredGetToStream()) and some rooted in bugs in HttpWagon. I'll go in
detail:
1. Flaky testSecuredGet(ToStream):
This failed once in a while due to race conditions between Jetty's qtp
threads and the main thread running the tests and the assertions. Jetty did
not fully complete the process chain while Surefire continued to verify the
result. This yielded to: expected <2> requests found <1> and so forth. I
added a simple sleep() and it did work. I avoided to have complex sync code
with CountDownLatch or alike. Some logging added to the code shows the
following in Surefire's XML output:
<failure message="not 2 security handler use
[HandlerRequestResponse{method='GET',
responseCode=401, requestUri='/test-secured-resource'}]
expected:<2> but was:<1>" type="junit.framework.Assertio
nFailedError"><![CDATA[junit.framework.AssertionFailedError: not 2
security handler use [HandlerRequestResponse{method='GET',
responseCode=401, requestUri='/test-secured-resource'}] expected:<2> but
was:<1>
at junit.framework.Assert.fail(Assert.java:57)
at junit.framework.Assert.failNotEquals(Assert.java:329)
at junit.framework.Assert.assertEquals(Assert.java:78)
at junit.framework.Assert.assertEquals(Assert.java:234)
at junit.framework.TestCase.assertEquals(TestCase.java:401)
at org.apache.maven.wagon.http.HttpWagonTestCase.testPreemptive
Authentication(HttpWagonTestCase.java:1910)
at org.apache.maven.wagon.http.HttpWagonTestCase.testPreemptive
AuthenticationGet(HttpWagonTestCase.java:1891)
at org.apache.maven.wagon.http.HttpWagonTestCase.runTestSecured
GetToStream(HttpWagonTestCase.java:1409)
at org.apache.maven.wagon.http.HttpWagonTestCase.testSecuredGet
ToStream(HttpWagonTestCase.java:1374)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAcce
ssorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
thodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at junit.framework.TestCase.runTest(TestCase.java:176)
at junit.framework.TestCase.runBare(TestCase.java:141)
at junit.framework.TestResult$1.protect(TestResult.java:122)
at junit.framework.TestResult.runProtected(TestResult.java:142)
at junit.framework.TestResult.run(TestResult.java:125)
at junit.framework.TestCase.run(TestCase.java:129)
at junit.framework.TestSuite.runTest(TestSuite.java:255)
at junit.framework.TestSuite.run(TestSuite.java:250)
at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38Cla
ssRunner.java:84)
at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUni
t4Provider.java:283)
at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithR
erun(JUnit4Provider.java:173)
at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestS
et(JUnit4Provider.java:153)
at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit
4Provider.java:128)
at org.apache.maven.surefire.booter.ForkedBooter.invokeProvider
InSameClassLoader(ForkedBooter.java:203)
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInPro
cess(ForkedBooter.java:155)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBoo
ter.java:103)
]]></failure>
now the logging:
<system-err><![CDATA[[main] INFO org.eclipse.jetty.server.Server -
jetty-8.1.22.v20160922
[main] INFO org.eclipse.jetty.server.AbstractConnector - Started
SelectChannelConnector@0.0.0.0:45658
[main] DEBUG org.apache.http.client.protocol.RequestAddCookies -
CookieSpec selected: compatibility
[main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager
- Connection request: [route: {}->http://localhost:45658][total kept
alive: 39; route allocated: 0 of 20; total allocated: 39 of 40]
[main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager
- Connection leased: [id: 86][route: {}->http://localhost:45658][total
kept alive: 39; route allocated: 1 of 20; total allocated: 40 of 40]
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Opening
connection {}->http://localhost:45658
[main] DEBUG org.apache.http.impl.conn.DefaultHttpClientConnectionOperator
- Connecting to localhost/127.0.0.1:45658
[main] DEBUG org.apache.http.impl.conn.DefaultHttpClientConnectionOperator
- Connection established 127.0.0.1:45659<->127.0.0.1:45658
[main] DEBUG org.apache.http.impl.conn.DefaultManagedHttpClientConnection
- http-outgoing-86: set socket timeout to 1800000
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Executing
request GET /test-secured-resource HTTP/1.1
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Target auth
state: UNCHALLENGED
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Proxy auth
state: UNCHALLENGED
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> GET
/test-secured-resource HTTP/1.1
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Cache-control:
no-cache
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Cache-store:
no-store
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Pragma:
no-cache
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Expires: 0
[main] DEBUG org.apache.http.headers - http-outgoing-86 >>
Accept-Encoding: gzip
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Host:
localhost:45658
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Connection:
Keep-Alive
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> User-Agent:
Apache-HttpClient/4.5.2 (Java/1.7.0_111)
[main] DEBUG org.apache.http.headers - http-outgoing-86 << HTTP/1.1 401
Unauthorized
[main] DEBUG org.apache.http.headers - http-outgoing-86 <<
WWW-Authenticate: basic realm="MyRealm"
[main] DEBUG org.apache.http.headers - http-outgoing-86 << Cache-Control:
must-revalidate,no-cache,no-store
[main] DEBUG org.apache.http.headers - http-outgoing-86 << Content-Type:
text/html;charset=ISO-8859-1
[main] DEBUG org.apache.http.headers - http-outgoing-86 <<
Content-Length: 1311
[main] DEBUG org.apache.http.headers - http-outgoing-86 << Server:
Jetty(8.1.22.v20160922)
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Connection
can be kept alive indefinitely
[main] DEBUG org.apache.http.impl.auth.HttpAuthenticator -
Authentication required
[main] DEBUG org.apache.http.impl.auth.HttpAuthenticator -
localhost:45658 requested authentication
[main] DEBUG org.apache.http.impl.client.TargetAuthenticationStrategy -
Authentication schemes in the order of preference: [Negotiate, Kerberos,
NTLM, Digest, Basic]
[main] DEBUG org.apache.http.impl.client.TargetAuthenticationStrategy -
Challenge for Negotiate authentication scheme not available
[main] DEBUG org.apache.http.impl.client.TargetAuthenticationStrategy -
Challenge for Kerberos authentication scheme not available
[main] DEBUG org.apache.http.impl.client.TargetAuthenticationStrategy -
Challenge for NTLM authentication scheme not available
[main] DEBUG org.apache.http.impl.client.TargetAuthenticationStrategy -
Challenge for Digest authentication scheme not available
[main] DEBUG org.apache.http.impl.auth.HttpAuthenticator - Selected
authentication options: [BASIC [complete=true]]
[main] DEBUG org.apache.http.impl.conn.DefaultManagedHttpClientConnection
- http-outgoing-86: set socket timeout to 1800000
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Executing
request GET /test-secured-resource HTTP/1.1
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Target auth
state: CHALLENGED
[main] DEBUG org.apache.http.impl.auth.HttpAuthenticator - Generating
response to an authentication challenge using basic scheme
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Proxy auth
state: UNCHALLENGED
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> GET
/test-secured-resource HTTP/1.1
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Cache-control:
no-cache
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Cache-store:
no-store
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Pragma:
no-cache
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Expires: 0
[main] DEBUG org.apache.http.headers - http-outgoing-86 >>
Accept-Encoding: gzip
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Host:
localhost:45658
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Connection:
Keep-Alive
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> User-Agent:
Apache-HttpClient/4.5.2 (Java/1.7.0_111)
[main] DEBUG org.apache.http.headers - http-outgoing-86 >> Authorization:
Basic dXNlcjpzZWNyZXQ=
org.apache.maven.wagon.http.HttpWagonTestCase$TestSecurityHandler@9187167
(count 1): handled GET /test-secured-resource with status 401
[main] DEBUG org.apache.http.headers - http-outgoing-86 << HTTP/1.1 200 OK
[main] DEBUG org.apache.http.headers - http-outgoing-86 << Accept-Ranges:
bytes
[main] DEBUG org.apache.http.headers - http-outgoing-86 <<
Content-Length: 10
[main] DEBUG org.apache.http.headers - http-outgoing-86 << Last-Modified:
Mon, 26 Dec 2016 23:07:55 GMT
[main] DEBUG org.apache.http.headers - http-outgoing-86 << Server:
Jetty(8.1.22.v20160922)
[main] DEBUG org.apache.http.impl.execchain.MainClientExec - Connection
can be kept alive indefinitely
[main] DEBUG org.apache.http.impl.auth.HttpAuthenticator -
Authentication succeeded
[main] DEBUG org.apache.http.impl.client.TargetAuthenticationStrategy -
Caching 'basic' auth scheme for http://localhost:45658
[main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager
- Connection [id: 86][route: {}->http://localhost:45658] can be kept
alive indefinitely
[main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager
- Connection released: [id: 86][route: {}->http://localhost:45658][total
kept alive: 40; route allocated: 1 of 20; total allocated: 40 of 40]
org.apache.maven.wagon.http.HttpWagonTestCase$TestSecurityHandler@9187167
(1)
org.apache.maven.wagon.http.HttpWagonTestCase$TestSecurityHandler@9187167
(count 2): handled GET /test-secured-resource with status 200
[main] INFO org.eclipse.jetty.server.handler.ContextHandler - stopped
o.e.j.s.ServletContextHandler{/,file:/usr/home/mosipov/Proje
kte/maven-wagon/wagon-providers/wagon-http/target/test-output/}
]]></system-err>
now take a look at TestSecurityHandler output. I added it after
super.handle() called by Jetty. As you can see,
"org.apache.maven.wagon.http.HttpWagonTestCase$TestSecurityHandler@9187167
(1)" is printed where the assertions kick in, after Wagon has completed,
but the second request is handled afterwards. A traditional race condition.
2. Bugs found:
Several auth tests fail for no reason too once in a while. Logging showed
me that HttpClient simply did not send any Basic data, regardless if
preemptive or after a roundtrip. The basic problem was that non-threadsafe
classes have been used in a non-threadsafe manner as well as auth caches
have not beed released properly, and preemptive auth was configured
incorrectly. After fixing the issues one by one, the tests never failed
again.
I have tested the code on three platforms and six JDK versions tens of
times, they never failed again. After we have resolved your HugeDowloadTest
issue and no one else objects, I'd like to merge this into master and like
you to reroll 2.11 with those changes.
Meanwhile, I'll test this branch with Maven Core IT Suite too.
Michael
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@maven.apache.org
For additional commands, e-mail: dev-h...@maven.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@maven.apache.org
For additional commands, e-mail: dev-h...@maven.apache.org
