Request tracing for PhoenixGenApi with per-key log files.

Traces requests that match a configured request_type or user_id, writing each trace as a key=value line to a dedicated log file (one file per request type, one file per user id).

Why this is fast

The hot-path check performed on every executed request is deliberately tiny:

• a single :persistent_term read to know whether tracing is enabled at all
• two in-memory membership checks against the enabled request_type / user_id sets
• if nothing matches, the call returns immediately

Only when a request matches does it dispatch an asynchronous message to the writer process, which performs the file I/O. Tracing therefore never blocks request execution and adds negligible overhead when disabled or unmatched.

Enabling tracing

Tracing is fully opt-in. It is disabled by default and only writes when a request matches an explicitly enabled request type or user id.

At runtime (functions)

# Trace a single request type
PhoenixGenApi.Tracer.enable_request_type("get_user")

# Trace several request types at once
PhoenixGenApi.Tracer.enable_request_type(["get_user", "create_order"])

# Trace all requests for a specific user
PhoenixGenApi.Tracer.enable_user_id("user_123")

# Stop tracing
PhoenixGenApi.Tracer.disable_request_type("get_user")
PhoenixGenApi.Tracer.disable_user_id("user_123")

Via configuration

config :phoenix_gen_api, :tracer,
  enabled: true,
  log_dir: "log/phoenix_gen_api_traces",
  max_file_bytes: 50_000_000,
  max_backup_files: 5,
  log_level: :debug,
  request_types: ["get_user"],
  user_ids: ["user_123"]

Config options:

• :enabled — global on/off switch (default: false)
• :log_dir — directory for the per-key trace files (default: "log/phoenix_gen_api_traces")
• :max_file_bytes — rotate a trace file once it exceeds this size (default: 50_000_000 = 50 MB)
• :max_backup_files — how many rotated .1, .2, ... backup files to keep (default: 5)
• :log_level — Logger level temporarily raised globally while tracing is enabled, so debug/info output is captured (default: :debug)
• :request_types — request types to trace at startup
• :user_ids — user ids to trace at startup

Trace files

Files are named after the traced key:

log/phoenix_gen_api_traces/request_type-get_user.log
log/phoenix_gen_api_traces/user_id-user_123.log

When a request matches both an enabled request type and an enabled user id, one line is written to each matching file.

Each line is space-separated key=value, e.g.:

timestamp=2026-08-17T12:00:00.000Z node=app@host event=request_start     request_id=req_1 user_id=user_123 device_id=dev_1 request_type=get_user     service=user_service version=nil args="%{"id" => "u1"}"

Tracing every action of a request

Tracing does not stop at the three lifecycle events. While a request is being traced, the trace file records every action the request takes:

• structured milestone events (config lookup, hooks, rate limit, permission, argument conversion, execution, retries, RPC fallback, async/stream dispatch, errors)
• raw Logger output emitted by any process that touches the request (event=log lines with level, pid, mfa and message)

Raw log capture is driven by process metadata: begin_trace/1 attaches phoenix_gen_api_trace and phoenix_gen_api_trace_request metadata to the current process, and worker processes re-apply that metadata so their logs are captured too. While tracing is enabled the global Logger level is raised to :log_level so debug/info messages reach the capture handler, and it is restored when tracing is disabled.

The trace context can also be managed by hand:

ctx = PhoenixGenApi.Tracer.begin_trace(request)  # nil when not traced
PhoenixGenApi.Tracer.trace_event("my_step", %{"status" => "ok"})
PhoenixGenApi.Tracer.end_trace(ctx)              # restores metadata

Events written per traced request:

• event=request_start — emitted when the executor begins handling the request, includes the full request (including args)
• event=config_lookup — the service config was resolved (ok), missing (not_found) or disabled
• event=hook_before — a before_execute hook ran (ok) or failed
• event=rate_limit — rate limiter decision: allowed, limited (with retry_after_ms) or error
• event=permission — emitted after the permission check, includes permission=allowed|denied and permission_mode
• event=arguments — argument conversion succeeded (with count) or failed
• event=execution — the MFA was invoked, with mode=local|remote and mfa
• event=error — execution raised/exited/errored, with kind and error
• event=retry / event=retry_exhausted — local and remote retry attempts
• event=rpc_fallback — a remote node failed and the request fell back
• event=async / event=stream — async/stream dispatch (queued, queue_full, started, timeout, error)
• event=hook_after — an after_execute hook ran (ok) or failed
• event=log — a raw Logger line emitted during the trace
• event=request_end — emitted when execution finishes, includes success, async, duration_us and error (if any)

Inspecting state

PhoenixGenApi.Tracer.enabled?()
PhoenixGenApi.Tracer.enabled_request_types()
PhoenixGenApi.Tracer.enabled_user_ids()
PhoenixGenApi.Tracer.status()