Logging & Debugging

Every training run writes structured outputs to log_path. This skill covers what's produced and how to use it.

Reference

• docs/rl/rl-logging.mdx — Complete file reference for RL training outputs
• tinker_cookbook/utils/ml_log.py — Metrics logging API
• tinker_cookbook/utils/logtree.py — Logtree (structured rollout transcripts)
• tinker_cookbook/utils/trace.py — Tracing/profiling (@scope, trace_iteration, Gantt charts)

Output files

Each training run writes to its log_path directory:

File	Format	Contents
metrics.jsonl	JSONL	Scalar metrics per training iteration
config.json	JSON	Full serialized training config (reproducibility)
checkpoints.jsonl	JSONL	Checkpoint metadata (paths, loop state for resume)
code.diff	text	Git diff at training start
train_iteration_NNNNNN.html	HTML	Human-readable logtree report
train_iteration_NNNNNN_logtree.json	JSON	Machine-readable rollout transcripts
train_iteration_NNNNNN_rollout_summaries.jsonl	JSONL	Per-trajectory rewards and metrics
eval_<name>_iteration_NNNNNN.*	mixed	Same formats for eval rollouts
timing_spans.jsonl	JSONL	Per-iteration span timing data (from trace_iteration)
trace_events.jsonl	JSONL	Perfetto/Chrome Trace format events (from trace_init)
gantt_NNNNNN.html	HTML	Plotly Gantt chart of span timeline (optional)

Iteration numbers are zero-padded to 6 digits.

Analyzing metrics

import pandas as pd

df = pd.read_json("path/to/log_path/metrics.jsonl", lines=True)
df.plot(x="progress/batch", y="env/all/reward/total")

Common metric keys

Progress:

• progress/batch — iteration index
• progress/done_frac — completion fraction

RL rewards:

• env/all/reward/total — mean total reward
• env/all/<metric> — env-emitted metrics (e.g., correct, format_parse)

Training health:

• entropy — per-token entropy
• kl_sample_train_v1, kl_sample_train_v2 — KL divergence (should stay < 0.01)
• optim/lr — current learning rate
• ac_tokens_per_turn — mean generated tokens per turn

Timing (from trace_iteration):

• time/total — iteration wall-clock duration
• time/<name> — single-call duration (e.g., time/train_step)
• time/<name>:total, time/<name>:count, time/<name>:mean, time/<name>:max — aggregates for functions called multiple times (e.g., time/sample_async:total)

Analyzing rollouts

Rollout summaries (aggregate)

import json

with open("train_iteration_000010_rollout_summaries.jsonl") as f:
    trajectories = [json.loads(line) for line in f]

for traj in trajectories:
    print(f"reward={traj['total_reward']:.2f}, metrics={traj['trajectory_metrics']}")
    # Each trajectory has: total_reward, final_reward, trajectory_metrics,
    # steps (list of {ob_len, ac_len, reward, episode_done, metrics})

Logtree JSON (full transcripts)

Contains full text of prompts, model responses, grading details. Walk the tree recursively looking for nodes with data.type == "conversation" to extract conversations. See docs/rl/rl-logging.mdx for the full schema.

HTML reports

Open train_iteration_NNNNNN.html in a browser for a human-readable view of rollouts with collapsible sections. num_groups_to_log (default: 4) controls how many trajectory groups get detailed logging.

Logging in your own code

Scalar metrics

from tinker_cookbook.utils import ml_log

# Set up logging (done once in training scripts)
ml_logger = ml_log.setup_logging(log_path="/tmp/my_run", wandb_project=None, wandb_name=None)

# Log scalar metrics
ml_logger.log_metrics({"train/loss": 0.5, "eval/accuracy": 0.85}, step=100)

Logtree (structured transcripts)

from tinker_cookbook.utils import logtree

with logtree.scope_header("my_section"):
    # Nested logging of rollouts, grading, etc.
    ...

Weights & Biases integration

Pass wandb_project and wandb_name in your config to enable W&B logging:

config = train.Config(
    wandb_project="my-project",
    wandb_name="my-experiment",
    ...
)

Tracing & profiling

The tinker_cookbook/utils/trace module provides per-iteration profiling across all training modules (RL, SL, DPO, distillation).

Core API

from tinker_cookbook.utils import trace

# Initialize Perfetto trace collector (optional — writes trace_events.jsonl)
trace.trace_init()

# In training loop — collect per-iteration timing
for i_batch in range(n_batches):
    with trace.trace_iteration(step=i_batch) as window:
        # All @scope-decorated calls are automatically recorded
        await gather_rollouts(...)
        await train_step(...)

    # Get timing metrics for this iteration
    metrics.update(window.get_timing_metrics())

    # Persist span data for post-hoc analysis
    window.write_spans_jsonl(log_path / "timing_spans.jsonl", step=i_batch)

    # Optional: Gantt chart visualization (requires plotly)
    trace.save_gantt_chart_html(window, i_batch, log_path / f"gantt_{i_batch}.html")

Instrumenting your code

from tinker_cookbook.utils import trace

# Decorator — automatically traces function calls
@trace.scope
async def my_training_step(tc, batch):
    result = await tc.forward_backward_async(data=batch, loss_fn="cross_entropy")
    return result

# Inline span — for timing a code block without a dedicated function
async with trace.scope_span("data_prep"):
    batch = prepare_next_batch(...)

# Sync variant
with trace.scope_span_sync("data_prep"):
    batch = prepare_next_batch(...)

@scope and scope_span are no-ops when called outside trace_iteration — safe to leave in production.

Viewing Perfetto traces

# Convert JSONL to JSON for visualization
uv run python -m tinker_cookbook.utils.trace trace_events.jsonl trace.json
# Open trace.json in chrome://tracing or https://ui.perfetto.dev/

Debugging tips

1. Training not improving: Check metrics.jsonl — is loss decreasing? Are rewards increasing?
2. KL divergence spiking: KL > 0.01 indicates instability. Lower the learning rate.
3. Reward stuck at 0: Check rollout summaries — are responses being parsed correctly?
4. OOM / timeout: Reduce batch_size, group_size, or max_tokens
5. Shrink workloads for debugging: Set small batch_size, group_size, and max_steps
6. Compare runs: Load multiple metrics.jsonl into a DataFrame and overlay plots