andygrove opened a new issue, #7467: URL: https://github.com/apache/datafusion-comet/issues/7467
## Describe the issue On TPC-DS q54, file opening (footer and page-index load) is almost the whole cost of the native Parquet scans, even with `spark.comet.parquet.prefetchNextFileMetadata.enabled=true` (#7094) and `spark.comet.parquet.metadataCache.sharedWithinStage.enabled=true`. Decoding is a small fraction. The query is short, so per-file latency adds up on its critical path. This is related to #7093 and #4994 but gives measurements on a specific query, so I'm filing it separately. ## Setup TPC-DS SF1000, Parquet with zstd, data in S3, 32 executors x 16 cores, Spark 4.2.0, Comet `718f2d6c` (1.3.0-SNAPSHOT). Comet is fully native for q54 with no fallbacks, and the plan has the same shape as Spark's (same sort-merge joins, same broadcasts, similar shuffle sizes). Executor off-heap 32G, `spark.comet.exec.memoryPool.fraction=0.8`. q54 per iteration (2 iterations, seconds): | Engine | q54 | |---|---| | Spark 4.2.0 | 3.9, 2.7 | | Comet 1.1.0 | 8.0, 5.7 | | Comet 1.2.0 | 5.9, 6.7 | | Comet 718f2d6c | 4.0, 4.1 | Comet is the slower of the two on this query, while it is faster overall across the suite. ## Scan metrics for q54 (summed over tasks, latest build) | Table | Files read | "Wall clock time elapsed for file opening" | "Wall clock time elapsed for data decompression + decoding" | |---|---|---|---| | store_sales | 440 | 26.7 s | 1.9 s | | catalog_sales | 80 | 21.4 s | 0.9 s | | web_sales | 93 | 16.6 s | 0.5 s | | customer | 88 | 10.0 s | n/a | | customer_address | 161 | 8.8 s | 0.3 s | For `store_sales`, "Total time spent reading and parsing metadata from the footer" is 26.6 s of a 29.5 s scan total, so about 90% of the scan time. The median per-task file-open time is 39 ms. Other `store_sales` metrics: - `Number of Parquet footer payloads read from storage` = 534 for 440 files read. Files that are split across tasks have their footer loaded once per range. - `Metadata loads read from storage ahead of the file's open and used by it` = 34, so the prefetch covers only about 6% of the loads. - `Serialized Parquet footer payload bytes read` = 2.5 MiB, while `Footer-prefetch, page-index, and Bloom-filter bytes returned to the reader` = 267 MiB. That is about 0.5 MiB fetched per load to obtain a footer of a few KiB. - `ObjectStore GET operations after range coalescing` = 1,376, versus 534 footer loads. - `Data bytes served from footer reads instead of new requests` = 0 (footer bytes are not reused by the first data read). ## Questions - Why does the next-file prefetch cover so few opens? Each task reads only a few files, so there may be little next-file work to overlap, or the prefetch may start too late. - Could the footer read be sized closer to the actual footer (or reuse a size hint from a previous file in the same table) instead of fetching 512 KiB each time? - Could the footer bytes already fetched serve the first data-page read when the row group sits in the tail? - For files split across tasks, could the footer load be shared within the stage so it is read once per file rather than once per range? I could not get stage-level timings for this run (the history server had evicted them), so I haven't confirmed that file open is on the critical path, only that it dominates the scan's task time. I'll add a per-stage breakdown if I can capture one. -- 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] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
