hudi
hudi copied to clipboard
apache
[SUPPORT] Hudi Application getting stuck when Async cleaner is spawned
Tips before filing an issue
-
Have you gone through our FAQs?
-
Join the mailing list to engage in conversations and get faster support at [email protected].
-
If you have triaged this as a bug, then file an issue directly.
Describe the problem you faced
After some failed commits, Hudi application thread-pool is stuck while acquiring the lock without any progress.
A clear and concise description of the problem.
When Hudi application is stopped with some error or ungracefully for some time, when it is restarted it is getting stuck with the below logs without any progress for ~115 minutes.
To Reproduce
Steps to reproduce the behavior:
- Start Hudi application and run it for sometime
- Kill application in the middle of the commit and then restart again
- Use InProcessLockProvider and enable async cleaning and compaction.
Expected behavior Pipeline should not stuck and run without error. A clear and concise description of what you expected to happen.
Environment Description
-
Hudi version : 0.12.1
-
Spark version : 3.2.2
-
Hive version : 2.3.5
-
Hadoop version : 2.7.7
-
Storage (HDFS/S3/GCS..) : GCS
-
Running on Docker? (yes/no) : yes
Additional context
config:
cleaner config
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
#metadata table
hoodie.metadata.index.bloom.filter.enable=false
hoodie.metadata.index.column.stats.enable=false
#Single writer with async table services
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
Add any other context about the problem here.
Stacktrace
22/12/02 08:39:31 INFO pool-31-thread-1 BaseHoodieWriteClient: Async cleaner has been spawned. Waiting for it to finish
22/12/02 08:39:31 INFO pool-31-thread-1 AsyncCleanerService: Waiting for async clean service to finish
22/12/02 08:39:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:39:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:39:55 INFO dispatcher-BlockManagerMaster BlockManagerInfo: Removed broadcast_48_piece0 on hudi-prod-data-mor-b17eab84d1f75c1f-driver-svc.spark-jobs.svc:7079 in memory (size: 36.2 KiB, free: 1663.2 MiB)
22/12/02 08:39:55 INFO dispatcher-BlockManagerMaster BlockManagerInfo: Removed broadcast_48_piece0 on 10.207.18.169:46689 in memory (size: 36.2 KiB, free: 1048.4 MiB)
22/12/02 08:39:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:40:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:40:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:40:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:40:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:40:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:40:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:41:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:41:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:41:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:41:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:41:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:41:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:42:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:42:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:42:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:42:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:42:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:42:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:43:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:43:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:43:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:43:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:43:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:43:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:44:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:44:12 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 FAILED_TO_ACQUIRE in-process lock.
22/12/02 08:44:12 INFO pool-36-thread-1 LockManager: Retrying to acquire lock...
22/12/02 08:44:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:44:22 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 ACQUIRING in-process lock.
22/12/02 08:44:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:44:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:44:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:44:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:45:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:45:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:45:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:45:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:45:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:45:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:46:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:46:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:46:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:46:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:46:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:46:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:47:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:47:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:47:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:47:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:47:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:47:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:48:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:48:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:48:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:48:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:48:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:48:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:49:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:49:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:49:22 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 FAILED_TO_ACQUIRE in-process lock.
22/12/02 08:49:22 INFO pool-36-thread-1 LockManager: Retrying to acquire lock...
22/12/02 08:49:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:49:32 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 ACQUIRING in-process lock.
22/12/02 08:49:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:49:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:49:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:50:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:50:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:50:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:50:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:50:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:50:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:51:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:51:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:51:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:51:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:51:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:51:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:52:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:52:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:52:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:52:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:52:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:52:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:53:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:53:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:53:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:53:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:53:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:53:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:54:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:54:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:54:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:54:32 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 FAILED_TO_ACQUIRE in-process lock.
22/12/02 08:54:32 INFO pool-36-thread-1 LockManager: Retrying to acquire lock...
22/12/02 08:54:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:54:42 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 ACQUIRING in-process lock.
22/12/02 08:54:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:54:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:55:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:55:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:55:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:55:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:55:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:55:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:56:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:56:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:56:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:56:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:56:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:56:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:57:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:57:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:57:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:57:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:57:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:57:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:58:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:58:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:58:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:58:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:58:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:58:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:59:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:59:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:59:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:59:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:59:42 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 FAILED_TO_ACQUIRE in-process lock.
22/12/02 08:59:42 INFO pool-36-thread-1 LockManager: Retrying to acquire lock...
22/12/02 08:59:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 08:59:52 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 ACQUIRING in-process lock.
22/12/02 08:59:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:00:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:00:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:00:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:00:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:00:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:00:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:01:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:01:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:01:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:01:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:01:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:01:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:02:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:02:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:02:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:02:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:02:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:02:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:03:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:03:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:03:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:03:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:03:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:03:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:04:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:04:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:04:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:04:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:04:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:04:52 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 FAILED_TO_ACQUIRE in-process lock.
22/12/02 09:04:52 INFO pool-36-thread-1 LockManager: Retrying to acquire lock...
22/12/02 09:04:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:05:02 INFO pool-36-thread-1 InProcessLockProvider: Thread pool-36-thread-1 ACQUIRING in-process lock.
22/12/02 09:05:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:05:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:05:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:05:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:05:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:05:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:06:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:06:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:06:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:06:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:06:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:06:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:07:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:07:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:07:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:07:37 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:07:47 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:07:57 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:08:07 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:08:17 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
22/12/02 09:08:27 INFO async_compact_thread-thread-1 HoodieAsyncService: Waiting for next instant up to 10 seconds
@nsivabalan have you already looked into this? related to rollback and cleaner entanglement under lazy mode.
any news on this? I am using hudi 0.14.1 on aws glue and getting from time to time the following error that seems to be related to this issue: Error waiting for async clean service to finish
spark_df.write.format('hudi').options(**hudi_final_settings).mode('Append').save()
File "/opt/amazon/spark/python/lib/pyspark.zip/pyspark/sql/readwriter.py", line 966, in save
self._jwrite.save()
File "/opt/amazon/spark/python/lib/py4j-0.10.9.5-src.zip/py4j/java_gateway.py", line 1321, in __call__
return_value = get_return_value(
File "/opt/amazon/spark/python/lib/pyspark.zip/pyspark/sql/utils.py", line 190, in deco
return f(*a, **kw)
File "/opt/amazon/spark/python/lib/py4j-0.10.9.5-src.zip/py4j/protocol.py", line 326, in get_return_value
raise Py4JJavaError(
py4j.protocol.Py4JJavaError: An error occurred while calling o169.save.
: org.apache.hudi.exception.HoodieException: Error waiting for async clean service to finish
at org.apache.hudi.async.AsyncCleanerService.waitForCompletion(AsyncCleanerService.java:77)
at org.apache.hudi.client.BaseHoodieTableServiceClient.asyncClean(BaseHoodieTableServiceClient.java:133)
at org.apache.hudi.client.BaseHoodieWriteClient.autoCleanOnCommit(BaseHoodieWriteClient.java:595)
at org.apache.hudi.client.BaseHoodieWriteClient.mayBeCleanAndArchive(BaseHoodieWriteClient.java:579)
at org.apache.hudi.client.BaseHoodieWriteClient.commitStats(BaseHoodieWriteClient.java:248)
at org.apache.hudi.client.SparkRDDWriteClient.commit(SparkRDDWriteClient.java:104)
at org.apache.hudi.HoodieSparkSqlWriterInternal.commitAndPerformPostOperations(HoodieSparkSqlWriter.scala:1081)
at org.apache.hudi.HoodieSparkSqlWriterInternal.writeInternal(HoodieSparkSqlWriter.scala:520)
at org.apache.hudi.HoodieSparkSqlWriterInternal.write(HoodieSparkSqlWriter.scala:204)
at org.apache.hudi.HoodieSparkSqlWriter$.write(HoodieSparkSqlWriter.scala:121)
at org.apache.hudi.DefaultSource.createRelation(DefaultSource.scala:150)
at org.apache.spark.sql.execution.datasources.SaveIntoDataSourceCommand.run(SaveIntoDataSourceCommand.scala:45)
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:103)
at org.apache.spark.sql.catalyst.QueryPlanningTracker$.withTracker(QueryPlanningTracker.scala:107)
at org.apache.spark.sql.execution.SQLExecution$.withTracker(SQLExecution.scala:224)
at org.apache.spark.sql.execution.SQLExecution$.executeQuery$1(SQLExecution.scala:114)
at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$7(SQLExecution.scala:139)
at org.apache.spark.sql.catalyst.QueryPlanningTracker$.withTracker(QueryPlanningTracker.scala:107)
at org.apache.spark.sql.execution.SQLExecution$.withTracker(SQLExecution.scala:224)
at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$6(SQLExecution.scala:139)
at org.apache.spark.sql.execution.SQLExecution$.withSQLConfPropagated(SQLExecution.scala:245)
at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$1(SQLExecution.scala:138)
at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:779)
at org.apache.spark.sql.execution.SQLExecution$.withNewExecutionId(SQLExecution.scala:68)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.applyOrElse(QueryExecution.scala:100)
at org.apache.spark.sql.execution.QueryExecution$$anonfun$eagerlyExecuteCommands$1.applyOrElse(QueryExecution.scala:96)
at org.apache.spark.sql.catalyst.trees.TreeNode.$anonfun$transformDownWithPruning$1(TreeNode.scala:615)
at org.apache.spark.sql.catalyst.trees.CurrentOrigin$.withOrigin(TreeNode.scala:177)
at org.apache.spark.sql.catalyst.trees.TreeNode.transformDownWithPruning(TreeNode.scala:615)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.org$apache$spark$sql$catalyst$plans$logical$AnalysisHelper$$super$transformDownWithPruning(LogicalPlan.scala:30)
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:30)
at org.apache.spark.sql.catalyst.plans.logical.LogicalPlan.transformDownWithPruning(LogicalPlan.scala:30)
at org.apache.spark.sql.catalyst.trees.TreeNode.transformDown(TreeNode.scala:591)
at org.apache.spark.sql.execution.QueryExecution.eagerlyExecuteCommands(QueryExecution.scala:96)
at org.apache.spark.sql.execution.QueryExecution.commandExecuted$lzycompute(QueryExecution.scala:83)
at org.apache.spark.sql.execution.QueryExecution.commandExecuted(QueryExecution.scala:81)
at org.apache.spark.sql.execution.QueryExecution.assertCommandExecuted(QueryExecution.scala:124)
at org.apache.spark.sql.DataFrameWriter.runCommand(DataFrameWriter.scala:860)
at org.apache.spark.sql.DataFrameWriter.saveToV1Source(DataFrameWriter.scala:390)
at org.apache.spark.sql.DataFrameWriter.saveInternal(DataFrameWriter.scala:363)
at org.apache.spark.sql.DataFrameWriter.save(DataFrameWriter.scala:247)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at py4j.reflection.MethodInvoker.invoke(MethodInvoker.java:244)
at py4j.reflection.ReflectionEngine.invoke(ReflectionEngine.java:357)
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.lang.Thread.run(Thread.java:750)
Caused by: java.util.concurrent.ExecutionException: org.apache.hudi.exception.HoodieException: Failed to apply clean commit to metadata
at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1908)
at org.apache.hudi.async.HoodieAsyncService.waitForShutdown(HoodieAsyncService.java:103)
at org.apache.hudi.async.AsyncCleanerService.waitForCompletion(AsyncCleanerService.java:75)
... 57 more
Caused by: org.apache.hudi.exception.HoodieException: Failed to apply clean commit to metadata
at org.apache.hudi.table.action.BaseActionExecutor.writeTableMetadata(BaseActionExecutor.java:91)
at org.apache.hudi.table.action.clean.CleanActionExecutor.runClean(CleanActionExecutor.java:227)
at org.apache.hudi.table.action.clean.CleanActionExecutor.runPendingClean(CleanActionExecutor.java:193)
at org.apache.hudi.table.action.clean.CleanActionExecutor.execute(CleanActionExecutor.java:263)
at org.apache.hudi.table.HoodieSparkCopyOnWriteTable.clean(HoodieSparkCopyOnWriteTable.java:291)
at org.apache.hudi.client.BaseHoodieTableServiceClient.clean(BaseHoodieTableServiceClient.java:763)
at org.apache.hudi.client.BaseHoodieWriteClient.clean(BaseHoodieWriteClient.java:862)
at org.apache.hudi.client.BaseHoodieWriteClient.clean(BaseHoodieWriteClient.java:835)
at org.apache.hudi.async.AsyncCleanerService.lambda$startService$0(AsyncCleanerService.java:55)
at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
... 1 more
Caused by: java.lang.IllegalArgumentException
at org.apache.hudi.common.util.ValidationUtils.checkArgument(ValidationUtils.java:33)
at org.apache.hudi.common.table.timeline.HoodieActiveTimeline.transitionState(HoodieActiveTimeline.java:618)
at org.apache.hudi.common.table.timeline.HoodieActiveTimeline.transitionState(HoodieActiveTimeline.java:599)
at org.apache.hudi.common.table.timeline.HoodieActiveTimeline.saveAsComplete(HoodieActiveTimeline.java:224)
at org.apache.hudi.table.action.commit.BaseSparkCommitActionExecutor.commit(BaseSparkCommitActionExecutor.java:311)
at org.apache.hudi.table.action.commit.BaseCommitActionExecutor.autoCommit(BaseCommitActionExecutor.java:201)
at org.apache.hudi.table.action.commit.BaseCommitActionExecutor.commitOnAutoCommit(BaseCommitActionExecutor.java:183)
at org.apache.hudi.table.action.commit.BaseSparkCommitActionExecutor.updateIndexAndCommitIfNeeded(BaseSparkCommitActionExecutor.java:279)
at org.apache.hudi.table.action.commit.BaseSparkCommitActionExecutor.execute(BaseSparkCommitActionExecutor.java:184)
at org.apache.hudi.table.action.deltacommit.SparkUpsertPreppedDeltaCommitActionExecutor.execute(SparkUpsertPreppedDeltaCommitActionExecutor.java:44)
at org.apache.hudi.table.HoodieSparkMergeOnReadTable.upsertPrepped(HoodieSparkMergeOnReadTable.java:126)
at org.apache.hudi.table.HoodieSparkMergeOnReadTable.upsertPrepped(HoodieSparkMergeOnReadTable.java:88)
at org.apache.hudi.client.SparkRDDWriteClient.upsertPreppedRecords(SparkRDDWriteClient.java:156)
at org.apache.hudi.client.SparkRDDWriteClient.upsertPreppedRecords(SparkRDDWriteClient.java:63)
at org.apache.hudi.metadata.HoodieBackedTableMetadataWriter.commitInternal(HoodieBackedTableMetadataWriter.java:1099)
at org.apache.hudi.metadata.SparkHoodieBackedTableMetadataWriter.commit(SparkHoodieBackedTableMetadataWriter.java:117)
at org.apache.hudi.metadata.HoodieBackedTableMetadataWriter.processAndCommit(HoodieBackedTableMetadataWriter.java:810)
at org.apache.hudi.metadata.HoodieBackedTableMetadataWriter.update(HoodieBackedTableMetadataWriter.java:899)
at org.apache.hudi.table.action.BaseActionExecutor.writeTableMetadata(BaseActionExecutor.java:86)
... 12 more
