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

GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Matching credential not found) #2117

Closed
1 of 7 tasks
Jasper2015 opened this issue Nov 26, 2018 · 2 comments
Assignees

Comments

@Jasper2015
Copy link

Description

I have a rdkafka producer program, which produces message periodically. It works fine with SSL, but once enabled SASL_SSL, I always get error "GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Matching credential not found)". The error appears just after kinit process, which looks good from the log. I debuged the program, it looks fhe failure was in calling sasl_client_start (in the libsasl2).

How to reproduce

The program is using librdkafka-0.11.6.
I have tried the configuration (keytab and principals) using Kafka java samples, which works fine.

Here is the log files:
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:request.required.acks=1,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:batch.num.messages=50,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:batch.num.messages=50,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:queue.buffering.max.ms=100,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:queue.buffering.max.ms=100,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:message.send.max.retries=3,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:message.send.max.retries=3,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:ssl.ca.location=keys/ca-cert,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:ssl.ca.location=keys/ca-cert,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:ssl.certificate.location=keys/clt-kafka-client.pem,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:ssl.certificate.location=keys/clt-kafka-client.pem,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:ssl.key.location=keys/clt-kafka-client.key,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:ssl.key.location=keys/clt-kafka-client.key,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:ssl.key.password=test1234,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:ssl.key.password=test1234,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:security.protocol=SASL_SSL,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:security.protocol=SASL_SSL,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:sasl.kerberos.service.name=kafka,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:sasl.kerberos.service.name=kafka,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:sasl.kerberos.keytab=/etc/security/keytabs/client2.keytab,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:sasl.kerberos.keytab=/etc/security/keytabs/client2.keytab,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:sasl.kerberos.principal=client2/kafkaclient,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:sasl.kerberos.principal=client2/kafkaclient,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:debug=broker,security,protocol,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:debug=broker,security,protocol,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting topic config:log_level=7,res: -2
2018-11-25 23:29:18 INFO - DCKafkaWrapper::setKafkaConfig: setting config:log_level=7,res: 0
2018-11-25 23:29:18 INFO - DCKafkaWrapper::installKafkaCallbacks: with configuration-dr_cb;event_cb;partitioner_cb
2018-11-25 23:29:18 INFO - DCKafkaWrapper::installKafkaCallbacks: call back installed for dr_cb.
2018-11-25 23:29:18 INFO - DCKafkaWrapper::installKafkaCallbacks: call back installed for event_cb.
2018-11-25 23:29:18 INFO - DCKafkaWrapper::installKafkaCallbacks: call back installed for partitioner_cb.
2018-11-25 23:29:18 INFO - DCKafkaWrapper::initialize: brockers is set: kafkaserver:8092
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SASL Description:[thrd:app]: Selected provider Cyrus for SASL mechanism GSSAPI
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:OPENSSL Description:[thrd:app]: librdkafka built with OpenSSL version 0x1000207f
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SSL Description:[thrd:app]: Loading CA certificate(s) from file keys/ca-cert
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SSL Description:[thrd:app]: Loading certificate from file keys/clt-kafka-client.pem
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SSL Description:[thrd:app]: Loading private key file from keys/clt-kafka-client.key
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SSLPASSWD Description:[thrd:app]: Private key file "keys/clt-kafka-client.key" requires password
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:BRKMAIN Description:[thrd::0/internal]: :0/internal: Enter main broker thread
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:STATE Description:[thrd::0/internal]: :0/internal: Broker changed state INIT -> UP
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:BROKER Description:[thrd:app]: sasl_ssl://kafkaserver:8092/bootstrap: Added new broker with NodeId -1
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:INIT Description:[thrd:app]: librdkafka v0.11.6 (0xb06ff) rdkafka#producer-1 initialized (builtin.features 0xffff, debug 0x282)
2018-11-25 23:29:18 INFO - DCKafkaWrapper::initialize: Creating Producer OK
2018-11-25 23:29:18 INFO - DCKafkaWrapper::initialize: Creating Topic OK
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:BRKMAIN Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Enter main broker thread
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:CONNECT Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: broker in state INIT connecting
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:CONNECT Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Connecting to ipv4#127.0.0.1:8092 (sasl_ssl) with socket 8
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:STATE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker changed state INIT -> CONNECT
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:CONNECT Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Connected to ipv4#127.0.0.1:8092
2018-11-25 23:29:18 ERROR - CSVLoader::ParseFirstLine Server conf error
2018-11-25 23:29:18 INFO - initialize: ok
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SSLVERIFY Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker SSL certificate verified
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:CONNECTED Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Connected (#1)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:FEATURE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Updated enabled protocol features +ApiVersion to ApiVersion
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:STATE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker changed state CONNECT -> APIVERSION_QUERY
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SEND Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Sent ApiVersionRequest (v0, 25 bytes @ 0, CorrId 1)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:RECV Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Received ApiVersionResponse (v0, 264 bytes, CorrId 1, rtt 0.27ms)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:FEATURE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Updated enabled protocol features to MsgVer1,ApiVersion,BrokerBalancedConsumer,ThrottleTime,Sasl,SaslHandshake,BrokerGroupCoordinator,LZ4,OffsetTime,MsgVer2
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:AUTH Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Auth in state APIVERSION_QUERY (handshake supported)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:STATE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker changed state APIVERSION_QUERY -> AUTH_HANDSHAKE
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SEND Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Sent SaslHandshakeRequest (v0, 29 bytes @ 0, CorrId 2)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:RECV Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Received SaslHandshakeResponse (v0, 14 bytes, CorrId 2, rtt 0.70ms)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SASLMECHS Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker supported SASL mechanisms: GSSAPI
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:AUTH Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Auth in state AUTH_HANDSHAKE (handshake supported)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:STATE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker changed state AUTH_HANDSHAKE -> AUTH
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SASL Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Initializing SASL client: service name kafka, hostname kafkaserver, mechanisms GSSAPI, provider Cyrus
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SASLREFRESH Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Refreshing SASL keys with command: kinit -S "kafka/kafkaserver" -k -t "/etc/security/keytabs/client2.keytab" client2/kafkaclient
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SASLREFRESH Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: SASL key refreshed
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SASL Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: My supported SASL mechanisms: SCRAM-SHA-1 GS2-IAKERB GS2-KRB5 GSS-SPNEGO GSSAPI DIGEST-MD5 EXTERNAL NTLM CRAM-MD5 PLAIN LOGIN ANONYMOUS
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:2 fac:LIBSASL Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Matching credential not found)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:BROKERFAIL Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: failed: err: Local: Authentication failure: (errno: Invalid argument)
2018-11-25 23:29:18 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:STATE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker changed state AUTH -> DOWN
2018-11-25 23:29:18 INFO - start: ok
2018-11-25 23:29:18 INFO - PluginManager::startup done
2018-11-25 23:29:19 DEBUG - DCKafkaWrapper::produce: ...

2018-11-25 23:29:19 DEBUG - DCKafkaWrapper::produce: % Produced message (118 bytes)
2018-11-25 23:29:19 ERROR - DCKafkaClientEventCallback::event_cb , Error: Local: Authentication failure): sasl_ssl://kafkaserver:8092/bootstrap: Failed to initialize SASL authentication: SASL handshake failed (start (-1)): SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Matching credential not found) (after 82ms in state AUTH)
2018-11-25 23:29:19 ERROR - DCKafkaClientEventCallback::event_cb , Error: Local: All broker connections are down): 1/1 brokers are down
2018-11-25 23:29:19 INFO - DCKafkaProducerThread::run, one batch of message is sent to remote server NumofRec:0
2018-11-25 23:29:19 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:CONNECT Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: broker in state DOWN connecting
2018-11-25 23:29:19 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:CONNECT Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Connecting to ipv4#127.0.0.1:8092 (sasl_ssl) with socket 8
2018-11-25 23:29:19 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:STATE Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker changed state DOWN -> CONNECT
2018-11-25 23:29:19 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:CONNECT Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Connected to ipv4#127.0.0.1:8092
2018-11-25 23:29:19 DEBUG - DCKafkaClientEventCallback::event_cb , Event Log: Severity:7 fac:SSLVERIFY Description:[thrd:sasl_ssl://kafkaserver:8092/bootstrap]: sasl_ssl://kafkaserver:8092/bootstrap: Broker SSL certificate verified

Checklist

IMPORTANT: We will close issues where the checklist has not been completed.

Please provide the following information:

  • librdkafka version (release number or git tag): librdkafka-0.11.6
  • Apache Kafka version: kafka_2.11-2.0.0
  • librdkafka client configuration: `request.required.acks=1; batch.num.messages=50; queue.buffering.max.ms=100; message.send.max.retries=3; ssl.ca.location=keys/ca-cert; ssl.certificate.location=keys/clt-kafka-client.pem; ssl.key.location=keys/clt-kafka-client.key; ssl.key.password=test1234; security.protocol=SASL_SSL; sasl.kerberos.service.name=kafka; sasl.kerberos.keytab=/etc/security/keytabs/client2.keytab; sasl.kerberos.principal=client2/kafkaclient; debug=broker,security,protocol; log_level=7
  • Operating system: Ubuntu 16.04
  • Provide logs (with `debug=broker,security,protocol ) from librdkafka
  • Provide broker log excerpts: No excepition
  • Critical issue
@edenhill
Copy link
Contributor

ping @rnpridgeon

@Jasper2015
Copy link
Author

Found the reason finally. It is because problem in my host file (I was doing the test on a single computer without DNS). However, the libsasl2 (or kerberos) was trying to retrieve the service side principal by reverse dns look up (in my case, it is look up machine name for 127.0.0.1, even though broker name was defined as kafkaserver[with ip 127.0.0.1] ). The first name in the hosts file for 127.0.0.1 matters a lot here.

I have fixed this issue by modifying /etc/hosts file
Here is my updated host file: 127.0.0.1 kafkaserver KAFKASERVER kafkaclient KAFKACLIENT localhost
Before the update, it was like this: 127.0.0.1 localhost afkaserver KAFKASERVER kafkaclient KAFKACLIENT

I think we can close this issue now. Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants