[CI] SmokeTestWatcherWithSecurityIT.testSearchTransformInsufficientPermissions Failure

[talevy]

REPRODUCE WITH: ./gradlew :x-pack:qa:smoke-test-watcher-with-security:integTestRunner \
  -Dtests.seed=9861B17A9382A49D \
  -Dtests.class=org.elasticsearch.smoketest.SmokeTestWatcherWithSecurityIT \
  -Dtests.method="testSearchTransformInsufficientPermissions" \
  -Dtests.security.manager=true \
  -Dtests.locale=sr-Latn-ME \
  -Dtests.timezone=America/Cambridge_Bay \
  -Dcompiler.java=10 \
  -Druntime.java=8

stacktrace

3:45:09 FAILURE 12.0s | SmokeTestWatcherWithSecurityIT.testSearchTransformInsufficientPermissions <<< FAILURES!
23:45:09    > Throwable #1: java.lang.AssertionError: 
23:45:09    > Expected: is a value equal to or greater than <1>
23:45:09    >      but: <0> was less than <1>
23:45:09    >   at __randomizedtesting.SeedInfo.seed([9861B17A9382A49D:514B584B289A370]:0)
23:45:09    >   at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
23:45:09    >   at org.elasticsearch.smoketest.SmokeTestWatcherWithSecurityIT.lambda$getWatchHistoryEntry$3(SmokeTestWatcherWithSecurityIT.java:326)
23:45:09    >   at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:847)
23:45:09    >   at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:821)
...
23:45:30 org.elasticsearch.ElasticsearchSecurityException: action [indices:data/write/bulk[s]] is unauthorized for user [watcher_manager]

[elasticmachine]

Pinging @elastic/es-core-infra

[andrershov]

Occurred again https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+multijob-unix-compatibility/os=centos/58/console

REPRODUCE WITH: ./gradlew :x-pack:qa:smoke-test-watcher-with-security:integTestRunner \
  -Dtests.seed=484163AFA937AD5E \
  -Dtests.class=org.elasticsearch.smoketest.SmokeTestWatcherWithSecurityIT \
  -Dtests.method="testSearchTransformInsufficientPermissions" \
  -Dtests.security.manager=true \
  -Dtests.locale=it \
  -Dtests.timezone=Antarctica/Mawson \
  -Dcompiler.java=11 \
  -Druntime.java=8

[jakelandis]

I haven't reproduced this exact issue... but stepping through the code, there appears to be a bug in the start/stop logic in SmokeTestWatcherWithSecurityIT such that it does not busy wait as (I believe) is the intent of the code.

Starting Watcher here is wrapped in an assertBusy() which appears to attempt to wait for 10 seconds max until the Watcher is indeed started. However, the break here allows not only to break the switch, but also effectively stops the busy wait logic since it exits the lamda normally. assertBusy only busy waits while an assertionError is getting thrown in the (lamda) code block.

Stop Watcher has the same bug here (note the assertion in both is asserting the success/failure of the http call, not the state of Watcher)... and it looks like SmokeTestWatcherWithSecurityClientYamlTestSuiteIT may have the same issue (but haven't stepped trough that yet).

This means that Watcher is not guaranteed to be started or stopped between tests since it is not properly blocking till started or stopped, and is likely the root cause of many of these Watcher failures.

I believe the fix is to simply change the break to a AssertionError for the state change switches.

Also, this specific test is peculiar since it can pass without Watcher ever started.

[cbuescher]

@jakelandis I got something that looks quite similar to this today on 6.5, not sure if this should have been fixed you your PR

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.5+multijob-unix-compatibility/os=centos/70/console

./gradlew :x-pack:qa:smoke-test-watcher-with-security:integTestRunner \
  -Dtests.seed=2EA37470CE126E3E \
  -Dtests.class=org.elasticsearch.smoketest.SmokeTestWatcherWithSecurityIT \
  -Dtests.method="testSearchTransformInsufficientPermissions" \
  -Dtests.security.manager=true \
  -Dtests.locale=es-UY \
  -Dtests.timezone=ART \
  -Dcompiler.java=11 \
  -Druntime.java=8

java.lang.AssertionError: 
Expected: is a value equal to or greater than <1>
     but: <0> was less than <1>
    at __randomizedtesting.SeedInfo.seed([2EA37470CE126E3E:B3D6708EEF1969D3]: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.smoketest.SmokeTestWatcherWithSecurityIT.lambda$getWatchHistoryEntry$3(SmokeTestWatcherWithSecurityIT.java:328)
    at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:848)
    at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:822)
    at org.elasticsearch.smoketest.SmokeTestWatcherWithSecurityIT.getWatchHistoryEntry(SmokeTestWatcherWithSecurityIT.java:306)
    at org.elasticsearch.smoketest.SmokeTestWatcherWithSecurityIT.getWatchHistoryEntry(SmokeTestWatcherWithSecurityIT.java:301)
    at org.elasticsearch.smoketest.SmokeTestWatcherWithSecurityIT.testSearchTransformInsufficientPermissions(SmokeTestWatcherWithSecurityIT.java:237)

[jakelandis]

Un-muted this test on PR #42409 to obtain additional logs.

If (when?) this test fails again please obtain the following information before muting the test:

• Copy of the relevant failure
• Copy of the reproduce line
• The Jenkins build link
• The Gradle scan link
• The relevant cluster logs from "Google Cloud Storage Upload Report" (link found in Jenkins build)

[martijnvg]

Closing in favour of #30777 as this test fails in a similar way&_a=(columns:!(_source),filters:!(('$state':(store:appState),meta:(alias:!n,disabled:!f,index:e58bf320-7efd-11e8-bf69-63c8ef516157,key:test,negate:!f,params:(query:testSearchTransformInsufficientPermissions,type:phrase),type:phrase,value:testSearchTransformInsufficientPermissions),query:(match:(test:(query:testSearchTransformInsufficientPermissions,type:phrase))))),index:e58bf320-7efd-11e8-bf69-63c8ef516157,interval:auto,query:(language:lucene,query:'class:*SmokeTestWatcherWithSecurityIT'),sort:!(time,desc))) as the mentioned issue.

PR #50931 will add more logging in case this fails again.