alkssh/src/observe.rs

//! The decline-path + serving-path event vocabulary
//! (`w3-decline-tracing` — the wave-2 gate's booked finding): the
//! observability surface every decline site in `src/` emits through,
//! and the serving-path lifecycle skeleton ([`serving_path_started`] /
//! [`serving_path_ended`] / [`serving_path_failed`]) the wave-3
//! mappings inherit.
//!
//! ## The family posture read (2026-10-28)
//!
//! Read before choosing this shape — no alkssh-private dialect:
//!
//! - `alktty` (`adapter.rs`, `session.rs`, `local/pipe.rs`,
//!   `local/pty.rs`): free `tracing::{debug, warn}` imports,
//!   message-last lowercase sentences with a component prefix
//!   (`"tty: backend stdin write failed: {e}"`), no spans, no macros.
//! - `alktunnels` (`producer.rs`, `consumer.rs`, `params.rs`): the
//!   same free-fn posture, structured fields where identity exists
//!   (`listen = …`, `error = %e`, `reason = …`), levels `debug` for
//!   structural observations, `warn` for recoverable failures,
//!   `error` for abnormal pump terminations.
//! - `alkcall` (`protocol/*`, `channels/*`): the widest use — the same
//!   fields convention (`channel_id`, `request_id`, `error = %e`),
//!   component-prefixed messages (`"channel client: …"`,
//!   `"open wrapper: …"`), `debug`/`warn` only.
//! - `alkhttp` (the closest structural analog): `warn`/`error` with
//!   `error = %e` (`"channels session ended"`).
//! - `alkgit`: no tracing at all at this writing.
//!
//! Never observed in the family: `info!` / `trace!` events, subscriber
//! setup in library code, macro or span wrappers — so none here
//! either. Adopted verbatim: free `tracing` fn calls, message-last
//! lowercase with the `"decline: …"` / `"serving path …"` phrasing,
//! flat per-event fields (`feature_build`, `row`, `channel_id`,
//! `decline_class`, `reason`, `exec_route`, `error`).
//!
//! ## The event vocabulary
//!
//! Every event carries exactly:
//!
//! - `feature_build = FEATURE_BUILD` — the crate's compile-time
//!   feature set as a stable string (`"none"`, `"git"`,
//!   `"session+git"`, …; features joined in the order `session, git,
//!   tunnel, sftp`), so a captured event is self-describing per
//!   build. The `sftp` feature gates no route, but ships in the
//!   build string: it is part of what the assembly deployed.
//! - `row` — the greppable wire row the event is about: the channel
//!   type for open-level (e.g. `"session"`, `"direct-tcpip"`, `"x11"`),
//!   the request name for request-level (e.g. `"pty_request"`,
//!   `"tcpip_forward"`), the handler hook name for auth (e.g.
//!   `"auth_publickey"`), the session-row hook names for the
//!   serving-path lifecycle.
//! - `channel_id` — the wire channel id (u32), on every event of a
//!   channel; the auth class has none (the auth hooks carry no
//!   channel at this surface).
//!
//! Decline events additionally carry exactly:
//!
//! - `decline_class` — `"open"` | `"request"` | `"serving"` |
//!   `"arrival"` | `"auth"`:
//!   the two wire decline classes of `mapping.md` §Wire decline
//!   reasons, plus the serving-path class (this wave the seam stub's
//!   decline *is* the serving path; the wave-3 mappings emit the same
//!   class from their real spawned paths) and the auth class (the
//!   disposition declines of ADR-004).
//! - `reason` — the decline cause, mirroring the architecture's own
//!   classifications: `"unfeatured"` (feature-gate absence),
//!   `"never-feature"` (ADR-003 §5 rows), `"cap-exceeded"`,
//!   `"connect-failed"` (`w3-tunnel-direct`: the tunnel rows'
//!   cannot-bridge class — the failed fabric open, the wave-2 seam
//!   stub's reason surviving as the real decline; also the
//!   `forwarded-tcpip` stub's standing decline class),
//!   `"seam-unconfigured"` (the config-driven row decline — the git
//!   row and, now, the session rows (feature on, seam unset;
//!   `w3-git-mapping` / `w3-tty-session`) and the tunnel rows' absent
//!   fabric handle even under the feature (`w3-tunnel-direct`; the
//!   unset-declines posture)),
//!   `"shell-unconfigured"` / `"wrapper-unconfigured"` (`w3-tty-
//!   session`: the OQ-08 unset-field rows — feature on, the
//!   serve-config field unset, never a fallback),
//!   `"negotiation-failed"` (`w3-tty-session`: the alktty
//!   negotiation error frame the bridge received — the session never
//!   started; the frame's JSON detail stays alktty-side),
//!   `"unknown-service"` / `"service-only"` / `"invalid-repo-id"`
//!   (the exec grammar's git declinables — the parse core's two and
//!   the git row's validation gate; no service token or repo string
//!   ever rides — only the vocabulary value),
//!   `"exec-oversize"` (the pre-parse `max_exec_command_len` cap),
//!   `"invalid-target"` (`w3-tunnel-direct`: the direct rows'
//!   impossible wire target — an out-of-range `direct-tcpip` port),
//!   `"unix-unavailable"` (`w3-tunnel-direct`: the OQ-11 runtime-Unix
//!   gate — the off-Unix `direct-streamlocal` decline, answered
//!   before any fabric call),
//!   `"no-identity"` / `"channel-not-held"` (the git row's serving-
//!   path guards — unreachable in practice, fail-closed; the tunnel
//!   rows' open-level `no-identity` guard rides the same value —
//!   reachable never, on the wire, for the same reason),
//!   `"unimplemented"` (the subsystem rows — OQ-13),
//!   `"declined-by-design"` (env, OQ-09),
//!   `"correlation-miss"` / `"cap-exceeded"` / `"accept-refused"` /
//!   `"unvanilla-inbound"` (`w3-tunnel-listen`: the `-R` leg's arrival
//!   declines — the class whose events carry the minted `listen` token
//!   instead of a channel id — and the unvanilla inbound
//!   `forwarded-tcpip` open),
//!   `"listen-failed"` / `"no-such-listen"` (`w3-tunnel-listen`: the
//!   listen dial's failed/bounded outcome and the cancel forms'
//!   not-found pair) — the global-request and arrival rows, and on the
//!   auth class `"method-unimplemented"` / `"cert-unsupported"` /
//!   `"non-ed25519"` / `"fingerprint-unresolved"`.
//!   Client-side (the dial handler's `server_channel_open_*`
//!   skeleton, `w4-dial`): `"no-acceptor"` (the decline-all default —
//!   a server-initiated open with no registered acceptor; the
//!   registry is `w4-reverse-listen`'s) and `"never-feature"` (the
//!   x11/agent rows — ADR-003 §5).
//! - `exec_route` — only on `exec_request`-row events: the dispatch
//!   route the parse routed to (`"git"` | `"pipe"`), so a git row's
//!   decline is distinguishable from a pipe row's in combined builds.
//!   Other rows carry none (a `None` field is not recorded by
//!   `tracing`).
//!
//! Levels: declines and the lifecycle's started/ended emit at
//! `debug` — a decline is the door's normal, honest posture (vanilla
//! clients probe unfeatured rows routinely; nothing abnormal
//! happened), matching the family's structural-observation level.
//! Only [`serving_path_failed`] is `warn` — a serving path that could
//! not complete its wire reporting is a real failure (the family's
//! recoverable-failure level).
//!
//! ## Safety posture (conventions 6, OQ-03)
//!
//! **No secret material ever enters an event; never the username.**
//! Structurally enforced, not recalled: the helpers take only
//! `&'static str` vocabulary values and the wire channel id — there
//! is no parameter a username, command string, env name/value, repo
//! path, key, or fingerprint could ride. In particular *the
//! fingerprint stays out of the events* (`auth.md` §Dispositions: log
//! exposure is deployment policy — the crate's events are
//! safe-by-default at every level, so the fingerprint is a
//! deployer-side computation over its own logs, never crate-emitted).
//! The `error` field carries only russh protocol errors. The wire
//! rows in `tests/observe.rs` pin the posture: the username never
//! appears in any captured field. If a future decline site needs
//! request-argument detail (e.g. the git grammar's decline reasons in
//! `w3-git-mapping`), it must add an explicitly-vocabulary'd field and
//! record its safety reasoning — dynamic strings do not ride this
//! module by default.

/// The compile-time feature set, as a stable string (`"none"`,
/// `"session"`, `"session+git"`, …). Features join in the order
/// `session, git, tunnel, sftp`; the featureless build is `"none"`.
pub(crate) const FEATURE_BUILD: &str = feature_build();

const fn feature_build() -> &'static str {
    match (
        cfg!(feature = "session"),
        cfg!(feature = "git"),
        cfg!(feature = "tunnel"),
        cfg!(feature = "sftp"),
    ) {
        (false, false, false, false) => "none",
        (true, false, false, false) => "session",
        (false, true, false, false) => "git",
        (false, false, true, false) => "tunnel",
        (false, false, false, true) => "sftp",
        (true, true, false, false) => "session+git",
        (true, false, true, false) => "session+tunnel",
        (true, false, false, true) => "session+sftp",
        (false, true, true, false) => "git+tunnel",
        (false, true, false, true) => "git+sftp",
        (false, false, true, true) => "tunnel+sftp",
        (true, true, true, false) => "session+git+tunnel",
        (true, true, false, true) => "session+git+sftp",
        (true, false, true, true) => "session+tunnel+sftp",
        (false, true, true, true) => "git+tunnel+sftp",
        (true, true, true, true) => "session+git+tunnel+sftp",
    }
}

/// An open-level decline: the channel-open gate refused an open
/// (`unfeatured` / `never-feature` / `cap-exceeded` / the tunnel seam
/// stub's `connect-failed`). The wire answer is the open-failure code
/// ([`crate::dispatch`]); this is the event for the decision behind it.
pub(crate) fn decline_open(row: &'static str, reason: &'static str, channel_id: u32) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        channel_id,
        decline_class = "open",
        reason,
        "decline: channel open rejected"
    );
}

/// A request-level decline on a session channel: a capability the
/// build does not serve (`subsystem` / `env` / `x11` / agent, an
/// unfeatured parse route) or a not-yet-landed listen form. The wire
/// answer is `channel_failure` (the channel stays usable) or the
/// denied-request reply — the event is the deciding context.
pub(crate) fn decline_request(
    row: &'static str,
    reason: &'static str,
    channel_id: u32,
    exec_route: Option<&'static str>,
) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        channel_id,
        decline_class = "request",
        reason,
        exec_route,
        "decline: channel request rejected"
    );
}

/// An auth-class decline: a disposition of the ADR-004 bridge turned
/// the method away. No channel id exists at this surface; the
/// *fingerprint never rides the event* (see §Safety posture) — the
/// `reason` codes distinguish the decline causes without exposing who.
pub(crate) fn decline_auth(row: &'static str, reason: &'static str) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        decline_class = "auth",
        reason,
        "decline: auth disposition rejected"
    );
}

/// A request-level decline on a **global** request — the `-R` listen
/// forms (`mapping.md` §Global-request rows). No channel id exists at
/// this surface; the fields are otherwise the `request` vocabulary.
pub(crate) fn decline_global_request(row: &'static str, reason: &'static str) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        decline_class = "request",
        reason,
        "decline: global request rejected"
    );
}

/// A decline on the `-R` leg's **arrival** surface (`w3-tunnel-
/// listen`): a fabric inbound forwarded open that cannot become an
/// SSH channel — `correlation-miss` (no route for the minted token —
/// teardown-at-birth), `cap-exceeded` (the per-arrival admission), or
/// `accept-refused` (the vanilla client rejected the SSH open — the
/// count released, never a half-open channel). No SSH channel id
/// exists yet at this surface (that is the point of the declines), so
/// the minted `listen` token — the correlation key itself — rides
/// instead; the token is bookkeeping metadata (the producer's minted
/// correlation number), never secret material.
#[cfg(feature = "tunnel")]
pub(crate) fn decline_arrival(row: &'static str, reason: &'static str, listen: u32) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        listen,
        decline_class = "arrival",
        reason,
        "decline: forwarded arrival rejected"
    );
}

/// A serving-path decline: a routed row whose serving task answers
/// failure-then-close rather than serving. This wave that is the seam
/// stub (the wire shape pinned in `tests/spawn_return.rs`); the wave-3
/// mappings emit it from their real spawned paths wherever serving
/// itself cannot proceed — the class the spawned paths inherit.
#[cfg(any(feature = "git", feature = "session"))]
pub(crate) fn decline_serving(
    row: &'static str,
    reason: &'static str,
    channel_id: u32,
    exec_route: Option<&'static str>,
) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        channel_id,
        decline_class = "serving",
        reason,
        exec_route,
        "decline: serving path rejected"
    );
}

/// Spawned-path started — emitted as the spawned task's first action,
/// so "started" is the task's own honest start, not the hook's spawn
/// call. The mapping tasks' serving paths inherit this shape.
#[cfg(any(feature = "git", feature = "session", feature = "tunnel"))]
pub(crate) fn serving_path_started(
    row: &'static str,
    channel_id: u32,
    exec_route: Option<&'static str>,
) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        channel_id,
        exec_route,
        "serving path started"
    );
}

/// Spawned-path ended — the serving future finished (cleanly, or with
/// the decline it was wired to answer); emitted *after* the path's
/// wire reporting has completed.
#[cfg(any(feature = "git", feature = "session", feature = "tunnel"))]
pub(crate) fn serving_path_ended(
    row: &'static str,
    channel_id: u32,
    exec_route: Option<&'static str>,
) {
    tracing::debug!(
        feature_build = FEATURE_BUILD,
        row,
        channel_id,
        exec_route,
        "serving path ended"
    );
}

/// Spawned-path failure — the serving path could not complete its
/// wire reporting (the session handle's sends failed: the session is
/// gone, or the report never landed). The vocabulary's one `warn` —
/// the family's recoverable-failure level. Only russh protocol errors
/// ride the `error` field (§Safety posture); the mapping tasks emit
/// this from their real paths when serving fails before reporting.
/// (The tunnel bridge never calls this: its wire reporting is
/// open-level — `accept`/`reject` cannot fail send-wise — so the fn
/// stays gated to the git/session rows.)
#[cfg(any(feature = "git", feature = "session"))]
pub(crate) fn serving_path_failed<E: std::fmt::Debug>(
    row: &'static str,
    channel_id: u32,
    error: &E,
    exec_route: Option<&'static str>,
) {
    tracing::warn!(
        feature_build = FEATURE_BUILD,
        row,
        channel_id,
        exec_route,
        error = ?error,
        "serving path failed"
    );
}

#[cfg(test)]
mod tests {
    use tracing::subscriber::with_default;

    /// A fake error shape — the failure row only pins that a Debug
    /// error value rides the `error` field.
    #[derive(Debug)]
    #[cfg(any(feature = "git", feature = "session"))]
    struct Probe;
    #[cfg(any(feature = "git", feature = "session"))]
    static PROBE: Probe = Probe;

    use super::*;

    /// A minimal field-capturing visitor shared by these rows and the
    /// wire rows in `tests/observe.rs` (the test convention recorded
    /// in the task notes — the family has no event-capture precedent,
    /// only alktunnels' fmt-subscriber dev-dep for debug output, so
    /// the convention is a hand-rolled minimal [`tracing::Subscriber`]
    /// — no `tracing-subscriber` dependency).
    struct Visitor(Vec<(String, String)>);

    impl tracing::field::Visit for Visitor {
        fn record_str(&mut self, field: &tracing::field::Field, value: &str) {
            self.0.push((field.name().to_owned(), value.to_owned()));
        }

        fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
            self.0.push((field.name().to_owned(), format!("{value:?}")));
        }
    }

    /// Captures the fields of the one event the emit fn fires, via
    /// the thread-local default subscriber (`with_default` — these
    /// are direct helper rows; the spawned-task surfaces are driven
    /// over the wire in `tests/observe.rs` against the global
    /// capture).
    fn capture(emit: impl FnOnce()) -> Vec<(String, String)> {
        struct Capture(std::sync::Mutex<Vec<(String, String)>>);
        impl tracing::Subscriber for Capture {
            fn enabled(&self, _metadata: &tracing::Metadata<'_>) -> bool {
                true
            }
            fn new_span(&self, _span: &tracing::span::Attributes<'_>) -> tracing::Id {
                tracing::Id::from_u64(1)
            }
            fn record(&self, _span: &tracing::Id, _values: &tracing::span::Record<'_>) {}
            fn record_follows_from(&self, _span: &tracing::Id, _follows: &tracing::Id) {}
            fn event(&self, event: &tracing::Event<'_>) {
                let mut v = Visitor(Vec::new());
                event.record(&mut v);
                self.0
                    .lock()
                    .unwrap_or_else(|e| e.into_inner())
                    .append(&mut v.0);
            }
            fn enter(&self, _span: &tracing::Id) {}
            fn exit(&self, _span: &tracing::Id) {}
            fn clone_span(&self, _id: &tracing::Id) -> tracing::Id {
                tracing::Id::from_u64(1)
            }
        }
        let holder = std::sync::Arc::new(Capture(Default::default()));
        with_default(std::sync::Arc::clone(&holder), || {
            let prior = holder.0.lock().unwrap().len();
            emit();
            assert!(holder.0.lock().unwrap().len() > prior);
        });
        holder.0.lock().unwrap().clone()
    }

    fn field<'a>(fields: &'a [(String, String)], name: &str) -> &'a str {
        fields
            .iter()
            .find(|(n, _)| n == name)
            .map(|(_, v)| v.as_str())
            .unwrap_or_else(|| panic!("no field {name} in {fields:?}"))
    }

    /// - *Contract stamp:* the event vocabulary (`w3-decline-tracing`)
    ///   — an open decline carries exactly the base shape, values
    ///   included.
    #[test]
    fn decline_open_carries_the_full_vocabulary() {
        let fields = capture(|| decline_open("x11", "never-feature", 7));
        assert_eq!(field(&fields, "feature_build"), FEATURE_BUILD);
        assert_eq!(field(&fields, "row"), "x11");
        assert_eq!(field(&fields, "channel_id"), "7");
        assert_eq!(field(&fields, "decline_class"), "open");
        assert_eq!(field(&fields, "reason"), "never-feature");
        assert_eq!(field(&fields, "message"), "decline: channel open rejected");
        let names: Vec<String> = fields.iter().map(|(n, _)| n.clone()).collect();
        assert_eq!(
            names,
            vec![
                "message".to_owned(),
                "feature_build".to_owned(),
                "row".to_owned(),
                "channel_id".to_owned(),
                "decline_class".to_owned(),
                "reason".to_owned(),
            ],
            "an open decline carries exactly the vocabulary, nothing else \
             (the message field first — the event! macro's shape)"
        );
    }

    /// - *Contract stamp:* the `exec_route` field — present on the
    ///   exec row, absent elsewhere (a `None` field is not recorded
    ///   by `tracing`).
    #[test]
    fn decline_request_carries_the_route_when_the_parse_routed() {
        let fields = capture(|| decline_request("exec_request", "unfeatured", 3, Some("git")));
        assert_eq!(field(&fields, "decline_class"), "request");
        assert_eq!(field(&fields, "exec_route"), "git");

        let fields = capture(|| decline_request("subsystem_request", "unimplemented", 3, None));
        assert_eq!(field(&fields, "decline_class"), "request");
        assert!(
            !fields.iter().any(|(n, _)| n == "exec_route"),
            "a None route field is not recorded at all"
        );
    }

    #[test]
    fn decline_auth_carries_no_channel() {
        let fields = capture(|| decline_auth("auth_password", "method-unimplemented"));
        let names: Vec<String> = fields.iter().map(|(n, _)| n.clone()).collect();
        assert!(!names.iter().any(|n| n.starts_with("channel")));
        assert_eq!(field(&fields, "decline_class"), "auth");
        assert_eq!(field(&fields, "row"), "auth_password");
        assert_eq!(field(&fields, "reason"), "method-unimplemented");
    }

    /// - *Contract stamp:* the `exec_route` field — present on the
    ///   exec row, absent elsewhere (a `None` field is not recorded
    ///   by `tracing`). The pty/shell lifecycle rows carry no route.
    #[cfg(any(feature = "git", feature = "session"))]
    #[test]
    fn serving_path_lifecycle_carries_started_ended_and_the_warn_failure() {
        let fields = capture(|| serving_path_started("pty_request", 1, None));
        assert_eq!(field(&fields, "message"), "serving path started");
        let names: Vec<String> = fields.iter().map(|(n, _)| n.clone()).collect();
        assert!(
            !names.iter().any(|n| n == "decline_class"),
            "lifecycle events carry no decline class"
        );

        let fields = capture(|| serving_path_ended("exec_request", 1, Some("pipe")));
        assert_eq!(field(&fields, "exec_route"), "pipe");
        assert_eq!(field(&fields, "message"), "serving path ended");

        let fields = capture(|| serving_path_failed("shell_request", 1, &PROBE, None));
        assert_eq!(field(&fields, "message"), "serving path failed");
        assert_eq!(field(&fields, "error"), "Probe");
    }

    /// - *Contract stamp:* the arrival vocabulary (`w3-tunnel-listen`)
    ///   — an arrival decline carries the minted `listen` token
    ///   instead of a channel id (none exists yet — that is the point
    ///   of the declines; the token is bookkeeping metadata, never
    ///   secret material).
    #[cfg(feature = "tunnel")]
    #[test]
    fn decline_arrival_carries_the_listen_token_not_a_channel_id() {
        let fields = capture(|| decline_arrival("forwarded-tcpip", "correlation-miss", 9182));
        assert_eq!(field(&fields, "feature_build"), FEATURE_BUILD);
        assert_eq!(field(&fields, "row"), "forwarded-tcpip");
        assert_eq!(field(&fields, "listen"), "9182");
        assert_eq!(field(&fields, "decline_class"), "arrival");
        assert_eq!(field(&fields, "reason"), "correlation-miss");
        assert_eq!(
            field(&fields, "message"),
            "decline: forwarded arrival rejected"
        );
        let names: Vec<String> = fields.iter().map(|(n, _)| n.clone()).collect();
        assert!(
            !names.iter().any(|n| n == "channel_id"),
            "an arrival decline carries the listen token, never a channel id"
        );
    }

    /// The feature-build string: every enabled feature appears; a
    /// featureless build reads `none`. The expected half is derived
    /// from `cfg!` independently of the crate's match — divergence
    /// breaks this row loudly.
    #[test]
    fn feature_build_string_reflects_the_cfgs() {
        let mut expected = String::new();
        for (on, name) in [
            (cfg!(feature = "session"), "session"),
            (cfg!(feature = "git"), "git"),
            (cfg!(feature = "tunnel"), "tunnel"),
            (cfg!(feature = "sftp"), "sftp"),
        ] {
            if on {
                if !expected.is_empty() {
                    expected.push('+');
                }
                expected.push_str(name);
            }
        }
        if expected.is_empty() {
            expected.push_str("none");
        }
        assert_eq!(FEATURE_BUILD, expected);
    }
}