[Bug] Add a does not exist local jar, kyuubi catch java.io.FileNotFoundException but still return a result
- Dominant language
- Scala
- Stars
- 2.4k
- Forks
- 1k
- PR merge metrics
- No merged PRs in 30d
Description
### 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/kyuubi/issues?q=is%3Aissue) and found no similar issues.
### Describe the bug
Kyuubi 1.8.0 spark version spark-3.2.1
I use beeline connect kyuubi, and execute a add statement add a does not exist local jar, I expected kyuubi to return exception, but kyuubi still return a result.
```
Connected to: Spark SQL (version 3.2.1)
Driver: Kyuubi Project Hive JDBC Client (version 1.8.0)
Beeline version 1.8.0 by Apache Kyuubi
0: jdbc:hive2://kyuubi-01:1001> add jar test.jar;
2023-11-21 11:10:52.833 INFO KyuubiSessionManager-exec-pool: Thread-605 org.apache.kyuubi.operation.ExecuteStatement: Processing read_test's query[a9bee91e-32da-4390-9114-926e776dd886]: PENDING_STATE -> RUNNING_STATE, statement:
add jar test.jar
23/11/21 11:10:52 ERROR SparkContext: Failed to add file:/opt/test/apache-kyuubi-1.8.0-bin/work/read_test/test.jar to Spark environment
java.io.FileNotFoundException: Jar /opt/test/apache-kyuubi-1.8.0-bin/work/read_test/test.jar not found
at org.apache.spark.SparkContext.addLocalJarFile$1(SparkContext.scala:1935)
at org.apache.spark.SparkContext.addJar(SparkContext.scala:1990)
at org.apache.spark.SparkContext.addJar(SparkContext.scala:1928)
at org.apache.spark.sql.internal.SessionResourceLoader.$anonfun$addJar$1(SessionState.scala:181)
at org.apache.spark.sql.internal.SessionResourceLoader.$anonfun$addJar$1$adapted(SessionState.scala:180)
at scala.collection.immutable.List.foreach(List.scala:431)
at org.apache.spark.sql.internal.SessionResourceLoader.addJar(SessionState.scala:180)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.super$addJar(HiveSessionStateBuilder.scala:132)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.$anonfun$addJar$1(HiveSessionStateBuilder.scala:132)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.$anonfun$addJar$1$adapted(HiveSessionStateBuilder.scala:130)
at scala.collection.immutable.List.foreach(List.scala:431)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.addJar(HiveSessionStateBuilder.scala:130)
at org.apache.spark.sql.execution.command.AddJarsCommand.$anonfun$run$1(resources.scala:32)
at org.apache.spark.sql.execution.command.AddJarsCommand.$anonfun$run$1$adapted(resources.scala:32)
at scala.collection.immutable.Stream.foreach(Stream.scala:533)
at org.apache.spark.sql.execution.command.AddJarsCommand.run(resources.scala:32)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult$lzycompute(commands.scala:75)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult(commands.scala:73)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.executeCollect(commands.scala:84)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.$anonfun$applyOrElse$1(QueryExecution.scala:112)
at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$5(SQLExecution.scala:103)
at org.apache.spark.sql.execution.SQLExecution$.withSQLConfPropagated(SQLExecution.scala:163)
at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$1(SQLExecution.scala:90)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.execution.SQLExecution$.withNewExecutionId(SQLExecution.scala:64)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.applyOrElse(QueryExecution.scala:112)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.applyOrElse(QueryExecution.scala:108)
at org.apache.spark.sql.catalyst.trees.TreeNode.$anonfun$transformDownWithPruning$1(TreeNode.scala:481)
at org.apache.spark.sql.catalyst.trees.CurrentOrigin$.withOrigin(TreeNode.scala:82)
at org.apache.spark.sql.catalyst.trees.TreeNode.transformDownWithPruning(TreeNode.scala:481)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.org$apache$spark$sql$catalyst$plans$logical$AnalysisHelper$$super$transformDownWithPruning(LogicalPlan.scala:32)
at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.transformDownWithPruning(AnalysisHelper.scala:267)
at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.transformDownWithPruning$(AnalysisHelper.scala:263)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.transformDownWithPruning(LogicalPlan.scala:32)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.transformDownWithPruning(LogicalPlan.scala:32)
at org.apache.spark.sql.catalyst.trees.TreeNode.transformDown(TreeNode.scala:457)
at org.apache.spark.sql.execution.QueryExecution.eagerlyExecuteCommands(QueryExecution.scala:108)
at org.apache.spark.sql.execution.QueryExecution.commandExecuted$lzycompute(QueryExecution.scala:95)
at org.apache.spark.sql.execution.QueryExecution.commandExecuted(QueryExecution.scala:93)
at org.apache.spark.sql.Dataset.(Dataset.scala:231)
at org.apache.spark.sql.Dataset$.$anonfun$ofRows$3(Dataset.scala:107)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.Dataset$.ofRows(Dataset.scala:103)
at org.apache.spark.sql.SparkSession.$anonfun$bzlSql$1(SparkSession.scala:695)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.SparkSession.bzlSql(SparkSession.scala:665)
at org.apache.spark.sql.SparkSession.$anonfun$sql$1(SparkSession.scala:654)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.SparkSession.sql(SparkSession.scala:654)
at org.apache.kyuubi.engine.spark.operation.ExecuteStatement.$anonfun$executeStatement$1(ExecuteStatement.scala:86)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
at org.apache.kyuubi.engine.spark.operation.SparkOperation.$anonfun$withLocalProperties$1(SparkOperation.scala:155)
at org.apache.spark.sql.execution.SQLExecution$.withSQLConfPropagated(SQLExecution.scala:163)
at org.apache.kyuubi.engine.spark.operation.SparkOperation.withLocalProperties(SparkOperation.scala:139)
at org.apache.kyuubi.engine.spark.operation.ExecuteStatement.executeStatement(ExecuteStatement.scala:81)
at org.apache.kyuubi.engine.spark.operation.ExecuteStatement$$anon$1.run(ExecuteStatement.scala:103)
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:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2023-11-21 11:10:52.930 INFO KyuubiSessionManager-exec-pool: Thread-605 org.apache.kyuubi.operation.ExecuteStatement: Query[a9bee91e-32da-4390-9114-926e776dd886] in FINISHED_STATE
2023-11-21 11:10:52.930 INFO KyuubiSessionManager-exec-pool: Thread-605 org.apache.kyuubi.operation.ExecuteStatement: Processing read_test's query[a9bee91e-32da-4390-9114-926e776dd886]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.097 seconds
+---------+
| Result |
+---------+
+---------+
No rows selected (0.266 seconds)
```
### Affects Version(s)
1.8.0
### Kyuubi Server Log Output
```logtalk
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/opt/hadoop/gateway/sparkgateway/3.2.1-bzl.version-25/jars/slf4j-log4j12-1.7.30.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/opt/hadoop/gateway/hadoopgateway/3.3.2-bzl-client.version-6/share/hadoop/common/lib/slf4j-log4j12-1.7.30.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
Warning: Ignoring non-Spark config property: hive.exec.compress.output
23/11/21 10:58:44 INFO Client: Submitting application name: unknown::p3:0:kyuubi_USER_SPARK_SQL_read_test_default_f420fa41-d415-4e9c-ba32-8e81b88cd4ab
23/11/21 10:58:44 INFO Client: Requesting a new application from cluster with 2058 NodeManagers
23/11/21 10:58:44 INFO Client: Verifying our application has not requested more than the maximum memory capability of the cluster (12288 MB per container)
23/11/21 10:58:44 INFO Client: Will allocate AM container, with 896 MB memory including 384 MB overhead
23/11/21 10:58:44 INFO Client: Setting up container launch context for our AM
23/11/21 10:58:44 INFO Client: Setting up the launch environment for our AM container
23/11/21 10:58:44 INFO Client: Preparing resources for our AM container
23/11/21 10:58:45 WARN Client: Neither spark.yarn.jars nor spark.yarn.archive is set, falling back to uploading libraries under SPARK_HOME.
23/11/21 10:58:46 INFO Client: Uploading resource file:/tmp/spark-20f2630d-b2a1-4eaf-81eb-9a4fae317240/__spark_libs__2729148718701852928.zip -> hdfs://bzl-hdfs/user/yarn/yj-yarn/sparkstagingnew/read_test/.sparkStaging/application_1699362779536_655326/__spark_libs__2729148718701852928.zip
23/11/21 10:58:49 INFO Client: Uploading resource file:/tmp/spark-20f2630d-b2a1-4eaf-81eb-9a4fae317240/__spark_conf__9111429664748163326.zip -> hdfs://bzl-hdfs/user/yarn/yj-yarn/sparkstagingnew/read_test/.sparkStaging/application_1699362779536_655326/__spark_conf__.zip
23/11/21 10:58:49 INFO Client: Submitting application application_1699362779536_655326 to ResourceManager
23/11/21 10:58:50 INFO Client: Application report for application_1699362779536_655326 (state: ACCEPTED)
23/11/21 10:58:50 INFO Client:
client token: N/A
diagnostics: AM container is launched, waiting for AM container to Register with RM
ApplicationMaster host: N/A
ApplicationMaster RPC port: -1
queue: root.default
start time: 1700535529514
final status: UNDEFINED
tracking URL: http://yj-yarnmaster1-001:8088/proxy/application_1699362779536_655326/
user: read_test
23/11/21 10:58:51 INFO Client: Application report for application_1699362779536_655326 (state: ACCEPTED)
23/11/21 10:58:52 INFO Client: Application report for application_1699362779536_655326 (state: ACCEPTED)
23/11/21 10:58:53 INFO Client: Application report for application_1699362779536_655326 (state: ACCEPTED)
23/11/21 10:58:54 INFO Client: Application report for application_1699362779536_655326 (state: ACCEPTED)
23/11/21 10:58:55 INFO Client: Application report for application_1699362779536_655326 (state: ACCEPTED)
23/11/21 10:58:56 INFO Client: Application report for application_1699362779536_655326 (state: ACCEPTED)
23/11/21 10:58:57 INFO Client: Application report for application_1699362779536_655326 (state: RUNNING)
23/11/21 10:58:57 INFO Client:
client token: N/A
diagnostics: N/A
ApplicationMaster host: 10.104.2.159
ApplicationMaster RPC port: -1
queue: root.default
start time: 1700535529514
final status: UNDEFINED
tracking URL: http://yj-yarnmaster1-001:8088/proxy/application_1699362779536_655326/
user: read_test
Hive Session ID = b3f88687-ac51-49e8-9f36-668fae139736
23/11/21 11:10:52 ERROR SparkContext: Failed to add file:/opt/test/apache-kyuubi-1.8.0-bin/work/read_test/test.jar to Spark environment
java.io.FileNotFoundException: Jar /opt/test/apache-kyuubi-1.8.0-bin/work/read_test/test.jar not found
at org.apache.spark.SparkContext.addLocalJarFile$1(SparkContext.scala:1935)
at org.apache.spark.SparkContext.addJar(SparkContext.scala:1990)
at org.apache.spark.SparkContext.addJar(SparkContext.scala:1928)
at org.apache.spark.sql.internal.SessionResourceLoader.$anonfun$addJar$1(SessionState.scala:181)
at org.apache.spark.sql.internal.SessionResourceLoader.$anonfun$addJar$1$adapted(SessionState.scala:180)
at scala.collection.immutable.List.foreach(List.scala:431)
at org.apache.spark.sql.internal.SessionResourceLoader.addJar(SessionState.scala:180)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.super$addJar(HiveSessionStateBuilder.scala:132)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.$anonfun$addJar$1(HiveSessionStateBuilder.scala:132)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.$anonfun$addJar$1$adapted(HiveSessionStateBuilder.scala:130)
at scala.collection.immutable.List.foreach(List.scala:431)
at org.apache.spark.sql.hive.HiveSessionResourceLoader.addJar(HiveSessionStateBuilder.scala:130)
at org.apache.spark.sql.execution.command.AddJarsCommand.$anonfun$run$1(resources.scala:32)
at org.apache.spark.sql.execution.command.AddJarsCommand.$anonfun$run$1$adapted(resources.scala:32)
at scala.collection.immutable.Stream.foreach(Stream.scala:533)
at org.apache.spark.sql.execution.command.AddJarsCommand.run(resources.scala:32)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult$lzycompute(commands.scala:75)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult(commands.scala:73)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.executeCollect(commands.scala:84)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.$anonfun$applyOrElse$1(QueryExecution.scala:112)
at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$5(SQLExecution.scala:103)
at org.apache.spark.sql.execution.SQLExecution$.withSQLConfPropagated(SQLExecution.scala:163)
at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$1(SQLExecution.scala:90)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.execution.SQLExecution$.withNewExecutionId(SQLExecution.scala:64)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.applyOrElse(QueryExecution.scala:112)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.applyOrElse(QueryExecution.scala:108)
at org.apache.spark.sql.catalyst.trees.TreeNode.$anonfun$transformDownWithPruning$1(TreeNode.scala:481)
at org.apache.spark.sql.catalyst.trees.CurrentOrigin$.withOrigin(TreeNode.scala:82)
at org.apache.spark.sql.catalyst.trees.TreeNode.transformDownWithPruning(TreeNode.scala:481)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.org$apache$spark$sql$catalyst$plans$logical$AnalysisHelper$$super$transformDownWithPruning(LogicalPlan.scala:32)
at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.transformDownWithPruning(AnalysisHelper.scala:267)
at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.transformDownWithPruning$(AnalysisHelper.scala:263)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.transformDownWithPruning(LogicalPlan.scala:32)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.transformDownWithPruning(LogicalPlan.scala:32)
at org.apache.spark.sql.catalyst.trees.TreeNode.transformDown(TreeNode.scala:457)
at org.apache.spark.sql.execution.QueryExecution.eagerlyExecuteCommands(QueryExecution.scala:108)
at org.apache.spark.sql.execution.QueryExecution.commandExecuted$lzycompute(QueryExecution.scala:95)
at org.apache.spark.sql.execution.QueryExecution.commandExecuted(QueryExecution.scala:93)
at org.apache.spark.sql.Dataset.(Dataset.scala:231)
at org.apache.spark.sql.Dataset$.$anonfun$ofRows$3(Dataset.scala:107)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.Dataset$.ofRows(Dataset.scala:103)
at org.apache.spark.sql.SparkSession.$anonfun$bzlSql$1(SparkSession.scala:695)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.SparkSession.bzlSql(SparkSession.scala:665)
at org.apache.spark.sql.SparkSession.$anonfun$sql$1(SparkSession.scala:654)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:858)
at org.apache.spark.sql.SparkSession.sql(SparkSession.scala:654)
at org.apache.kyuubi.engine.spark.operation.ExecuteStatement.$anonfun$executeStatement$1(ExecuteStatement.scala:86)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
at org.apache.kyuubi.engine.spark.operation.SparkOperation.$anonfun$withLocalProperties$1(SparkOperation.scala:155)
at org.apache.spark.sql.execution.SQLExecution$.withSQLConfPropagated(SQLExecution.scala:163)
at org.apache.kyuubi.engine.spark.operation.SparkOperation.withLocalProperties(SparkOperation.scala:139)
at org.apache.kyuubi.engine.spark.operation.ExecuteStatement.executeStatement(ExecuteStatement.scala:81)
at org.apache.kyuubi.engine.spark.operation.ExecuteStatement$$anon$1.run(ExecuteStatement.scala:103)
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:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
```
### Kyuubi Engine Log Output
### Kyuubi Server Configurations
_No response_
### Kyuubi Engine Configurations
_No response_
### Additional context
_No response_
### Are you willing to submit PR?
- [ ] Yes. I would be willing to submit a PR with guidance from the Kyuubi community to fix.
- [ ] No. I cannot submit a PR at this time.
Contributor guide
Research direction
Start with engine/spark/src/main/scala/org/apache/kyuubi/engine/spark/operation/ExecuteStatement.scala at executeStatement, then trace the Spark SQL handling shown in the stack trace. Reproduce ADD JAR with a nonexistent local jar and verify that the operation reports the FileNotFoundException instead of a successful empty result; add regression coverage where the existing operation tests live.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- scala, sql
- Domain
- backend
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 38/100