[CI] KerberosAuthenticationIT testLoginByUsernamePassword failing

[mark-vieira]

This and a couple of other Kerberos tests are failing on Amazon Linux 2022. This OS was recently added to our testing matrix so it's likely there's something funny with that CI image that these tests don't like. Since this seems to only reproduce on that system, I was unable to reproduce locally.

We may need to spin up an Amazon 2022 machine on AWS to reproduce this.

Build scan:
https://gradle-enterprise.elastic.co/s/3tsrwmkn3as6k/tests/:x-pack:qa:kerberos-tests:javaRestTest/org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT/testLoginByUsernamePassword

Reproduction line:
./gradlew ':x-pack:qa:kerberos-tests:javaRestTest' --tests "org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT.testLoginByUsernamePassword" -Dtests.seed=96CAAA1E169FAF62 -Dtests.locale=es-MX -Dtests.timezone=Australia/West -Druntime.java=17

Applicable branches:
main, 8.4, 8.3, 7.17

Reproduces locally?:
Didn't try

Failure history:
https://gradle-enterprise.elastic.co/scans/tests?tests.container=org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT&tests.test=testLoginByUsernamePassword

Failure excerpt:

java.security.PrivilegedActionException: (No message provided)

  at __randomizedtesting.SeedInfo.seed([96CAAA1E169FAF62:AEEBA327C743A7FB]:0)
  at java.security.AccessController.doPrivileged(AccessController.java:716)
  at javax.security.auth.Subject.doAsPrivileged(Subject.java:584)
  at org.elasticsearch.xpack.security.authc.kerberos.SpnegoHttpClientConfigCallbackHandler.lambda$doAsPrivilegedWrapper$2(SpnegoHttpClientConfigCallbackHandler.java:207)
  at java.security.AccessController.doPrivileged(AccessController.java:569)
  at org.elasticsearch.xpack.security.authc.kerberos.SpnegoHttpClientConfigCallbackHandler.doAsPrivilegedWrapper(SpnegoHttpClientConfigCallbackHandler.java:207)
  at org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT.executeRequestAndVerifyResponse(KerberosAuthenticationIT.java:176)
  at org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT.testLoginByUsernamePassword(KerberosAuthenticationIT.java:120)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
  at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:568)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1758)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:946)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:982)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:996)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:44)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at org.apache.lucene.tests.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:45)
  at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
  at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:843)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:490)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:955)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:840)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:891)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:902)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
  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 org.apache.lucene.tests.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
  at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
  at org.apache.lucene.tests.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:47)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:850)
  at java.lang.Thread.run(Thread.java:833)

  Caused by: org.elasticsearch.client.ResponseException: method [GET], host [http://127.0.0.1:34083], URI [/_security/_authenticate], status line [HTTP/1.1 401 Unauthorized]
  {"error":{"root_cause":[{"type":"security_exception","reason":"missing authentication credentials for REST request [/_security/_authenticate]","header":{"WWW-Authenticate":["Basic realm=\"security\" charset=\"UTF-8\"","Negotiate","Bearer realm=\"security\"","ApiKey"]}}],"type":"security_exception","reason":"missing authentication credentials for REST request [/_security/_authenticate]","header":{"WWW-Authenticate":["Basic realm=\"security\" charset=\"UTF-8\"","Negotiate","Bearer realm=\"security\"","ApiKey"]}},"status":401}

    at org.elasticsearch.client.RestClient.convertResponse(RestClient.java:347)
    at org.elasticsearch.client.RestClient.performRequest(RestClient.java:313)
    at org.elasticsearch.client.RestClient.performRequest(RestClient.java:288)
    at org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT.lambda$executeRequestAndVerifyResponse$0(KerberosAuthenticationIT.java:178)
    at java.security.AccessController.doPrivileged(AccessController.java:712)
    at javax.security.auth.Subject.doAsPrivileged(Subject.java:584)
    at org.elasticsearch.xpack.security.authc.kerberos.SpnegoHttpClientConfigCallbackHandler.lambda$doAsPrivilegedWrapper$2(SpnegoHttpClientConfigCallbackHandler.java:207)
    at java.security.AccessController.doPrivileged(AccessController.java:569)
    at org.elasticsearch.xpack.security.authc.kerberos.SpnegoHttpClientConfigCallbackHandler.doAsPrivilegedWrapper(SpnegoHttpClientConfigCallbackHandler.java:207)
    at org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT.executeRequestAndVerifyResponse(KerberosAuthenticationIT.java:176)
    at org.elasticsearch.xpack.security.authc.kerberos.KerberosAuthenticationIT.testLoginByUsernamePassword(KerberosAuthenticationIT.java:120)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:568)
    at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1758)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:946)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:982)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:996)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at org.apache.lucene.tests.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:44)
    at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
    at org.apache.lucene.tests.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:45)
    at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
    at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:843)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:490)
    at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:955)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:840)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:891)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:902)
    at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at org.apache.lucene.tests.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
    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 org.apache.lucene.tests.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
    at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
    at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
    at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
    at org.apache.lucene.tests.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:47)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:850)
    at java.lang.Thread.run(Thread.java:833)

[elasticsearchmachine]

Pinging @elastic/es-security (Team:Security)

[droberts195]

This error message is also in the output:

>>>KRBError:
	 cTime is Mon Mar 14 10:41:49 AQTT 2022 1647236509000
	 sTime is Mon Aug 15 11:32:47 AQTT 2022 1660545167000
	 suSec is 311990
	 error code is 7
	 error Message is Server not found in Kerberos database
	 crealm is BUILD.ELASTIC.CO
	 cname is george@BUILD.ELASTIC.CO
	 sname is HTTP/127.0.0.1@BUILD.ELASTIC.CO
	 msgType is 30
KrbException: Server not found in Kerberos database (7) - LOOKING_UP_SERVER
	at java.security.jgss/sun.security.krb5.KrbTgsRep.<init>(KrbTgsRep.java:72)
	at java.security.jgss/sun.security.krb5.KrbTgsReq.getReply(KrbTgsReq.java:224)
	at java.security.jgss/sun.security.krb5.KrbTgsReq.sendAndGetCreds(KrbTgsReq.java:235)
	at java.security.jgss/sun.security.krb5.internal.CredentialsUtil.serviceCredsSingle(CredentialsUtil.java:477)
	at java.security.jgss/sun.security.krb5.internal.CredentialsUtil.serviceCreds(CredentialsUtil.java:340)
	at java.security.jgss/sun.security.krb5.internal.CredentialsUtil.serviceCreds(CredentialsUtil.java:314)
	at java.security.jgss/sun.security.krb5.internal.CredentialsUtil.acquireServiceCreds(CredentialsUtil.java:169)
	at java.security.jgss/sun.security.krb5.Credentials.acquireServiceCreds(Credentials.java:493)
	at java.security.jgss/sun.security.jgss.krb5.Krb5Context.initSecContext(Krb5Context.java:700)
	at java.security.jgss/sun.security.jgss.GSSContextImpl.initSecContext(GSSContextImpl.java:266)
	at java.security.jgss/sun.security.jgss.GSSContextImpl.initSecContext(GSSContextImpl.java:196)
	at java.security.jgss/sun.security.jgss.spnego.SpNegoContext.GSS_initSecContext(SpNegoContext.java:883)
	at java.security.jgss/sun.security.jgss.spnego.SpNegoContext.initSecContext(SpNegoContext.java:315)
	at java.security.jgss/sun.security.jgss.GSSContextImpl.initSecContext(GSSContextImpl.java:266)
	at java.security.jgss/sun.security.jgss.GSSContextImpl.initSecContext(GSSContextImpl.java:196)
	at org.apache.http.impl.auth.GGSSchemeBase.generateGSSToken(GGSSchemeBase.java:123)
	at org.apache.http.impl.auth.SPNegoScheme.generateToken(SPNegoScheme.java:95)
	at org.apache.http.impl.auth.GGSSchemeBase.authenticate(GGSSchemeBase.java:221)
	at org.apache.http.impl.auth.SPNegoScheme.authenticate(SPNegoScheme.java:85)
	at org.apache.http.impl.auth.HttpAuthenticator.doAuth(HttpAuthenticator.java:233)
	at org.apache.http.impl.auth.HttpAuthenticator.generateAuthResponse(HttpAuthenticator.java:198)
	at org.apache.http.impl.nio.client.MainClientExec.generateRequest(MainClientExec.java:224)
	at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.generateRequest(DefaultClientExchangeHandlerImpl.java:134)
	at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.requestReady(HttpAsyncRequestExecutor.java:193)
	at org.apache.http.impl.nio.DefaultNHttpClientConnection.produceOutput(DefaultNHttpClientConnection.java:287)
	at org.apache.http.impl.nio.client.InternalIODispatch.onOutputReady(InternalIODispatch.java:86)
	at org.apache.http.impl.nio.client.InternalIODispatch.onOutputReady(InternalIODispatch.java:39)
	at org.apache.http.impl.nio.reactor.AbstractIODispatch.outputReady(AbstractIODispatch.java:145)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.writable(BaseIOReactor.java:187)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:341)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
	at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:591)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: KrbException: Identifier doesn't match expected value (906)
	at java.security.jgss/sun.security.krb5.internal.KDCRep.init(KDCRep.java:140)
	at java.security.jgss/sun.security.krb5.internal.TGSRep.init(TGSRep.java:65)
	at java.security.jgss/sun.security.krb5.internal.TGSRep.<init>(TGSRep.java:60)
	at java.security.jgss/sun.security.krb5.KrbTgsRep.<init>(KrbTgsRep.java:54)
	... 34 more

[mark-vieira]

FYI, there is some urgency on tracking this down. We want to certify that Elasticsearch is compatbile with Amazon LInux 2022 to be included in the official launch partner program. We have until 31 August to show proof of validation to Amazon for this.

[slobodanadamovic]

@mark-vieira
The only thing which looks odd to me is the fact that Kerberos is searching for HTTP/127.0.0.1@BUILD.ELASTIC.CO server principal, but in our test es.keytab file we have only one entry defined for the principal HTTP/localhost@BUILD.ELASTIC.CO.

I'm suspecting this is caused by the missing mapping for 127.0.0.1 to localhost in /etc/hosts. I might be wrong, but maybe it's worth checking.

[mark-vieira]

I'm suspecting this is caused by the missing mapping for 127.0.0.1 to localhost in /etc/hosts. I might be wrong, but maybe it's worth checking.

That's a reasonable assumption. I'll reach out to the infra team and see what's happening here.

[mark-vieira]

@slobodanadamovic The kerberos server is running as a fixture in a Docker container. Are we perhaps missing a extra_hosts entry here:

elasticsearch/test/fixtures/krb5kdc-fixture/docker-compose.yml

Line 9 in 6bc4b56

- "kerberos.build.elastic.co:127.0.0.1"

I'm not familiar with how that principal gets resolved and what would determine localhost vs 127.0.0.1.

[mark-vieira]

Ok, that compose file fix didn't work and I've checked /etc/hosts and it includes a proper entry for localhost

127.0.0.1	localhost	localhost.localdomain	localhost4	localhost4.localdomain4

@slobodanadamovic do you mind perhaps syncing up to work though this? I have a remote environment that I can reproduce this error on.

[slobodanadamovic]

@mark-vieira Yeah, let's sync when you're online and we can debug it together.

[slobodanadamovic]

Ok, that compose file fix didn't work and I've checked /etc/hosts and it includes a proper entry for localhost

@mark-vieira I did a bit more digging and I think the problem here is on the client side (Amazon Linux). Is it possible to check /etc/hosts on amazon linux image?

The reason I think it's caused by DNS misconfiguration is because I was able to reproduce the error by changing the buildHttpHost method in KerberosAuthenticationIT to always return 127.0.0.1:port.

127.0.0.1 is defined in build.gradle:

elasticsearch/x-pack/qa/kerberos-tests/build.gradle

Line 19 in e4ff839

setting 'http.host', '127.0.0.1'

This IP is then resolved to a host name by calling InetAddress.getCanonicalHostName(). getCanonicalHostName method will return passed IP address if it fails to resolve a domain name.

elasticsearch/x-pack/qa/kerberos-tests/src/javaRestTest/java/org/elasticsearch/xpack/security/authc/kerberos/KerberosAuthenticationIT.java

Lines 158 to 166 in e4ff839

	protected HttpHost buildHttpHost(String host, int port) {
	try {
	InetAddress inetAddress = InetAddress.getByName(host);
	return super.buildHttpHost(inetAddress.getCanonicalHostName(), port);
	} catch (UnknownHostException e) {
	assumeNoException("failed to resolve host [" + host + "]", e);
	}
	throw new IllegalStateException("DNS not resolved and assume did not trip");
	}

Resolved hostname from above is then used in tests to form a principal by prefixing it with HTTP/:

elasticsearch/x-pack/qa/kerberos-tests/src/javaRestTest/java/org/elasticsearch/xpack/security/authc/kerberos/SpnegoHttpClientConfigCallbackHandler.java

Line 354 in f87ce07

(PrivilegedExceptionAction<GSSName>) () -> gssManager.createName("HTTP/" + serviceHost, null)

[mark-vieira]

@mark-vieira I did a bit more digging and I think the problem here is on the client side (Amazon Linux). Is it possible to check /etc/hosts on amazon linux image?

The snippet I showed above is of the /etc/hosts file on the Amazon host, not the Docker image. Sorry if that was confusing.