Uploaded image for project: 'Nuxeo Platform'
  1. Nuxeo Platform
  2. NXP-16869

Fix random read timeout on UserGroupTest

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 7.3-SNAPSHOT
    • Fix Version/s: 8.10
    • Component/s: Rest API, Tests

      Description

      The following test stuck the build for more than 1 hour:
      https://qa.nuxeo.org/jenkins/job/nuxeo-master/407/

      23:08:55 Running org.nuxeo.ecm.restapi.test.UserGroupTest
23:13:56 main 23:13:56,108 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-8437474450302615088.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:18:56 main 23:18:56,504 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-6234553413716845538.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:23:56 main 23:23:56,861 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-1513242006739394091.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:28:57 main 23:28:57,184 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-815697981780963906.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:33:57 main 23:33:57,519 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-5068629670675785054.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:38:58 main 23:38:57,946 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-1868787792161663313.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:43:58 main 23:43:58,264 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-6268829601615086635.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:48:58 main 23:48:58,524 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-6576942247165566368.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:53:58 main 23:53:58,753 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-2597231488297003190.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
23:58:59 main 23:58:58,976 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-4859956926840886606.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:03:59 main 00:03:59,294 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-3600319079149893693.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:08:59 main 00:08:59,587 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-2094327408882289516.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:13:59 main 00:13:59,971 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-1995111942387414553.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:18:59 main 00:19:00,304 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-962815760307148677.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:24:00 main 00:24:00,701 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-7234947124020367949.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:29:00 main 00:29:01,105 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-7618855787956743122.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:34:01 main 00:34:01,381 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-4962905515190188090.tdump{{fState,afterTeardown}{fSuite,class org.nuxeo.ecm.restapi.test.UserGroupTest}}
00:34:02 main 00:34:02,562 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-884525765478976312.tdump{}
00:34:03 Tests run: 17, Failures: 0, Errors: 17, Skipped: 0, Time elapsed: 5,107.808 sec <<< FAILURE! - in org.nuxeo.ecm.restapi.test.UserGroupTest

      All tests on this class eventually failed:

          org.nuxeo.ecm.restapi.test.UserGroupTest.itCanFetchAUser
    org.nuxeo.ecm.restapi.test.UserGroupTest.itReturnsA404OnNonExistentUser
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanUpdateAUser
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanDeleteAUser
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanCreateAUser
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanGetAGroup
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanChangeAGroup
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanDeleteGroup
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanCreateAGroup
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanAddAGroupToAUser
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanAddAUserToAGroup
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanRemoveAUserToAGroup
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanSearchUsers
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanPaginateUsers
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanSearchGroups
    org.nuxeo.ecm.restapi.test.UserGroupTest.itCanPaginateGroups
    org.nuxeo.ecm.restapi.test.UserGroupTest.itDoesntWritePassword
    org.nuxeo.elasticsearch.test.aggregates.TestAggregates.testPageProviderWithDateHistogramSelection

      Here is a trace for one of these tests (org.nuxeo.ecm.restapi.test.UserGroupTest.itReturnsA404OnNonExistentUser):

      Error Message

java.net.SocketTimeoutException: Read timed out

Stacktrace

com.sun.jersey.api.client.ClientHandlerException: java.net.SocketTimeoutException: Read timed out
	at com.sun.jersey.client.urlconnection.URLConnectionClientHandler.handle(URLConnectionClientHandler.java:155)
	at com.sun.jersey.api.client.filter.HTTPBasicAuthFilter.handle(HTTPBasicAuthFilter.java:105)
	at com.sun.jersey.api.client.Client.handle(Client.java:652)
	at com.sun.jersey.api.client.WebResource.handle(WebResource.java:682)
	at com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)
	at com.sun.jersey.api.client.WebResource$Builder.get(WebResource.java:509)
	at org.nuxeo.ecm.restapi.test.BaseTest.getResponse(BaseTest.java:157)
	at org.nuxeo.ecm.restapi.test.BaseTest.getResponse(BaseTest.java:97)
	at org.nuxeo.ecm.restapi.test.UserGroupTest.itCanFetchAUser(UserGroupTest.java:67)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$15.evaluate(FeaturesRunner.java:472)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeMethodRunStatement.evaluate(FeaturesRunner.java:351)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeSetupStatement.evaluate(FeaturesRunner.java:367)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterMethodRunStatement.evaluate(FeaturesRunner.java:398)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterTeardownStatement.evaluate(FeaturesRunner.java:417)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:530)
	at org.nuxeo.runtime.test.runner.RuntimeDeployment$DeploymentStatement.evaluate(RuntimeDeployment.java:265)
	at org.nuxeo.runtime.test.runner.RuntimeFeature$2$1.evaluate(RuntimeFeature.java:124)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:290)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:530)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:273)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runners.Suite.runChild(Suite.java:127)
	at org.junit.runners.Suite.runChild(Suite.java:26)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54)
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
	at java.net.SocketInputStream.read(SocketInputStream.java:170)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
	at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:704)
	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:647)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1535)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1440)
	at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
	at com.sun.jersey.client.urlconnection.URLConnectionClientHandler._invoke(URLConnectionClientHandler.java:253)
	at com.sun.jersey.client.urlconnection.URLConnectionClientHandler.handle(URLConnectionClientHandler.java:153)
	... 56 more

Standard Output

main 23:08:54,684 WARN  [DetectThreadDeadlocksFeature] Thread dump available at target/tcheck-253324737392631552.tdump{}

      Test on page provider does not seem to be linked , here is the trace anyway:

      Error Message

expected:<...e, [], [BucketRange([3072, 1, 3072.00, 4096.00), BucketRange(6144, 1, 6144.00, 7168].00)])> but was:<...e, [], [BucketRange([2048, 1, 2048.00, 3072.00), BucketRange(5120, 1, 5120.00, 6144].00)])>

Stacktrace

org.junit.ComparisonFailure: expected:<...e, [], [BucketRange([3072, 1, 3072.00, 4096.00), BucketRange(6144, 1, 6144.00, 7168].00)])> but was:<...e, [], [BucketRange([2048, 1, 2048.00, 3072.00), BucketRange(5120, 1, 5120.00, 6144].00)])>
	at org.junit.Assert.assertEquals(Assert.java:115)
	at org.junit.Assert.assertEquals(Assert.java:144)
	at org.nuxeo.elasticsearch.test.aggregates.TestAggregates.testPageProviderWithDateHistogramSelection(TestAggregates.java:721)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$15.evaluate(FeaturesRunner.java:472)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeMethodRunStatement.evaluate(FeaturesRunner.java:351)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeSetupStatement.evaluate(FeaturesRunner.java:367)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterMethodRunStatement.evaluate(FeaturesRunner.java:398)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterTeardownStatement.evaluate(FeaturesRunner.java:417)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:530)
	at org.nuxeo.runtime.test.runner.RuntimeDeployment$DeploymentStatement.evaluate(RuntimeDeployment.java:265)
	at org.nuxeo.runtime.test.runner.RuntimeFeature$2$1.evaluate(RuntimeFeature.java:124)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:290)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:530)
	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:273)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runners.Suite.runChild(Suite.java:127)
	at org.junit.runners.Suite.runChild(Suite.java:26)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54)
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)

        Attachments

          Issue Links

          depends on

          Bug - A problem which impairs or prevents the functions of the product. NXP-16229 Automation Client must fully consume and close HTTP responses

          • Critical - Crashes, loss of data, severe memory leak.
          • Resolved

          Bug - A problem which impairs or prevents the functions of the product. NXP-14194 Fix blocked unit tests when automation client is waiting for an answer from server

          • Major - Major loss of function.
          • Resolved

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: