search

projectnessie / nessie

Nessie: Transactional Catalog for Data Lakes with Git-like semantics
https://projectnessie.org
Apache License 2.0
992 stars 130 forks source link

[Bug]: Failed to read table metadata from s3 [REST] #8830

Open sdasdasd1 opened 3 months ago

sdasdasd1 commented 3 months ago

What happened

When executing this spark.sql(f"SHOW TBLPROPERTIES {catalog}.{self.maintenance_args['table']};") get this error in nessie server output

2024-06-14 11:27:57,310 INFO  [io.qua.htt.access-log] (executor-thread-8) 10.16.34.50 - - [14/Jun/2024:11:27:57 +0000] "GET /iceberg/v1/config HTTP/1.1" 200 799
2024-06-14 11:27:57,712 ERROR [org.pro.nes.tas.ser.imp.TasksServiceImpl] (tasks-async-1) tasks: Unhandled state during local task attempt for catalog-snapshot:408142adb275ffa9927f53e6ffc3efa6605c26f0de9582be41d09b6b56d7a530: java.lang.RuntimeException: java.util.concurrent.CompletionException: java.lang.RuntimeException: java.io.IOException: Failed to read table metadata from s3://obs-zdp-warehouse-stage-mz/test_schema/test_partitioned_foreach_batch1_70145cf9-b481-4063-8372-080bba6189c9/metadata/39014-e8bc4dbf-bdc6-4a80-8474-f23bbcaa4f7b.metadata.json
    at org.projectnessie.catalog.service.impl.EntitySnapshotTaskBehavior.stateAsException(EntitySnapshotTaskBehavior.java:37)
    at org.projectnessie.catalog.service.impl.EntitySnapshotTaskBehavior.stateAsException(EntitySnapshotTaskBehavior.java:29)
    at org.projectnessie.nessie.tasks.service.impl.TasksServiceImpl.tryLocal(TasksServiceImpl.java:200)
    at org.projectnessie.nessie.tasks.service.impl.TasksServiceImpl.lambda$submit$2(TasksServiceImpl.java:152)
    at io.smallrye.context.impl.wrappers.SlowContextualRunnable.run(SlowContextualRunnable.java:19)
    at org.projectnessie.nessie.tasks.async.TasksAsync.lambda$call$0(TasksAsync.java:29)
    at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
    at java.base/java.lang.Thread.run(Thread.java:1583)

2024-06-14 11:27:57,715 WARN  [org.pro.cat.ser.res.IcebergErrorMapper] (executor-thread-8) Unhandled exception returned as HTTP/500: java.lang.RuntimeException: java.util.concurrent.CompletionException: java.lang.RuntimeException: java.io.IOException: Failed to read table metadata from s3://obs-zdp-warehouse-stage-mz/test_schema/test_partitioned_foreach_batch1_70145cf9-b481-4063-8372-080bba6189c9/metadata/39014-e8bc4dbf-bdc6-4a80-8474-f23bbcaa4f7b.metadata.json: java.lang.RuntimeException: java.util.concurrent.CompletionException: java.lang.RuntimeException: java.io.IOException: Failed to read table metadata from s3://obs-zdp-warehouse-stage-mz/test_schema/test_partitioned_foreach_batch1_70145cf9-b481-4063-8372-080bba6189c9/metadata/39014-e8bc4dbf-bdc6-4a80-8474-f23bbcaa4f7b.metadata.json
    at org.projectnessie.catalog.service.impl.EntitySnapshotTaskBehavior.stateAsException(EntitySnapshotTaskBehavior.java:37)
    at org.projectnessie.catalog.service.impl.EntitySnapshotTaskBehavior.stateAsException(EntitySnapshotTaskBehavior.java:29)
    at org.projectnessie.nessie.tasks.service.impl.TasksServiceImpl.tryLocal(TasksServiceImpl.java:200)
    at org.projectnessie.nessie.tasks.service.impl.TasksServiceImpl.lambda$submit$2(TasksServiceImpl.java:152)
    at io.smallrye.context.impl.wrappers.SlowContextualRunnable.run(SlowContextualRunnable.java:19)
    at org.projectnessie.nessie.tasks.async.TasksAsync.lambda$call$0(TasksAsync.java:29)
    at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
    at java.base/java.lang.Thread.run(Thread.java:1583)

and this error in spark output

Traceback (most recent call last):
  File "/tmp/spark-198064de-6f0a-459b-92e1-4e9f6f02b0d1/runner.py", line 100, in <module>
    job_instance.run()
  File "/stackable/spark/requirements/de_pyspark_etl/jobs/spark_k8s/set_necessary_tbl_properties.py", line 33, in run
    curr_properties: DataFrame = self.spark.sql(f"SHOW TBLPROPERTIES {catalog}.{self.maintenance_args['table']};")
                                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/stackable/spark/python/lib/pyspark.zip/pyspark/sql/session.py", line 1631, in sql
  File "/stackable/spark/python/lib/py4j-0.10.9.7-src.zip/py4j/java_gateway.py", line 1322, in __call__
  File "/stackable/spark/python/lib/pyspark.zip/pyspark/errors/exceptions/captured.py", line 179, in deco
  File "/stackable/spark/python/lib/py4j-0.10.9.7-src.zip/py4j/protocol.py", line 326, in get_return_value
py4j.protocol.Py4JJavaError: An error occurred while calling o90.sql.
: org.apache.iceberg.exceptions.ServiceFailureException: Server error: RuntimeException: java.util.concurrent.CompletionException: java.lang.RuntimeException: java.io.IOException: Failed to read table metadata from s3://obs-zdp-warehouse-stage-mz/test_schema/test_partitioned_foreach_batch1_70145cf9-b481-4063-8372-080bba6189c9/metadata/39014-e8bc4dbf-bdc6-4a80-8474-f23bbcaa4f7b.metadata.json
    at org.apache.iceberg.rest.ErrorHandlers$DefaultErrorHandler.accept(ErrorHandlers.java:217)
    at org.apache.iceberg.rest.ErrorHandlers$TableErrorHandler.accept(ErrorHandlers.java:118)
    at org.apache.iceberg.rest.ErrorHandlers$TableErrorHandler.accept(ErrorHandlers.java:102)
    at org.apache.iceberg.rest.HTTPClient.throwFailure(HTTPClient.java:201)
    at org.apache.iceberg.rest.HTTPClient.execute(HTTPClient.java:313)
    at org.apache.iceberg.rest.HTTPClient.execute(HTTPClient.java:252)
    at org.apache.iceberg.rest.HTTPClient.get(HTTPClient.java:348)
    at org.apache.iceberg.rest.RESTClient.get(RESTClient.java:96)
    at org.apache.iceberg.rest.RESTSessionCatalog.loadInternal(RESTSessionCatalog.java:331)
    at org.apache.iceberg.rest.RESTSessionCatalog.loadTable(RESTSessionCatalog.java:347)
    at org.apache.iceberg.catalog.BaseSessionCatalog$AsCatalog.loadTable(BaseSessionCatalog.java:99)
    at org.apache.iceberg.rest.RESTCatalog.loadTable(RESTCatalog.java:102)
    at org.apache.iceberg.shaded.com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$doComputeIfAbsent$14(BoundedLocalCache.java:2406)
    at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1908)
    at org.apache.iceberg.shaded.com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2404)
    at org.apache.iceberg.shaded.com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2387)
    at org.apache.iceberg.shaded.com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:108)
    at org.apache.iceberg.shaded.com.github.benmanes.caffeine.cache.LocalManualCache.get(LocalManualCache.java:62)
    at org.apache.iceberg.CachingCatalog.loadTable(CachingCatalog.java:166)
    at org.apache.iceberg.spark.SparkCatalog.load(SparkCatalog.java:843)
    at org.apache.iceberg.spark.SparkCatalog.loadTable(SparkCatalog.java:170)
    at org.apache.spark.sql.connector.catalog.CatalogV2Util$.getTable(CatalogV2Util.scala:355)
    at org.apache.spark.sql.connector.catalog.CatalogV2Util$.loadTable(CatalogV2Util.scala:336)
    at org.apache.spark.sql.catalyst.analysis.Analyzer$ResolveRelations$.$anonfun$lookupTableOrView$2(Analyzer.scala:1201)
    at scala.Option.orElse(Option.scala:447)
    at org.apache.spark.sql.catalyst.analysis.Analyzer$ResolveRelations$.org$apache$spark$sql$catalyst$analysis$Analyzer$ResolveRelations$$lookupTableOrView(Analyzer.scala:1196)
    at org.apache.spark.sql.catalyst.analysis.Analyzer$ResolveRelations$$anonfun$apply$14.applyOrElse(Analyzer.scala:1155)
    at org.apache.spark.sql.catalyst.analysis.Analyzer$ResolveRelations$$anonfun$apply$14.applyOrElse(Analyzer.scala:1090)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.$anonfun$resolveOperatorsUpWithPruning$3(AnalysisHelper.scala:138)
    at org.apache.spark.sql.catalyst.trees.CurrentOrigin$.withOrigin(origin.scala:76)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.$anonfun$resolveOperatorsUpWithPruning$1(AnalysisHelper.scala:138)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper$.allowInvokingTransformsInAnalyzer(AnalysisHelper.scala:323)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.resolveOperatorsUpWithPruning(AnalysisHelper.scala:134)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.resolveOperatorsUpWithPruning$(AnalysisHelper.scala:130)
    at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.resolveOperatorsUpWithPruning(LogicalPlan.scala:32)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.$anonfun$resolveOperatorsUpWithPruning$2(AnalysisHelper.scala:135)
    at org.apache.spark.sql.catalyst.trees.UnaryLike.mapChildren(TreeNode.scala:1215)
    at org.apache.spark.sql.catalyst.trees.UnaryLike.mapChildren$(TreeNode.scala:1214)
    at org.apache.spark.sql.catalyst.plans.logical.ShowTableProperties.mapChildren(v2Commands.scala:942)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.$anonfun$resolveOperatorsUpWithPruning$1(AnalysisHelper.scala:135)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper$.allowInvokingTransformsInAnalyzer(AnalysisHelper.scala:323)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.resolveOperatorsUpWithPruning(AnalysisHelper.scala:134)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper.resolveOperatorsUpWithPruning$(AnalysisHelper.scala:130)
    at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.resolveOperatorsUpWithPruning(LogicalPlan.scala:32)
    at org.apache.spark.sql.catalyst.analysis.Analyzer$ResolveRelations$.apply(Analyzer.scala:1090)
    at org.apache.spark.sql.catalyst.analysis.Analyzer$ResolveRelations$.apply(Analyzer.scala:1049)
    at org.apache.spark.sql.catalyst.rules.RuleExecutor.$anonfun$execute$2(RuleExecutor.scala:222)
    at scala.collection.LinearSeqOptimized.foldLeft(LinearSeqOptimized.scala:126)
    at scala.collection.LinearSeqOptimized.foldLeft$(LinearSeqOptimized.scala:122)
    at scala.collection.immutable.List.foldLeft(List.scala:91)
    at org.apache.spark.sql.catalyst.rules.RuleExecutor.$anonfun$execute$1(RuleExecutor.scala:219)
    at org.apache.spark.sql.catalyst.rules.RuleExecutor.$anonfun$execute$1$adapted(RuleExecutor.scala:211)
    at scala.collection.immutable.List.foreach(List.scala:431)
    at org.apache.spark.sql.catalyst.rules.RuleExecutor.execute(RuleExecutor.scala:211)
    at org.apache.spark.sql.catalyst.analysis.Analyzer.org$apache$spark$sql$catalyst$analysis$Analyzer$$executeSameContext(Analyzer.scala:226)
    at org.apache.spark.sql.catalyst.analysis.Analyzer.$anonfun$execute$1(Analyzer.scala:222)
    at org.apache.spark.sql.catalyst.analysis.AnalysisContext$.withNewAnalysisContext(Analyzer.scala:173)
    at org.apache.spark.sql.catalyst.analysis.Analyzer.execute(Analyzer.scala:222)
    at org.apache.spark.sql.catalyst.analysis.Analyzer.execute(Analyzer.scala:188)
    at org.apache.spark.sql.catalyst.rules.RuleExecutor.$anonfun$executeAndTrack$1(RuleExecutor.scala:182)
    at org.apache.spark.sql.catalyst.QueryPlanningTracker$.withTracker(QueryPlanningTracker.scala:89)
    at org.apache.spark.sql.catalyst.rules.RuleExecutor.executeAndTrack(RuleExecutor.scala:182)
    at org.apache.spark.sql.catalyst.analysis.Analyzer.$anonfun$executeAndCheck$1(Analyzer.scala:209)
    at org.apache.spark.sql.catalyst.plans.logical.AnalysisHelper$.markInAnalyzer(AnalysisHelper.scala:330)
    at org.apache.spark.sql.catalyst.analysis.Analyzer.executeAndCheck(Analyzer.scala:208)
    at org.apache.spark.sql.execution.QueryExecution.$anonfun$analyzed$1(QueryExecution.scala:77)
    at org.apache.spark.sql.catalyst.QueryPlanningTracker.measurePhase(QueryPlanningTracker.scala:138)
    at org.apache.spark.sql.execution.QueryExecution.$anonfun$executePhase$2(QueryExecution.scala:219)
    at org.apache.spark.sql.execution.QueryExecution$.withInternalError(QueryExecution.scala:546)
    at org.apache.spark.sql.execution.QueryExecution.$anonfun$executePhase$1(QueryExecution.scala:219)
    at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:900)
    at org.apache.spark.sql.execution.QueryExecution.executePhase(QueryExecution.scala:218)
    at org.apache.spark.sql.execution.QueryExecution.analyzed$lzycompute(QueryExecution.scala:77)
    at org.apache.spark.sql.execution.QueryExecution.analyzed(QueryExecution.scala:74)
    at org.apache.spark.sql.execution.QueryExecution.assertAnalyzed(QueryExecution.scala:66)
    at org.apache.spark.sql.Dataset$.$anonfun$ofRows$2(Dataset.scala:99)
    at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:900)
    at org.apache.spark.sql.Dataset$.ofRows(Dataset.scala:97)
    at org.apache.spark.sql.SparkSession.$anonfun$sql$1(SparkSession.scala:638)
    at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:900)
    at org.apache.spark.sql.SparkSession.sql(SparkSession.scala:629)
    at org.apache.spark.sql.SparkSession.sql(SparkSession.scala:659)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at py4j.reflection.MethodInvoker.invoke(MethodInvoker.java:244)
    at py4j.reflection.ReflectionEngine.invoke(ReflectionEngine.java:374)
    at py4j.Gateway.invoke(Gateway.java:282)
    at py4j.commands.AbstractCommand.invokeMethod(AbstractCommand.java:132)
    at py4j.commands.CallCommand.execute(CallCommand.java:79)
    at py4j.ClientServerConnection.waitForCommands(ClientServerConnection.java:182)
    at py4j.ClientServerConnection.run(ClientServerConnection.java:106)
    at java.base/java.lang.Thread.run(Thread.java:829)
2024-06-14T11:27:58,535 INFO [shutdown-hook-0] org.apache.spark.util.ShutdownHookManager - Shutdown hook called

How to reproduce it

Deploy Nessie with helm chart 0.90.4 Set this settings on server side

...
  chart:
    spec:
      chart: nessie
      version: ${nessie_version}
      sourceRef:
        kind: HelmRepository
        name: nessiecatalog
        namespace: trino
      interval: 1m
  values:
    logLevel: DEBUG
    versionStoreType: JDBC
    postgres:
      jdbcUrl: ${nessie_jdbcUrl}
      secret:
        name: nessie-secret
        username: postgres_username
        password: postgres_password
    advancedConfig:
      nessie.catalog.default-warehouse: dwh
      nessie.catalog.warehouses.dwh.location: ${s3_warehouse_bucket}
      nessie.catalog.service.s3.endpoint: "https://obs...."
      nessie.catalog.service.s3.region: "..."
    extraEnv:
      - name: NESSIE_CATALOG_SERVICE_S3_ACCESS-KEY_NAME
        valueFromSecret:
          name: obs-s3-credentials-secret
          key: accessKey
      - name: NESSIE_CATALOG_SERVICE_S3_ACCESS-KEY_SECRET
        valueFromSecret:
          name: obs-s3-credentials-secret
          key: secretKey

Set this settings on Spark(3.5.1 Iceberg 1.5.0) side

    spark.driver.extraClassPath: /stackable/spark/extra-jars/*
    spark.driver.userClassPathFirst: 'false'
    spark.executor.extraClassPath: /stackable/spark/extra-jars/*
    spark.executor.userClassPathFirst: 'false'
    spark.hadoop.fs.s3.impl: org.apache.hadoop.fs.s3a.S3AFileSystem
    spark.hadoop.fs.s3a.aws.credentials.provider: org.apache.hadoop.fs.s3a.SimpleAWSCredentialsProvider
    spark.hadoop.fs.s3a.bucket.obs-de-cicd-mz.access.key: ...
    spark.hadoop.fs.s3a.bucket.obs-de-cicd-mz.secret.key: ...
    spark.hadoop.fs.s3a.endpoint: ...
    spark.io.compression.codec: zstd
    spark.jars.ivySettings: /ivy/ivy.settings
    spark.kubernetes.file.upload.path: local:///tmp
    spark.kubernetes.memoryOverheadFactor: '0.2'
    spark.sql.ansi.enabled: 'true'
    spark.sql.catalog.iceberg_nessie: org.apache.iceberg.spark.SparkCatalog
    spark.sql.catalog.iceberg_nessie.type: rest
    spark.sql.catalog.iceberg_nessie.uri: https://nessie-zdp-stage.xx.me/iceberg/
    spark.sql.catalogImplementation: in-memory
    spark.sql.debug: 'false'
    spark.sql.defaultCatalog: iceberg_nessie
    spark.sql.extensions: org.apache.iceberg.spark.extensions.IcebergSparkSessionExtensions,org.projectnessie.spark.extensions.NessieSparkSessionExtensions
    spark.sql.sources.partitionOverwriteMode: dynamic
    spark.sql.storeAssignmentPolicy: ANSI
    spark.ui.proxyBase: /sparkui/pyspark-pi-c2b4c15d-6144
    spark.ui.proxyRedirectUri: /

Run this Spark command on existing iceberg table (it was okay with the nessie catalog previously) spark.sql(f"SHOW TBLPROPERTIES {catalog}.{self.maintenance_args['table']};")

Nessie server type (docker/uber-jar/built from source) and version

0.90.4

Client type (Ex: UI/Spark/pynessie ...) and version

No response

Additional information

No response

adutra commented 3 months ago

@sdasdasd1 this might not solve your problem but I noticed that your env vars have odd names, e.g. NESSIE_CATALOG_SERVICE_S3_ACCESS-KEY_NAME – note the dash. It should be imho NESSIE_CATALOG_SERVICE_S3_ACCESS_KEY_NAME.

adutra commented 3 months ago

@sdasdasd1 this might not solve your problem but I noticed that your env vars have odd names, e.g. NESSIE_CATALOG_SERVICE_S3_ACCESS-KEY_NAME – note the dash. It should be imho NESSIE_CATALOG_SERVICE_S3_ACCESS_KEY_NAME.

sdasdasd1 commented 3 months ago

@adutra Are u sure? Look at this in documentation. Original parameter is nessie.catalog.service.s3.access-key.secret And referring to docs I should not replace it to "_" And I cant use it in advancedConfig in lovercase because value refs to k8s secret which is unavailable in advancedConfig section. Only in extraEnv.

Снимок экрана 2024-06-14 в 17 59 56
sdasdasd1 commented 3 months ago
Снимок экрана 2024-06-14 в 18 04 22

but let me try...

adutra commented 3 months ago

Check the conversion rules here: https://smallrye.io/smallrye-config/Main/config/environment-variables/

sdasdasd1 commented 3 months ago

@adutra It didn't help, I get the same errors

dimas-b commented 3 months ago

This is probably the reason why fixing credential properties did not help: #8860