Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[CI] RetentionLeaseSyncIT.testRetentionLeasesSyncOnExpiration failure on 6.x #37963

Closed
matriv opened this issue Jan 29, 2019 · 5 comments

Comments

Projects
None yet
4 participants
@matriv
Copy link
Contributor

commented Jan 29, 2019

Logs: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+intake/1239/console

REPRODUCE WITH: ./gradlew :server:integTest \
  -Dtests.seed=A7802B12B16AAE08 \
  -Dtests.class=org.elasticsearch.index.seqno.RetentionLeaseSyncIT \
  -Dtests.method="testRetentionLeasesSyncOnExpiration" \
  -Dtests.security.manager=true \
  -Dtests.locale=ar-JO \
  -Dtests.timezone=NET \
  -Dcompiler.java=11 \
  -Druntime.java=8

Unable to reproduce locally (50 runs)

11:34:54   1> [2019-01-29T13:34:53,919][INFO ][o.e.i.s.RetentionLeaseSyncIT] [testRetentionLeasesSyncOnExpiration] after test
11:34:54 FAILURE 10.6s J3 | RetentionLeaseSyncIT.testRetentionLeasesSyncOnExpiration <<< FAILURES!
11:34:54    > Throwable #1: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 	at __randomizedtesting.SeedInfo.seed([A7802B12B16AAE08:E044B073BE5A3A0]:0)
11:34:54    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 	at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:848)
11:34:54    > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:822)
11:34:54    > 	at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.testRetentionLeasesSyncOnExpiration(RetentionLeaseSyncIT.java:152)
11:34:54    > 	at java.lang.Thread.run(Thread.java:748)
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: item 0: was <RetentionLease{id='uBdsaYWK', retainingSequenceNumber=5554481904067957458, timestamp=1548754483278, source='VNShmdtL'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: item 0: was <RetentionLease{id='uBdsaYWK', retainingSequenceNumber=5554481904067957458, timestamp=1548754483278, source='VNShmdtL'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: item 0: was <RetentionLease{id='uBdsaYWK', retainingSequenceNumber=5554481904067957458, timestamp=1548754483278, source='VNShmdtL'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54    > 	Suppressed: java.lang.AssertionError: 
11:34:54    > Expected: iterable containing [<RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>]
11:34:54    >      but: No item matched: <RetentionLease{id='wZvuRhEt', retainingSequenceNumber=1420806087916294428, timestamp=1548754483478, source='hotgIUTx'}>
11:34:54   2> NOTE: leaving temporary files on disk at: /var/lib/jenkins/workspace/elastic+elasticsearch+6.x+intake/server/build/testrun/integTest/J3/temp/org.elasticsearch.index.seqno.RetentionLeaseSyncIT_A7802B12B16AAE08-001
11:34:54   2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=576, maxMBSortInHeap=6.103012952259353, sim=RandomSimilarity(queryNorm=true): {}, locale=ar-JO, timezone=NET
11:34:54   2> NOTE: Linux 4.4.0-1061-aws amd64/Oracle Corporation 1.8.0_202 (64-bit)/cpus=16,threads=1,free=380326680,total=522715136
11:34:54    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
11:34:54   2> NOTE: All tests run in this JVM: [LegacyInnerHitsIT, CompletionSuggestSearchIT, HotThreadsIT, ClusterSearchShardsIT, RepositoriesServiceIT, IndicesExistsIT, ForceMergeBlocksIT, RetentionLeaseSyncIT]
11:34:54    > 		at org.elasticsearch.index.seqno.RetentionLeaseSyncIT.lambda$testRetentionLeasesSyncOnExpiration$5(RetentionLeaseSyncIT.java:162)
11:34:54    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:836)
11:34:54    > 		... 39 more
11:34:54   1> [2019-01-29T13:34:53,945][INFO ][o.e.n.Node               ] [suite] stopping ...
11:34:54   1> [2019-01-29T13:34:53,946][INFO ][o.e.c.s.MasterService    ] [node_s2] zen-disco-node-left({node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482}), reason(left)[{node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482} left], reason: removed {{node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482},}
11:34:54   1> [2019-01-29T13:34:53,948][INFO ][o.e.c.s.ClusterApplierService] [node_sc3] removed {{node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482},}, reason: apply cluster state (from master [master {node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769} committed version [19]])
11:34:54   1> [2019-01-29T13:34:53,948][INFO ][o.e.c.s.ClusterApplierService] [node_s1] removed {{node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482},}, reason: apply cluster state (from master [master {node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769} committed version [19]])
11:34:54   1> [2019-01-29T13:34:53,949][INFO ][o.e.n.Node               ] [suite] stopped
11:34:54   1> [2019-01-29T13:34:53,949][INFO ][o.e.c.s.ClusterApplierService] [node_s2] removed {{node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482},}, reason: apply cluster state (from master [master {node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769} committed version [19] source [zen-disco-node-left({node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482}), reason(left)[{node_s0}{0Bchj2avTK-08wk80p3kaA}{axMeSwkET7qvcESoSnjuEQ}{127.0.0.1}{127.0.0.1:38482} left]]])
11:34:54   1> [2019-01-29T13:34:53,949][INFO ][o.e.n.Node               ] [suite] closing ...
11:34:54   1> [2019-01-29T13:34:53,950][INFO ][o.e.n.Node               ] [suite] closed
11:34:54   1> [2019-01-29T13:34:53,951][INFO ][o.e.n.Node               ] [suite] stopping ...
11:34:54   1> [2019-01-29T13:34:53,951][WARN ][o.e.d.z.ZenDiscovery     ] [node_s2] not enough master nodes (has [1], but needed [2]), current nodes: nodes: 
11:34:54   1>    {node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769}, local, master
11:34:54   1>    {node_sc3}{TdQBPuFDRwWNKk34APUmmQ}{5V69ciVuTJa56yaCaYrvPQ}{127.0.0.1}{127.0.0.1:43056}
11:34:54   1>    {node_s1}{RJiGJfpOQdGYVy-dHmhQhA}{Z7ejYTaiQ1S7MWrR1-jfsQ}{127.0.0.1}{127.0.0.1:45791}
11:34:54   1> [2019-01-29T13:34:53,952][INFO ][o.e.t.d.MockZenPing      ] [node_s2] pinging using mock zen ping
11:34:54   1> [2019-01-29T13:34:53,953][INFO ][o.e.n.Node               ] [suite] stopped
11:34:54   1> [2019-01-29T13:34:53,953][INFO ][o.e.n.Node               ] [suite] closing ...
11:34:54   1> [2019-01-29T13:34:53,954][INFO ][o.e.n.Node               ] [suite] closed
11:34:54   1> [2019-01-29T13:34:53,955][INFO ][o.e.n.Node               ] [suite] stopping ...
11:34:54   1> [2019-01-29T13:34:53,955][WARN ][o.e.d.z.ZenDiscovery     ] [node_s2] not enough master nodes discovered during pinging (found [[Candidate{node={node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769}, clusterStateVersion=19}]], but needed [2]), pinging again
11:34:54   1> [2019-01-29T13:34:53,956][INFO ][o.e.d.z.ZenDiscovery     ] [node_sc3] master_left [{node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769}], reason [transport disconnected]
11:34:54   1> [2019-01-29T13:34:53,956][WARN ][o.e.d.z.ZenDiscovery     ] [node_sc3] master left (reason = transport disconnected), current nodes: nodes: 
11:34:54   1>    {node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769}, master
11:34:54   1>    {node_sc3}{TdQBPuFDRwWNKk34APUmmQ}{5V69ciVuTJa56yaCaYrvPQ}{127.0.0.1}{127.0.0.1:43056}, local
11:34:54   1>    {node_s1}{RJiGJfpOQdGYVy-dHmhQhA}{Z7ejYTaiQ1S7MWrR1-jfsQ}{127.0.0.1}{127.0.0.1:45791}
11:34:54   1> [2019-01-29T13:34:53,956][INFO ][o.e.n.Node               ] [suite] stopped
11:34:54   1> [2019-01-29T13:34:53,956][INFO ][o.e.t.d.MockZenPing      ] [node_sc3] pinging using mock zen ping
11:34:54   1> [2019-01-29T13:34:53,956][INFO ][o.e.n.Node               ] [suite] closing ...
11:34:54   1> [2019-01-29T13:34:53,958][INFO ][o.e.n.Node               ] [suite] closed
11:34:54   1> [2019-01-29T13:34:53,958][WARN ][o.e.c.NodeConnectionsService] [node_sc3] failed to connect to node {node_s2}{PhKdUp5qSKG-aUFUW3cIuQ}{vOb9YjDVR9-mXWf8skXriw}{127.0.0.1}{127.0.0.1:37769} (tried [1] times)
11:34:54   1> org.elasticsearch.transport.ConnectTransportException: [node_s2][127.0.0.1:37769] connect_exception
11:34:54   1> 	at org.elasticsearch.transport.TcpTransport$ChannelsConnectedListener.onFailure(TcpTransport.java:1308) ~[main/:?]
11:34:54   1> 	at org.elasticsearch.action.ActionListener.lambda$toBiConsumer$2(ActionListener.java:100) ~[main/:?]
11:34:54   1> 	at org.elasticsearch.common.concurrent.CompletableContext.lambda$addListener$0(CompletableContext.java:42) ~[elasticsearch-core-6.7.0-SNAPSHOT.jar:6.7.0-SNAPSHOT]
11:34:54   1> 	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_202]
11:34:54   1> 	at org.elasticsearch.common.concurrent.CompletableContext.completeExceptionally(CompletableContext.java:57) ~[elasticsearch-core-6.7.0-SNAPSHOT.jar:6.7.0-SNAPSHOT]
11:34:54   1> 	at org.elasticsearch.transport.MockTcpTransport.lambda$initiateChannel$0(MockTcpTransport.java:195) ~[framework-6.7.0-SNAPSHOT.jar:?]
11:34:54   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
11:34:54   1> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
11:34:54   1> Caused by: java.net.ConnectException: Connection refused (Connection refused)
11:34:54   1> 	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_202]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.access$101(MockSocket.java:32) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.lambda$connect$0(MockSocket.java:66) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_202]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.connect(MockSocket.java:65) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.connect(MockSocket.java:59) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at org.elasticsearch.transport.MockTcpTransport.lambda$initiateChannel$0(MockTcpTransport.java:190) ~[framework-6.7.0-SNAPSHOT.jar:?]
11:34:54   1> 	... 5 more
11:34:54   1> [2019-01-29T13:34:53,958][WARN ][o.e.c.NodeConnectionsService] [node_sc3] failed to connect to node {node_s1}{RJiGJfpOQdGYVy-dHmhQhA}{Z7ejYTaiQ1S7MWrR1-jfsQ}{127.0.0.1}{127.0.0.1:45791} (tried [1] times)
11:34:54   1> org.elasticsearch.transport.ConnectTransportException: [node_s1][127.0.0.1:45791] connect_exception
11:34:54   1> 	at org.elasticsearch.transport.TcpTransport$ChannelsConnectedListener.onFailure(TcpTransport.java:1308) ~[main/:?]
11:34:54   1> 	at org.elasticsearch.action.ActionListener.lambda$toBiConsumer$2(ActionListener.java:100) ~[main/:?]
11:34:54   1> 	at org.elasticsearch.common.concurrent.CompletableContext.lambda$addListener$0(CompletableContext.java:42) ~[elasticsearch-core-6.7.0-SNAPSHOT.jar:6.7.0-SNAPSHOT]
11:34:54   1> 	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_202]
11:34:54   1> 	at org.elasticsearch.common.concurrent.CompletableContext.completeExceptionally(CompletableContext.java:57) ~[elasticsearch-core-6.7.0-SNAPSHOT.jar:6.7.0-SNAPSHOT]
11:34:54   1> 	at org.elasticsearch.transport.MockTcpTransport.lambda$initiateChannel$0(MockTcpTransport.java:195) ~[framework-6.7.0-SNAPSHOT.jar:?]
11:34:54   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
11:34:54   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
11:34:54   1> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
11:34:54   1> Caused by: java.net.ConnectException: Connection refused (Connection refused)
11:34:54   1> 	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_202]
11:34:54   1> 	at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_202]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.access$101(MockSocket.java:32) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.lambda$connect$0(MockSocket.java:66) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_202]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.connect(MockSocket.java:65) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at org.elasticsearch.mocksocket.MockSocket.connect(MockSocket.java:59) ~[mocksocket-1.2.jar:?]
11:34:54   1> 	at org.elasticsearch.transport.MockTcpTransport.lambda$initiateChannel$0(MockTcpTransport.java:190) ~[framework-6.7.0-SNAPSHOT.jar:?]
11:34:54   1> 	... 5 more

There is also this:

2.1/net.sf.jopt-simple/jopt-simple/5.0.2/98cafc6081d5632b61be2c9e60650b64ddbc637c/jopt-simple-5.0.2.jar:/var/lib/jenkins/workspace/elastic+elasticsearch+6.x+intake/client/rest/build/distributions/elasticsearch-rest-client-6.7.0-SNAPSHOT.ja	at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1542)
11:39:14 	at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:123)
11:39:14 	at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:997)
11:39:14 	at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:994)
11:39:14 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
11:39:14 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
11:39:14 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
11:39:14 	at java.base/java.lang.Thread.run(Thread.java:834)
11:39:14 [ant:junit4] ERROR: JVM J7 ended with an exception: Forked process returned with error code: 137. Very likely a JVM crash.  See process stderr at: /var/lib/jenkins/workspace/elastic+elasticsearch+6.x+intake/server/build/testrun/integTest/temp/junit4-J7-20190129_093305_81516079772723897455842.syserr
11:39:14 	at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1542)
11:39:14 	at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:123)
11:39:14 	at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:997)
11:39:14 	at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:994)
11:39:14 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
11:39:14 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
11:39:14 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
11:39:14 	at java.base/java.lang.Thread.run(Thread.java:834)
@elasticmachine

This comment has been minimized.

Copy link

commented Jan 29, 2019

@matriv

This comment has been minimized.

Copy link
Contributor Author

commented Jan 29, 2019

Another error: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+internalClusterTest/61/console

There is also this:

12:57:13   1> [2019-01-29T22:57:00,359][WARN ][o.e.c.s.ClusterApplierService] [node_sd4] failed to notify ClusterStateListener
12:57:13   1> org.apache.lucene.util.SetOnce$AlreadySetException: The object cannot be set twice!
12:57:13   1> 	at org.apache.lucene.util.SetOnce.set(SetOnce.java:69) ~[lucene-core-8.0.0-snapshot-83f9835.jar:8.0.0-snapshot-83f9835 83f9835a47a00a2ec58a4cf5fc0d492497cf7898 - jpountz - 2019-01-21 13:06:00]
12:57:13   1> 	at org.elasticsearch.common.logging.NodeAndClusterIdConverter.setNodeIdAndClusterId(NodeAndClusterIdConverter.java:59) ~[main/:?]
12:57:13   1> 	at org.elasticsearch.common.logging.NodeAndClusterIdStateListener.onNewClusterState(NodeAndClusterIdStateListener.java:69) ~[main/:?]
12:57:13   1> 	at org.elasticsearch.cluster.ClusterStateObserver$ContextPreservingListener.onNewClusterState(ClusterStateObserver.java:308) ~[main/:?]
12:57:13   1> 	at org.elasticsearch.cluster.ClusterStateObserver$ObserverClusterStateListener.clusterChanged(ClusterStateObserver.java:193) ~[main/:?]
12:57:13   1> 	at org.elasticsearch.cluster.service.ClusterApplierService.lambda$callClusterStateListeners$6(ClusterApplierService.java:481) ~[main/:?]
12:57:13   1> 	at java.util.concurrent.ConcurrentHashMap$KeySpliterator.forEachRemaining(ConcurrentHashMap.java:3527) [?:1.8.0_202]
12:57:13   1> 	at java.util.stream.Streams$ConcatSpliterator.forEachRemaining(Streams.java:743) [?:1.8.0_202]
12:57:13   1> 	at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:580) [?:1.8.0_202]
12:57:13   1> 	at org.elasticsearch.cluster.service.ClusterApplierService.callClusterStateListeners(ClusterApplierService.java:478) [main/:?]
12:57:13   1> 	at org.elasticsearch.cluster.service.ClusterApplierService.applyChanges(ClusterApplierService.java:467) [main/:?]
12:57:13   1> 	at org.elasticsearch.cluster.service.ClusterApplierService.runTask(ClusterApplierService.java:414) [main/:?]
12:57:13   1> 	at org.elasticsearch.cluster.service.ClusterApplierService$UpdateTask.run(ClusterApplierService.java:165) [main/:?]
12:57:13   1> 	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:681) [main/:?]
12:57:13   1> 	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:252) [main/:?]
12:57:13   1> 	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:215) [main/:?]
12:57:13   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
12:57:13   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]

matriv added a commit that referenced this issue Jan 29, 2019

@matriv

This comment has been minimized.

Copy link
Contributor Author

commented Jan 29, 2019

Muted with f09d1ee

@dnhatn

This comment has been minimized.

Copy link
Contributor

commented Jan 30, 2019

@jasontedor I am assigning this to you but feel free to reassign to me :).

@jasontedor

This comment has been minimized.

Copy link
Member

commented Jan 30, 2019

@dnhatn Thank you, I have reassigned it to you.

@jasontedor jasontedor assigned dnhatn and unassigned jasontedor Jan 30, 2019

dnhatn added a commit that referenced this issue Jan 31, 2019

dnhatn added a commit to dnhatn/elasticsearch that referenced this issue Jan 31, 2019

Relax assertion in testRetentionLeasesSyncOnExpiration
The returned retention leases are collected from a HashMap which the
insert-order is not reserved. We should relax the order of leases.

Closes elastic#37963
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.