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

[TEST] IndexAuditTrailTests.testRunAsDenied failing #31028

Closed
ywelsch opened this issue Jun 1, 2018 · 1 comment
Closed

[TEST] IndexAuditTrailTests.testRunAsDenied failing #31028

ywelsch opened this issue Jun 1, 2018 · 1 comment
Assignees
Labels
:Security/Audit X-Pack Audit logging >test-failure Triaged test failures from CI

Comments

@ywelsch
Copy link
Contributor

ywelsch commented Jun 1, 2018

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

Relevant output:

> Throwable #1: java.lang.AssertionError: timed out waiting for yellow
   > Expected: <false>
   >      but: was <true>
   > 	at __randomizedtesting.SeedInfo.seed([671FC3F9520DD1BE:E3A26B8E4ACC5E11]:0)
   > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
   > 	at org.elasticsearch.xpack.security.audit.index.IndexAuditTrailTests.ensureYellowAndNoInitializingShards(IndexAuditTrailTests.java:949)
   > 	at org.elasticsearch.xpack.security.audit.index.IndexAuditTrailTests.getIndexedAuditMessage(IndexAuditTrailTests.java:903)
   > 	at org.elasticsearch.xpack.security.audit.index.IndexAuditTrailTests.testRunAsDenied(IndexAuditTrailTests.java:754)
   > 	at java.lang.Thread.run(Thread.java:748)

1> [2018-06-01T07:15:16,636][INFO ][o.e.x.s.a.i.IndexAuditTrailTests] ensureYellow timed out, cluster state:
  1> cluster uuid: uiuS3NTuTBC12HAyoPVuzA
  1> version: 6
  1> state uuid: oZxE__XXSpKbd2tKUfiPYA
  1> from_diff: false
  1> meta data version: 4
  1> nodes: 
  1>    {remote_node_s1}{dPbAW8RNTNq97oXdTCBfCQ}{JMrucCOtSSa2EKGr-HYoYg}{127.0.0.1}{127.0.0.1:30457}{xpack.installed=true}
  1>    {remote_node_s0}{VvPtBZOZTAugGgWtU3m6aw}{hQslfoPKTg6e5o54-OMFyg}{127.0.0.1}{127.0.0.1:30456}{xpack.installed=true}, local, master
  1> routing_table (version 1):
  1> routing_nodes:
  1> -----node_id[dPbAW8RNTNq97oXdTCBfCQ][V]
  1> -----node_id[VvPtBZOZTAugGgWtU3m6aw][V]
  1> ---- unassigned
  1> customs:
  1>    snapshot_deletions: SnapshotDeletionsInProgress[]   snapshots: SnapshotsInProgress[]   restore: RestoreInProgress[]
  1> tasks: (0):

Probable cause:

[2018-06-01T07:14:46,632][ERROR][o.e.x.s.a.i.IndexAuditTrailTests$2] failed to get remote cluster state
  1> org.elasticsearch.transport.RemoteTransportException: [remote_node_s1][127.0.0.1:30457][cluster:monitor/state]
  1> Caused by: org.elasticsearch.ElasticsearchSecurityException: unable to authenticate user [test_user] for action [cluster:monitor/state]
  1> 	at org.elasticsearch.xpack.core.security.support.Exceptions.authenticationError(Exceptions.java:24) ~[x-pack-core-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.xpack.core.security.authc.DefaultAuthenticationFailureHandler.failedAuthentication(DefaultAuthenticationFailureHandler.java:31) ~[x-pack-core-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$AuditableTransportRequest.authenticationFailed(AuthenticationService.java:518) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.consumeUser(AuthenticationService.java:356) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$consumeToken$14(AuthenticationService.java:294) ~[main/:?]
  1> 	at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:60) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.xpack.core.common.IteratingActionListener.onResponse(IteratingActionListener.java:96) ~[x-pack-core-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.xpack.core.common.IteratingActionListener.run(IteratingActionListener.java:76) ~[x-pack-core-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.consumeToken(AuthenticationService.java:298) ~[main/:?]
  2> REPRODUCE WITH: ./gradlew :x-pack:plugin:security:test -Dtests.seed=671FC3F9520DD1BE -Dtests.class=org.elasticsearch.xpack.security.audit.index.IndexAuditTrailTests -Dtests.method="testRunAsDenied" -Dtests.security.manager=true -Dtests.locale=ar-SY -Dtests.timezone=America/Argentina/Rio_Gallegos
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$extractToken$9(AuthenticationService.java:234) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.extractToken(AuthenticationService.java:244) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$authenticateAsync$0(AuthenticationService.java:178) ~[main/:?]
  1> 	at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:60) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.xpack.security.authc.TokenService.getAndValidateToken(TokenService.java:287) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$authenticateAsync$2(AuthenticationService.java:174) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lambda$lookForExistingAuthentication$4(AuthenticationService.java:205) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.lookForExistingAuthentication(AuthenticationService.java:216) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.authenticateAsync(AuthenticationService.java:170) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService$Authenticator.access$000(AuthenticationService.java:131) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.authc.AuthenticationService.authenticate(AuthenticationService.java:101) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.transport.ServerTransportFilter$NodeProfile.inbound(ServerTransportFilter.java:130) ~[main/:?]
  1> 	at org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler.messageReceived(SecurityServerTransportInterceptor.java:302) ~[main/:?]
  1> 	at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:66) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.transport.TcpTransport$RequestHandler.doRun(TcpTransport.java:1542) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.common.util.concurrent.EsExecutors$1.execute(EsExecutors.java:135) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.transport.TcpTransport.handleRequest(TcpTransport.java:1501) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.transport.TcpTransport.messageReceived(TcpTransport.java:1371) ~[elasticsearch-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:64) ~[transport-netty4-6.3.0-SNAPSHOT.jar:6.3.0-SNAPSHOT]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) ~[netty-codec-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297) ~[netty-codec-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413) ~[netty-codec-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) ~[netty-codec-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:241) ~[netty-handler-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:545) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) ~[netty-transport-4.1.16.Final.jar:4.1.16.Final]
  1> 	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) ~[netty-common-4.1.16.Final.jar:4.1.16.Final]
  1> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
@ywelsch ywelsch added >test-failure Triaged test failures from CI :Security/Audit X-Pack Audit logging labels Jun 1, 2018
@elasticmachine
Copy link
Collaborator

Pinging @elastic/es-security

@albertzaharovits albertzaharovits self-assigned this Jun 1, 2018
albertzaharovits added a commit that referenced this issue Feb 5, 2019
Authn is enabled only if `license_type` is non `basic`, but `basic` is
what the `LicenseService` generates implicitly. This commit explicitly sets
license type to `trial`, which allows for authn, in the `SecuritySettingsSource`
which is the settings configuration parameter for `InternalTestCluster`s.

The real problem, that had created tests failures like #31028 and #32685, is
that the check `licenseState.isAuthAllowed()` can change sporadically. If it were
to return `true` or `false` during the whole test there would be no problem.
The problem manifests when it turns from `true` to `false` right before `Realms.asList()`.
There are other license checks before this one (request filter, token service, etc)
that would not cause a problem if they would suddenly see the check as `false`.
But switching to `false` before `Realms.asList()` makes it appear that no installed
realms could have handled the authn token which is an authentication error, as can
be seen in the failing tests.

Closes #31028 #32685
albertzaharovits added a commit to albertzaharovits/elasticsearch that referenced this issue Feb 5, 2019
Authn is enabled only if `license_type` is non `basic`, but `basic` is
what the `LicenseService` generates implicitly. This commit explicitly sets
license type to `trial`, which allows for authn, in the `SecuritySettingsSource`
which is the settings configuration parameter for `InternalTestCluster`s.

The real problem, that had created tests failures like elastic#31028 and elastic#32685, is
that the check `licenseState.isAuthAllowed()` can change sporadically. If it were
to return `true` or `false` during the whole test there would be no problem.
The problem manifests when it turns from `true` to `false` right before `Realms.asList()`.
There are other license checks before this one (request filter, token service, etc)
that would not cause a problem if they would suddenly see the check as `false`.
But switching to `false` before `Realms.asList()` makes it appear that no installed
realms could have handled the authn token which is an authentication error, as can
be seen in the failing tests.

Closes elastic#31028 elastic#32685
albertzaharovits added a commit to albertzaharovits/elasticsearch that referenced this issue Feb 5, 2019
Authn is enabled only if `license_type` is non `basic`, but `basic` is
what the `LicenseService` generates implicitly. This commit explicitly sets
license type to `trial`, which allows for authn, in the `SecuritySettingsSource`
which is the settings configuration parameter for `InternalTestCluster`s.

The real problem, that had created tests failures like elastic#31028 and elastic#32685, is
that the check `licenseState.isAuthAllowed()` can change sporadically. If it were
to return `true` or `false` during the whole test there would be no problem.
The problem manifests when it turns from `true` to `false` right before `Realms.asList()`.
There are other license checks before this one (request filter, token service, etc)
that would not cause a problem if they would suddenly see the check as `false`.
But switching to `false` before `Realms.asList()` makes it appear that no installed
realms could have handled the authn token which is an authentication error, as can
be seen in the failing tests.

Closes elastic#31028 elastic#32685
albertzaharovits added a commit that referenced this issue Feb 5, 2019
Authn is enabled only if `license_type` is non `basic`, but `basic` is
what the `LicenseService` generates implicitly. This commit explicitly sets
license type to `trial`, which allows for authn, in the `SecuritySettingsSource`
which is the settings configuration parameter for `InternalTestCluster`s.

The real problem, that had created tests failures like #31028 and #32685, is
that the check `licenseState.isAuthAllowed()` can change sporadically. If it were
to return `true` or `false` during the whole test there would be no problem.
The problem manifests when it turns from `true` to `false` right before `Realms.asList()`.
There are other license checks before this one (request filter, token service, etc)
that would not cause a problem if they would suddenly see the check as `false`.
But switching to `false` before `Realms.asList()` makes it appear that no installed
realms could have handled the authn token which is an authentication error, as can
be seen in the failing tests.

Closes #31028 #32685
albertzaharovits added a commit that referenced this issue Feb 5, 2019
Authn is enabled only if `license_type` is non `basic`, but `basic` is
what the `LicenseService` generates implicitly. This commit explicitly sets
license type to `trial`, which allows for authn, in the `SecuritySettingsSource`
which is the settings configuration parameter for `InternalTestCluster`s.

The real problem, that had created tests failures like #31028 and #32685, is
that the check `licenseState.isAuthAllowed()` can change sporadically. If it were
to return `true` or `false` during the whole test there would be no problem.
The problem manifests when it turns from `true` to `false` right before `Realms.asList()`.
There are other license checks before this one (request filter, token service, etc)
that would not cause a problem if they would suddenly see the check as `false`.
But switching to `false` before `Realms.asList()` makes it appear that no installed
realms could have handled the authn token which is an authentication error, as can
be seen in the failing tests.

Closes #31028 #32685
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
:Security/Audit X-Pack Audit logging >test-failure Triaged test failures from CI
Projects
None yet
Development

No branches or pull requests

3 participants