cbomgit opened a new issue, #13090: URL: https://github.com/apache/hudi/issues/13090
**Describe the problem you faced** We have a process that ingests 100 - 130GB of data per day into a COW table partitioned on year/month/day. The key is timestamp_eventId_skuNumber. A single batch may contain events that span up to 14 event dates (meaning we fan out to up to 14 partitions). Our write operation is an UPSERT in order to not have duplicates in the table. For some input batches, we see very long index lookup times (3 - 10 hours), with large shuffle writes and reads (10 - 25 TB).   When I look at the tasks, it seems like each task is reading in a large amount of data, requiring us to create clusters with 1 executor per node. See the following task list:  When I look at the tasks that take the longest, I see the following types of log statements: ``` 2025-04-04 04:35:01,928 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView: Sending request : (http://ip-10-0-133-87.ec2.internal:43393/v1/hoodie/view/datafile/latest/partition?partition=region%3DNA%2Fyear%3D2025%2Fmonth%3D03%2Fday%3D16&basepath=s3%3A%2F%2Fmads-ms-conversions-prod%2Fdaily-data%2Fglider&fileid=85460a75-3674-412c-8bec-36ea8a4345e7-0&lastinstantts=20250403234937872&timelinehash=30ed4d42429b272930e0456aba07ccac0e1b20f0cd421dab56afb2f1b6126952) 2025-04-04 04:35:01,967 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.io.HoodieKeyLookupHandle: Total records (7915696), bloom filter candidates (0)/fp(0), actual matches (0) 2025-04-04 04:35:01,967 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView: Sending request : (http://ip-10-0-133-87.ec2.internal:43393/v1/hoodie/view/datafile/latest/partition?partition=region%3DNA%2Fyear%3D2025%2Fmonth%3D03%2Fday%3D06&basepath=s3%3A%2F%2Fmads-ms-conversions-prod%2Fdaily-data%2Fglider&fileid=a9c2acd3-8dde-4d15-b0d8-458cd8847242-0&lastinstantts=20250403234937872&timelinehash=30ed4d42429b272930e0456aba07ccac0e1b20f0cd421dab56afb2f1b6126952) 2025-04-04 04:35:02,388 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) com.amazon.ws.emr.hadoop.fs.s3n.S3NativeFileSystem: Opening 's3://mads-ms-conversions-prod/daily-data/glider/region=NA/year=2025/month=03/day=06/a9c2acd3-8dde-4d15-b0d8-458cd8847242-0_2-2066-1095662_20250327160656670.parquet' for reading 2025-04-04 04:35:03,035 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.io.HoodieKeyLookupHandle: Read bloom filter from (region=NA/year=2025/month=03/day=06,a9c2acd3-8dde-4d15-b0d8-458cd8847242-0) in 1068 ms 2025-04-04 04:35:03,808 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView: Sending request : (http://ip-10-0-133-87.ec2.internal:43393/v1/hoodie/view/datafile/latest/partition?partition=region%3DNA%2Fyear%3D2025%2Fmonth%3D03%2Fday%3D06&basepath=s3%3A%2F%2Fmads-ms-conversions-prod%2Fdaily-data%2Fglider&fileid=a9c2acd3-8dde-4d15-b0d8-458cd8847242-0&lastinstantts=20250403234937872&timelinehash=30ed4d42429b272930e0456aba07ccac0e1b20f0cd421dab56afb2f1b6126952) 2025-04-04 04:35:03,847 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.io.HoodieKeyLookupHandle: Total records (17873), bloom filter candidates (0)/fp(0), actual matches (0) 2025-04-04 04:35:03,847 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView: Sending request : (http://ip-10-0-133-87.ec2.internal:43393/v1/hoodie/view/datafile/latest/partition?partition=region%3DNA%2Fyear%3D2025%2Fmonth%3D03%2Fday%3D09&basepath=s3%3A%2F%2Fmads-ms-conversions-prod%2Fdaily-data%2Fglider&fileid=df7becfe-2b4d-4e91-bc2d-e23f3bc91aa9-0&lastinstantts=20250403234937872&timelinehash=30ed4d42429b272930e0456aba07ccac0e1b20f0cd421dab56afb2f1b6126952) 2025-04-04 04:35:04,099 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) com.amazon.ws.emr.hadoop.fs.s3n.S3NativeFileSystem: Opening 's3://mads-ms-conversions-prod/daily-data/glider/region=NA/year=2025/month=03/day=09/df7becfe-2b4d-4e91-bc2d-e23f3bc91aa9-0_2-1502-791157_20250327143233103.parquet' for reading 2025-04-04 04:35:04,726 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.io.HoodieKeyLookupHandle: Read bloom filter from (region=NA/year=2025/month=03/day=09,df7becfe-2b4d-4e91-bc2d-e23f3bc91aa9-0) in 879 ms 2025-04-04 04:35:05,905 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView: Sending request : (http://ip-10-0-133-87.ec2.internal:43393/v1/hoodie/view/datafile/latest/partition?partition=region%3DNA%2Fyear%3D2025%2Fmonth%3D03%2Fday%3D09&basepath=s3%3A%2F%2Fmads-ms-conversions-prod%2Fdaily-data%2Fglider&fileid=df7becfe-2b4d-4e91-bc2d-e23f3bc91aa9-0&lastinstantts=20250403234937872&timelinehash=30ed4d42429b272930e0456aba07ccac0e1b20f0cd421dab56afb2f1b6126952) 2025-04-04 04:35:05,952 [INFO] (Executor task launch worker for task 0.0 in stage 32.0 (TID 66836)) org.apache.hudi.io.HoodieKeyLookupHandle: Total records (27262), bloom filter candidates (0)/fp(0), actual matches (0) ``` It seems to me like something isn't working correctly with our index, but I'm having trouble understanding what exactly is going on in order to help me tune our settings correctly. The following settings are being used for our job: ``` Computed insert options: hoodie.datasource.write.insert.drop.duplicates -> false hoodie.parquet.small.file.limit -> 104857600 hoodie.copyonwrite.record.size.estimate -> 106 hoodie.insert.shuffle.parallelism -> 12000 hoodie.datasource.write.precombine.field -> eventVersion hoodie.bloom.index.filter.dynamic.max.entries -> 1270220 hoodie.cleaner.fileversions.retained -> 2 hoodie.parquet.max.file.size -> 134217728 hoodie.cleaner.parallelism -> 12000 hoodie.write.lock.client.num_retries -> 10 hoodie.bloom.index.prune.by.ranges -> true hoodie.metadata.enable -> true hoodie.clean.automatic -> false hoodie.datasource.write.operation -> UPSERT hoodie.write.lock.wait_time_ms -> 600000 hoodie.metrics.reporter.type -> CLOUDWATCH hoodie.datasource.write.recordkey.field -> timestamp,eventId,trackedItem hoodie.table.name -> ****** hoodie.datasource.write.table.type -> COPY_ON_WRITE hoodie.datasource.write.hive_style_partitioning -> true hoodie.write.lock.dynamodb.partition_key -> ****** hoodie.cleaner.policy -> KEEP_LATEST_FILE_VERSIONS hoodie.write.markers.type -> DIRECT hoodie.metrics.on -> false hoodie.datasource.write.reconcile.schema -> true hoodie.datasource.write.keygenerator.class -> org.apache.hudi.keygen.ComplexKeyGenerator hoodie.cleaner.policy.failed.writes -> LAZY hoodie.upsert.shuffle.parallelism -> 12000 hoodie.write.lock.dynamodb.table -> HoodieLockTable hoodie.write.lock.provider -> org.apache.hudi.aws.transaction.lock.DynamoDBBasedLockProvider hoodie.datasource.write.partitionpath.field -> region,year,month,day hoodie.bloom.index.filter.type -> DYNAMIC_V0 hoodie.write.lock.wait_time_ms_between_retry -> 30000 hoodie.write.concurrency.mode -> optimistic_concurrency_control hoodie.write.lock.dynamodb.region -> us-east-1 ``` We're using a **To Reproduce** Steps to reproduce the behavior: I'm unclear on how to fully reproduce, some batches of data ingest quickly (20 - 30 min), others take 3 - 10 hours. A couple of questions on my end are: 1. How can we better inspect the index behavior and verify it's doing the right thing? 2. Is there a way to log more verbose logs related to index behavior? 3. Would we be better off backing off to a SIMPLE BLOOM or just a SIMPLE INDEX? **Expected behavior** A clear and concise description of what you expected to happen. **Environment Description** * Hudi version : 11.1 * Spark version : 3.2.1 * Hive version : 3.1.3 * Hadoop version : 3.2.1 * Storage (HDFS/S3/GCS..) : s3 * Running on Docker? (yes/no) : no -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
