Skip to content

support pass extensions for plan logging and profiling per optimization pass#74

Open
yliang412 wants to merge 11 commits into
mainfrom
yuchen/pass-hooks
Open

support pass extensions for plan logging and profiling per optimization pass#74
yliang412 wants to merge 11 commits into
mainfrom
yuchen/pass-hooks

Conversation

@yliang412
Copy link
Copy Markdown
Member

@yliang412 yliang412 commented Apr 28, 2026

Problem

The optd rewrite and optimization phases were hard-coded in Cascades::optimize, which made them difficult to observe or instrument. EXPLAIN only showed a limited before/after view, and there was no systematic way to collect per-phase plan snapshots or timing metrics.

Summary of changes

  • Added a generic PlanPass / PassExtension / PassManager framework in optd-core.
  • Converted decorrelation and simplification into named PlanPass implementations.
  • Added async phase support in PassManager so the memo-based cascades phase can use the same extension hooks.
  • Wired Cascades through PassManager, including reverse-order after_pass callbacks so extensions behave like proper around hooks.
  • Added ExplainPassExtension in the DataFusion planner to record optd plans after each named phase.
  • Added physical_plan after optd-cascades to EXPLAIN output and removed the redundant physical_plan after optd-finalized row.
  • Updated planner test snapshot filtering to include all logical_plan after optd-* and physical_plan after optd-* sections.
  • Added runtime pass profiling via SET optd.profile_passes = true.
  • Moved profiling into optd/core/src/rules/profile.rs so tracing uses the default optd_core::rules::profile target.
  • Emitted profiling metrics through tracing with structured fields for pass name, changed flag, elapsed time, total time, and invocation count.
  • Regenerated planner snapshots to include the new per-phase explain sections.

Example: Profiling Tracing Output

RUST_LOG=optd_core::rules::profile=info cargo run --bin planner_test_apply -- tpch::q3 -- --exact
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.18s
     Running `target/debug/planner_test_apply 'tpch::q3' -- --exact`
2026-04-28T16:55:39.305964Z  INFO optd_core::rules::profile: optimizer pass profile pass="decorrelation" changed=false elapsed_ms=0.0179 total_ms=0.0179 invocations=1
2026-04-28T16:55:39.306993Z  INFO optd_core::rules::profile: optimizer pass profile pass="simplification" changed=true elapsed_ms=0.473 total_ms=0.473 invocations=1
2026-04-28T16:55:39.309540Z  INFO optd_core::rules::profile: optimizer pass profile pass="cascades" changed=true elapsed_ms=2.25 total_ms=2.25 invocations=1

(The log actually get print twice, because we plan the query twice, once for planning, once for execution)

Future work

  • Consider whether cascades should become a first-class pass abstraction instead of using async phase hooks.

@yliang412 yliang412 changed the title Yuchen/pass hooks allow pass hooks for per pass plan logging and profiling Apr 28, 2026
@yliang412 yliang412 changed the title allow pass hooks for per pass plan logging and profiling support pass extensions for optimization time plan logging and profiling per pass Apr 28, 2026
Signed-off-by: Yuchen Liang <yuchenl3@andrew.cmu.edu>
Signed-off-by: Yuchen Liang <yuchenl3@andrew.cmu.edu>
@yliang412 yliang412 changed the title support pass extensions for optimization time plan logging and profiling per pass support pass extensions for plan logging and profiling per optimization pass Apr 28, 2026
Signed-off-by: Yuchen Liang <yuchenl3@andrew.cmu.edu>
@yliang412 yliang412 marked this pull request as ready for review April 28, 2026 15:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant