Developer Guide — TRACE Logging¶

1. Purpose¶

TRACE is Fontshow’s structured observability layer.

It provides:

Deep execution visibility
Deterministic diagnostics
Machine-readable introspection
Performance tracing
Inference reasoning transparency

TRACE is not for user messages and not a replacement for errors/warnings.

2. When to Use TRACE¶

Use TRACE when you need to record:

Execution Flow (`flow`)¶

Entry/exit of major functions
Stage lifecycle
CLI dispatch
Pipeline boundaries

External Interactions (`io`)¶

Subprocess calls
Filesystem probing
External tools (fc-query, fc-list, fonttools)

Raw Data (`raw`)¶

Raw external outputs (bounded)
Formatting decisions
Intermediate data representations

Parsing (`parse`)¶

Normalization steps
Filtering decisions
Transformation stages

Inference (`infer`)¶

Decision reasoning
Candidate acceptance/rejection
Evidence and confidence

Validation (`validate`)¶

Schema rule failures
Semantic rule triggers
Strict-mode rejection

Cache (`cache`)¶

Cache hit/miss/store

Performance (`perf`)¶

Timing spans
Performance metrics

LaTeX (`latex`)¶

Layout decisions
Formatting steps
Output shaping

Overall¶

Use TRACE for:

execution observability
inference reasoning
performance measurement
cache behavior
validation diagnostics

3. When NOT to Use TRACE¶

Do NOT use TRACE for:

User-visible messages → use INFO/WARN/ERROR
Errors/exceptions → use ERROR
Debug print-style logging → DEBUG (temporary only)
Summaries → INFO
Results → INFO

4. TRACE Logging API¶

Always use:

log_trace_cat(log, "<category>", "<message>", extra={...})

Example:

log_trace_cat(
    log,
    "infer",
    "language candidate accepted",
    extra={
        "lang": lang,
        "confidence": confidence,
        "evidence_count": len(evidence),
    },
)

5. TRACE Field Naming Standard¶

TRACE payload fields MUST follow stable naming conventions.

General rules¶

Use snake_case
Use deterministic values
Prefer explicit names
Keep payload bounded
Avoid ambiguity

Standard Field Names¶

Execution / flow¶

Field	Meaning
`stage`	logical stage name
`command`	CLI command
`handler`	resolved function
`exit_code`	process exit code

Paths / filesystem¶

Field	Meaning
`font_path`	font file path
`input_path`	input file
`output_path`	output file

Counts / sizes¶

Field	Meaning
`count`	generic count
`fonts_total`	total fonts
`fonts_parsed`	parsed fonts
`faces`	TTC face count
`bytes`	byte size

Inference¶

Field	Meaning
`lang`	language code
`confidence`	inference confidence
`evidence`	inference evidence
`ratio`	coverage ratio
`threshold`	inference threshold

Validation¶

Field	Meaning
`rule`	rule identifier
`severity`	warning/error
`schema_version`	schema version

External calls¶

Field	Meaning
`command`	external command
`duration_ms`	execution time
`exit_code`	return code

Cache¶

Field	Meaning
`cache_key`	cache key
`hit`	bool
`store`	bool

6. TRACE Performance Checklist¶

TRACE must remain cheap when disabled.

Always verify¶

TRACE produces no side effects
TRACE does not change output
TRACE does not alter ordering
TRACE does not allocate large payloads
TRACE does not compute heavy values unnecessarily

Guard heavy TRACE¶

if log.isEnabledFor(TRACE) and trace_enabled("raw"):
    expensive_data = compute()

Timing best practices¶

Use perf_counter()
Convert to duration_ms
Avoid timing inside tight loops unless aggregated

Hot-loop rules¶

Allowed:

aggregated TRACE
gated TRACE

Avoid:

TRACE per iteration in large loops
TRACE with large payloads

7. Determinism Guarantee¶

TRACE must never change:

Program output
File content
Ordering
Exit codes
Logic

TRACE is strictly observational.

8. TRACE Categories¶

Fixed authoritative categories:

flow io raw parse infer validate cache perf latex

Never introduce new categories without updating the TRACE policy.

9. Caller Reporting¶

TRACE must reflect the logical caller, not logging helpers.

Use:

stacklevel=2

when needed.

10. TRACE Instrumentation Cheat Sheet¶

Stage entry / exit¶

log_trace_cat(log, "flow", "stage started")
...
log_trace_cat(log, "flow", "stage completed")

External command¶

log_trace_cat(log, "io", "fc-query start", extra={"font_path": path})
...
log_trace_cat(log, "io", "fc-query executed", extra={"exit_code": rc})

Performance timing¶

t0 = perf_counter()
...
log_trace_cat(log, "perf", "operation timing", extra={"duration_ms": ms})

Cache hit / miss¶

log_trace_cat(log, "cache", "cache hit", extra={"cache_key": key})
log_trace_cat(log, "cache", "cache miss", extra={"cache_key": key})

Inference decision¶

log_trace_cat(
    log,
    "infer",
    "candidate rejected",
    extra={"lang": lang, "ratio": ratio},
)

Validation rule¶

log_trace_cat(
    log,
    "validate",
    "rule triggered",
    extra={"rule": rule_id, "severity": severity},
)

Raw bounded data¶

log_trace_cat(
    log,
    "raw",
    "raw output",
    extra={"raw": blob[:4096]},
)

11. TRACE Activation (Developer)¶

Enable TRACE:

FONTSHOW_LOG_LEVEL=TRACE

Selective categories:

FONTSHOW_TRACE=flow,io,infer

Human-readable format:

FONTSHOW_TRACE_FORMAT=human

12. Common Mistakes¶

Using TRACE for user messages ❌
Creating new categories ❌
Logging inside hot loops without gating ❌
Logging large raw data without bounding ❌
Computing heavy TRACE data unconditionally ❌

13. TRACE Philosophy¶

TRACE is:

Structured
Deterministic
Selectively activatable
Performance-safe
Observational only

It enables deep introspection without altering runtime behavior.

14. Determinism Guarantee¶

Fontshow TRACE infrastructure is strictly observational and must never alter functional output. The following guarantees hold.

Stable FS Identifier¶

NFSS temporary family identifiers (FS…) are deterministic and stable.

Derived from intrinsic font identity
Independent from execution timing
Independent from TRACE activation
Independent from font enumeration order
Stable across runs on the same system

This guarantees reproducible catalog generation.

TRACE Does Not Affect Output¶

TRACE logging is strictly side-effect free.

No data mutation
No ordering changes
No pipeline behavior changes
No conditional logic driven by TRACE

Enabling or disabling TRACE must never modify produced artifacts.

Reproducible Catalog¶

Given identical:

Font inventory
Environment
Configuration

Fontshow produces byte-identical catalog output regardless of:

TRACE enabled / disabled
TRACE category selection
TRACE verbosity level

This property is continuously verified during development.

Timestamp Exclusion¶

Catalog determinism excludes:

generation timestamps
runtime metadata

These fields are allowed to differ and do not constitute nondeterminism.

15. TRACE Troubleshooting¶

No TRACE Visible¶

Check:

FONTSHOW_LOG_LEVEL=TRACE
FONTSHOW_TRACE=<category|all>
TRACE not disabled by CLI quiet mode