Skip to content

[CI] WatchAckTests testAckAllActions failure in CI #35506

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

Closed
jaymode opened this issue Nov 13, 2018 · 10 comments
Closed

[CI] WatchAckTests testAckAllActions failure in CI #35506

jaymode opened this issue Nov 13, 2018 · 10 comments
Assignees
Labels
:Data Management/Watcher >test-failure Triaged test failures from CI

Comments

@jaymode
Copy link
Member

jaymode commented Nov 13, 2018

Looking at the logs, I suspect this failure may be due to the same issue as #35503 where the watch service reloads concurrently due to new allocation ids

Build link: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.4+matrix-java-periodic/ES_BUILD_JAVA=java10,ES_RUNTIME_JAVA=java8fips,nodes=virtual&&linux/56/consoleFull

Reproduce line:

./gradlew :x-pack:plugin:watcher:test -Dtests.seed=545DF1A27C1717B6 -Dtests.class=org.elasticsearch.xpack.watcher.test.integration.WatchAckTests -Dtests.method="testAckAllActions" -Dtests.security.manager=true -Dtests.locale=ga -Dtests.timezone=ACT

Failure:

Throwable #1: java.lang.AssertionError: 
 Expected: is <1L>
      but: was <0L>
 	at __randomizedtesting.SeedInfo.seed([545DF1A27C1717B6:837F8503E7FBB51C]:0)
 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
 	at org.elasticsearch.xpack.watcher.test.integration.WatchAckTests.testAckAllActions(WatchAckTests.java:138)
 	at java.lang.Thread.run(Thread.java:748)
@jaymode jaymode added >test-failure Triaged test failures from CI :Data Management/Watcher labels Nov 13, 2018
@elasticmachine
Copy link
Collaborator

Pinging @elastic/es-core-infra

@jakelandis jakelandis self-assigned this Nov 15, 2018
@ywelsch
Copy link
Contributor

ywelsch commented Mar 28, 2019

I've muted the test on all branches down to 6.7.

A more recent failure: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+intake/2792/console

java.lang.AssertionError: 
Expected: is <ACKED>
     but: was <AWAITS_SUCCESSFUL_EXECUTION>
	at __randomizedtesting.SeedInfo.seed([958F25D00742B5A5:42AD51719CAE170F]:0)
	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
	at org.junit.Assert.assertThat(Assert.java:956)
	at org.junit.Assert.assertThat(Assert.java:923)
	at org.elasticsearch.xpack.watcher.test.integration.WatchAckTests.testAckAllActions(WatchAckTests.java:151)
	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:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)

ywelsch added a commit that referenced this issue Mar 28, 2019
ywelsch added a commit that referenced this issue Mar 28, 2019
ywelsch added a commit that referenced this issue Mar 28, 2019
ywelsch added a commit that referenced this issue Mar 28, 2019
@droberts195
Copy link
Contributor

Exactly the same unexpected state as in #35506 (comment) occurred in a different test, ExecuteWatchTests.testExecuteActionMode, in https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+artifactory/134/console:

Expected: is <ACKED>
     but: was <AWAITS_SUCCESSFUL_EXECUTION>

It doesn't reproduce with:

./gradlew :x-pack:plugin:watcher:unitTest \
  -Dtests.seed=CE39FD261BCE5EDE \
  -Dtests.class=org.elasticsearch.xpack.watcher.transport.action.execute.ExecuteWatchTests \
  -Dtests.method="testExecuteActionMode" \
  -Dtests.security.manager=true \
  -Dtests.locale=sk-SK \
  -Dtests.timezone=Europe/Sofia \
  -Dcompiler.java=12 \
  -Druntime.java=8

The full exception is:

   > Throwable #1: java.lang.AssertionError: 
   > Expected: is <ACKED>
   >      but: was <AWAITS_SUCCESSFUL_EXECUTION>
   > 	at __randomizedtesting.SeedInfo.seed([CE39FD261BCE5EDE:691F02A140D9596C]:0)
   > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
   > 	at org.elasticsearch.xpack.watcher.transport.action.execute.ExecuteWatchTests.testExecuteActionMode(ExecuteWatchTests.java:130)
   > 	at java.lang.Thread.run(Thread.java:748)

If you think there's a different root cause let me know and I'll open a separate issue for it.

@gwbrown
Copy link
Contributor

gwbrown commented Apr 9, 2019

This should be fixed in master by #40658, if anyone runs across this failure let me know. I'll wait for the backport before closing this.

@jtibshirani
Copy link
Contributor

A potentially related error popped up on 7.x and 7.0.

Command to reproduce:

./gradlew :x-pack:plugin:watcher:test \
  -Dtests.seed=EF24BB36A7FBEB83 \
  -Dtests.class=org.elasticsearch.xpack.watcher.test.integration.WatchAckTests \
  -Dtests.method="testAckSingleAction" \
  -Dtests.security.manager=true \
  -Dtests.locale=cs \
  -Dtests.timezone=Asia/Chongqing \
  -Dcompiler.java=12 \
  -Druntime.java=8

Build logs: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+7.0+artifactory/155/console
Relevant excerpt:

FAILURE 10.0s J7 | WatchAckTests.testAckSingleAction <<< FAILURES!
   > Throwable #1: java.lang.AssertionError: 
   > Expected: a value greater than <1L>
   >      but: <1L> was equal to <1L>
   > 	at __randomizedtesting.SeedInfo.seed([EF24BB36A7FBEB83:EDB478ADAB6340A3]:0)
   > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
   > 	at org.elasticsearch.xpack.watcher.test.integration.WatchAckTests.testAckSingleAction(WatchAckTests.java:101)
   > 	at java.lang.Thread.run(Thread.java:748)

@gwbrown do you think this might be fixed by #40658 as well? If so, I can wait before filing another issue + muting.

@gwbrown
Copy link
Contributor

gwbrown commented Apr 9, 2019

@jtibshirani I think it might be helped by that - it fits the profile for failures that would be improved by that PR. I intend to let master run for a few days to make sure it's stable with the fixed before merging the backports, so if this fails more we can mute it on 7.0/7.x and I can unmute in the backports for those branches.

It doesn't look like it's failing very much, so if it doesn't fail more I'd be inclined to just wait the extra day or two. If we see failures in the tests I've unmuted on master and I have to revert, we can also go ahead and mute this.

@gwbrown
Copy link
Contributor

gwbrown commented Apr 12, 2019

#40658 has been merged to all currently maintained branches after a week of running in master with no failures in this test, so I'm closing this issue.

@gwbrown gwbrown closed this as completed Apr 12, 2019
@dimitris-athanasiou
Copy link
Contributor

dimitris-athanasiou commented Feb 26, 2020

It seems this we have picked up a similar failure here on 7.x.

Build log: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+7.x+multijob+fast+part2/3568/console

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

Failure:

java.lang.AssertionError: 
12:01:55     Expected: is <1L>
12:01:55          but: was <0L>
12:01:55         at __randomizedtesting.SeedInfo.seed([6DEA8487F6CD3068:BAC8F0266D2192C2]:0)
12:01:55         at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18)
12:01:55         at org.junit.Assert.assertThat(Assert.java:956)
12:01:55         at org.junit.Assert.assertThat(Assert.java:923)
12:01:55         at org.elasticsearch.xpack.watcher.test.integration.WatchAckTests.testAckAllActions(WatchAckTests.java:136)
12:01:55 REPRODUCE WITH: ./gradlew ':x-pack:plugin:watcher:test' --tests "org.elasticsearch.xpack.watcher.test.integration.WatchAckTests.testAckAllActions" -Dtests.seed=6DEA8487F6CD3068 -Dtests.security.manager=true -Dtests.locale=th-TH-u-nu-thai-x-lvariant-TH -Dtests.timezone=Africa/Bamako -Dcompiler.java=13
12:01:55 
12:01:55 Suite: Test class org.elasticsearch.xpack.watcher.test.integration.WatchAckTests

Reproduce with:

./gradlew ':x-pack:plugin:watcher:test' --tests "org.elasticsearch.xpack.watcher.test.integration.WatchAckTests.testAckAllActions" -Dtests.seed=6DEA8487F6CD3068 -Dtests.security.manager=true -Dtests.locale=th-TH-u-nu-thai-x-lvariant-TH -Dtests.timezone=Africa/Bamako -Dcompiler.java=13

Can't reproduce locally.

@martijnvg
Copy link
Member

Note that this failure is similar to #52453, because in both cases the watch count from the watcher stats api response return an incorrect value. So perhaps the issues should merge into a single issue. I suspect that this is a broader test problem.

@martijnvg
Copy link
Member

I'm closing this issue in favour for #52453.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
:Data Management/Watcher >test-failure Triaged test failures from CI
Projects
None yet
Development

No branches or pull requests

9 participants