apache / apache/hudi

[SUPPORT] SparkSQL hangs indefinitely during Hudi table read operation

Open
#10,232 4 comments 0 reactions 0 assignees View on GitHub
area:performance area:sql issue:stability
Dominant language
Java
Stars
6.2k
Forks
2.5k
Avg merge
2d 8h
Merged PRs (30d)
111

Description

**Describe the problem you faced**

I'm attempting to read a Hudi table on Glue Catalog using SparkSQL with metadata enabled. However, my job appears to hang indefinitely at a certain step. Despite enabling DEBUG logs, I'm unable to find any indications of what may be causing this issue. Notably, this problem only occurs with Hudi tables where `clean` is the latest action in the timeline.

**To Reproduce**

Steps to reproduce the behavior:

1. Create a Hudi table where `clean` is the latest action in the timeline
image

2. Open spark-shell
```bash
spark-shell \
--conf "spark.serializer=org.apache.spark.serializer.KryoSerializer" \
--conf "spark.sql.parquet.filterPushdown=true" \
--conf "spark.sql.parquet.mergeSchema=false" \
--conf "spark.speculation=false" \
--conf "spark.hadoop.mapreduce.fileoutputcommitter.algorithm.version=2" \
--conf "spark.hadoop.fs.s3a.impl=org.apache.hadoop.fs.s3a.S3AFileSystem" \
--conf "spark.hadoop.fs.s3.impl=org.apache.hadoop.fs.s3a.S3AFileSystem" \
--conf "spark.hadoop.fs.s3a.aws.credentials.provider=com.amazonaws.auth.DefaultAWSCredentialsProviderChain" \
--conf "spark.sql.catalogImplementation=hive" \
--conf "spark.sql.catalog.spark_catalog.type=hive" \
--conf "spark.sql.catalog.spark_catalog=org.apache.spark.sql.hudi.catalog.HoodieCatalog" \
--conf "spark.sql.extensions=org.apache.spark.sql.hudi.HoodieSparkSessionExtension" \
--conf "spark.kryo.registrator=org.apache.spark.HoodieSparkKryoRegistrar"
```

3. Run spark.sql():
```bash
scala> spark.sql("SET hoodie.metadata.enable=true")
scala> spark.sql("SELECT * FROM . LIMIT 50").show()
```

**Expected behavior**

Spark job can read the table without hanging

**Environment Description**

* Hudi version : 0.14.0

* Spark version : 3.4.1

* Hive version : 2.3.9

* Hadoop version : 3.3.6

* Storage (HDFS/S3/GCS..) : S3

* Running on Docker? (yes/no) : yes

**Additional context**

I encountered no issues while using Hudi version 0.13.1. However, upon trying the new Hudi 0.14.0 version, I experienced this problem.

The driver pod consistently uses up to 1 CPU core, although I'm uncertain about the processes that are running:

image

For tables where `commit` is the latest action in the timeline, Hudi 0.14.0 can read the table without any hanging issues.

image

**Stacktrace**

```
23/12/03 12:21:23 INFO HiveConf: Found configuration file file:/opt/spark/conf/hive-site.xml
23/12/03 12:21:23 INFO HiveClientImpl: Warehouse location for Hive client (version 2.3.9) is file:/opt/spark/work-dir/spark-warehouse
23/12/03 12:21:23 INFO AWSGlueClientFactory: Using region from ec2 metadata : ap-southeast-1
23/12/03 12:21:24 INFO AWSGlueClientFactory: Using region from ec2 metadata : ap-southeast-1
23/12/03 12:21:26 WARN MetricsConfig: Cannot locate configuration: tried hadoop-metrics2-s3a-file-system.properties,hadoop-metrics2.properties
23/12/03 12:21:26 INFO MetricsSystemImpl: Scheduled Metric snapshot period at 10 second(s).
23/12/03 12:21:26 INFO MetricsSystemImpl: s3a-file-system metrics system started
23/12/03 12:21:27 WARN SDKV2Upgrade: Directly referencing AWS SDK V1 credential provider com.amazonaws.auth.DefaultAWSCredentialsProviderChain. AWS SDK V1 credential providers will be removed once S3A is upgraded to SDK V2
23/12/03 12:21:28 WARN DFSPropertiesConfiguration: Cannot find HUDI_CONF_DIR, please set it as the dir of hudi-defaults.conf
23/12/03 12:21:28 WARN DFSPropertiesConfiguration: Properties file file:/etc/hudi/conf/hudi-defaults.conf not found. Ignoring to load props file
23/12/03 12:21:28 INFO DataSourceUtils: Getting table path..
23/12/03 12:21:28 INFO TablePathUtils: Getting table path from path : s3:////
23/12/03 12:21:28 INFO DefaultSource: Obtained hudi table path: s3:////
23/12/03 12:21:28 INFO HoodieTableMetaClient: Loading HoodieTableMetaClient from s3:////
23/12/03 12:21:28 INFO HoodieTableConfig: Loading table properties from s3://///.hoodie/hoodie.properties
23/12/03 12:21:28 INFO HoodieTableMetaClient: Finished Loading Table of type COPY_ON_WRITE(version=1, baseFileFormat=PARQUET) from s3:////
23/12/03 12:21:28 INFO DefaultSource: Is bootstrapped table => false, tableType is: COPY_ON_WRITE, queryType is: snapshot
23/12/03 12:21:28 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20231202193157845__clean__COMPLETED__20231202193208000]}
23/12/03 12:21:28 INFO TableSchemaResolver: Reading schema from s3://///c_day=20231130/cce9afd1-46a1-4668-b8b4-0ac697f1ed57-0_3-21-2099_20231202191150326.parquet
23/12/03 12:21:29 INFO S3AInputStream: Switching to Random IO seek policy
23/12/03 12:21:29 INFO HoodieTableMetaClient: Loading HoodieTableMetaClient from s3:////
23/12/03 12:21:29 INFO HoodieTableConfig: Loading table properties from s3://///.hoodie/hoodie.properties
23/12/03 12:21:29 INFO HoodieTableMetaClient: Finished Loading Table of type COPY_ON_WRITE(version=1, baseFileFormat=PARQUET) from s3:////
23/12/03 12:21:29 INFO HoodieTableMetaClient: Loading HoodieTableMetaClient from s3://///.hoodie/metadata
23/12/03 12:21:29 INFO HoodieTableConfig: Loading table properties from s3://///.hoodie/metadata/.hoodie/hoodie.properties
23/12/03 12:21:29 INFO HoodieTableMetaClient: Finished Loading Table of type MERGE_ON_READ(version=1, baseFileFormat=HFILE) from s3://///.hoodie/metadata
23/12/03 12:21:29 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20231202193157845__deltacommit__COMPLETED__20231202193207000]}
23/12/03 12:21:29 INFO AbstractTableFileSystemView: Took 2 ms to read 0 instants, 0 replaced file groups
23/12/03 12:21:30 INFO ClusteringUtils: Found 0 files in pending clustering operations
23/12/03 12:21:30 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20231202193157845__clean__COMPLETED__20231202193208000]}
23/12/03 12:21:30 INFO BaseHoodieTableFileIndex: Refresh table stg_tracking_unified__click, spent: 365 ms
23/12/03 12:21:30 DEBUG HoodieFileIndex: Unable to compose relative partition path prefix from the predicates; falling back to fetching all partitions
23/12/03 12:21:30 INFO HoodieTableMetadataUtil: Loading latest merged file slices for metadata table partition files
23/12/03 12:21:30 INFO AbstractTableFileSystemView: Took 0 ms to read 0 instants, 0 replaced file groups
23/12/03 12:21:30 INFO ClusteringUtils: Found 0 files in pending clustering operations
23/12/03 12:21:30 INFO AbstractTableFileSystemView: Building file system view for partition (files)
23/12/03 12:21:30 DEBUG AbstractTableFileSystemView: #files found in partition (files) =15, Time taken =26
23/12/03 12:21:30 DEBUG HoodieTableFileSystemView: Adding file-groups for partition :files, #FileGroups=1
23/12/03 12:21:30 DEBUG AbstractTableFileSystemView: addFilesToView: NumFiles=15, NumFileGroups=1, FileGroupsCreationTime=11, StoreTimeTaken=1
23/12/03 12:21:30 DEBUG AbstractTableFileSystemView: Time to load partition (files) =40
23/12/03 12:21:30 INFO HoodieBackedTableMetadata: Opened metadata base file from s3://///.hoodie/metadata/files/files-0000_0-31-2210_20231201193545608001.hfile at instant 20231201193545608001 in 14 ms
23/12/03 12:21:30 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20231202193157845__clean__COMPLETED__20231202193208000]}

[It's stuck at this point. No further logs are printed after this]
```

Contributor guide

No contributing guide indexed for this repository

Research direction

Start with the spark-shell configuration and the spark.sql SET and SELECT commands, reproducing the read against a table whose latest timeline action is clean. Compare the 0.14.0 behavior with 0.13.1 and inspect the final HoodieActiveTimeline and HoodieBackedTableMetadata log entries; done means the query returns without hanging for clean-latest tables.

Written by the indexing model from the issue text.

Assessment

Tech stack
aws, scala, spark
Domain
data-engineering, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.