Kerberos keytab authentication fails

[alexanderdehes]

Versions

Please specify real version numbers or git SHAs, not just "Latest" since that changes fairly regularly.

Sarama	Kafka	Go
1.24.1	1.0.0	1.13

Configuration

What configuration values are you using for Sarama and Kafka?

ENV VERSION 1.0.0
ENV KAFKA_BROKERS xx144eza:6668,xx144ey9:6668
ENV KAFKA_SASL_ENABLED true
ENV KAFKA_SASL_GSSAPI_AUTH_TYPE KEYTAB_AUTH
ENV KAFKA_SASL_GSSAPI_KEY_TAB_PATH /app/kerberos/testuser.keytab
ENV KAFKA_SASL_MECHANISM GSSAPI
ENV KAFKA_SASL_GSSAPI_SERVICE_NAME=kafka
ENV KAFKA_SASL_GSSAPI_REALM=DTA.KLM.COM
ENV KAFKA_SASL_GSSAPI_KERBEROS_CONFIG_PATH=/app/kerberos/krb5.conf
ENV KAFKA_SASL_GSSAPI_USERNAME testuser
ENV LOG_LEVEL debug

Logs

{"level":"info","msg":"Kerberos client error: [Root cause: KRBMessage_Handling_Error] KRBMessage_Handling_Error: AS Exchange Error: AS_REP is not valid or client password/keytab incorrect \u003c KRBMessage_Handling_Error: clock skew with KDC too large. Greater than 300 seconds","source":"sarama","time":"2020-03-21T14:03:55Z"}

{"level":"info","msg":"Starting kafka minion version1.0.0","time":"2020-04-15T14:45:57Z"}
{"level":"debug","msg":"Sarama client config has been created successfully","time":"2020-04-15T14:45:57Z"}
{"address":"kl144eza.is.klmcorp.net:6668,kl144ey9.is.klmcorp.net:6668","level":"info","module":"cluster","msg":"connecting to kafka cluster","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Initializing new client","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Closed connection to broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Closed connection to broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata no available broker to send metadata request to","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/brokers resurrecting 2 dead seed brokers","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata retrying after 250ms... (3 attempts remaining)\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Closed connection to broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:57Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"Closed connection to broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata no available broker to send metadata request to","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/brokers resurrecting 2 dead seed brokers","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata retrying after 250ms... (2 attempts remaining)\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"Closed connection to broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"Closed connection to broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata no available broker to send metadata request to","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/brokers resurrecting 2 dead seed brokers","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata retrying after 250ms... (1 attempts remaining)\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:58Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"Closed connection to broker kl144eza.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"client/metadata fetching metadata for all topics from broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"Error while performing GSSAPI Kerberos Authentication: EOF\n","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"Closed connection to broker kl144ey9.is.klmcorp.net:6668\n","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"client/metadata got error from broker -1 while fetching metadata: EOF\n","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"client/metadata no available broker to send metadata request to","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"client/brokers resurrecting 2 dead seed brokers","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"level":"info","msg":"Closing Client","source":"sarama","time":"2020-04-15T14:45:59Z"}
{"address":"kl144eza.is.klmcorp.net:6668,kl144ey9.is.klmcorp.net:6668","level":"panic","module":"cluster","msg":"failed to start client","reason":"kafka: client has run out of available brokers to talk to (Is your cluster reachable?)","time":"2020-04-15T14:45:59Z"}
panic: (*logrus.Entry) (0xabfea0,0xc000192460)

goroutine 1 [running]:
github.com/sirupsen/logrus.Entry.log(0xc0000e4a10, 0xc0001985d0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/pkg/mod/github.com/sirupsen/logrus@v1.5.0/entry.go:261 +0x339
github.com/sirupsen/logrus.(*Entry).Log(0xc0001923f0, 0x0, 0xc000487848, 0x1, 0x1)
/go/pkg/mod/github.com/sirupsen/logrus@v1.5.0/entry.go:289 +0xeb
github.com/sirupsen/logrus.(*Entry).Logf(0xc0001923f0, 0xc000000000, 0xad08e7, 0x16, 0x0, 0x0, 0x0)
/go/pkg/mod/github.com/sirupsen/logrus@v1.5.0/entry.go:335 +0xe2
github.com/sirupsen/logrus.(*Entry).Panicf(...)
/go/pkg/mod/github.com/sirupsen/logrus@v1.5.0/entry.go:373
github.com/google-cloud-tools/kafka-minion/kafka.NewCluster(0xc000099380, 0xc000088e40, 0xc000088e40)
/app/kafka/cluster.go:80 +0x733
main.main()
/app/main.go:53 +0x2c2

Problem Description

I am using kafka-minion (which uses samara) and it works well with an unsecure connection to kafka.
When I configure kerberos authentication it fails in the process of getting a TGT ticket.

From a linux server (using kinit) with the same krb5.conf and keytab I can get a TGT and then connect to kafka.

[alexanderdehes]

related issue redpanda-data/kminion#38

[alexanderdehes]

Looking at the issue in more detail I see that problem is probably caused by sarama not sending an correct authentication request to the broker

I am running a V1.0.0 broker with kerberos enabled. That implies that you have to set GSSAPI as KAFKA SASL security mechanism.
This will cause the Authorize function in gssapi_kerberos.go to be called. In that function a GSS_API_INITIAL request is sent to the broker, but this is not accepted as the v1.0.0. broker only expects requests in kafka protocol format (e.g. SASLAuthenticateRequest).
In krbAuth.step == GSS_API_VERIFY it detects that zero bytes are returned by the broker (broker does not response omn invalid message).
All steps executed before that read the keytab and check against the KDC server seems to work well.

I have tested the same credentials and authentication from a java program and then I can see (in network trace) that the kafka protocol is used and it works fine.

[twmb]

For clarity, the GSSAPI authentication method specifically needs to not use kafka protocol wrapping. It looks like your issue was solved here.

I'm fairly certain that the reason the asn1 change broke things is because gssapi still returned the forked asn1.ObjectType, which the stdlib's asn1 marshalled differently.

[dnwe]

Believe to be fixed by #1658 (comment)