[CI] IndexAuditUpgradeIT.testAuditLogs fails #33867

alpar-t · 2018-09-19T15:50:38Z

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.4+bwc-tests/8/console

Reproduction line

does not reproduce locally

 ./gradlew :x-pack:qa:rolling-upgrade:with-system-key:v6.3.1#upgradedClusterTestRunner \
  -Dtests.seed=57D936B12E792F96 \
  -Dtests.class=org.elasticsearch.upgrades.IndexAuditUpgradeIT \
  -Dtests.method="testAuditLogs" \
  -Dtests.security.manager=true \
  -Dtests.locale=bg \
  -Dtests.timezone=Pacific/Marquesas

Example relevant log:

00:00:46    > Throwable #1: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2343, key=upgraded-node-0}, {doc_count=2175, key=node-1}, {doc_count=2106, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 	at __randomizedtesting.SeedInfo.seed([57D936B12E792F96:300A75E395A08B0D]:0)
00:00:46    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:830)
00:00:46    > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:804)
00:00:46    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.testAuditLogs(IndexAuditUpgradeIT.java:68)
00:00:46    > 	at java.lang.Thread.run(Thread.java:748)
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46   2> NOTE: leaving temporary files on disk at: /var/lib/jenkins/workspace/elastic+elasticsearch+6.4+bwc-tests/x-pack/qa/rolling-upgrade/with-system-key/build/testrun/v6.3.1#upgradedClusterTestRunner/J0/temp/org.elasticsearch.upgrades.IndexAuditUpgradeIT_57D936B12E792F96-001
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46   2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=174, maxMBSortInHeap=7.47073894872366, sim=RandomSimilarity(queryNorm=true): {}, locale=bg, timezone=Pacific/Marquesas
00:00:46   2> NOTE: Linux 4.4.0-1061-aws amd64/Oracle Corporation 1.8.0_181 (64-bit)/cpus=16,threads=1,free=433534592,total=514850816
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46   2> NOTE: All tests run in this JVM: [IndexingIT, RollupIDUpgradeIT, TokenBackwardsCompatibilityIT, IndexAuditUpgradeIT]
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=2025, key=upgraded-node-0}, {doc_count=1841, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=2141, key=upgraded-node-0}, {doc_count=1933, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2212, key=upgraded-node-0}, {doc_count=2175, key=node-1}, {doc_count=2000, key=upgraded-node-1}, {doc_count=891, key=node-0}]
00:00:46    > Expected: a collection with size <6>
00:00:46    >      but: collection size was <5>
00:00:46    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
00:00:46    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
00:00:46    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:818)
00:00:46    > 		... 39 more
00:00:46 Completed [4/6] in 10.40s, 1 test, 1 failure <<< FAILURES!

Frequency

It happened 8 times in August, not super frequent but seems consistent.

The text was updated successfully, but these errors were encountered:

elasticmachine · 2018-09-19T15:50:39Z

Pinging @elastic/es-security

danielmitterdorfer · 2018-10-04T14:56:16Z

We looked at this in the test triage meeting. From the failure output we can see that there are actually only five out of six nodes reporting that they have indexed data (e.g. here from the first assertion error):

Found node buckets [{doc_count=2431, key=node-2}, {doc_count=2175, key=node-1}, {doc_count=1983, key=upgraded-node-0}, {doc_count=1794, key=upgraded-node-1}, {doc_count=891, key=node-0}]

So one possibility is that one of the nodes had a problem indexing data and for that we'd need to inspect cluster logs when the next failure occurs. Another observation is that this only occurs in 6.x so this might indicate a bug in 6.x.

For the person on test triage: If this occurs another time, please grab the cluster logs and attach it here.

davidkyle · 2018-11-02T12:06:42Z

Another failure with the same assertion

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.4+multijob-unix-compatibility/os=opensuse/33/console

   > Throwable #1: java.lang.AssertionError: Found node buckets [{doc_count=630, key=upgraded-node-1}]
   > Expected: a collection with size <0>
   >      but: collection size was <1>
   > 	at __randomizedtesting.SeedInfo.seed([81138282C946761F:E6C0C1D0729FD284]:0)
   > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
   > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
   > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
   > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:829)
   > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:803)
   > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.testAuditLogs(IndexAuditUpgradeIT.java:68)
   > 	at java.lang.Thread.run(Thread.java:748)
   > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=83, key=upgraded-node-1}]
   > Expected: a collection with size <0>
   >      but: collection size was <1>
   > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
   > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
   > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:70)
   > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:817)
   > 		... 39 more
...

Logs are attached

IndexAuditUpgradeIT-Logs.zip

There is no log for node upgradedClusterTestCluster node0 as the test failed in the 2 thirds upgraded stage

./gradlew :x-pack:qa:rolling-upgrade:without-system-key:v5.6.13-SNAPSHOT#twoThirdsUpgradedTestRunner \
  -Dtests.seed=81138282C946761F \
  -Dtests.class=org.elasticsearch.upgrades.IndexAuditUpgradeIT \
  -Dtests.method="testAuditLogs" \
  -Dtests.security.manager=true \
  -Dtests.locale=pt-PT \
  -Dtests.timezone=GB-Eire

jaymode · 2018-11-02T14:58:24Z

@albertzaharovits since you have some of the auditing code fresh in mind, can you please take a look at this test failure?

iverase · 2018-11-26T08:47:01Z

This failure seems to have happened four times during this weekend in 6.x. For example:

./gradlew :x-pack:qa:rolling-upgrade:with-system-key:v6.4.2#upgradedClusterTestRunner \
  -Dtests.seed=F17834F8C8394574 \
  -Dtests.class=org.elasticsearch.upgrades.IndexAuditUpgradeIT \
  -Dtests.method="testAuditLogs" \
  -Dtests.security.manager=true \
  -Dtests.locale=is-IS \
  -Dtests.timezone=SystemV/MST7 \
  -Dcompiler.java=11 \
  -Druntime.java=8

I am muting the test

Relates: #33867

andyb-elastic · 2018-12-04T00:27:16Z

Another one of these happened today, doesn't reproduce locally

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+periodic/288/console

build-288.txt.zip

andyb-elastic · 2018-12-04T00:36:56Z

Muted on 6.x - 521751e

jdconrad · 2018-12-07T00:07:45Z

Another on 6.5 https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.5+bwc-tests/120/console

martijnvg · 2018-12-11T09:46:43Z

Another failure on 6.5 branch: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.5+bwc-tests/138/console

1> [2018-12-10T16:01:26,213][INFO ][o.e.u.IndexAuditUpgradeIT] [testAuditLogs] after test
FAILURE 12.1s | IndexAuditUpgradeIT.testAuditLogs <<< FAILURES!
   > Throwable #1: java.lang.AssertionError: Found node buckets [{doc_count=1405, key=upgraded-node-1}, {doc_count=284, key=upgraded-node-2}]
   > Expected: a collection with size <3>
   >      but: collection size was <2>
   >    at __randomizedtesting.SeedInfo.seed([57554E0963E78375:30860D5BD83E27EE]:0)
   >    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
   >    at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:125)
   >    at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:68)
   >    at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:848)
   >    at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:822)
   >    at org.elasticsearch.upgrades.IndexAuditUpgradeIT.testAuditLogs(IndexAuditUpgradeIT.java:66)
   >    at java.lang.Thread.run(Thread.java:748)

Tim-Brooks · 2019-01-11T00:28:01Z

Another one on 6.5

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.5+bwc-tests/262/console

jaymode · 2019-02-12T21:45:09Z

@albertzaharovits fixed this in #38286

matriv · 2019-05-07T15:45:24Z

Another occurence: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.7+bwc-tests/359/consoleFull

Reproduction line:

./gradlew :x-pack:qa:rolling-upgrade:with-system-key:v6.0.0#twoThirdsUpgradedTestRunner \
  -Dtests.seed=53BD6CE84200B7B4 \
  -Dtests.class=org.elasticsearch.upgrades.IndexAuditUpgradeIT \
  -Dtests.method="testAuditLogs" \
  -Dtests.security.manager=true \
  -Dtests.locale=zh \
  -Dtests.timezone=Indian/Mahe \
  -Dcompiler.java=12 \
  -Druntime.java=8

error message:

08:41:03 FAILURE 33.5s | IndexAuditUpgradeIT.testAuditLogs <<< FAILURES!
08:41:03    > Throwable #1: java.lang.AssertionError: Found node buckets [{doc_count=143, key=upgraded-node-1}]
08:41:03    > Expected: a collection with size <2>
08:41:03    >      but: collection size was <1>
08:41:03    > 	at __randomizedtesting.SeedInfo.seed([53BD6CE84200B7B4:346E2FBAF9D9132F]:0)
08:41:03    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
08:41:03    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
08:41:03    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:69)
08:41:03    > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:858)
08:41:03    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.testAuditLogs(IndexAuditUpgradeIT.java:67)
08:41:03    > 	at java.lang.Thread.run(Thread.java:748)

Here are the full logs.

benwtrent · 2019-05-08T14:32:28Z

Additional failures:

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.7+bwc-tests/362/consoleFull

Message:

03:44:10 FAILURE 33.7s | IndexAuditUpgradeIT.testAuditLogs <<< FAILURES!
03:44:10    > Throwable #1: java.lang.AssertionError: Found node buckets [{doc_count=32, key=upgraded-node-1}]
03:44:10    > Expected: a collection with size <2>
03:44:10    >      but: collection size was <1>
03:44:10    > 	at __randomizedtesting.SeedInfo.seed([E59897C6A188BE7C:824BD4941A511AE7]:0)
03:44:10    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
03:44:10    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.assertNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:126)
03:44:10    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:69)
03:44:10    > 	at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:858)
03:44:10    > 	at org.elasticsearch.upgrades.IndexAuditUpgradeIT.testAuditLogs(IndexAuditUpgradeIT.java:67)
03:44:10    > 	at java.lang.Thread.run(Thread.java:748)
03:44:10    > 	Suppressed: java.lang.AssertionError: Found node buckets [{doc_count=32, key=upgraded-node-1}]

Noticed there were issues when the second upgraded node entered the cluster, but unsure if that is a possible cause, or if it is an effect of the test failing.

Other failures:
https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.8+bwc-tests/24

benwtrent · 2019-05-08T18:56:02Z

Another failure complaining of IndexAuditUpgradeIT.testAuditLogs

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.8+bwc-tests/25/consoleFull

 ./gradlew :x-pack:qa:rolling-upgrade:with-system-key:v6.0.1#twoThirdsUpgradedTestRunner -Dtests.seed=45291CCC37B84082 -Dtests.class=org.elasticsearch.upgrades.IndexAuditUpgradeIT -Dtests.method="testAuditLogs" -Dtests.security.manager=true -Dtests.locale=es-ES -Dtests.timezone=SystemV/AST4ADT -Dcompiler.java=12 -Druntime.java=8

13:23:34    > Expected: a collection with size <1>
13:23:34    >      but: collection size was <0>
13:23:34    > 		at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
13:23:34    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.masterIsNewVersion(IndexAuditUpgradeIT.java:135)
13:23:34    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.expectedNumUniqueNodeNameBuckets(IndexAuditUpgradeIT.java:79)
13:23:34    > 		at org.elasticsearch.upgrades.IndexAuditUpgradeIT.lambda$testAuditLogs$0(IndexAuditUpgradeIT.java:69)
13:23:34    > 		at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:846)
13:23:34    > 		... 38 more

Additional interesting trace lower down the stack

Throwable #2: org.elasticsearch.client.ResponseException: method [GET], host [http://[::1]:41677], URI [/_snapshot/_all], status line [HTTP/1.1 503 Service Unavailable]
13:23:34    > {"error":{"root_cause":[{"type":"master_not_discovered_exception","reason":null}],"type":"master_not_discovered_exception","reason":null},"status":503}
13:23:34    > 	at org.elasticsearch.client.RestClient$SyncResponseListener.get(RestClient.java:936)
13:23:34    > 	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:233)
13:23:34    > 	at org.elasticsearch.test.rest.ESRestTestCase.wipeSnapshots(ESRestTestCase.java:516)
13:23:34    > 	at org.elasticsearch.test.rest.ESRestTestCase.wipeCluster(ESRestTestCase.java:454)
13:23:34    > 	at org.elasticsearch.test.rest.ESRestTestCase.cleanUpCluster(ESRestTestCase.java:275)
13:23:34    > 	at java.lang.Thread.run(Thread.java:748)
13:23:34    > Caused by: org.elasticsearch.client.ResponseException: method [GET], host [http://[::1]:41677], URI [/_snapshot/_all], status line [HTTP/1.1 503 Service Unavailable]
13:23:34    > {"error":{"root_cause":[{"type":"master_not_discovered_exception","reason":null}],"type":"master_not_discovered_exception","reason":null},"status":503}
13:23:34    > 	at org.elasticsearch.client.RestClient$1.completed(RestClient.java:552)
13:23:34    > 	at org.elasticsearch.client.RestClient$1.completed(RestClient.java:537)
13:23:34    > 	at org.apache.http.concurrent.BasicFuture.completed(BasicFuture.java:119)
13:23:34    > 	at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.responseCompleted(DefaultClientExchangeHandlerImpl.java:177)
13:23:34    > 	at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.processResponse(HttpAsyncRequestExecutor.java:436)
13:23:34    > 	at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.inputReady(HttpAsyncRequestExecutor.java:326)
13:23:34    > 	at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:265)
13:23:34    > 	at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:81)
13:23:34    > 	at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39)
13:23:34    > 	at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:114)
13:23:34    > 	at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
13:23:34    > 	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
13:23:34    > 	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
13:23:34    > 	at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
13:23:34    > 	at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
13:23:34    > 	at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)
13:23:34    > 	... 1 more

It is unclear to me if IndexAuditUpgradeIT.testAuditLogs failing is causing the cluster instability (and thus causing many other Integration tests to subsequently fail), or vice versa (the cluster instability causing the test to fail).

albertzaharovits · 2020-02-03T19:53:02Z

We don't run these tests anymore.

alpar-t added >test-failure Triaged test failures from CI :Security/Audit X-Pack Audit logging v6.4.2 labels Sep 19, 2018

jaymode assigned albertzaharovits Nov 2, 2018

iverase added a commit that referenced this issue Nov 26, 2018

Mute IndexUpgradeIT.testAuditLogs

cfb76ba

Relates: #33867

albertzaharovits mentioned this issue Nov 28, 2018

Fix IndexAuditTrail rolling restart on rollover edge #35988

Merged

albertzaharovits closed this as completed in #35988 Nov 29, 2018

andyb-elastic reopened this Dec 4, 2018

albertzaharovits mentioned this issue Feb 3, 2019

Fix IndexAuditTrail rolling upgrade on rollover edge - take 2 #38286

Merged

jaymode closed this as completed Feb 12, 2019

matriv reopened this May 7, 2019

benwtrent mentioned this issue May 8, 2019

XPack rolling upgrade to 6.7.3 periodically fails due to node crashing #41952

Closed

albertzaharovits closed this as completed Feb 3, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[CI] IndexAuditUpgradeIT.testAuditLogs fails #33867

[CI] IndexAuditUpgradeIT.testAuditLogs fails #33867

alpar-t commented Sep 19, 2018

elasticmachine commented Sep 19, 2018

danielmitterdorfer commented Oct 4, 2018 •

edited

davidkyle commented Nov 2, 2018

jaymode commented Nov 2, 2018

iverase commented Nov 26, 2018

andyb-elastic commented Dec 4, 2018

andyb-elastic commented Dec 4, 2018

jdconrad commented Dec 7, 2018

martijnvg commented Dec 11, 2018

Tim-Brooks commented Jan 11, 2019

jaymode commented Feb 12, 2019

matriv commented May 7, 2019

benwtrent commented May 8, 2019 •

edited

benwtrent commented May 8, 2019

albertzaharovits commented Feb 3, 2020

[CI] IndexAuditUpgradeIT.testAuditLogs fails #33867

[CI] IndexAuditUpgradeIT.testAuditLogs fails #33867

Comments

alpar-t commented Sep 19, 2018

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.4+bwc-tests/8/console

Reproduction line

Example relevant log:

Frequency

elasticmachine commented Sep 19, 2018

danielmitterdorfer commented Oct 4, 2018 • edited

davidkyle commented Nov 2, 2018

jaymode commented Nov 2, 2018

iverase commented Nov 26, 2018

andyb-elastic commented Dec 4, 2018

andyb-elastic commented Dec 4, 2018

jdconrad commented Dec 7, 2018

martijnvg commented Dec 11, 2018

Tim-Brooks commented Jan 11, 2019

jaymode commented Feb 12, 2019

matriv commented May 7, 2019

benwtrent commented May 8, 2019 • edited

benwtrent commented May 8, 2019

albertzaharovits commented Feb 3, 2020

danielmitterdorfer commented Oct 4, 2018 •

edited

benwtrent commented May 8, 2019 •

edited