MLikeWater opened a new issue, #2855: URL: https://github.com/apache/incubator-kyuubi/issues/2855
### Code of Conduct - [X] I agree to follow this project's [Code of Conduct](https://www.apache.org/foundation/policies/conduct) ### Search before asking - [X] I have searched in the [issues](https://github.com/apache/incubator-kyuubi/issues?q=is%3Aissue) and found no similar issues. ### Describe the bug # Environment - apache-kyuubi-1.6.0-SNAPSHOT-bin-spark-3.2 on K8s - Hive metastore 3.1.2 on K8s # Problem description The following error occurs when using beeline to access the Kyuubi Server: ``` $ ./bin/beeline -u jdbc:hive2://10.2.1.5:10011 -n meimei -pxxxx Connecting to jdbc:hive2://10.2.1.5:10011 19:41:44.223 INFO org.apache.kyuubi.operation.LaunchEngine: Processing meimei's query[7fa8917b-ae8d-4e99-a370-4e764bb87e77]: INITIALIZED_STATE -> PENDING_STATE, statement: LAUNCH_ENGINE 19:41:44.224 INFO org.apache.kyuubi.operation.LaunchEngine: Processing meimei's query[7fa8917b-ae8d-4e99-a370-4e764bb87e77]: PENDING_STATE -> RUNNING_STATE, statement: LAUNCH_ENGINE 19:41:44.226 INFO org.apache.curator.framework.imps.CuratorFrameworkImpl: Starting 19:41:44.226 DEBUG org.apache.curator.CuratorZookeeperClient: Starting 19:41:44.226 DEBUG org.apache.curator.ConnectionState: Starting 19:41:44.226 DEBUG org.apache.curator.ConnectionState: reset 19:41:44.226 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=zookeeper-client.zookeeper.svc sessionTimeout=600000 watcher=org.apache.curator.ConnectionState@4b974c8f 19:41:44.231 DEBUG org.apache.zookeeper.SaslServerPrincipal: Canonicalized address to zookeeper-client.zookeeper.svc.cluster.local 19:41:44.231 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server zookeeper-client.zookeeper.svc/10.43.179.76:2181. Will not attempt to authenticate using SASL (unknown error) 19:41:44.231 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to zookeeper-client.zookeeper.svc/10.43.179.76:2181, initiating session 19:41:44.231 DEBUG org.apache.zookeeper.ClientCnxn: Session establishment request sent on zookeeper-client.zookeeper.svc/10.43.179.76:2181 19:41:44.235 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server zookeeper-client.zookeeper.svc/10.43.179.76:2181, sessionid = 0x301e9d892de0002, negotiated timeout = 40000 19:41:44.235 INFO org.apache.curator.framework.state.ConnectionStateManager: State change: CONNECTED 19:41:44.238 DEBUG org.apache.zookeeper.ClientCnxn: Reading reply sessionid:0x301e9d892de0002, packet:: clientPath:null serverPath:null finished:false header:: 1,12 replyHeader:: 1,4294967370,0 request:: '/kyuubi_1.6.0-SNAPSHOT_USER_SPARK_SQL/meimei/default,F response:: v{'serviceUri=xxxxxx:41710;version=1.6.0-SNAPSHOT;refId=ea154ab7-6620-42be-8bff-0c62c45ca428;sequence=0000000000},s{4294967361,4294967361,1654860162507,1654860162507,0,1,0,0,8,1,4294967362} 19:41:44.240 DEBUG org.apache.zookeeper.ClientCnxn: Reading reply sessionid:0x301e9d892de0002, packet:: clientPath:null serverPath:null finished:false header:: 2,4 replyHeader:: 2,4294967370,0 request:: '/kyuubi_1.6.0-SNAPSHOT_USER_SPARK_SQL/meimei/default/serviceUri=xxxxxx:41710;version=1.6.0-SNAPSHOT;refId=ea154ab7-6620-42be-8bff-0c62c45ca428;sequence=0000000000,F response:: #74672d6c6f63616c2d6264776f726b65722d322e74672e6d742e636f6d3a3431373130,s{4294967362,4294967362,1654860162517,1654860162517,0,0,0,72596181287501829,35,0,4294967362} 19:41:44.240 INFO org.apache.kyuubi.ha.client.zookeeper.ZookeeperDiscoveryClient: Get service instance:xxxxxxx:41710 and version:Some(1.6.0-SNAPSHOT) under /kyuubi_1.6.0-SNAPSHOT_USER_SPARK_SQL/meimei/default 19:41:44.241 DEBUG org.apache.thrift.transport.TSaslTransport: opening transport org.apache.thrift.transport.TSaslClientTransport@367d456b 19:41:44.243 DEBUG org.apache.thrift.transport.TSaslClientTransport: Sending mechanism name PLAIN and initial response of length 17 19:41:44.243 DEBUG org.apache.thrift.transport.TSaslTransport: CLIENT: Writing message with status START and payload length 5 19:41:44.243 DEBUG org.apache.thrift.transport.TSaslTransport: CLIENT: Writing message with status COMPLETE and payload length 17 19:41:44.243 DEBUG org.apache.thrift.transport.TSaslTransport: CLIENT: Start message handled 19:41:44.243 DEBUG org.apache.thrift.transport.TSaslTransport: CLIENT: Main negotiation loop complete 19:41:44.243 DEBUG org.apache.thrift.transport.TSaslTransport: CLIENT: SASL Client receiving last message 19:41:44.244 DEBUG org.apache.thrift.transport.TSaslTransport: CLIENT: Received message with status COMPLETE and payload length 0 19:41:44.244 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 192 19:41:44.257 DEBUG org.apache.thrift.transport.TSaslTransport: CLIENT: reading data length: 164 19:41:44.258 INFO org.apache.kyuubi.session.KyuubiSessionImpl: [meimei:10.2.1.6] SessionHandle [7dde4e6b-b7e8-44c1-a337-4cf52246c3d7] - Connected to engine [xxxxxx:41710] with SessionHandle [cd440cd3-e9fc-41f9-ad93-5002e699802a] 19:41:44.258 DEBUG org.apache.curator.framework.imps.CuratorFrameworkImpl: Closing 19:41:44.258 INFO org.apache.curator.framework.imps.CuratorFrameworkImpl: backgroundOperationsLoop exiting 19:41:44.258 DEBUG org.apache.curator.CuratorZookeeperClient: Closing 19:41:44.259 DEBUG org.apache.curator.ConnectionState: Closing 19:41:44.259 DEBUG org.apache.zookeeper.ZooKeeper: Closing session: 0x301e9d892de0002 19:41:44.259 DEBUG org.apache.zookeeper.ClientCnxn: Closing client for session: 0x301e9d892de0002 19:41:44.262 DEBUG org.apache.zookeeper.ClientCnxn: Reading reply sessionid:0x301e9d892de0002, packet:: clientPath:null serverPath:null finished:false header:: 3,-11 replyHeader:: 3,4294967371,0 request:: null response:: null 19:41:44.262 DEBUG org.apache.zookeeper.ClientCnxn: Disconnecting client for session: 0x301e9d892de0002 19:41:44.263 INFO org.apache.zookeeper.ZooKeeper: Session: 0x301e9d892de0002 closed 19:41:44.263 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down for session: 0x301e9d892de0002 19:42:44.263 ERROR org.apache.kyuubi.operation.LaunchEngine: Failed to renew engine credentials when launching engine org.apache.kyuubi.KyuubiException: Exception thrown in awaitResult: at org.apache.kyuubi.util.ThreadUtils$.awaitResult(ThreadUtils.scala:64) ~[kyuubi-common_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.CredentialsRef.$anonfun$waitUntilReady$1(CredentialsRef.scala:66) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.CredentialsRef.$anonfun$waitUntilReady$1$adapted(CredentialsRef.scala:66) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at scala.Option.foreach(Option.scala:407) ~[scala-library-2.12.15.jar:?] at org.apache.kyuubi.credentials.CredentialsRef.waitUntilReady(CredentialsRef.scala:66) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.HadoopCredentialsManager.getOrCreateUserCredentialsRef(HadoopCredentialsManager.scala:215) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.HadoopCredentialsManager.sendCredentialsIfNeeded(HadoopCredentialsManager.scala:170) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.operation.LaunchEngine.renewEngineCredentials(LaunchEngine.scala:71) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.operation.LaunchEngine.$anonfun$runInternal$1(LaunchEngine.scala:52) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_311] at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_311] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_311] Caused by: java.util.concurrent.TimeoutException: Futures timed out after [60000 milliseconds] at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:259) ~[scala-library-2.12.15.jar:?] at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:263) ~[scala-library-2.12.15.jar:?] at org.apache.kyuubi.util.ThreadUtils$.awaitResult(ThreadUtils.scala:61) ~[kyuubi-common_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] ... 13 more 19:42:44.263 INFO org.apache.kyuubi.operation.LaunchEngine: Processing meimei's query[7fa8917b-ae8d-4e99-a370-4e764bb87e77]: RUNNING_STATE -> FINISHED_STATE, statement: LAUNCH_ENGINE, time taken: 60.039 seconds Connected to: Apache Kyuubi (Incubating) (version 1.6.0-SNAPSHOT) Driver: Kyuubi Project Hive JDBC Client (version 1.6.0-SNAPSHOT) Beeline version 1.6.0-SNAPSHOT by Apache Kyuubi (Incubating) 0: jdbc:hive2://10.2.1.5:10011> ``` The query is normal.However, each access needs to wait more than 60 seconds. ### Affects Version(s) 1.6.0-SNAPSHOT(master compile) ### Kyuubi Server Log Output ```logtalk 19:26:51.869 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 95 19:26:51.869 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 100 19:26:51.869 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TGetOperationStatusReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false)) 19:26:55.639 DEBUG org.apache.thrift.transport.TSaslServerTransport: transport map does not contain key 19:26:55.639 DEBUG org.apache.thrift.transport.TSaslTransport: opening transport org.apache.thrift.transport.TSaslServerTransport@6e411656 19:26:55.640 DEBUG org.apache.thrift.transport.TSaslTransport: No data or no sasl data in the stream 19:26:55.640 DEBUG org.apache.thrift.transport.TSaslServerTransport: failed to open server transport org.apache.thrift.transport.TSaslTransportException: No data or no sasl data in the stream at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:328) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport.open(TSaslServerTransport.java:41) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:216) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:269) ~[libthrift-0.9.3.jar:0.9.3] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_311] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_311] 19:26:56.869 DEBUG org.apache.kyuubi.server.KyuubiServer: OperationHandle [type=UNKNOWN_OPERATION, identifier: 3c53a0f5-1e7b-408d-9736-5ab6ada8e25c]: Long polling timed out, null 19:26:56.870 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 79 19:26:56.870 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 117 19:26:56.870 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TFetchResultsReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false), orientation:FETCH_NEXT, maxRows:1000, fetchType:1) 19:26:56.870 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 95 19:26:56.871 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 100 19:26:56.871 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TGetOperationStatusReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false)) 19:27:00.026 DEBUG org.apache.thrift.transport.TSaslServerTransport: transport map does not contain key 19:27:00.026 DEBUG org.apache.thrift.transport.TSaslTransport: opening transport org.apache.thrift.transport.TSaslServerTransport@79d15b39 19:27:00.027 DEBUG org.apache.thrift.transport.TSaslTransport: No data or no sasl data in the stream 19:27:00.027 DEBUG org.apache.thrift.transport.TSaslServerTransport: failed to open server transport org.apache.thrift.transport.TSaslTransportException: No data or no sasl data in the stream at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:328) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport.open(TSaslServerTransport.java:41) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:216) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:269) ~[libthrift-0.9.3.jar:0.9.3] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_311] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_311] 19:27:00.827 DEBUG org.apache.zookeeper.ClientCnxn: Got ping response for sessionid: 0x20165086c3b0002 after 0ms 19:27:01.871 DEBUG org.apache.kyuubi.server.KyuubiServer: OperationHandle [type=UNKNOWN_OPERATION, identifier: 3c53a0f5-1e7b-408d-9736-5ab6ada8e25c]: Long polling timed out, null 19:27:01.871 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 79 19:27:01.872 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 117 19:27:01.872 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TFetchResultsReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false), orientation:FETCH_NEXT, maxRows:1000, fetchType:1) 19:27:01.872 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 95 19:27:01.873 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 100 19:27:01.873 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TGetOperationStatusReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false)) 19:27:05.639 DEBUG org.apache.thrift.transport.TSaslServerTransport: transport map does not contain key 19:27:05.639 DEBUG org.apache.thrift.transport.TSaslTransport: opening transport org.apache.thrift.transport.TSaslServerTransport@21454f61 19:27:05.640 DEBUG org.apache.thrift.transport.TSaslTransport: No data or no sasl data in the stream 19:27:05.640 DEBUG org.apache.thrift.transport.TSaslServerTransport: failed to open server transport org.apache.thrift.transport.TSaslTransportException: No data or no sasl data in the stream at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:328) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport.open(TSaslServerTransport.java:41) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:216) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:269) ~[libthrift-0.9.3.jar:0.9.3] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_311] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_311] 19:27:06.873 DEBUG org.apache.kyuubi.server.KyuubiServer: OperationHandle [type=UNKNOWN_OPERATION, identifier: 3c53a0f5-1e7b-408d-9736-5ab6ada8e25c]: Long polling timed out, null 19:27:06.873 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 79 19:27:06.874 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 117 19:27:06.874 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TFetchResultsReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false), orientation:FETCH_NEXT, maxRows:1000, fetchType:1) 19:27:06.874 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 95 19:27:06.874 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 100 19:27:06.874 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TGetOperationStatusReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false)) 19:27:10.026 DEBUG org.apache.thrift.transport.TSaslServerTransport: transport map does not contain key 19:27:10.026 DEBUG org.apache.thrift.transport.TSaslTransport: opening transport org.apache.thrift.transport.TSaslServerTransport@71152abe 19:27:10.027 DEBUG org.apache.thrift.transport.TSaslTransport: No data or no sasl data in the stream 19:27:10.027 DEBUG org.apache.thrift.transport.TSaslServerTransport: failed to open server transport org.apache.thrift.transport.TSaslTransportException: No data or no sasl data in the stream at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:328) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport.open(TSaslServerTransport.java:41) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:216) ~[libthrift-0.9.3.jar:0.9.3] at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:269) ~[libthrift-0.9.3.jar:0.9.3] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_311] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_311] 19:27:11.862 ERROR org.apache.kyuubi.operation.LaunchEngine: Failed to renew engine credentials when launching engine org.apache.kyuubi.KyuubiException: Exception thrown in awaitResult: at org.apache.kyuubi.util.ThreadUtils$.awaitResult(ThreadUtils.scala:64) ~[kyuubi-common_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.CredentialsRef.$anonfun$waitUntilReady$1(CredentialsRef.scala:66) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.CredentialsRef.$anonfun$waitUntilReady$1$adapted(CredentialsRef.scala:66) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at scala.Option.foreach(Option.scala:407) ~[scala-library-2.12.15.jar:?] at org.apache.kyuubi.credentials.CredentialsRef.waitUntilReady(CredentialsRef.scala:66) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.HadoopCredentialsManager.getOrCreateUserCredentialsRef(HadoopCredentialsManager.scala:215) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.credentials.HadoopCredentialsManager.sendCredentialsIfNeeded(HadoopCredentialsManager.scala:170) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.operation.LaunchEngine.renewEngineCredentials(LaunchEngine.scala:71) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at org.apache.kyuubi.operation.LaunchEngine.$anonfun$runInternal$1(LaunchEngine.scala:52) ~[kyuubi-server_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_311] at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_311] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_311] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_311] Caused by: java.util.concurrent.TimeoutException: Futures timed out after [60000 milliseconds] at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:259) ~[scala-library-2.12.15.jar:?] at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:263) ~[scala-library-2.12.15.jar:?] at org.apache.kyuubi.util.ThreadUtils$.awaitResult(ThreadUtils.scala:61) ~[kyuubi-common_2.12-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT] ... 13 more 19:27:11.862 INFO org.apache.kyuubi.operation.LaunchEngine: Processing meimei's query[3c53a0f5-1e7b-408d-9736-5ab6ada8e25c]: RUNNING_STATE -> FINISHED_STATE, statement: LAUNCH_ENGINE, time taken: 60.035 seconds 19:27:11.863 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 79 19:27:11.863 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 117 19:27:11.863 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TFetchResultsReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false), orientation:FETCH_NEXT, maxRows:1000, fetchType:1) 19:27:11.863 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 2749 19:27:11.865 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 117 19:27:11.865 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TFetchResultsReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:3C 53 A0 F5 1E 7B 40 8D 97 36 5A B6 AD A8 E2 5C, secret:69 9E 18 02 59 C0 41 6E AB 18 87 5C 56 D9 C9 66), operationType:UNKNOWN, hasResultSet:false), orientation:FETCH_NEXT, maxRows:1000, fetchType:1) 19:27:11.865 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 95 19:27:11.868 DEBUG org.apache.thrift.transport.TSaslTransport: SERVER: reading data length: 85 19:27:11.868 DEBUG org.apache.kyuubi.server.KyuubiTBinaryFrontendService: TGetInfoReq(sessionHandle:TSessionHandle(sessionId:THandleIdentifier(guid:1C 69 9A E3 78 39 4C 42 93 4A 4E A8 DB 25 5B 33, secret:05 04 EE 6E 40 E9 47 41 96 9F FD F9 47 17 AB 3E)), infoType:CLI_DBMS_NAME) 19:27:11.868 DEBUG org.apache.thrift.transport.TSaslTransport: writing data length: 72 ``` ### Kyuubi Engine Log Output ```logtalk 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:35 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: max needed for rpId: 0 numpending: 0, tasksperexecutor: 2 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: No change in number of executors 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Request to remove executorIds: (2,0), (5,0), (1,0), (4,0), (3,0) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 2 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 5 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 1 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 4 because there are only 5 executor(s) left (minimum number of executor limit 5) 22/06/10 19:55:36 DEBUG ExecutorAllocationManager: Not removing idle executor 3 because there are only 5 executor(s) left (minimum number of executor limit 5) ^C ``` ### Kyuubi Server Configurations ```yaml kyuubi.ha.enabled true kyuubi.ha.zookeeper.quorum zookeeper-client.zookeeper.svc kyuubi.ha.zookeeper.client.port 2181 kyuubi.ha.zookeeper.session.timeout 600000 kyuubi.frontend.bind.port 10011 # spark.hive.metastore.uris thrift://xxxx:9083 spark.hive.metastore.warehouse.dir ofs://cluster1/tgwarehouse spark.master k8s://https://xxxxx/k8s/clusters/local spark.submit.deployMode client spark.kubernetes.container.image harbor.xxx/mcloud/spark:v3.2.1 spark.kubernetes.container.image.pullPolicy Always spark.kubernetes.namespace spark-operator spark.kubernetes.authenticate.driver.serviceAccountName spark-operator-spark spark.kubernetes.authenticate.executor.serviceAccountName spark-operator-spark spark.kubernetes.node.selector.spark enable spark.ui.port 44307 spark.kubernetes.executor.limit.cores 2 spark.executor.memory 8g spark.executor.cores 2 spark.hive.default.fileformat orc spark.sql.adaptive.enabled true spark.sql.adaptive.advisoryPartitionSizeInBytes 134217728 spark.sql.adaptive.autoBroadcastJoinThreshold 10m spark.sql.broadcastTimeout 600s spark.sql.hive.metastorePartitionPruning true spark.dynamicAllocation.enabled true spark.dynamicAllocation.minExecutors 5 spark.dynamicAllocation.maxExecutors 10 spark.dynamicAllocation.shuffleTracking.enabled true spark.dynamicAllocation.executorIdleTimeout 120s spark.dynamicAllocation.shuffleTracking.enabled true spark.dynamicAllocation.shuffleTracking.timeout 30min spark.dynamicAllocation.schedulerBacklogTimeout 1s spark.dynamicAllocation.sustainedSchedulerBacklogTimeout 1s spark.cleaner.periodicGC.interval 5min kyuubi.kinit.keytab /opt/kyuubi/scm.keytab kyuubi.kinit.principal scm/scm@xxxx kyuubi.authentication LDAP kyuubi.authentication.ldap.base.dn xxx kyuubi.authentication.ldap.url ldap://xxxx kyuubi.authentication.sasl.qop auth kyuubi.frontend.min.worker.threads 200 kyuubi.engine.share.level USER spark.sql.extensions=org.apache.kyuubi.plugin.spark.authz.ranger.RangerSparkExtension ``` ### Kyuubi Engine Configurations _No response_ ### Additional context _No response_ ### Are you willing to submit PR? - [ ] Yes I am willing to submit a PR! -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
