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] AsyncSearchActionTests fails unpredictably #53360

Closed
williamrandolph opened this issue Mar 10, 2020 · 10 comments · Fixed by #53375
Closed

[CI] AsyncSearchActionTests fails unpredictably #53360

williamrandolph opened this issue Mar 10, 2020 · 10 comments · Fixed by #53375
Assignees
Labels
:Search/Search Search-related issues that do not fall into other categories >test-failure Triaged test failures from CI

Comments

@williamrandolph
Copy link
Contributor

williamrandolph commented Mar 10, 2020

We've had a couple of test failures from AsyncSearchActionTests today. The failures haven't reproduced locally for me.

Failure on master: https://gradle-enterprise.elastic.co/s/asvh7ted2nfvy/

org.elasticsearch.xpack.search.AsyncSearchActionTests > testInvalidId FAILED |  
-- | --
  | java.lang.AssertionError: Values should be different. Actual: 2 |  
  | at org.junit.Assert.fail(Assert.java:88) |  
  | at org.junit.Assert.failEquals(Assert.java:185) |  
  | at org.junit.Assert.assertNotEquals(Assert.java:199) |  
  | at org.junit.Assert.assertNotEquals(Assert.java:211) |  
  | at org.elasticsearch.xpack.search.AsyncSearchIntegTestCase$2.lambda$doNext$0(AsyncSearchIntegTestCase.java:214) |  
  | at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:881) |  
  | at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:854) |  
  | at org.elasticsearch.xpack.search.AsyncSearchIntegTestCase$2.doNext(AsyncSearchIntegTestCase.java:209) |  
  | at org.elasticsearch.xpack.search.AsyncSearchIntegTestCase$2.next(AsyncSearchIntegTestCase.java:187) |  
  | at org.elasticsearch.xpack.search.AsyncSearchIntegTestCase$2.next(AsyncSearchIntegTestCase.java:172) |  
  | at org.elasticsearch.xpack.search.AsyncSearchActionTests.testInvalidId(AsyncSearchActionTests.java:234) |  
  |   |  
  | java.lang.AssertionError: Accounting breaker not reset to 0 on node: node_sd3, are there still Lucene indices around? |  
  | Expected: <0L> |  
  | but: was <11134L> |  
  | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18) |  
  | at org.junit.Assert.assertThat(Assert.java:956) |  
  | at org.elasticsearch.test.InternalTestCluster.lambda$ensureEstimatedStats$37(InternalTestCluster.java:2195) |  
  | at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:881) |  
  | at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:854) |  
  | at org.elasticsearch.test.InternalTestCluster.ensureEstimatedStats(InternalTestCluster.java:2193) |  
  | at org.elasticsearch.test.TestCluster.assertAfterTest(TestCluster.java:90) |  
  | at org.elasticsearch.test.InternalTestCluster.assertAfterTest(InternalTestCluster.java:2235) |  
  | at org.elasticsearch.test.ESIntegTestCase.afterInternal(ESIntegTestCase.java:550) |  
  | at org.elasticsearch.test.ESIntegTestCase.cleanUpCluster(ESIntegTestCase.java:1936) |  
  […]

Earlier failure on 7.x master: https://gradle-enterprise.elastic.co/s/3pjzmjjxc66wi

org.elasticsearch.xpack.search.AsyncSearchActionTests > testCleanupOnFailure FAILED |  
-- | --
  | java.lang.AssertionError: |  
  | Expected: <6> |  
  | but: was <5> |  
  | at __randomizedtesting.SeedInfo.seed([43B69EECA92F38A8:C8A2BFFE0F2A2760]:0) |  
  | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18) |  
  | at org.junit.Assert.assertThat(Assert.java:956) |  
  | at org.junit.Assert.assertThat(Assert.java:923) |  
  | at org.elasticsearch.xpack.search.AsyncSearchActionTests.testCleanupOnFailure(AsyncSearchActionTests.java:221)

I believe @jimczi is working on this actively, but I'm going to go ahead and mute while he's in progress.

Relates #49931

@williamrandolph williamrandolph added :Search/Search Search-related issues that do not fall into other categories >test-failure Triaged test failures from CI labels Mar 10, 2020
@elasticmachine
Copy link
Collaborator

Pinging @elastic/es-search (:Search/Search)

@williamrandolph
Copy link
Contributor Author

@jimczi Thanks for handling this!

@jimczi
Copy link
Contributor

jimczi commented Mar 11, 2020

thanks for muting @williamrandolph , I'll watch the build since I was not able to reproduce the exact same exceptions locally.

@jimczi
Copy link
Contributor

jimczi commented Mar 11, 2020

Reopened since it failed on the first build :(

@jimczi jimczi reopened this Mar 11, 2020
jimczi added a commit that referenced this issue Mar 11, 2020
This change removes the need to always get a new version when iterating
on an async search. This is needed since we cannot guarantee that shards will
be queried exactly in order.

Relates #53360
@gwbrown
Copy link
Contributor

gwbrown commented Mar 12, 2020

There was another failure just now on master, Jenkins build and Build scan

Failure details, as there's a problem with the build scan that makes it a pain to access this info:

org.elasticsearch.xpack.search.AsyncSearchActionTests > testTermsAggregation FAILED	
    java.util.concurrent.ExecutionException: org.elasticsearch.transport.RemoteTransportException: [node_sd1][127.0.0.1:36453][indices:data/read/async_search/delete]	
        at __randomizedtesting.SeedInfo.seed([B320B9F0ED6D70E8:7C43B6B9168AE8E0]:0)	
        at org.elasticsearch.common.util.concurrent.BaseFuture$Sync.getValue(BaseFuture.java:266)	
        at org.elasticsearch.common.util.concurrent.BaseFuture$Sync.get(BaseFuture.java:253)	
        at org.elasticsearch.common.util.concurrent.BaseFuture.get(BaseFuture.java:87)	
        at org.elasticsearch.xpack.search.AsyncSearchIntegTestCase.deleteAsyncSearch(AsyncSearchIntegTestCase.java:105)	
        at org.elasticsearch.xpack.search.AsyncSearchActionTests.testTermsAggregation(AsyncSearchActionTests.java:167)	
	
        Caused by:	
        org.elasticsearch.transport.RemoteTransportException: [node_sd1][127.0.0.1:36453][indices:data/read/async_search/delete]	
	
            Caused by:	
            org.elasticsearch.ResourceNotFoundException: FndnX1VmYnJnUUJLbFRnVWE1eWFMRVEZLV9RUG1xUTZTVktlYllWZXNjZUEzZzo1OQ==	
                at org.elasticsearch.xpack.search.AsyncSearchIndexService.lambda$deleteResponse$5(AsyncSearchIndexService.java:211)	
                at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)	
                at org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:43)	
                at org.elasticsearch.client.node.NodeClient.lambda$executeLocally$0(NodeClient.java:91)	
                at org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:144)	
                at org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:138)	
                at org.elasticsearch.action.bulk.TransportSingleItemBulkWriteAction.lambda$wrapBulkResponse$0(TransportSingleItemBulkWriteAction.java:62)	
                at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)	
                at org.elasticsearch.action.bulk.TransportBulkAction$BulkOperation$1.finishHim(TransportBulkAction.java:523)	
                at org.elasticsearch.action.bulk.TransportBulkAction$BulkOperation$1.onResponse(TransportBulkAction.java:504)	
                at org.elasticsearch.action.bulk.TransportBulkAction$BulkOperation$1.onResponse(TransportBulkAction.java:493)	
                at org.elasticsearch.client.node.NodeClient.lambda$executeLocally$0(NodeClient.java:91)	
                at org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:144)	
                at org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:138)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase.finishOnSuccess(TransportReplicationAction.java:817)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase$1.handleResponse(TransportReplicationAction.java:736)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase$1.handleResponse(TransportReplicationAction.java:722)	
                at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.handleResponse(TransportService.java:1057)	
                at org.elasticsearch.transport.TransportService$DirectResponseChannel.processResponse(TransportService.java:1135)	
                at org.elasticsearch.transport.TransportService$DirectResponseChannel.sendResponse(TransportService.java:1115)	
                at org.elasticsearch.transport.TaskTransportChannel.sendResponse(TaskTransportChannel.java:54)	
                at org.elasticsearch.action.support.ChannelActionListener.onResponse(ChannelActionListener.java:47)	
                at org.elasticsearch.action.support.ChannelActionListener.onResponse(ChannelActionListener.java:30)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.lambda$runWithPrimaryShardReference$2(TransportReplicationAction.java:368)	
                at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)	
                at org.elasticsearch.action.ActionListener$4.onResponse(ActionListener.java:163)	
                at org.elasticsearch.action.support.replication.ReplicationOperation.finish(ReplicationOperation.java:306)	
                at org.elasticsearch.action.support.replication.ReplicationOperation.decPendingAndFinishIfNeeded(ReplicationOperation.java:287)	
                at org.elasticsearch.action.support.replication.ReplicationOperation$1.onResponse(ReplicationOperation.java:144)	
                at org.elasticsearch.action.support.replication.ReplicationOperation$1.onResponse(ReplicationOperation.java:136)	
                at org.elasticsearch.action.support.replication.TransportWriteAction$WritePrimaryResult$1.onSuccess(TransportWriteAction.java:156)	
                at org.elasticsearch.action.support.replication.TransportWriteAction$AsyncAfterWriteAction.maybeFinish(TransportWriteAction.java:291)	
                at org.elasticsearch.action.support.replication.TransportWriteAction$AsyncAfterWriteAction.lambda$run$1(TransportWriteAction.java:322)	
                at org.elasticsearch.common.util.concurrent.AsyncIOProcessor.notifyList(AsyncIOProcessor.java:122)	
                at org.elasticsearch.common.util.concurrent.AsyncIOProcessor.drainAndProcessAndRelease(AsyncIOProcessor.java:100)	
                at org.elasticsearch.common.util.concurrent.AsyncIOProcessor.put(AsyncIOProcessor.java:84)	
                at org.elasticsearch.index.shard.IndexShard.sync(IndexShard.java:3005)	
                at org.elasticsearch.action.support.replication.TransportWriteAction$AsyncAfterWriteAction.run(TransportWriteAction.java:320)	
                at org.elasticsearch.action.support.replication.TransportWriteAction$WritePrimaryResult.runPostReplicationActions(TransportWriteAction.java:163)	
                at org.elasticsearch.action.support.replication.ReplicationOperation.handlePrimaryResult(ReplicationOperation.java:136)	
                at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)	
                at org.elasticsearch.action.ActionListener$4.onResponse(ActionListener.java:163)	
                at org.elasticsearch.action.ActionListener.completeWith(ActionListener.java:336)	
                at org.elasticsearch.action.bulk.TransportShardBulkAction$2.finishRequest(TransportShardBulkAction.java:199)	
                at org.elasticsearch.action.bulk.TransportShardBulkAction$2.doRun(TransportShardBulkAction.java:168)	
                at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)	
                at org.elasticsearch.action.bulk.TransportShardBulkAction.performOnPrimary(TransportShardBulkAction.java:204)	
                at org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:116)	
                at org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:82)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryShardReference.perform(TransportReplicationAction.java:894)	
                at org.elasticsearch.action.support.replication.ReplicationOperation.execute(ReplicationOperation.java:109)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.runWithPrimaryShardReference(TransportReplicationAction.java:373)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.lambda$doRun$0(TransportReplicationAction.java:296)	
                at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)	
                at org.elasticsearch.index.shard.IndexShard.lambda$wrapPrimaryOperationPermitListener$24(IndexShard.java:2715)	
                at org.elasticsearch.action.ActionListener$3.onResponse(ActionListener.java:113)	
                at org.elasticsearch.index.shard.IndexShardOperationPermits.acquire(IndexShardOperationPermits.java:285)	
                at org.elasticsearch.index.shard.IndexShardOperationPermits.acquire(IndexShardOperationPermits.java:237)	
                at org.elasticsearch.index.shard.IndexShard.acquirePrimaryOperationPermit(IndexShard.java:2689)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction.acquirePrimaryOperationPermit(TransportReplicationAction.java:835)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.doRun(TransportReplicationAction.java:292)	
                at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)	
                at org.elasticsearch.action.support.replication.TransportReplicationAction.handlePrimaryRequest(TransportReplicationAction.java:255)	
                at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:63)	
                at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:696)	
                at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:747)	
                at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)	
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)	
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)	
                at java.lang.Thread.run(Thread.java:834)	
REPRODUCE WITH: ./gradlew ':x-pack:plugin:async-search:test' --tests "org.elasticsearch.xpack.search.AsyncSearchActionTests.testTermsAggregation" -Dtests.seed=B320B9F0ED6D70E8 -Dtests.security.manager=true -Dtests.locale=en-SG -Dtests.timezone=Etc/GMT+4 -Dcompiler.java=13	

jimczi added a commit to jimczi/elasticsearch that referenced this issue Mar 12, 2020
Deleting an async search id can throw a ResourceNotFoundException even if the query was successfully cancelled.
We delete the stored response automatically if the query is cancelled so that creates a race with the delete
action that also ensures that the task is removed. This change ensures that we ignore missing async search ids
in the async search index if they were successfuly cancelled.

Relates elastic#53360
Relates elastic#49931
jaymode added a commit to jaymode/elasticsearch that referenced this issue Mar 12, 2020
This test failed in CI and there has been an ongoing issue for tests
in this class failing.

Relates elastic#53360
jimczi added a commit that referenced this issue Mar 12, 2020
Deleting an async search id can throw a ResourceNotFoundException even if the query was successfully cancelled.
We delete the stored response automatically if the query is cancelled so that creates a race with the delete action that also ensures that the task is removed. This change ensures that we ignore missing async search ids in the async search index if they were successfully cancelled.

Relates #53360
Relates #49931
@mayya-sharipova
Copy link
Contributor

Another failure of several tests today on 7.x intake: https://gradle-enterprise.elastic.co/s/ldwksp7pl32ye

org.elasticsearch.xpack.search.AsyncSearchActionTests > testInvalidId FAILED |  
-- | --
  | java.lang.AssertionError: Values should be different. Actual: 1 |  
  | at org.junit.Assert.fail(Assert.java:88) |  
  | at org.junit.Assert.failEquals(Assert.java:185) |  
  | at org.junit.Assert.assertNotEquals(Assert.java:199) |  
  | at org.junit.Assert.assertNotEquals(Assert.java:211) |  
  | at org.elasticsearch.xpack.search.AsyncSearchIntegTestCase$2.lambda$doNext$0(AsyncSearchIntegTestCase.java:227)

jimczi added a commit that referenced this issue Mar 16, 2020
This change removes the need to always get a new version when iterating
on an async search. This is needed since we cannot guarantee that shards will
be queried exactly in order.

Relates #53360
@jimczi
Copy link
Contributor

jimczi commented Mar 16, 2020

Thanks @mayya-sharipova , a backport was missing, I pushed dc2edc9 and will watch the build in 7.x before closing.

@jimczi
Copy link
Contributor

jimczi commented Mar 20, 2020

The tests seem stable in master and 7.x, hence closing.

@ywangd
Copy link
Member

ywangd commented Mar 31, 2020

This started to fail for "darwin-compatibility" since March 27 for master, 7.x and 7.7. On CI, all tests of this class fail all the time for "darwin-compatibility", see following trend:

https://gradle-enterprise.elastic.co/scans/tests?list.size=50&list.sortColumn=startTime&list.sortOrder=desc&search.buildToolType=gradle&search.buildToolType=maven&search.startTimeMax=1585698495283&search.startTimeMin=1585093695283&search.tags=CI&search.tags=MAC&search.tzOffset=660&tests.container=org.elasticsearch.xpack.search.AsyncSearchActionTests&tests.sortField=FAILED&tests.test=testNoIndex&tests.unstableOnly=true

But I cannot reproduce locally:

./gradlew ':x-pack:plugin:async-search:test' --tests "org.elasticsearch.xpack.search.AsyncSearchActionTests.testNoIndex" \
  -Dtests.seed=49A4746586643385 \
  -Dtests.security.manager=true \
  -Dtests.locale=es-MX \
  -Dtests.timezone=SystemV/MST7MDT \
  -Dcompiler.java=13

Sample error message

:x-pack:plugin:async-search:test » org.elasticsearch.xpack.search.AsyncSearchActionTests » testNoIndex (11.246s)
6 channels still being tracked in RestCancellableNodeClient while there should be none expected:<0> but was:<6>
java.lang.AssertionError: 6 channels still being tracked in RestCancellableNodeClient while there should be none expected:<0> but was:<6>

Build scan:
https://gradle-enterprise.elastic.co/s/q4uaac6hl4jvu

Build log:
https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+multijob-darwin-compatibility/613/console

Failure email notification:
https://groups.google.com/a/elastic.co/forum/?utm_medium=email&utm_source=footer#!topic/build-elasticsearch/vxu0iDmfzcg

@ywangd ywangd reopened this Mar 31, 2020
@ywangd
Copy link
Member

ywangd commented Apr 1, 2020

I am closing this issue as recent discussion is in #54180

@ywangd ywangd closed this as completed Apr 1, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
:Search/Search Search-related issues that do not fall into other categories >test-failure Triaged test failures from CI
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants