search

trinodb / trino

Official repository of Trino, the distributed SQL query engine for big data, formerly known as PrestoSQL (https://trino.io)
https://trino.io
Apache License 2.0
10.42k stars 3k forks source link

Cannot access Kudu tables due to expire of Kerberos TGTs #14372

Open xiacongling opened 2 years ago

xiacongling commented 2 years ago

Hi, community. We recently encounter a problem that Trino (386) cannot list and query tables in a Kerberized Kudu cluster. The error message is:

org.apache.kudu.client.NonRecoverableException: server requires authentication, but client Kerberos credentials (TGT) have expired. Authentication tokens were not used because no token is available, org.apache.kudu.client.NonRecoverableException: server requires authentication, but client Kerberos credentials (TGT) have expired. Authentication tokens were not used because no token is available

Our Trino cluster works well when it is newly started, and a few days later, some of the workers and/or the coordinator start to raise such exceptions. A server restart can temporarily fix the problem and fails still occur days after. We configure the lifetime of Kerberos ticket to be 1 day. That is to say, after a few times of ticket refreshment, the authentication mechanism will fail.

I use the production test environment multinode-kerberos-kudu to re-produce the error, using the following steps:

  1. start a kerberized kudu cluster and trino cluster by testing/bin/ptl env up --environment multinode-kerberos-kudu --debug
  2. wait for more than 1 minute (the lifetime of ticket is set to 1 minute)
  3. make a query to the kudu catalog, like show tables from kudu.default;

If you are lucky enough (it cannot be re-produced every time, I will explain later), you will see similar error messages.

The exception stack is as follows: 

"type": "org.apache.kudu.client.KuduException.OriginalException",
"message": "Original asynchronous stack trace",
"suppressed": [],
"stack": [
    "org.apache.kudu.client.ConnectToCluster.incrementCountAndCheckExhausted(ConnectToCluster.java:268)",
    "org.apache.kudu.client.ConnectToCluster.access$100(ConnectToCluster.java:51)",
    "org.apache.kudu.client.ConnectToCluster$ConnectToMasterErrCB.call(ConnectToCluster.java:387)",
    "org.apache.kudu.client.ConnectToCluster$ConnectToMasterErrCB.call(ConnectToCluster.java:376)",
    "com.stumbleupon.async.Deferred.doCall(Deferred.java:1280)",
    "com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259)",
    "com.stumbleupon.async.Deferred.handleContinuation(Deferred.java:1315)",
    "com.stumbleupon.async.Deferred.doCall(Deferred.java:1286)",
    "com.stumbleupon.async.Deferred.runCallbacks(Deferred.java:1259)",
    "com.stumbleupon.async.Deferred.callback(Deferred.java:1002)",
    "org.apache.kudu.client.KuduRpc.handleCallback(KuduRpc.java:276)",
    "org.apache.kudu.client.KuduRpc.errback(KuduRpc.java:330)",
    "org.apache.kudu.client.RpcProxy.responseReceived(RpcProxy.java:255)",
    "org.apache.kudu.client.RpcProxy.access$000(RpcProxy.java:63)",
    "org.apache.kudu.client.RpcProxy$1.call(RpcProxy.java:157)",
    "org.apache.kudu.client.RpcProxy$1.call(RpcProxy.java:153)",
    "org.apache.kudu.client.Connection.cleanup(Connection.java:727)",
    "org.apache.kudu.client.Connection.exceptionCaught(Connection.java:445)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:302)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:281)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:273)",
    "org.apache.kudu.shaded.io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:143)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:302)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:381)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)",
    "org.apache.kudu.shaded.io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)",
    "org.apache.kudu.shaded.io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)",
    "org.apache.kudu.shaded.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)",
    "org.apache.kudu.shaded.io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)",
    "org.apache.kudu.shaded.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)",
    "org.apache.kudu.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)",
    "org.apache.kudu.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)",
    "org.apache.kudu.shaded.io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)",
    "org.apache.kudu.shaded.io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)",
    "org.apache.kudu.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)",
    "org.apache.kudu.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)",
    "org.apache.kudu.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)",
    "org.apache.kudu.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)",
    "org.apache.kudu.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)",
    "org.apache.kudu.shaded.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)",
    "java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)",
    "java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)",
    "java.base/java.lang.Thread.run(Thread.java:829)"
],

The error occurs when KuduClient starts connecting to Kudu tserver. Kudu connection negotiator will check ticket expiration via the following code:

Subject s = securityContext.getSubject();
// ...
if (SecurityUtil.isTgtExpired(s)) {
  errorsByMech.put(clientMech.name(), "client Kerberos credentials (TGT) have expired");
  continue;
}

and an error will be raised later from the negotiation. It is inferred that TGT is expired when connection being made. But, we have a delegated KuduClient in io.trino.plugin.kudu.KerberizedKuduClient and before we get the client instance, Trino will check and refresh the ticket via: 

// io.trino.plugin.kudu.KerberizedKuduClient
protected KuduClient delegate()
{
    cachingKerberosAuthentication.reauthenticateIfSoonWillBeExpired();
    return kuduClient;
}

After step into the code, I find that the Subject's credentials are not well managed by Trino. The reauthentication code is:

// io.trino.plugin.base.authentication.CachingKerberosAuthentication:L48-L56
public synchronized void reauthenticateIfSoonWillBeExpired()
{
    if (ticketNeedsRefresh()) {
        kerberosAuthentication.attemptLogin(subject);        // create a new LoginContext and invoke its login method
        KerberosTicket tgtTicket = getTicketGrantingTicket(subject);      // get the first TGT from subject.privateCredentials
        nextRefreshTime = KerberosTicketUtils.getRefreshTime(tgtTicket);   // calculated by tickets startTime and endTime
    }
}

The problem is the first TGT from subject.privateCredentials is not always the newest one! Look at the implementation of getTicketGrantingTicket():

public static KerberosTicket getTicketGrantingTicket(Subject subject)
{
    Set<KerberosTicket> tickets = subject.getPrivateCredentials(KerberosTicket.class);  // the underlying collection is a HashSet!
    for (KerberosTicket ticket : tickets) {
        if (isOriginalTicketGrantingTicket(ticket)) {
            return ticket;
        }
    }
    throw new IllegalArgumentException("kerberos ticket not found in " + subject);
}

The HashSet's iteration is unpredictable, so the re-production above is unstable. The mechanism will lead to the following problems:

  1. Ticket expiration detection in Kudu client follow the similar way, it may get an old ticket and reject to connect (as the problem described above);
  2. The nextRefreshTime calculated with ticket startTime and endTime will be an time point in the past, thus, Trino will reauthenticate again for the next query;
  3. There will be a lot of tickets stored in the subject (tickets are not removed from subject.privateCredentials), and situation may become worse and worse - it is harder and harder for a new ticket to locate in the first place of a HashSet's iterator, and more and more reauthentication will be send to KDC.
grantatspothero commented 1 year ago

Thanks for detailed writeup 🙌

findepi commented 1 year ago

https://github.com/trinodb/trino/issues/14441 merged, but we believe there needs to be more work, see https://github.com/trinodb/trino/pull/15997 & https://github.com/trinodb/trino/pull/14373#issuecomment-1422394658