Step 3: Execution Path Analysis

You have a failing test. Now you map the exact path the request takes — from TezClient.submitDAG() through every dispatcher hop and state transition — until the wrong thing happens. Not a sketch. Not "it goes through the vertex somewhere." The actual chain of class#method hops, each cited, that you could read aloud while a committer nods along.

The rule that governs this step: you must be able to point at one hop and say "the state is correct above this hop and wrong below it." Until you can, you are still guessing, and a wrong map produces a wrong root cause in Step 4.

Budget: 2–4 evenings. The work is reading code, grep, running the repro under probes, and drawing.

This step produces three artifacts, all under capstone-work/execution-path/:

1. path-skeleton.md — an annotated hop table, top to bottom, each hop a class#method with a citation against your checkout.
2. path.mmd — the same path as a mermaid diagram, with exactly one styled bug node.
3. probe-trace.txt — the grep output from a probe run that confirms the map empirically, plus notes.md with the surprises you found.

The canonical submit path

Every DAG that fails crossed this skeleton before it failed. Learn it as the reference axis — you locate your bug as a deviation from it. The classes are real; run the grep under each to open the method on your own checkout (line numbers move, class#method does not).

TezClient.submitDAG(DAG)
    tez-api/.../client/TezClient.java
        |  session vs. non-session branch inside submitDAG
        v
DAGClientHandler.submitDAG(...)
    tez-dag/.../dag/api/client/DAGClientHandler.java
        |
        v
DAGAppMaster.startDAG(...)  / submitDAGToAppMaster(...)
    tez-dag/.../dag/app/DAGAppMaster.java
        |  builds DAGImpl, emits DAGEventType.DAG_INIT
        v
AsyncDispatcher.dispatch(Event)
    tez-common/.../common/AsyncDispatcher.java   <-- note: tez-common, not tez-dag
        |
        v
DAGImpl.handle(DAGEvent)          NEW --DAG_INIT--> INITED, then --DAG_START--> RUNNING
    tez-dag/.../dag/app/dag/impl/DAGImpl.java
        |  for each Vertex: emits VertexEventType.V_INIT
        v
VertexImpl.handle(VertexEvent)    NEW --V_INIT--> INITIALIZING --V_INITED--> INITED
    tez-dag/.../dag/app/dag/impl/VertexImpl.java   --V_START--> RUNNING
        |  invokes VertexManagerPlugin, schedules TaskImpl T_SCHEDULE events
        v
TaskImpl.handle(TaskEvent)        NEW --T_SCHEDULE--> SCHEDULED
    tez-dag/.../dag/app/dag/impl/TaskImpl.java
        |  spawns a TaskAttemptImpl, emits TA_SCHEDULE
        v
TaskAttemptImpl.handle(...)       NEW --TA_SCHEDULE--> START_WAIT
    tez-dag/.../dag/app/dag/impl/TaskAttemptImpl.java
        |  requests a container from the scheduler
        v
TaskSchedulerManager / YarnTaskSchedulerService / DagAwareYarnTaskScheduler
    tez-dag/.../dag/app/rm/
        |  assigns a container; TaskAttemptImpl START_WAIT --TA_STARTED_REMOTELY--> RUNNING
        v
[ container process boots ]
TezTaskRunner2.run()
    tez-runtime-internals/.../runtime/task/TezTaskRunner2.java
        |
        v
LogicalIOProcessorRuntimeTask.run()
    tez-runtime-internals/.../runtime/LogicalIOProcessorRuntimeTask.java
        |  initializes Inputs/Outputs/Processor, calls Processor.run(...)
        v
[ user processor runs; shuffle via ShuffleManager / Fetcher if there is an input edge ]
        |
        v
heartbeat -> TaskCommunicatorManager -> TaskAttemptImpl TA_DONE / TA_FAILED

That is the highway. Your bug is at one exit.

Tracing techniques, ranked

Use them in this order. The cheaper technique is not just faster — it perturbs the system less, which matters enormously for races.

1. IDE debugger in local mode (first choice for non-races)

A path you stepped through is a fact; a path you reasoned about is a hypothesis. The cheapest way to step through Tez is to debug your repro test directly — it is faster and more isolated than a whole cluster. Maven surefire will suspend for a remote debugger:

mvn test -pl tez-dag -Dtest=TestVertexImplTezNNNNRepro \
  -Dmaven.surefire.debug   # suspends the test JVM on port 5005

Attach IntelliJ (Run → Edit Configurations → + → Remote JVM Debug, localhost:5005). Set a breakpoint on the handler your path analysis fingered. Use a conditional breakpoint to skip the hundreds of unrelated events — right-click the breakpoint → Condition, e.g. getState() == VertexState.RUNNING or event.getType() == V_TASK_COMPLETED. Once stopped, the Frames panel is your execution path, authoritatively — walk up it with Shift+F8, re-evaluating the value the JIRA is about at each frame. The frame where it flips from correct to wrong is your defect site. Screenshot the stack; it goes straight into your Step 3 doc.

For an end-to-end bug, debug the whole node in local mode instead — set TEZ_LOCAL_MODE=true (see the local-mode deep dive) so the AM and tasks run in one debuggable JVM.

2. Targeted logging patches kept in a scratch commit

When the bug is timing-dependent — a race — a breakpoint is the wrong tool: stopping the thread changes the interleaving and the bug vanishes (a Heisenbug). Then you log. Add temporary probes at the hops you think the event traverses, and keep them in a scratch commit you never push:

// Inside the handler you suspect, in VertexImpl.java:
private static final Logger LOG = LoggerFactory.getLogger(VertexImpl.class);
LOG.info("PROBE-TEZNNNN: V_TASK_COMPLETED for vertex={} state={} completedTasks={}",
    getName(), getState(), getCompletedTaskCount());

Rules for probes: prefix every one with PROBE-TEZ<NNNN> so you grep them in one pass and delete them in one pass; use LOG.info (not debug) so they appear without touching log config; include the field values you care about. Never commit probes to your fix branch — they are scaffolding. Keep them on a separate probe branch.

mvn test -pl tez-dag -Dtest=TestVertexImplTezNNNNRepro -q 2>&1 \
  | grep "PROBE-TEZNNNN" | tee capstone-work/execution-path/probe-trace.txt

3. log4j level surgery per package

Before you write a single probe, turn the packages you care about up to DEBUG and read what the code already logs — Tez's state machines are chatty. Edit the module's src/test/resources/log4j.properties (see Step 2 for the snippet). The real package roots you will target, by bug class:

4. Reading state-machine transitions from logs

The single highest-signal line Tez emits is the state transition. Every impl logs " transitioned from " when its state changes. Grep the surefire report and you have the transition trace for free — no probes required:

grep -h "transitioned from" tez-dag/target/surefire-reports/*.txt
# VertexImpl: vertex_..._v1 transitioned from RUNNING to FAILED due to event V_INTERNAL_ERROR
# TaskAttemptImpl: attempt_..._0 transitioned from RUNNING to FAILED

Read it top to bottom; the line where a state stops matching your expectation names the class and the event. Grep the class for that event's transition registration (grep -nE "addTransition|stateMachineFactory" <impl>.java) to find the handler.

Read the transition table from source

The log tells you which transition fired; the source tells you what it was allowed to do. Tez state machines are built from a stateMachineFactory with one addTransition call per legal (state, event) pair — the transition table is the machine's whole contract, and reading it is the fastest way to see whether your bug is "an event fired a handler that did the wrong thing" or "an event arrived in a state where it should have been illegal but wasn't." Dump the table for your class:

grep -nE "addTransition|stateMachineFactory" \
  tez-dag/src/main/java/org/apache/tez/dag/app/dag/impl/VertexImpl.java | head -60

Each addTransition reads addTransition(FROM_STATE, TO_STATE(s), EVENT, Handler). Three shapes matter for bug hunting, and each points at a different defect class:

Find the addTransition line for the (state, event) pair your log fingered, open the named handler class (usually a nested private static class ...Transition), and that handler body is where Step 4's root cause lives. This is also how you tell a missing transition (event silently dropped, machine wedges) from a wrong one (event handled, wrong result): a wedge means there is no addTransition row for your (state, event) at all. The state-machine deep dive walks the full StateMachineFactory mechanics.

Locate your specific failure segment

The skeleton is the highway; use the repro logs to find your exit.

The deep dives map each segment in detail: event-routing, task-attempt-lifecycle, shuffle-sort, scheduler.

Build the path document

The deliverable is a hop table plus a diagram. Do both — they validate each other.

The hop-table template (path-skeleton.md)

Each row is one hop: the class#method, the file, the state transition (if any), and the observed value of the thing the bug is about. The Divergence column is the whole point — it is where the observed value stops matching the expected one.

# Execution path: TEZ-NNNN

## Checkout
- Traced on: master @ <sha from `git rev-parse HEAD`>, JDK 21

## Entry point
- TezClient.submitDAG(DAG)  ->  the repro's submit call

## Hop table (top to bottom)
| # | class#method | file | transition / action | observed state | expected |
|---|---|---|---|---|---|
| 1 | DAGImpl#handle | dag/impl/DAGImpl.java | NEW --DAG_INIT--> INITED | ok | ok |
| 2 | VertexImpl#handle | dag/impl/VertexImpl.java | INITED --V_START--> RUNNING | ok | ok |
| 3 | VertexImpl#<TaskCompletedTransition> | dag/impl/VertexImpl.java | on V_TASK_COMPLETED | completedTasks=N | =N |
| 4 | VertexImpl#<RouteEventTransition> | dag/impl/VertexImpl.java | on V_ROUTE_EVENT | **recoveryData read as null** | non-null | <- DIVERGES
| 5 | VertexImpl#tryEnactKill / commit path | dag/impl/VertexImpl.java | RUNNING --> FAILED | FAILED | SUCCEEDED |

## Divergence
- Hop 4: recoveryData is null here but the JIRA's scenario requires it to be set.
  Correct above hop 4 (task accounting fine); wrong at/below (vertex fails).

## Observation point
- class#method to break on: VertexImpl#<the transition handling V_ROUTE_EVENT>
- What is correct above: completed-task count is accurate
- What is wrong below: the vertex transitions to FAILED instead of SUCCEEDED

## How confirmed
- [x] Conditional breakpoint hit; Frames panel screenshot attached
- [x] PROBE-TEZNNNN trace shows V_TASK_COMPLETED arriving before V_ROUTE_EVENT

Cite class#method from your checkout. Do not write line numbers into the doc — they rot between branches and mislead the reviewer. If you want a line for your own navigation, keep it in a scratch file, not the artifact.

The mermaid diagram (path.mmd)

Same path, visual, with exactly one styled bug node. This goes into the PR and the write-up; it is proof you read the code instead of paraphrasing the JIRA.

sequenceDiagram
    participant C as Client
    participant AM as DAGAppMaster
    participant D as DAGImpl
    participant V as VertexImpl v1
    participant T as TaskImpl t0
    participant TA as TaskAttempt t0.0

    C->>AM: submitDAG
    AM->>D: DAG_INIT / DAG_START
    D->>V: V_INIT / V_START
    V->>T: T_SCHEDULE
    T->>TA: TA_SCHEDULE
    Note over TA: container assigned + launched
    TA->>TA: START_WAIT -> RUNNING
    TA-->>V: last task V_TASK_COMPLETED
    Note over V: BUG: V_TASK_COMPLETED processed<br/>before V_ROUTE_EVENT; recoveryData null
    V->>V: RUNNING -> FAILED

Render it before you commit it — paste into mermaid.live or mdbook serve — so a syntax error does not ship in your PR.

Using tests as tracers

You do not have to invent a driver to step through the code. The nearest Test* class already builds the collaborators and drives the machine — run it under the debugger and step through. Find the tracer for your segment:

# Which test drives the class your bug lives in?
grep -ln "class TestVertexImpl\|class TestTaskImpl\|class TestTaskAttempt" \
  tez-dag/src/test/java/org/apache/tez/dag/app/dag/impl/*.java

# Run the nearest existing test method under the debugger and step through its handle() calls.
mvn test -pl tez-dag -Dtest='TestVertexImpl#test<nearestScenario>' -Dmaven.surefire.debug

Stepping through an existing passing test that exercises your segment teaches you the normal path; your repro test teaches you the broken one. The diff between the two stack walks is your root cause, handed to you.

Verify empirically, then reconcile

The map is a hypothesis until the probe trace confirms it. Compare probe-trace.txt to your hop table. The discrepancies are the most valuable output of this whole step — they are exactly where your mental model differs from the code. Watch for:

• "I thought this handler ran once. It ran three times." — re-entrancy.
• "I thought events arrived A, B, C. They arrived B, A, C." — async reordering, the classic Tez race.
• "I thought the vertex was RUNNING. It was INITED." — wrong assumption about the state at the time the event fired.

When a probe surprises you, do not delete the probe — lean in. That surprise is the shortest path to Step 4. Record every surprise in capstone-work/execution-path/notes.md; if you have zero surprises, you did not look hard enough.

Before you leave this step, make sure your working tree is clean of scaffolding:

git diff | grep -n "PROBE-" && echo "REMOVE PROBES BEFORE COMMITTING FIX" || echo "clean"

Validation / Self-check

Before advancing to Step 4:

1. You can name, from memory, every state transition between TezClient.submitDAG() and your failure point.
2. Every hop in your table has a real class#method citation against your recorded checkout SHA — none hand-waved as "then it goes through the vertex somewhere," and no invented line numbers.
3. You confirmed the path with a debugger or with PROBE-TEZ<NNNN> logging — not by reading alone — and noted where it diverged from your map.
4. You can point at exactly one hop and say "correct above, wrong below."
5. notes.md records at least one surprise from the probe run.
6. The mermaid diagram renders without errors and styles exactly one bug node.
7. git diff contains no PROBE- lines; your working tree is clean of scaffolding.
8. You can answer in one sentence: which event, in which state, on which class, fires the handler that produces the failure?

Then go to Step 4: Root Cause Identification.