[SUPPORT] Hudi Clean and Delta commits taking ~50 mins to finish frequently

[BalaMahesh]

Tips before filing an issue

• Have you gone through our FAQs?

• Join the mailing list to engage in conversations and get faster support at dev-subscribe@hudi.apache.org.

• If you have triaged this as a bug, then file an issue directly.

Describe the problem you faced

We have a Hudi table with metadata enabled and using delta streamer, async clean, async compact services . Delta commit and clean operations are taking ~50 minutes frequently.

A clear and concise description of the problem.

To Reproduce

Steps to reproduce the behavior:

1. Run 0.12.1 version Hudi with metadata table enabled. 2.Enable async compaction and cleaner services.

2. use the below configuration. hoodie.cleaner.policy=KEEP_LATEST_COMMITS hoodie.clean.automatic=true hoodie.clean.async=true hoodie.cleaner.commits.retained=5 hoodie.keep.min.commits=10

   compaction config

   hoodie.datasource.compaction.async.enable=true hoodie.parquet.small.file.limit=1048576 hoodie.compaction.target.io=50 hoodie.metadata.metrics.enable=true

   hoodie.metadata.index.bloom.filter.enable=false hoodie.metadata.index.column.stats.enable=false hoodie.write.concurrency.mode=optimistic_concurrency_control hoodie.cleaner.policy.failed.writes=LAZY hoodie.write.lock.provider=org.apache.hudi.client.transaction.lock.InProcessLockProvider hoodie.write.lock.wait_time_ms=300000

Expected behavior

Delta commit and clean actions should not take longer times.

A clear and concise description of what you expected to happen.

Environment Description

• Hudi version : 0.12.1

• Spark version : 3.2.1

• Hive version : 2.3.5

• Hadoop version : 2.7.7

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

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

Additional context

Add any other context about the problem here.

Delta streamer runs in continuous mode.

Adding the screenshot of timeline of operations

Below is the only error I see in logs.

Stacktrace

RequestHandler: Bad request response due to client view behind server view. Last known instant from client was 20230103113021745 but server has the following timeline [[20221128033016359__rollback__COMPLETED], [20221128042615784__rollback__COMPLETED], [20221128052249948__rollback__COMPLETED], [20221128100542977__rollback__COMPLETED], [20221128114411534__rollback__COMPLETED], [20221128121237952__rollback__COMPLETED], [20221128121547373__rollback__COMPLETED], [20221128124007294__rollback__COMPLETED], [20221128130510784__rollback__COMPLETED], [20221128150135765__rollback__COMPLETED], [20221202082857955__rollback__COMPLETED], [20221202083358380__rollback__COMPLETED], [20221205180609234__rollback__COMPLETED], [20221213024840399__rollback__COMPLETED], [20221215121336002__rollback__COMPLETED], [20230103075416732__clean__COMPLETED], [20230103080003681__clean__COMPLETED], [20230103080537813__clean__COMPLETED], [20230103081110194__clean__COMPLETED], [20230103081642791__clean__COMPLETED], [20230103082158513__clean__COMPLETED], [20230103082749103__clean__COMPLETED], [20230103083327661__clean__COMPLETED], [20230103083915577__clean__COMPLETED], [20230103084450294__clean__COMPLETED], [20230103085022170__clean__COMPLETED], [20230103085539296__deltacommit__COMPLETED], [20230103085550414__clean__COMPLETED], [20230103090129353__deltacommit__COMPLETED], [20230103090140117__clean__COMPLETED], [20230103090705599__deltacommit__COMPLETED], [20230103090716308__clean__COMPLETED], [20230103091245975__deltacommit__COMPLETED], [20230103091256846__clean__COMPLETED], [20230103091825253__deltacommit__COMPLETED], [20230103091836101__clean__COMPLETED], [20230103092403683__deltacommit__COMPLETED], [20230103092414824__clean__COMPLETED], [20230103092828723__commit__COMPLETED], [20230103092851264__clean__COMPLETED], [20230103092923310__deltacommit__COMPLETED], [20230103093158260__clean__COMPLETED], [20230103102048896__deltacommit__COMPLETED], [20230103102100480__clean__COMPLETED], [20230103102637434__deltacommit__COMPLETED], [20230103102648856__clean__COMPLETED], [20230103103218354__deltacommit__COMPLETED], [20230103103229738__clean__COMPLETED], [20230103103812033__deltacommit__COMPLETED], [20230103103823381__clean__COMPLETED], [20230103104351306__deltacommit__COMPLETED], [20230103104402684__clean__COMPLETED], [20230103104950491__deltacommit__COMPLETED], [20230103105002062__clean__COMPLETED], [20230103105541444__deltacommit__COMPLETED], [20230103105552964__clean__COMPLETED], [20230103110154035__deltacommit__COMPLETED], [20230103110205541__clean__COMPLETED], [20230103110749857__deltacommit__COMPLETED], [20230103110801657__clean__COMPLETED], [20230103111344582__deltacommit__COMPLETED], [20230103111356019__clean__COMPLETED], [20230103111912226__deltacommit__COMPLETED], [20230103111923380__clean__COMPLETED], [20230103112519397__deltacommit__COMPLETED], [20230103112531041__clean__COMPLETED], [20230103113021745__commit__COMPLETED], [20230103113045783__clean__COMPLETED]]

[yihua]

Hi @BalaMahesh Thanks for raising the issue. To better triage this, could you provide more details about the Hudi table, partitioned or non-partitioned table, how many partitions if partitioned, Spark driver logs, and screenshots of the stages which take a long time to finish?

[BalaMahesh]

This is a non-partitioned table with minimum file size set to 1 MB and ~150 parquet files are created. Below are the screenshots from spark web ui.

I am adding the logs between 23/01/04 03:48:51 and 23/01/04 04:41:25 - which took longer duration for delta commit.

hudi_logs.txt

[BalaMahesh]

@yihua - did you get chance to check this ?

[danny0405]

@BalaMahesh DId you try with the bloomfilter index metadata disabled ?

[BalaMahesh]

We were running with

hoodie.metadata.index.bloom.filter.enable=false hoodie.metadata.index.column.stats.enable=false

I hope that answers your question. We have set this false because, I have run into this issue when set to true. https://github.com/apache/hudi/issues/7657

I have changed the index type to simple and then restarted the application.

Index look up duration has come down and uniform now.

delta commit durations are uniform too except for the issue I mentioned here https://github.com/apache/hudi/issues/7364. After the restart delta commit gets stuck and then later progresses.

[danny0405]

I guess we run into some performance issue when using BloomFilter index for mor table with metadata table disabled, thanks for the feedback, let me record this issue first for this on-call time and have a discussion on the meeting

[BalaMahesh]

I guess we run into some performance issue when using BloomFilter index for mor table with metadata table disabled, thanks for the feedback, let me record this issue first for this on-call time and have a discussion on the meeting

Metadata table is enabled for this MoR job but

hoodie.metadata.index.bloom.filter.enable=false hoodie.metadata.index.column.stats.enable=false

these are set to false.

[michael1991]

We were running with

hoodie.metadata.index.bloom.filter.enable=false hoodie.metadata.index.column.stats.enable=false

I hope that answers your question. We have set this false because, I have run into this issue when set to true. #7657

I have changed the index type to simple and then restarted the application.

Index look up duration has come down and uniform now.

delta commit durations are uniform too except for the issue I mentioned here #7364. After the restart delta commit gets stuck and then later progresses.

@BalaMahesh Hello, BalaMahesh, we met same issue here, I have two questions here, hope you could have chance to response. Thanks in advance !

• how to find charts of "Index lookup duration" ?
• simple is the default index type on Spark engine, and we are using simple index type on our Custom Spark job, seems simple index type is not the key solution. do you have any more updates ?

Thanks in advance again !

[BalaMahesh]

We were running with hoodie.metadata.index.bloom.filter.enable=false hoodie.metadata.index.column.stats.enable=false I hope that answers your question. We have set this false because, I have run into this issue when set to true. #7657 I have changed the index type to simple and then restarted the application. Index look up duration has come down and uniform now. delta commit durations are uniform too except for the issue I mentioned here #7364. After the restart delta commit gets stuck and then later progresses.

@BalaMahesh Hello, BalaMahesh, we met same issue here, I have two questions here, hope you could have chance to response. Thanks in advance !

• how to find charts of "Index lookup duration" ?
• simple is the default index type on Spark engine, and we are using simple index type on our Custom Spark job, seems simple index type is not the key solution. do you have any more updates ?

Thanks in advance again !

1. You have to push metrics to either Prometheus push gateway or any other monitoring solution for plotting these charts.
2. You can see the spark stages and jobs in the spark web ui to identify which task is taking long.

[michael1991]

We were running with hoodie.metadata.index.bloom.filter.enable=false hoodie.metadata.index.column.stats.enable=false I hope that answers your question. We have set this false because, I have run into this issue when set to true. #7657 I have changed the index type to simple and then restarted the application. Index look up duration has come down and uniform now. delta commit durations are uniform too except for the issue I mentioned here #7364. After the restart delta commit gets stuck and then later progresses.

@BalaMahesh Hello, BalaMahesh, we met same issue here, I have two questions here, hope you could have chance to response. Thanks in advance !

• how to find charts of "Index lookup duration" ?
• simple is the default index type on Spark engine, and we are using simple index type on our Custom Spark job, seems simple index type is not the key solution. do you have any more updates ?

Thanks in advance again !

1. You have to push metrics to either Prometheus push gateway or any other monitoring solution for plotting these charts.
2. You can see the spark stages and jobs in the spark web ui to identify which task is taking long.

Got it! Thanks a lot !!!