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)
It is your call now. since I cant release it
-Dan
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
>
>
