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

            Activity

              People

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

                Dates

                • Created:
                  Updated:
                  Resolved: