Kerberos: Receive new ticket

[pronvis]

I am looking at DataWriter.ticketRenewThread and looks like it will fail after 1 week of continuable work. 1 weak is the maximum period for kerberos ticket to be Renewed.
Is it possible to fix this issue? (Or is this issue even exists?)
My hdfs-worker should work for a long period of time and I don't want to STOP/START workers every week :)

[bharatviswa504]

Hi,
In HDFS Connector already this code is there to handle this.
if(isRunning) reloginFromKeytab(). So, HDFS Connector handle automatic renewal.
ticketRenewThread = new Thread(new Runnable() {
@OverRide
public void run() {
synchronized (DataWriter.this) {
while (isRunning) {
try {
DataWriter.this.wait(renewPeriod);
if (isRunning) {
ugi.reloginFromKeytab();
}
} catch (IOException e) {
// We ignore this exception during relogin as each successful relogin gives
// additional 24 hours of authentication in the default config. In normal
// situations, the probability of failing relogin 24 times is low and if
// that happens, the task will fail eventually.
log.error("Error renewing the ticket", e);
} catch (InterruptedException e) {
// ignored
}
}
}
}
});
log.info("Starting the Kerberos ticket renew thread with period {}ms.", renewPeriod);
ticketRenewThread.start();
}

[pronvis]

Ye, I saw this code, but didn't find that it will open new Ticket after "possible renew period" for previous one will expire.
Looks like this code do what I need:
UserGroupInformation.spawnAutoRenewalThreadForUserCreds

[cotedm]

Yes, this is handled by the code @bharatviswa504 mentioned. Do you have a specific test case where you see this happen @invis87 or are you doing this from purely code inspection?

[pronvis]

@cotedm It is quite hard to test - workers should work for a week. But tomorrow I will create small hadoop cluster with special configuration for a "possible renew period" and will test hdfs-connector on it.

[pronvis]

So, finally KK stops receive new tickets:

[2017-03-20 07:46:12,830] DEBUG Use KERBEROS authentication for protocol ClientNamenodeProtocolPB (org.apache.hadoop.security.SaslRpcClient:176)
[2017-03-20 07:46:12,831] DEBUG PrivilegedActionException as:{{{login@realm}}} (auth:KERBEROS) cause:javax.security.sasl.SaslException: GSS initiate failed
[Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] (org.apache.hadoop.security.UserGroupInformation:1632)
[2017-03-20 07:46:12,831] DEBUG PrivilegedAction as:{{{login@realm}}} (auth:KERBEROS) from:org.apache.hadoop.ipc.Client$Connection.handleSaslConnectionFailure(Client.java:643) (org.apache.hadoop.security.UserGroupInformation:1652)
[2017-03-20 07:46:12,831] DEBUG Exception encountered while connecting to the server : javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] (org.apache.hadoop.ipc.Client:652)
[2017-03-20 07:46:12,831] WARN Not attempting to re-login since the last re-login was attempted less than 600 seconds before. (org.apache.hadoop.security.UserGroupInformation:1127)
[2017-03-20 07:46:13,502] DEBUG Received successful heartbeat response for group connector-test (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:652)
[2017-03-20 07:46:14,418] DEBUG PrivilegedAction as:{{{login@realm}}} (auth:KERBEROS) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:717) (org.apache.hadoop.security.UserGroupInformation:1652)
[2017-03-20 07:46:14,418] DEBUG Sending sasl message state: NEGOTIATE (org.apache.hadoop.security.SaslRpcClient:457)
[2017-03-20 07:46:14,418] DEBUG Received SASL message state: NEGOTIATE
auths {
  method: "TOKEN"
  mechanism: "DIGEST-MD5"
  protocol: ""
  serverId: "default"
  challenge: "realm=\"default\",nonce=\"{{{some_hash}}}\",qop=\"auth\",charset=utf-8,algorithm=md5-sess"
}
auths {
  method: "KERBEROS"
  mechanism: "GSSAPI"
  protocol: "hdfs"
  serverId: "{{{server_id}}}"
}
(org.apache.hadoop.security.SaslRpcClient:389)
[2017-03-20 07:46:14,418] DEBUG Get token info proto:interface org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolPB info:@org.apache.hadoop.security.token.TokenInfo(value=class org.apache.hadoop.hdfs.security.token.delegation.DelegationTokenSelector) (org.apache.hadoop.security.SaslRpcClient:264)
[2017-03-20 07:46:14,418] DEBUG Get kerberos info proto:interface org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolPB info:@org.apache.hadoop.security.KerberosInfo(clientPrincipal=, serverPrincipal=dfs.namenode.kerberos.principal) (org.apache.hadoop.security.SaslRpcClient:291)
[2017-03-20 07:46:14,419] DEBUG getting serverKey: dfs.namenode.kerberos.principal conf value: hdfs/_HOST@{{{realm}}} principal: hdfs/{{{hostname}}}@{{{realm}}} (org.apache.hadoop.security.SaslRpcClient:318)
[2017-03-20 07:46:14,419] DEBUG RPC Server's Kerberos principal name for protocol=org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolPB is hdfs/{{{hostname}}}@{{{realm}}} (org.apache.hadoop.security.SaslRpcClient:236)
[2017-03-20 07:46:14,419] DEBUG Creating SASL GSSAPI(KERBEROS)  client to authenticate to service at {{{hostname}}} (org.apache.hadoop.security.SaslRpcClient:247)
[2017-03-20 07:46:14,419] DEBUG Use KERBEROS authentication for protocol ClientNamenodeProtocolPB (org.apache.hadoop.security.SaslRpcClient:176)
[2017-03-20 07:46:14,419] DEBUG PrivilegedActionException as:{{{login@realm}}} (auth:KERBEROS) cause:javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] (org.apache.hadoop.security.UserGroupInformation:1632)
[2017-03-20 07:46:14,420] WARN Not attempting to re-login since the last re-login was attempted less than 600 seconds before. (org.apache.hadoop.security.UserGroupInformation:1127)

Also there is Exception in logs:

[2017-03-20 08:05:01,161] INFO Exception while invoking getFileInfo of class ClientNamenodeProtocolTranslatorPB over {{{hadoop_host}}}/192.168.100.23
5:8020 after 10 fail over attempts. Trying to fail over immediately. (org.apache.hadoop.io.retry.RetryInvocationHandler:140)
java.io.IOException: Failed on local exception: java.io.IOException: Couldn't setup connection for {{{login@realm}}} to cepng-hadoop-test-3.infr.sel-vpc.one
factor.com/192.168.100.235:8020; Host Details : local host is: "{{{my_host}}}/192.168.100.205"; destination host is: "{{{hadoop_host}}}":8020;
        at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:772)
        at org.apache.hadoop.ipc.Client.call(Client.java:1472)
        at org.apache.hadoop.ipc.Client.call(Client.java:1399)
        at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:232)
        at com.sun.proxy.$Proxy49.getFileInfo(Unknown Source)
        at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getFileInfo(ClientNamenodeProtocolTranslatorPB.java:752)
        at sun.reflect.GeneratedMethodAccessor14.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:187)
        at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:102)
        at com.sun.proxy.$Proxy50.getFileInfo(Unknown Source)
        at org.apache.hadoop.hdfs.DFSClient.getFileInfo(DFSClient.java:1988)
        at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:1118)
        at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:1114)
        at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)
        at org.apache.hadoop.hdfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:1114)
        at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:1400)
        at io.confluent.connect.hdfs.storage.HdfsStorage.exists(HdfsStorage.java:66)
        at io.confluent.connect.hdfs.wal.FSWAL.apply(FSWAL.java:102)
        at io.confluent.connect.hdfs.TopicPartitionWriter.applyWAL(TopicPartitionWriter.java:441)
        at io.confluent.connect.hdfs.TopicPartitionWriter.recover(TopicPartitionWriter.java:197)
        at io.confluent.connect.hdfs.TopicPartitionWriter.write(TopicPartitionWriter.java:227)
        at io.confluent.connect.hdfs.DataWriter.write(DataWriter.java:234)
        at io.confluent.connect.hdfs.HdfsSinkTask.put(HdfsSinkTask.java:91)
        at org.apache.kafka.connect.runtime.WorkerSinkTask.deliverMessages(WorkerSinkTask.java:381)
        at org.apache.kafka.connect.runtime.WorkerSinkTask.poll(WorkerSinkTask.java:227)
        at org.apache.kafka.connect.runtime.WorkerSinkTask.iteration(WorkerSinkTask.java:170)
        at org.apache.kafka.connect.runtime.WorkerSinkTask.execute(WorkerSinkTask.java:142)
        at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:140)
        at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:175)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
        Caused by: java.io.IOException: Couldn't setup connection for {{{login@realm}}} to {{{hadoop_host}}}/192.168.100.235:8020
        at org.apache.hadoop.ipc.Client$Connection$1.run(Client.java:672)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:422)
        at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1628)
        at org.apache.hadoop.ipc.Client$Connection.handleSaslConnectionFailure(Client.java:643)
        at org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:730)
        at org.apache.hadoop.ipc.Client$Connection.access$2800(Client.java:368)
        at org.apache.hadoop.ipc.Client.getConnection(Client.java:1521)
        at org.apache.hadoop.ipc.Client.call(Client.java:1438)
        ... 34 more
Caused by: javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)]
        at com.sun.security.sasl.gsskerb.GssKrb5Client.evaluateChallenge(GssKrb5Client.java:211)
        at org.apache.hadoop.security.SaslRpcClient.saslConnect(SaslRpcClient.java:413)
        at org.apache.hadoop.ipc.Client$Connection.setupSaslConnection(Client.java:553)
        at org.apache.hadoop.ipc.Client$Connection.access$1800(Client.java:368)
        at org.apache.hadoop.ipc.Client$Connection$2.run(Client.java:722)
        at org.apache.hadoop.ipc.Client$Connection$2.run(Client.java:718)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:422)
        at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1628)
        at org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:717)
        ... 37 more
Caused by: GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)
        at sun.security.jgss.krb5.Krb5InitCredential.getInstance(Krb5InitCredential.java:147)
        at sun.security.jgss.krb5.Krb5MechFactory.getCredentialElement(Krb5MechFactory.java:122)
        at sun.security.jgss.krb5.Krb5MechFactory.getMechanismContext(Krb5MechFactory.java:187)
        at sun.security.jgss.GSSManagerImpl.getMechanismContext(GSSManagerImpl.java:224)
        at sun.security.jgss.GSSContextImpl.initSecContext(GSSContextImpl.java:212)
        at sun.security.jgss.GSSContextImpl.initSecContext(GSSContextImpl.java:179)
        at com.sun.security.sasl.gsskerb.GssKrb5Client.evaluateChallenge(GssKrb5Client.java:192)
        ... 46 more

[pronvis]

@cotedm Hi, any ideas how to deal with that exception?

[cotedm]

@invis87 I'm not an HDFS client expert but my thought is that you are using the credential cache instead of a keytab here? Can you confirm? I believe you need to use a keytab for the relogin to work properly.

[pronvis]

@cotedm I am not pro in HDFS too, but klist command tells that there is no cache file (and I remember it was the same when KC worker worked).
Here is part of Worker config:

{
  "connect.hdfs.keytab": "${path}/${username}.keytab",
  "connect.hdfs.principal": "${username}@${realm}",
  "connector.class": "io.confluent.connect.hdfs.HdfsSinkConnector",
  "flush.size": "50000",
  "format.class": "io.confluent.connect.hdfs.avro.AvroFormat",
  "hadoop.conf.dir": "${path}/hadoop-conf",
  "hdfs.authentication.kerberos": "true",
  "hdfs.namenode.principal": "hdfs@${realm}",
  "hdfs.url": "hdfs://nameservice1",
  "kerberos.ticket.renew.period.ms": "3600000",
  "locale": "en",
  "logs.dir": "${path-to-logs-dir}",
  "name": "from-kafka-to-hdfs",
  "rotate.interval.ms": "3600000",
  "schema.compatibility": "BACKWARD",
  "tasks.max": "3",
  "timezone": "Europe/Moscow",
  "topics": "${topic}",
  "topics.dir": "${path-to-topics-dir}",
  ...
}

[pronvis]

@bharatviswa504 You wrote:

In HDFS Connector already this code is there to handle this.
if(isRunning) reloginFromKeytab(). So, HDFS Connector handle automatic renewal.

Yep, we have that method, but it fails :( Here is the log:

[2017-03-21 11:28:51,565] DEBUG Initiating logout for ${username}@${realm} (org.apache.hadoop.security.UserGroupInformation:1054)
[2017-03-21 11:28:51,565] DEBUG hadoop logout (org.apache.hadoop.security.UserGroupInformation:217)
[2017-03-21 11:28:51,566] DEBUG Initiating re-login for ${username}@${realm} (org.apache.hadoop.security.UserGroupInformation:1066)
[2017-03-21 11:28:51,569] DEBUG hadoop login (org.apache.hadoop.security.UserGroupInformation:209)
[2017-03-21 11:28:51,569] DEBUG hadoop login commit (org.apache.hadoop.security.UserGroupInformation:144)
[2017-03-21 11:28:51,569] DEBUG using existing subject:[${username}@${realm}, UnixPrincipal: root, UnixNumericUserPrincipal: 0, UnixNumericGroupPrincipal [Primary Group]: 0] (org.apache.hadoop.security.UserGroupInformation:149)
[2017-03-21 11:28:51,779] DEBUG PrivilegedAction as:${username}@${realm} (auth:KERBEROS) from:org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:717) (org.apache.hadoop.security.UserGroupInformation:1652)
[2017-03-21 11:28:51,779] DEBUG Sending sasl message state: NEGOTIATE
 (org.apache.hadoop.security.SaslRpcClient:457)
[2017-03-21 11:28:51,779] DEBUG Received SASL message state: NEGOTIATE
auths {
  method: "TOKEN"
  mechanism: "DIGEST-MD5"
  protocol: ""
  serverId: "default"
  challenge: "realm=\"default\",nonce=\"${some-hash}/eOTgl\",qop=\"auth\",charset=utf-8,algorithm=md5-sess"
}
auths {
  method: "KERBEROS"
  mechanism: "GSSAPI"
  protocol: "hdfs"
  serverId: "${host}.${realm}"
}
 (org.apache.hadoop.security.SaslRpcClient:389)
[2017-03-21 11:28:51,779] DEBUG Get token info proto:interface org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolPB info:@org.apache.hadoop.security.token.TokenInfo(value=class org.apache.hadoop.hdfs.security.token.delegation.DelegationTokenSelector) (org.apache.hadoop.security.SaslRpcClient:264)
[2017-03-21 11:28:51,780] DEBUG Get kerberos info proto:interface org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolPB info:@org.apache.hadoop.security.KerberosInfo(clientPrincipal=, serverPrincipal=dfs.namenode.kerberos.principal) (org.apache.hadoop.security.SaslRpcClient:291)
[2017-03-21 11:28:51,780] DEBUG getting serverKey: dfs.namenode.kerberos.principal conf value: hdfs/_HOST@${realm} principal: hdfs/${host}.${realm}@${realm} (org.apache.hadoop.security.SaslRpcClient:318)
[2017-03-21 11:28:51,780] DEBUG RPC Server's Kerberos principal name for protocol=org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolPB is hdfs/${host}.${realm}@${realm} (org.apache.hadoop.security.SaslRpcClient:236)
[2017-03-21 11:28:51,780] DEBUG Creating SASL GSSAPI(KERBEROS)  client to authenticate to service at ${host}.${realm} (org.apache.hadoop.security.SaslRpcClient:247)
[2017-03-21 11:28:51,780] DEBUG Use KERBEROS authentication for protocol ClientNamenodeProtocolPB (org.apache.hadoop.security.SaslRpcClient:176)
[2017-03-21 11:28:51,780] DEBUG PrivilegedActionException as:${username}@${realm} (auth:KERBEROS) cause:javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] (org.apache.hadoop.security.UserGroupInformation:1632)
[2017-03-21 11:28:51,780] DEBUG PrivilegedAction as:${username}@${realm} (auth:KERBEROS) from:org.apache.hadoop.ipc.Client$Connection.handleSaslConnectionFailure(Client.java:643) (org.apache.hadoop.security.UserGroupInformation:1652)
[2017-03-21 11:28:51,781] DEBUG Exception encountered while connecting to the server : javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] (org.apache.hadoop.ipc.Client:652)

P.S. we use version 3.0.1

[pronvis]

Looks like this is the same issue as:
#52
https://groups.google.com/forum/#!topic/confluent-platform/twFcx3H689U

[ysgadi]

i have to run kinit command on kafka connect host before start connector hdfs ?

[pronvis]

i have to run kinit command on kafka connect host before start connector hdfs ?

As far as I remember - nope, you haven't. Kafka connect tooks all ticket related work.

[ysgadi]

i have this error when i start kafka connector:
java.io.IOException: Failed on local exception: java.io.IOException: javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Fail to create credential. (63) - No service creds)];