why kyuubi session always FINISHED when deploy on yarn cluster mode?

[ethanzhou8109]

we use kyuubi as thriftserver for hue. when deploy mode is client, it works ok, and when deploy in cluster mode, session always finish and can't serve any more

server log

15:53:29.136 INFO org.apache.kyuubi.operation.LaunchEngine: Processing schedule's query[5df5809e-efb7-4cd3-b462-eee6ef96fcdf]: RUNNING_STATE -> ERROR_STATE, statement: LAUNCH_ENGINE, time taken: 182.442 seconds
15:53:29.136 ERROR org.apache.kyuubi.server.KyuubiTBinaryFrontendService: Error executing statement:
        --class org.apache.kyuubi.engine.spark.SparkSQLEngine \
        --conf spark.driver.maxResultSize=1g \
        --conf spark.kyuubi.ha.zookeeper.quorum=xxxx \
        --conf spark.kyuubi.client.ip=xxxx\
        --conf spark.kyuubi.session.idle.timeout=PT15M \
        --conf spark.kyuubi.session.engine.request.timeout=PT3H \
        --conf spark.jars=hdfs:///user/hive/udfs/hive-udfs.jar \
        --conf spark.kyuubi.session.engine.startup.waitCompletion=false \
        --conf spark.kyuubi.kinit.principal=xxx \
        --conf spark.kyuubi.engine.submit.time=1657093826712 \
        --conf spark.kyuubi.ha.zookeeper.client.port=2181 \
        --conf spark.app.name=kyuubi_USER_SPARK_SQL_schedule_default_9560959a-3598-44a6-ab1c-863595d74fbd \
        --conf spark.driver.memory=2g \
        --conf spark.kyuubi.ha.zookeeper.acl.enabled=false \
        --conf spark.kyuubi.ha.engine.ref.id=9560959a-3598-44a6-ab1c-863595d74fbd \
        --conf spark.kyuubi.ha.engine.ref.id=9560959a-3598-44a6-ab1c-863595d74fbd \
        --conf spark.dynamicAllocation.maxExecutors=10 \
        --conf spark.submit.deployMode=cluster \
        --conf spark.hive.server2.proxy.user=schedule \
        --conf spark.yarn.tags=KYUUBI \
        --conf spark.kyuubi.ha.zookeeper.namespace=/kyuubi-ha_1.5.2-incubating_USER_SPARK_SQL/schedule/default \
        --conf spark.executor.memory=4g \
        --conf spark.executor.cores=1 \
        --conf spark.kyuubi.ha.enabled=true \
        --conf spark.kyuubi.kinit.keytab=/etc/keytabs/hive.keytab \
        --conf spark.kyuubi.operation.idle.timeout=PT3H \
        at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_191]
        at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_191]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$waitForEngineLaunched$1(KyuubiSessionImpl.scala:131) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$waitForEngineLaunched$1$adapted(KyuubiSessionImpl.scala:127) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        --conf spark.kyuubi.kinit.keytab=/etc/keytabs/hive.keytab \
        --conf spark.kyuubi.operation.idle.timeout=PT3H \
        --proxy-user schedule /opt/kyuubi/apache-kyuubi-1.5.2-incubating-bin/externals/engines/spark/kyuubi-spark-sql-engine_2.12-1.5.2-incubating.jar. Killed Application application_1656658254164_4009 successfully.
        at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_191]
        at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_191]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$waitForEngineLaunched$1(KyuubiSessionImpl.scala:131) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_191]
        at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_191]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$waitForEngineLaunched$1(KyuubiSessionImpl.scala:131) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_191]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$waitForEngineLaunched$1(KyuubiSessionImpl.scala:131) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$waitForEngineLaunched$1$adapted(KyuubiSessionImpl.scala:127) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at scala.Option.foreach(Option.scala:407) ~[scala-library-2.12.15.jar:?]
        at org.apache.kyuubi.session.KyuubiSessionImpl.waitForEngineLaunched(KyuubiSessionImpl.scala:127) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.KyuubiSessionImpl.runOperation(KyuubiSessionImpl.scala:117) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.AbstractSession.$anonfun$executeStatement$1(AbstractSession.scala:124) ~[kyuubi-common_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.AbstractSession.withAcquireRelease(AbstractSession.scala:75) ~[kyuubi-common_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.AbstractSession.executeStatement(AbstractSession.scala:121) ~[kyuubi-common_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.service.AbstractBackendService.executeStatement(AbstractBackendService.scala:66) ~[kyuubi-common_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.server.KyuubiServer$$anon$1.org$apache$kyuubi$server$BackendServiceMetric$$super$executeStatement(KyuubiServer.scala:142) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.server.BackendServiceMetric.$anonfun$executeStatement$1(BackendServiceMetric.scala:62) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.metrics.MetricsSystem$.timerTracing(MetricsSystem.scala:111) ~[kyuubi-metrics_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.server.BackendServiceMetric.executeStatement(BackendServiceMetric.scala:62) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.server.BackendServiceMetric.executeStatement$(BackendServiceMetric.scala:55) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.server.KyuubiServer$$anon$1.executeStatement(KyuubiServer.scala:142) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.service.TFrontendService.ExecuteStatement(TFrontendService.scala:232) ~[kyuubi-common_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.hive.service.rpc.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1557) ~[hive-service-rpc-3.1.2.jar:3.1.2]
        at org.apache.hive.service.rpc.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1542) ~[hive-service-rpc-3.1.2.jar:3.1.2]
        at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39) ~[libthrift-0.9.3.jar:0.9.3]
        at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39) ~[libthrift-0.9.3.jar:0.9.3]
        at org.apache.kyuubi.service.authentication.HadoopThriftAuthBridgeServer$TUGIAssumingProcessor.process(HadoopThriftAuthBridgeServer.scala:162) ~[kyuubi-common_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286) ~[libthrift-0.9.3.jar:0.9.3]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_191]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_191]
        at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_191]
Caused by: org.apache.kyuubi.KyuubiSQLException: Timeout(180000 ms) to launched SPARK_SQL engine with /opt/spark/spark-3.1.2-bin-spark-3.1.2/bin/spark-submit \
        --class org.apache.kyuubi.engine.spark.SparkSQLEngine \
        --conf spark.driver.maxResultSize=1g \
        --conf spark.kyuubi.ha.zookeeper.quorum=xxx \
        --conf spark.kyuubi.client.ip=192.168.2.189 \
        --conf spark.kyuubi.session.idle.timeout=PT15M \
        --conf spark.kyuubi.session.engine.request.timeout=PT3H \
        --conf spark.jars=hdfs:///user/hive/udfs/hive-udfs.jar \
        --conf spark.kyuubi.session.engine.startup.waitCompletion=false \
        --conf spark.kyuubi.kinit.principal=xxx \
        --conf spark.kyuubi.engine.submit.time=1657093826712 \
        --conf spark.kyuubi.ha.zookeeper.client.port=2181 \
        --conf spark.app.name=kyuubi_USER_SPARK_SQL_schedule_default_9560959a-3598-44a6-ab1c-863595d74fbd \
        --conf spark.driver.memory=2g \
        --conf spark.kyuubi.ha.zookeeper.acl.enabled=false \
        --conf spark.kyuubi.ha.engine.ref.id=9560959a-3598-44a6-ab1c-863595d74fbd \
        --conf spark.dynamicAllocation.maxExecutors=10 \
        --conf spark.submit.deployMode=cluster \
        --conf spark.hive.server2.proxy.user=schedule \
        --conf spark.yarn.tags=KYUUBI \
        --conf spark.kyuubi.ha.zookeeper.namespace=/kyuubi-ha_1.5.2-incubating_USER_SPARK_SQL/schedule/default \
        --conf spark.executor.memory=4g \
        --conf spark.executor.cores=1 \
        --conf spark.kyuubi.ha.enabled=true \
        --conf spark.kyuubi.kinit.keytab=/etc/keytabs/hive.keytab \
        --conf spark.kyuubi.operation.idle.timeout=PT3H \
        --proxy-user schedule /opt/kyuubi/apache-kyuubi-1.5.2-incubating-bin/externals/engines/spark/kyuubi-spark-sql-engine_2.12-1.5.2-incubating.jar. Killed Application application_1656658254164_4009 successfully.
        at org.apache.kyuubi.KyuubiSQLException$.apply(KyuubiSQLException.scala:69) ~[kyuubi-common_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.engine.EngineRef.$anonfun$create$1(EngineRef.scala:257) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.engine.EngineRef.tryWithLock(EngineRef.scala:192) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.engine.EngineRef.create(EngineRef.scala:206) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.engine.EngineRef.$anonfun$getOrCreate$1(EngineRef.scala:282) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at scala.Option.getOrElse(Option.scala:189) ~[scala-library-2.12.15.jar:?]
        at org.apache.kyuubi.engine.EngineRef.getOrCreate(EngineRef.scala:282) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$openEngineSession$1(KyuubiSessionImpl.scala:98) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$openEngineSession$1$adapted(KyuubiSessionImpl.scala:97) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.ha.client.ZooKeeperClientProvider$.withZkClient(ZooKeeperClientProvider.scala:104) ~[kyuubi-ha_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.session.KyuubiSessionImpl.openEngineSession(KyuubiSessionImpl.scala:97) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at org.apache.kyuubi.operation.LaunchEngine.$anonfun$runInternal$1(LaunchEngine.scala:51) ~[kyuubi-server_2.12-1.5.2-incubating.jar:1.5.2-incubating]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_191]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_191]
        ... 3 more
Caused by: org.apache.kyuubi.KyuubiSQLException: Failed to detect the root cause, please check /data/log/kyuubi/work/schedule/kyuubi-spark-sql-engine.log.13 at server side if necessary. The last 10 line(s) of log are:
         start time: 1657093833427
         final status: SUCCEEDED
         tracking URL: http://xxx/proxy/application_1656658254164_4009/
         user: schedule
22/07/06 15:50:45 INFO util.ShutdownHookManager: Shutdown hook called

worker log

maxDate=1657698632036, sequenceNumber=163493, masterKeyId=337 on ha-hdfs:nameservice
22/07/06 15:50:32 INFO security.HadoopFSDelegationTokenProvider: Renewal interval is 86400047 for token HDFS_DELEGATION_TOKEN
22/07/06 15:50:33 INFO yarn.Client: Submitting application application_1656658254164_4009 to ResourceManager
22/07/06 15:50:33 INFO impl.YarnClientImpl: Submitted application application_1656658254164_4009
22/07/06 15:50:34 INFO yarn.Client: Application report for application_1656658254164_4009 (state: ACCEPTED)
22/07/06 15:50:34 INFO yarn.Client:
         client token: Token { kind: YARN_CLIENT_TOKEN, service:  }
         diagnostics: AM container is launched, waiting for AM container to Register with RM
         ApplicationMaster host: N/A
         ApplicationMaster RPC port: -1
         queue: root.users.schedule
         start time: 1657093833427
         final status: UNDEFINED
         tracking URL: http://xxx/proxy/application_1656658254164_4009/
         user: schedule
22/07/06 15:50:35 INFO yarn.Client: Application report for application_1656658254164_4009 (state: ACCEPTED)
22/07/06 15:50:36 INFO yarn.Client: Application report for application_1656658254164_4009 (state: ACCEPTED)
22/07/06 15:50:37 INFO yarn.Client: Application report for application_1656658254164_4009 (state: ACCEPTED)
22/07/06 15:50:38 INFO yarn.Client: Application report for application_1656658254164_4009 (state: ACCEPTED)
22/07/06 15:50:39 INFO yarn.Client: Application report for application_1656658254164_4009 (state: ACCEPTED)
22/07/06 15:50:40 INFO yarn.Client: Application report for application_1656658254164_4009 (state: RUNNING)
22/07/06 15:50:40 INFO yarn.Client:
         client token: Token { kind: YARN_CLIENT_TOKEN, service:  }
         diagnostics: N/A
         ApplicationMaster host: xxx
         ApplicationMaster RPC port: 35245
         queue: root.users.schedule
         start time: 1657093833427
         final status: UNDEFINED
         tracking URL: http://xxx/proxy/application_1656658254164_4009/
         user: schedule
22/07/06 15:50:41 INFO yarn.Client: Application report for application_1656658254164_4009 (state: RUNNING)
22/07/06 15:50:42 INFO yarn.Client: Application report for application_1656658254164_4009 (state: RUNNING)
22/07/06 15:50:43 INFO yarn.Client: Application report for application_1656658254164_4009 (state: RUNNING)
22/07/06 15:50:44 INFO yarn.Client: Application report for application_1656658254164_4009 (state: RUNNING)
22/07/06 15:50:45 INFO yarn.Client: Application report for application_1656658254164_4009 (state: FINISHED)
22/07/06 15:50:45 INFO yarn.Client:
         client token: Token { kind: YARN_CLIENT_TOKEN, service:  }
         diagnostics: N/A
         ApplicationMaster host: xxx
         ApplicationMaster RPC port: 35245
         queue: root.users.schedule
         start time: 1657093833427
         final status: SUCCEEDED
         tracking URL: http://xxx/proxy/application_1656658254164_4009/
         user: schedule
22/07/06 15:50:45 INFO util.ShutdownHookManager: Shutdown hook called
22/07/06 15:50:45 INFO util.ShutdownHookManager: Deleting directory /tmp/spark-fee5b574-8a51-4acc-9c17-6393e4904edf
22/07/06 15:50:45 INFO util.ShutdownHookManager: Deleting directory /tmp/spark-5994acaa-1da3-4606-81c9-523f3f6a865e

[pan3793]

For cluster mode, please check the Spark Driver(Yarn AM) log

[ethanzhou8109]

ok, i find the root cause，thx

[bcxu]

please share how to slove the root case, thx.