qbit-scripting/docs/PHASE-TIMING.md

Optional scripting phase timing

com.kingsrook.qqq.ScriptingPhase is a JDK Flight Recorder event, disabled by default. It adds no dependency, runtime qualification, permission or audit exemption. After one-time registration, disabled calls reuse one stateless no-op span without a per-call allocation, clock read or I/O. A custom Java runtime missing jdk.jfr uses the same no-op path. Recording setup/commit failures are isolated from application results and required audit persistence.

The only application fields are closed phase and outcome labels. No source, context, identifiers, actor, credentials, exception type/message or record values are attached. Stack capture defaults off. Standard JFR event metadata still includes duration and thread information; operators must protect recordings and avoid sensitive thread names. Operators can change JFR settings, including stacks, so the default privacy scope does not describe arbitrary additional recordings.

Enable a bounded recording

Use the standard JDK API from trusted host/operator code; no scripting API exposes recording controls:

try (var recording = new jdk.jfr.Recording()) {
    recording.enable("com.kingsrook.qqq.ScriptingPhase")
        .withThreshold(java.time.Duration.ZERO)
        .withoutStackTrace();
    recording.setMaxSize(32L * 1024 * 1024);
    recording.start();
    // Exercise the actual qualified host path for a bounded observation window.
    recording.stop();
    recording.dump(java.nio.file.Path.of("scripting-phases.jfr"));
}

Inspect with JDK Mission Control or jfr print --events com.kingsrook.qqq.ScriptingPhase scripting-phases.jfr. Recording output belongs in operator-controlled storage. A threshold drops shorter events and biases latency analysis; use zero when measuring the complete distribution. Recording has its own cost and bounded storage can discard older events. Compare enabled/disabled runs on the real deployment when evaluating overhead.

Exact measurement boundaries

Phase	Scope
HOOK_CALLBACK	Synchronous native hook callback, including binding lookup, authorized context preparation and applying the decision to the input records.
BINDING_LOOKUP	Current binding lookup and its existing checks. This also occurs in service calls outside a native save.
AUTHORIZATION_PUBLICATION	Synchronous runHook current-actor, exact binding, publication/build and grant checks before executor entry.
AUTHORIZED_RECORD_READ	Actual enforced native hook record read, field projection and read-recursion cleanup.
EXECUTION_TOTAL	Executor entry through result return/propagation, including recursion guard, STARTED/outcome audit and cleanup.
ARTIFACT_VERIFICATION	Stored build/artifact retrieval and signed-manifest/artifact verification.
WORKER_DISPATCH	Actual WorkerProvider.execute call, including synchronous broker callbacks. Transport startup is included if performed by that provider inside the call.
BROKER_CALLBACK	Callback thread/session and budget checks plus broker handling.
AUDIT_PERSISTENCE	Each ScriptingStore.history append, including required independent transaction commit and restoring the caller transaction where configured. This is not every draft/publication mutation.

RETURNED means the boundary returned normally; it does not mean ALLOW, successful script execution or committed source mutation. THREW means a throwable propagated out of that measured boundary. For example, a provider can throw while the executor returns an audited UNAVAILABLE result: dispatch is THREW and execution total is RETURNED. A native hook can return record validation errors normally.

Spans are nested and inclusive. Do not sum their durations or their p95 values: worker dispatch includes broker time, and execution total includes dispatch and audit. There is deliberately no request/actor correlation field. Analyze per-phase distributions separately; do not infer one-to-one relationships among interleaved events.

HOOK_CALLBACK excludes the outer native record action, database DML and caller commit. EXECUTION_TOTAL is not full record-save latency. Context and durable AFTER execution share executor/artifact/worker/broker/history boundaries, but do not necessarily pass the synchronous hook callback/publication phases. Compilation, queued delay, Jobs identity restoration, native transaction admission, network outside provider dispatch and outer commit require host measurements at their actual boundaries. No full-save or Kubernetes latency result is claimed here.

Verification

ScriptTimingTest records actual native insert/update routing through the existing protocol-only FakeWorker and checks all nine phases, exact event fields, default-off reuse, no recorded source/message marker, and unchanged audit rows. A throwing worker verifies native write refusal and durable-history API outcomes while distinguishing THREW dispatch from RETURNED execution. A trusted child JVM with --limit-modules java.base verifies graceful absence of JFR. A stopped recording verifies that span cleanup preserves the original application exception. These tests execute no author code and do not qualify a runtime or measure production performance.

The first focused gate passed 38 tests. Final focused/full verification status was recorded in the pre-extraction session notes (not published); earlier failed import/style gates remain in their original logs. No shared Maven artifact is installed by this change.