From 1d77555953107fa85193df097150061beca3701d Mon Sep 17 00:00:00 2001 From: Christian McDermott Date: Wed, 16 Sep 2026 14:29:15 -0400 Subject: [PATCH 1/5] docs(telemetry): define the product event catalogue (CHOO-2806) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The server reports nothing about how it is used. This writes down what it should report, before any of it is built, so that the events can be added to the export path CHOO-2807 is building without reworking it. Three kinds of event, for two different questions. A daily snapshot carries the counts — users, rooms, agents, sessions, connectors — and answers "how much, and is it growing". Milestone events carry the seconds since install and answer "how fast does a new deployment reach value, and where does it stick". Lifecycle events carry mix and failure. No identifier for anything inside a deployment is ever sent: not a room, tenant, agent, user or message, and not a hash of one. Every metric asked for is a count or a duration, so the server counts locally, where it legitimately knows the ids, and reports only the total. That keeps the whole subject out of a privacy review and matches the rule the Console already holds itself to. Deliberately no per-message event: the relay path has no batching and no retry because a desktop app emits a handful of events an hour, and a busy server emits thousands of messages an hour. Message volume is a count in the snapshot instead, which supports the same charts. Refs CHOO-2806. Co-Authored-By: Claude Opus 5 (1M context) --- docs/old/telemetry-events.md | 439 +++++++++++++++++++++++++++++++++++ 1 file changed, 439 insertions(+) create mode 100644 docs/old/telemetry-events.md diff --git a/docs/old/telemetry-events.md b/docs/old/telemetry-events.md new file mode 100644 index 000000000..f7dbf6cae --- /dev/null +++ b/docs/old/telemetry-events.md @@ -0,0 +1,439 @@ +# Product telemetry: the event catalogue + +What the Switch core server reports about how it is used, where it goes, and +what may never be in it. Design note for `CHOO-2806`. + +This is the **product/usage** half of telemetry. The operational half — +structured logging, the export path itself, server health, tracing and +alerting — is `CHOO-2807` and lands first. The two meet at one seam, described +under [What this needs from the export path](#what-this-needs-from-the-export-path). + +Nothing here is built yet. This note fixes the taxonomy so that the events can +be added to the export path without reworking it, and so that the question +"what does Switch phone home?" has one answer that can be read in a minute. + +## What we are trying to learn + +Two questions, and they want different shapes of data. + +**How much is Switch used, and is it growing?** Counts of users, rooms, agents, +sessions and connectors, over time. These are reported as a daily snapshot. + +**How quickly does a new deployment reach value, and where does it get stuck?** +How long from install to a working connector, from install to a room that is +actually being used, and whether one collaboration platform is markedly harder +to set up than another. These are reported as one-time milestone events carrying +elapsed time. + +The second question is the one that changes what gets built, so it is worth +being explicit: it requires a per-deployment clock starting at install, and it +requires each milestone to be emitted exactly once, ever. + +## Where it goes + +The Switch Console already reports to the company OTLP relay, which fans out to +Amplitude (product analytics) and Datadog (operations). The relay holds the +vendor keys; senders carry no credential and are admitted on a client id alone. +The endpoint and the wire format are in +`console/apps/switch-console-desktop/src/main/core/telemetry/` — `config.ts` for +the endpoint, `relay-client.ts` for the payload. + +The server reports to the same relay, in the same shape. There is deliberately +no second pipeline: a second one is a second thing to secure, a second consent +story, and a second place for a customer's data to leak from. + +The Console's implementation is the reference for the wire format, and its +choices are load-bearing rather than incidental: + +- **One OTLP log record per event**, not a metric and not a span. Amplitude + consumes events; the relay's filter keys on the `event.name` attribute. +- **The event name is sent twice** — as the log record's own `eventName` field + and as an `event.name` attribute. The relay filters on the attribute and the + exporter reads the field. Sending only one is dropped silently, with a 200 at + every hop. +- **A name prefix per product**, because one Amplitude project holds several. + The Console sends `switch_console.`; the server sends + `switch_core.`. + +## The rule: abstracted counts, never specifics + +**No identifier for anything inside a deployment is ever sent.** Not a room, +tenant, agent, user, message or channel — not the name, not the id, and not a +hash of either. + +This is the same rule the Console holds itself to (`console/AGENTS.md`), and +the Console enforces it with a test that tries to smuggle a room name into +every event and asserts it never reaches the wire. The server needs the +equivalent. + +It costs less than it sounds, because every metric asked for is a count or a +duration. The server counts locally, where it legitimately knows the ids, and +reports only the total. What is given up is per-room and per-tenant breakdowns: +we can say a deployment had 40 active rooms this week, never which. + +Specifically never sent, in addition to any identifier: + +- message bodies, prompts, code, or any room content +- room, agent, group, reference or document **names** +- file paths, working directories, repository names or URLs +- user emails, sign-in identities or platform handles +- hostnames, IP addresses, or the external channel a room is bridged to +- error messages and stack traces — an enumerated reason code instead + +Free text never reaches the wire at all: every property is a number, a boolean, +or a value from a closed set fixed in the catalogue. A property carrying an +unexpected value is a bug to be raised, not a string to be passed through. + +## Deployment identity and the install clock + +The relay admits a sender on a client id and nothing else, so the server needs +one. It does not have one today. + +**A per-deployment id**: a random UUID generated once on first use and stored in +the database, sent as the `flint.client_id` resource attribute. It identifies +the installation, and nothing else — it is not derived from a hostname, a +licence, a tenant, an account or any customer value, and it survives restarts +and redeploys so that a deployment is one Amplitude subject over its whole life +rather than a new one each boot. + +The row that holds it also holds **`installed_at`**, and that timestamp is the +clock every time-to-value metric is measured from. It is written once, when the +id is generated, and never updated. + +In Amplitude, **a deployment is the user**. Every event from one installation +collapses onto it, which is what makes a funnel across the milestone events +below work natively: Amplitude computes time-to-convert between two events for +the same subject. + +A deployment running several tenants reports as one subject, because the +alternative is a per-tenant identifier, which is exactly what the rule above +forbids. Tenant *count* is reported; tenant identity is not. + +**Deployments that already exist** have no install timestamp to recover. On +first upgrade they get an id, and `installed_at` is approximated from the oldest +row in the database. Every milestone event carries +`install_time_exact: false` in that case, so a backfilled deployment can be +excluded from time-to-value analysis rather than quietly skewing it. + +## Resource attributes + +On every event: + +| Attribute | Value | +|---|---| +| `service.name` | `switch-core` | +| `service.version` | the running version, as `/version` reports it | +| `flint.client_id` | the per-deployment id | +| `deployment.environment` | from the existing `ENVIRONMENT` setting | + +`deployment.environment` is the OpenTelemetry-conventional name and is already a +server setting. The Console instead sends a bespoke `build` attribute +(`dev`/`canary`/`stable`), which is a desktop release-channel notion with no +server equivalent. The two are deliberately different fields rather than one +field meaning different things on each side. + +## Three kinds of event + +**A daily snapshot**, one per deployment, carrying the counts that describe the +installation. This answers "how much". + +**Milestone events**, emitted at most once per deployment, each carrying the +seconds elapsed since install. This answers "how fast to value". + +**Lifecycle events**, one per occurrence, low volume. These carry mix and +failure: which platforms are in use, how often a bridge drops, whether one +connector fails repeatedly before it works. + +The snapshot exists because of the identifier rule. Without room ids, +per-occurrence events can tell you *how much* happened but never *across how +many rooms* — counting distinct anything in Amplitude requires an identifier for +the thing being counted. Counting locally and reporting the total sidesteps it. + +### Why there is no `message_sent` event + +Message volume is reported as a count in the daily snapshot, not as an event per +message. Three reasons, in order of weight: + +1. **Volume.** The relay path has no batching, no retry and no queue — one HTTP + request per event, fire-and-forget, because a desktop app emits a handful an + hour. A busy server emits thousands of messages an hour. Per-message events + would be a different class of load on a component not built for it. +2. **It answers nothing extra.** Without a room id, a per-message event supports + the same charts the snapshot count does. +3. **Content risk.** An event shaped around a message is the one most likely to + grow a property that reveals something about the message. Not having it + removes the temptation. + +If per-message granularity is ever genuinely needed, it should arrive with +batching on the export path first. + +## Definitions + +These are the definitions the counts below are computed against. They are +written down because most of them have a plausible alternative reading, and a +metric whose definition drifts is worse than no metric. + +**Interaction** — a human sent a message in a room that has at least one agent +in it, or an agent replied to one. This is the unit "active" is built on +throughout: mere membership is not activity, and two agents talking to each +other is not a human using the product. + +**Active user** — a human user with at least one interaction in the window. +Counted distinctly per window, so one person in six rooms is one active user. + +**Active room** — a room with at least one interaction in the window. Reported +over both one day and seven, because a weekly figure flatters a product used +intensely on Mondays and a daily one punishes it. + +**Session** — an agent session as the connection registry knows it: opened when +an agent connects, closed when it disconnects or its heartbeat lapses. + +**Connector** — a collaboration platform bridge (Slack, Mattermost, Discord, +Teams, Telegram). A connector is *added* when a bridge for that platform first +reaches a connected state; configuring one that never connects is not an add, +which is deliberate — the metric is about reaching value, not about saving a +form. + +Agent runtimes (Claude Code, Codex, OpenCode) are counted too, under +`agent_*_count`, but they are not what "connector" means in the time-to-value +metrics below. + +## The catalogue + +Event names are `snake_case`, past tense, prefixed `switch_core.` on the wire. +Every event of a given name always carries exactly the same property keys — +where a property does not apply, it carries an explicit `none` rather than being +omitted, so a missing key always means a bug rather than a case. + +Every event that can fail carries `outcome`, so that the failure population is +never invisible. + +### `usage_snapshot` — once a day per deployment + +| Property | Type | Notes | +|---|---|---| +| `tenant_count` | number | tenants on the deployment | +| `user_count` | number | user accounts that exist | +| `user_active_1d` | number | distinct humans who interacted in 24h | +| `user_active_7d` | number | same over 7 days | +| `room_count` | number | rooms not archived | +| `room_active_1d` | number | rooms with an interaction in 24h | +| `room_active_7d` | number | same over 7 days | +| `room_archived_count` | number | archived rooms | +| `room_internal_only_count` | number | rooms with no external channel | +| `room_membership_total` | number | user–room memberships summed over rooms | +| `room_users_mean` | number | mean human members per room | +| `room_users_max` | number | largest human membership of any one room | +| `agent_count` | number | registered agents | +| `agent_active_7d` | number | agents that interacted in 7 days | +| `agent_claude_code_count` | number | agents by runtime | +| `agent_codex_count` | number | | +| `agent_opencode_count` | number | | +| `agent_other_count` | number | including agents with no known runtime | +| `session_live_count` | number | sessions live at snapshot time | +| `session_started_1d` | number | sessions opened in 24h | +| `connector_slack_count` | number | connected bridges by platform | +| `connector_mattermost_count` | number | | +| `connector_discord_count` | number | | +| `connector_teams_count` | number | | +| `connector_telegram_count` | number | | +| `connector_configured_count` | number | configured, whether or not connected | +| `message_count_1d` | number | messages in 24h | +| `message_from_human_1d` | number | of those, sent by humans | +| `message_from_agent_1d` | number | of those, sent by agents | +| `attachment_count_1d` | number | attachments in 24h | + +Per-platform counts are separate properties rather than one map because the +platform set is closed and small, and because Amplitude charts a property far +more easily than it charts a nested object. + +The three `message_*_1d` figures come from the message table, which is +deliberately a *parallel* record of the bus rather than the authoritative one: a +write that fails after a successful send leaves a gap, so that a database +problem can never make messaging less reliable. These counts are therefore +near-complete, not exact. That is fine for "how much, and is it growing", and it +should be said plainly wherever the number is presented rather than discovered +later. + +### Milestone events — at most once per deployment + +Each carries `seconds_since_install` (number) and `install_time_exact` +(boolean). Together with `deployment_installed` they form the activation funnel. + +| Event | Emitted when | Extra properties | +|---|---|---| +| `deployment_installed` | the deployment id is first generated | `install_time_exact` | +| `first_connector_added` | any bridge first reaches connected | `bridge_platform` | +| `first_room_created` | the first room is created | `channel_type`, `bridge_platform` | +| `first_room_active` | the first room sees its first interaction | `bridge_platform`, `seconds_since_room_created` | +| `first_agent_registered` | the first agent registers | `known_agent_type` | +| `first_session_started` | the first agent session opens | `known_agent_type` | + +`first_room_active` is the one that matters most: it is "install to seeing +value" end to end, and its `seconds_since_room_created` separates the two halves +of that journey — whether the time went on getting a room set up, or on getting +anyone to use it once it existed. + +Emitted once *ever*, not once per process. Each needs a persisted marker, so a +restart cannot re-emit one and a deployment that passes a milestone while +telemetry is switched off does not emit it later as though it had just happened. + +### Lifecycle events + +**`connector_added`** — every connector, not only the first. + +| Property | Type | +|---|---| +| `bridge_platform` | platform | +| `seconds_since_install` | number | +| `seconds_since_configured` | number — configuration saved to first connect | +| `is_first_connector` | boolean | +| `failed_attempts_before_success` | number | + +`seconds_since_configured` and `failed_attempts_before_success` are what answer +"is one platform too hard". Elapsed time from install mostly measures when +somebody got round to it; time from *configuring* a bridge to it actually +working, and how many failures came first, measures the platform. Teams needing +six attempts and Slack needing one is the finding worth having. + +The honest limitation: much of connector setup happens in the platform's own +admin UI, which the server cannot see. These metrics cover the part that starts +when Switch is first told about the bridge. + +**`room_created`** + +| Property | Type | +|---|---| +| `channel_type` | `channel_public` \| `channel_private` \| `direct` \| `none` | +| `bridge_platform` | platform, or `none` for internal-only | +| `agent_count` | number | +| `human_count` | number | +| `has_instructions` | boolean | +| `created_by_kind` | `user` \| `agent` \| `system` | +| `from_template` | boolean | + +**`room_became_active`** — the first interaction in a room, once per room. + +| Property | Type | +|---|---| +| `seconds_since_room_created` | number | +| `bridge_platform` | platform | +| `channel_type` | channel type | +| `agent_count` | number | + +This is "time to create an active room" for every room, not only the first. The +distribution is the interesting part: if rooms created in week one go active in +minutes and rooms created in week six never do, that is a different problem from +a slow average. + +**`room_archived`** — `bridge_platform`, `age_days` (number), `was_ever_active` +(boolean). + +**`room_agents_added`** — `agent_count` (number), `added_by_kind`. + +**`agent_registered`** + +| Property | Type | +|---|---| +| `agent_type` | `always_on` \| `session_addressable` \| `session_passive` | +| `known_agent_type` | `claude-code` \| `codex` \| `opencode` \| `other` \| `none` | +| `registration_path` | `bootstrap` \| `personal_key` \| `console` \| `other` | +| `has_parent` | boolean — a subagent rather than a top-level agent | + +**`agent_session_started`** — `known_agent_type`, `start_source` +(`auto` \| `manual` \| `api`). + +**`agent_session_ended`** — `known_agent_type`, `duration_seconds` (number), +`reason` (`normal` \| `heartbeat_lapsed` \| `replaced` \| `room_claimed` \| +`error`). + +The connection registry already records a reason on every close, which is where +these values come from; the set is closed here so a new reason string added in +the code does not silently become a new Amplitude value. + +**`bridge_connected`** — `bridge_platform`, `outcome`, `failure_reason`. + +**`bridge_disconnected`** — `bridge_platform`, `reason` +(`shutdown` \| `restart` \| `auth_failed` \| `network` \| `platform_error` \| +`unknown`). + +Bridge drops are worth having as events rather than only as a snapshot count: +the snapshot says two bridges are down right now, the events say one platform +has flapped forty times today. That is the difference between noticing and +diagnosing. + +**`deployment_started`** — `migrated` (boolean, whether the boot applied +migrations), `tenant_count`. The version is already a resource attribute, so +this gives an upgrade curve across installations: which versions are actually +running. + +### Closed value sets + +`bridge_platform`: `slack` | `mattermost` | `discord` | `teams` | `telegram` | +`none`. + +`outcome`: `success` | `failure`. `failure_reason` is an enumerated code per +event, `none` on success — never an exception message. + +Any property whose value is not in its set is a bug. It should raise where the +event is built rather than be coerced, dropped, or sent as `unknown` — a +silently-widening value set is how an analytics catalogue stops being +trustworthy. + +## Consent + +A Switch server reporting its usage to a vendor relay is a different question +from a desktop app doing it, because the deployment may be a customer's and the +usage may be theirs. + +The Console's answer is opt-in, defaulting to off, gated on an explicit choice +having been made, and re-read on every event so revoking takes effect +immediately. **The server takes the same position**: telemetry is off unless +switched on, it is one setting, and when it is off no request is made at all. + +This interacts with the milestone events in a way worth stating: a deployment +that enables telemetry three months in has already passed most of its +activation funnel. Milestones are emitted only when they actually occur, never +retroactively, so such a deployment simply contributes nothing to time-to-value +— which is correct, and better than a backfilled figure that would read as an +instant activation. + +This is a setting an operator controls, and it must be documented where they +will see it before they deploy — not only in this note. What is sent, where it +goes, and how to turn it off belongs in the deployment documentation. + +## What this needs from the export path + +The seam with `CHOO-2807`. The catalogue above needs the export path to provide: + +1. **A send taking an event name and a flat map of properties**, emitting one + OTLP log record with the resource attributes above, the `switch_core.` prefix, + and the name in both required places. +2. **Non-blocking emission.** A slow or unreachable relay must never delay a + request, a message send, or a bridge event. A failed send is logged and + dropped; telemetry is never worth a user-visible stall. +3. **The consent gate inside the send**, so that no call site can bypass it and + no new event can forget it. +4. **The deployment id and `installed_at`**, generated and persisted once. +5. **A closed catalogue with the property allow-list enforced at the boundary**, + so an event carrying an undeclared property fails rather than shipping it. + +Nothing on that list is specific to product events; each is equally needed for +operational ones, which is why it belongs to the shared path rather than here. + +## Open questions + +- **Snapshot scheduling.** A daily snapshot from a singleton server is a + background task, but a deployment that restarts frequently could emit several + in a day or none. It needs a "last sent" watermark in the database rather than + a timer from boot. +- **Cost of the snapshot.** Several of its counts are distinct-count queries + over the message table across a seven-day window. On a large deployment that + is not free, and it should be measured before it runs daily on a live + instance. +- **Self-hosted versus hosted.** The consent default is right for both, but a + customer-operated deployment may warrant saying more in the docs than a + pilot instance does. +- **Retention and deletion.** Owned by the relay rather than by Switch, but an + operator who turns telemetry off will reasonably ask what happens to what was + already sent. The answer should exist before someone asks. From fcb0fb2304dc5d8ab489f7c961cd3228ffb87e3a Mon Sep 17 00:00:00 2001 From: Christian McDermott Date: Wed, 16 Sep 2026 14:33:46 -0400 Subject: [PATCH 2/5] docs(telemetry): count user-created rooms, and measure only new deployments Two definitions settled with the collaborating dev. The headline room figure is rooms a human created. An agent that spins up ten scratch rooms for its own orchestration has not produced ten rooms of customer value, and letting the two share a number would make adoption read as whatever the agents happened to be doing that week. Agent-created rooms keep a count of their own, and the activation milestones track user-created rooms only. Where a room event can carry the distinction it does, rather than dropping agent rooms, so "do agent-made rooms ever get used" stays answerable from the same event. Time to value is measured for deployments installed from here onward. An install date guessed from the oldest row in an existing database would be wrong by an unknown margin in an unknown direction, and a funnel built on it would read as confident when it is not. A deployment whose id is generated against a database that already has content emits no milestone events at all; the daily counts are unaffected and every deployment still reports those. Refs CHOO-2806. Co-Authored-By: Claude Opus 5 (1M context) --- docs/old/telemetry-events.md | 57 ++++++++++++++++++++++++++++-------- 1 file changed, 44 insertions(+), 13 deletions(-) diff --git a/docs/old/telemetry-events.md b/docs/old/telemetry-events.md index f7dbf6cae..148aefdce 100644 --- a/docs/old/telemetry-events.md +++ b/docs/old/telemetry-events.md @@ -109,11 +109,22 @@ A deployment running several tenants reports as one subject, because the alternative is a per-tenant identifier, which is exactly what the rule above forbids. Tenant *count* is reported; tenant identity is not. -**Deployments that already exist** have no install timestamp to recover. On -first upgrade they get an id, and `installed_at` is approximated from the oldest -row in the database. Every milestone event carries -`install_time_exact: false` in that case, so a backfilled deployment can be -excluded from time-to-value analysis rather than quietly skewing it. +**Time to value is measured for new deployments only.** When the id is +generated, the server checks whether the database already holds rooms, agents or +messages. On an empty database this is a genuinely new installation: +`installed_at` is set to now and the milestone events below are armed. On a +database that already has content, the deployment predates this telemetry, +`installed_at` stays null, and **no milestone event is ever emitted for it**. + +No approximation, and no backfill. An install date guessed from the oldest row +would be wrong by an unknown margin in an unknown direction, and a funnel built +on it would read as confident when it is not. A deployment that cannot answer +"how long did activation take" should say nothing rather than guess, so the +time-to-value figures describe only installations actually watched from their +first boot. + +The counts in the daily snapshot are unaffected — every deployment reports +those, old or new. ## Resource attributes @@ -185,6 +196,13 @@ Counted distinctly per window, so one person in six rooms is one active user. over both one day and seven, because a weekly figure flatters a product used intensely on Mondays and a daily one punishes it. +**Room created by a user** — a room a human made, through the gateway or the +Console. This is the headline "Rooms" figure. Rooms an agent provisioned for +itself are counted separately and never stand in for it: an orchestration that +spins up ten scratch rooms is not ten rooms of customer value, and letting the +two share a number would make adoption look like whatever the agents happened to +be doing that week. + **Session** — an agent session as the connection registry knows it: opened when an agent connects, closed when it disconnects or its heartbeat lapses. @@ -216,10 +234,11 @@ never invisible. | `user_count` | number | user accounts that exist | | `user_active_1d` | number | distinct humans who interacted in 24h | | `user_active_7d` | number | same over 7 days | -| `room_count` | number | rooms not archived | -| `room_active_1d` | number | rooms with an interaction in 24h | +| `room_count` | number | **the headline figure** — unarchived rooms created by a user | +| `room_agent_created_count` | number | unarchived rooms an agent created | +| `room_active_1d` | number | user-created rooms with an interaction in 24h | | `room_active_7d` | number | same over 7 days | -| `room_archived_count` | number | archived rooms | +| `room_archived_count` | number | archived rooms, both kinds | | `room_internal_only_count` | number | rooms with no external channel | | `room_membership_total` | number | user–room memberships summed over rooms | | `room_users_mean` | number | mean human members per room | @@ -257,18 +276,25 @@ later. ### Milestone events — at most once per deployment -Each carries `seconds_since_install` (number) and `install_time_exact` -(boolean). Together with `deployment_installed` they form the activation funnel. +Each carries `seconds_since_install` (number). Together with +`deployment_installed` they form the activation funnel. Emitted only by +deployments installed after this ships — see +[Deployment identity](#deployment-identity-and-the-install-clock). | Event | Emitted when | Extra properties | |---|---|---| -| `deployment_installed` | the deployment id is first generated | `install_time_exact` | +| `deployment_installed` | the deployment id is generated on an empty database | — | | `first_connector_added` | any bridge first reaches connected | `bridge_platform` | -| `first_room_created` | the first room is created | `channel_type`, `bridge_platform` | -| `first_room_active` | the first room sees its first interaction | `bridge_platform`, `seconds_since_room_created` | +| `first_room_created` | the first **user-created** room is created | `channel_type`, `bridge_platform` | +| `first_room_active` | that room sees its first interaction | `bridge_platform`, `seconds_since_room_created` | | `first_agent_registered` | the first agent registers | `known_agent_type` | | `first_session_started` | the first agent session opens | `known_agent_type` | +The two room milestones track user-created rooms only, for the reason given +under [Definitions](#definitions): a room an agent made for itself is not the +moment a customer got started, and counting it would report activation that +never happened. + `first_room_active` is the one that matters most: it is "install to seeing value" end to end, and its `seconds_since_room_created` separates the two halves of that journey — whether the time went on getting a room set up, or on getting @@ -320,6 +346,11 @@ when Switch is first told about the bridge. | `bridge_platform` | platform | | `channel_type` | channel type | | `agent_count` | number | +| `created_by_kind` | `user` \| `agent` \| `system` | + +`created_by_kind` rides along rather than agent-created rooms being dropped, so +the headline chart can filter to user-created rooms while the question "do +agent-made rooms ever get used?" stays answerable from the same event. This is "time to create an active room" for every room, not only the first. The distribution is the interesting part: if rooms created in week one go active in From 255aa8ab2347455e6bc8a5ef656c2c6991e85064 Mon Sep 17 00:00:00 2001 From: Christian McDermott Date: Wed, 16 Sep 2026 15:17:44 -0400 Subject: [PATCH 3/5] feat(telemetry): report anonymous usage counts and time to value (CHOO-2806) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The server reported nothing about how it is used. This adds the product half of telemetry: a daily snapshot of counts, a set of once-ever activation milestones, and the lifecycle events around rooms and connectors. Off unless an operator switches it on. Everything goes through one catalogue that declares each event and the exact properties it carries, and the catalogue is enforced rather than documented: an undeclared event, an undeclared property or a value outside its closed set all raise where the event is built. That is what makes "no room, tenant, agent, user or message is ever identified" a property of the code. The test suite plays the Console's own trick of smuggling a room name into every event and asserting it never reaches the wire. Counts are gathered per tenant and summed into deployment totals. Not because tenants are reported separately — they deliberately are not — but because row-level security means a session with nothing bound reads nothing, so a single unscoped COUNT would answer zero on a correctly configured deployment and the snapshot would be a page of confident zeroes. Turns rather than senders for the conversation figures. A message classified by who sent the one before it in the same room is the only way to tell an agent answering a person from two agents talking to each other; a sender-only count reports both as "from an agent". Room activation is derived in the daily pass rather than detected at write time. Doing it in the message path would mean a per-room flag and three extra queries on the hottest path in the server to learn something nobody needs within a day. There is deliberately no per-message event either: the relay has no batching and no retry because it was built for a desktop app emitting a handful of events an hour. Time to value is measured only for deployments installed from here onward. The migration decides that once, while the database is still empty enough to answer it honestly; an install date inferred from the oldest row would be wrong by an unknown margin in an unknown direction, and every activation figure built on it would look confident and be false. Such deployments report the daily counts and no milestones. The three bookkeeping tables carry no tenant, so they are named in GLOBAL_TABLES and in the raw-session allowlist: each records a fact about the installation rather than about anything inside it, and a deployment running three tenants has one identity, not three. Refs CHOO-2806. Co-Authored-By: Claude Opus 5 (1M context) --- .../bridges/agent/protocol/service.py | 6 +- .../bridges/collaboration/bridge_core.py | 10 +- .../collaboration/lifecycle_service.py | 169 +++++- core/switch_core/config.py | 54 ++ core/switch_core/db/models.py | 92 +++ core/switch_core/db/rls_ddl.py | 20 +- core/switch_core/main.py | 39 ++ .../a7e1c4b90d23_telemetry_bookkeeping.py | 94 +++ core/switch_core/room_service.py | 135 ++++- core/switch_core/rooms_yaml.py | 1 + core/switch_core/telemetry/__init__.py | 23 + core/switch_core/telemetry/catalogue.py | 324 ++++++++++ core/switch_core/telemetry/deployment.py | 119 ++++ core/switch_core/telemetry/reporter.py | 167 +++++ core/switch_core/telemetry/service.py | 200 ++++++ core/switch_core/telemetry/setup.py | 74 +++ core/switch_core/telemetry/sink.py | 211 +++++++ core/switch_core/telemetry/snapshot.py | 572 ++++++++++++++++++ .../db/test_tenant_exemption_allowlist.py | 21 + .../db/test_tenant_schema_catalogue.py | 14 +- .../switch_core/telemetry/test_catalogue.py | 176 ++++++ .../telemetry/test_deployment_and_reporter.py | 322 ++++++++++ .../telemetry/test_service_and_sink.py | 284 +++++++++ .../switch_core/telemetry/test_snapshot.py | 557 +++++++++++++++++ .../remote/helm/switch/templates/_helpers.tpl | 8 + deploy/remote/helm/switch/values.yaml | 20 + 26 files changed, 3704 insertions(+), 8 deletions(-) create mode 100644 core/switch_core/migrations/versions/a7e1c4b90d23_telemetry_bookkeeping.py create mode 100644 core/switch_core/telemetry/__init__.py create mode 100644 core/switch_core/telemetry/catalogue.py create mode 100644 core/switch_core/telemetry/deployment.py create mode 100644 core/switch_core/telemetry/reporter.py create mode 100644 core/switch_core/telemetry/service.py create mode 100644 core/switch_core/telemetry/setup.py create mode 100644 core/switch_core/telemetry/sink.py create mode 100644 core/switch_core/telemetry/snapshot.py create mode 100644 core/tests/switch_core/telemetry/test_catalogue.py create mode 100644 core/tests/switch_core/telemetry/test_deployment_and_reporter.py create mode 100644 core/tests/switch_core/telemetry/test_service_and_sink.py create mode 100644 core/tests/switch_core/telemetry/test_snapshot.py diff --git a/core/switch_core/bridges/agent/protocol/service.py b/core/switch_core/bridges/agent/protocol/service.py index bc296ae29..7e66a9e90 100644 --- a/core/switch_core/bridges/agent/protocol/service.py +++ b/core/switch_core/bridges/agent/protocol/service.py @@ -2363,6 +2363,7 @@ async def create_moderation_room( protection_config=security_config, instructions=instructions, created_by=agent.owner_id, + created_by_kind="agent", owner_id=agent.owner_id, group_id=group_id, read_visibility=read_visibility, @@ -2458,7 +2459,10 @@ async def invite_agent_to_room( include_for = [target.id] try: await self.room_service.add_agents_to_room( - room_id, agent_names=[agent_name], include_subagents_for=include_for + room_id, + agent_names=[agent_name], + include_subagents_for=include_for, + added_by_kind="agent", ) except ValueError as e: raise ValueError(f"Failed to invite agent: {str(e)}") from e diff --git a/core/switch_core/bridges/collaboration/bridge_core.py b/core/switch_core/bridges/collaboration/bridge_core.py index 1c9f9dbc8..63e2e1690 100644 --- a/core/switch_core/bridges/collaboration/bridge_core.py +++ b/core/switch_core/bridges/collaboration/bridge_core.py @@ -228,6 +228,11 @@ def adapter(self) -> CollaborationAdapter: def tenant_id(self) -> str: return self._bridge_tenant_id + @property + def bridge_type(self) -> str: + """The collaboration platform this bridge talks to.""" + return self._bridge_type + def _traced( self, handler: Callable[[_InboundEventT], Awaitable[None]] ) -> Callable[[_InboundEventT], Awaitable[None]]: @@ -858,7 +863,7 @@ async def _handle_agent_joined_channel_locked(self, join: InboundAgentJoin) -> N logger.debug("Room already exist, add %s to channel", join.agent_name) room_id, _ = existing await self._room_service.add_agents_to_room( - room_id, agent_names=[join.agent_name] + room_id, agent_names=[join.agent_name], added_by_kind="system" ) return @@ -1016,6 +1021,9 @@ async def _create_room_for_channel( channel_type=channel_type, bridge_id=self._bridge_id, external_channel_id=channel_id, + # Adopted from a channel that appeared on the platform, not asked + # for by anyone in Switch. + created_by_kind="system", ) try: diff --git a/core/switch_core/bridges/collaboration/lifecycle_service.py b/core/switch_core/bridges/collaboration/lifecycle_service.py index 0b9697df8..5f7d347fc 100644 --- a/core/switch_core/bridges/collaboration/lifecycle_service.py +++ b/core/switch_core/bridges/collaboration/lifecycle_service.py @@ -3,6 +3,7 @@ import asyncio import logging import re +from datetime import UTC, datetime from typing import TYPE_CHECKING from uuid import uuid4 @@ -24,6 +25,9 @@ from switch_core.db.stores.room_store import RoomStore from switch_core.db.tenant_lookup import all_tenant_ids, tenant_of_collaboration_bridge from switch_core.provisioning import Provisioning +from switch_core.telemetry import TelemetryService, emit_safely +from switch_core.telemetry.deployment import claim_milestone, seconds_since_install +from switch_core.telemetry.snapshot import normalise_platform from switch_core.tenant_context import current_tenant_id, no_tenant if TYPE_CHECKING: @@ -33,6 +37,38 @@ logger = logging.getLogger(__name__) +def _failure_reason(exc: BaseException) -> str: + """An enumerated reason for a bridge failure. + + Enumerated rather than the exception's message, which is free text that + routinely carries a workspace name, a URL or a token fragment — none of + which may leave the deployment. Matched on the class name so no adapter + library has to be imported here just to name its errors. + """ + name = type(exc).__name__.lower() + if any(word in name for word in ("auth", "unauthorized", "forbidden", "token")): + return "auth_failed" + if any(word in name for word in ("timeout", "connection", "socket", "dns")): + return "network" + if isinstance(exc, ValueError | KeyError): + return "config_invalid" + if any(word in name for word in ("api", "http", "server", "gateway")): + return "platform_error" + return "unknown" + + +def _seconds_since(moment: object) -> float: + """Seconds since a timestamp column, or -1 when it is not a timestamp. + + -1 rather than 0, so "we could not tell" is distinguishable from "it + happened just now" in a chart. + """ + if not isinstance(moment, datetime): + return -1.0 + anchored = moment if moment.tzinfo else moment.replace(tzinfo=UTC) + return max((datetime.now(UTC) - anchored).total_seconds(), 0.0) + + def _bridge_client_localpart(bridge_type: str, display_name: str) -> str: """The Matrix localpart for a messaging app's own client. @@ -53,6 +89,11 @@ def _bridge_client_localpart(bridge_type: str, display_name: str) -> str: class CollaborationBridgeLifecycleService: + # See RoomService: a test may assemble this without `__init__`. + _telemetry: TelemetryService | None = None + _connect_failures: dict[str, int] = {} + _bridge_facts: dict[str, tuple[str, object]] = {} + def __init__( self, *, @@ -68,6 +109,7 @@ def __init__( session_factory: async_sessionmaker[AsyncSession], config: SwitchConfig, client_factory: ClientFactory, + telemetry: TelemetryService | None = None, ) -> None: self._bridge_store = bridge_store self._external_user_store = external_user_store @@ -76,6 +118,7 @@ def __init__( self._agent_store = agent_store self._client_store = client_store self._client_lifecycle = client_lifecycle + self._telemetry = telemetry self._room_service = room_service self._matrix_admin = matrix_admin self._session_factory = session_factory @@ -86,6 +129,14 @@ def __init__( self._config_registry: dict[str, type[BridgeConnectionConfig]] = {} self._bridges: dict[str, BridgeCore] = {} self._tasks: dict[str, asyncio.Task[None]] = {} + # How many times each bridge has failed to come up since this + # process started. See `_note_connect_failure`. + self._connect_failures: dict[str, int] = {} + # Each bridge's platform and when its row was written, read off the + # row at start. Kept here rather than fetched from the BridgeCore so + # reporting never depends on what that object exposes — a stand-in + # supplied by a test is still a legitimate bridge to run. + self._bridge_facts: dict[str, tuple[str, object]] = {} # bridge_id -> the host resource it holds exclusively while running # (see CollaborationAdapter.exclusive_resource). Lets a second # claimant be refused by name instead of failing on the resource. @@ -528,6 +579,10 @@ async def start(self, bridge_id: str) -> None: transport_factory=self._client_factory.transport_for, ) + # Stashed rather than passed: `_run_bridge`'s signature is what the + # tenant-binding tests patch, and widening it to carry two reporting + # details would make every fake of it wrong. + self._bridge_facts[bridge_id] = (bridge.type, bridge.created_at) task = asyncio.create_task( self._run_bridge(bridge_id, tenant_id, bridge_core, bridge_client) ) @@ -612,18 +667,119 @@ async def _run_bridge( which runs until shutdown — binds nothing at all, leaving each delivery to bind the tenant of the room it is for. """ + platform, configured_at = self._bridge_facts.get(bridge_id, ("none", None)) with no_tenant(): + connected = False try: await self._record_bridge_memberships( bridge_id, tenant_id, bridge_client.client_id ) await bridge_core.start() + # `bridge_core.start()` returning is the moment the adapter is + # actually talking to the platform — `start()` above only + # launched this task, and `bridge_client.start()` below runs + # until shutdown, so this is the one point that means + # "connected". + connected = True + await self._report_connector_up(bridge_id, platform, configured_at) await bridge_client.start() - except Exception: + except Exception as exc: logger.exception("Bridge %s crashed", bridge_id) self._bridges.pop(bridge_id, None) self._tasks.pop(bridge_id, None) self._held_resources.pop(bridge_id, None) + # Told apart by whether the adapter ever came up: a failure + # before that never connected at all, and reporting it as a + # disconnection would invent an uptime the bridge never had. + if connected: + emit_safely( + self._telemetry, + "bridge_disconnected", + { + "bridge_platform": normalise_platform(platform), + "reason": _failure_reason(exc), + }, + ) + else: + self._note_connect_failure(bridge_id) + emit_safely( + self._telemetry, + "bridge_connected", + { + "bridge_platform": normalise_platform(platform), + "outcome": "failure", + "failure_reason": _failure_reason(exc), + }, + ) + + def _note_connect_failure(self, bridge_id: str) -> None: + """Remember that this bridge failed to come up. + + In memory rather than in a row, and that is a real limitation: a + restart forgets, so `failed_attempts_before_success` under-reports a + connector whose struggles spanned one. It is still the only signal + that separates "this platform is hard to set up" from "nobody tried it + until March", and a table for it would be a migration to hold a + number that is interesting for about a day per deployment. + """ + self._connect_failures[bridge_id] = self._connect_failures.get(bridge_id, 0) + 1 + + async def _report_connector_up( + self, bridge_id: str, platform: str, configured_at: object + ) -> None: + """Report a bridge reaching the platform, and the effort it took. + + Two events, because they answer different questions. `bridge_connected` + fires every time and is how a flapping bridge shows up at all. + `connector_added` fires only the first time this bridge ever connected + — the setup finally working — and carries the timings that say whether + one platform is harder than another. + """ + emit_safely( + self._telemetry, + "bridge_connected", + { + "bridge_platform": normalise_platform(platform), + "outcome": "success", + "failure_reason": "none", + }, + ) + + if self._telemetry is None: + return + # The first successful connect for this bridge, ever. Claimed against + # the bridge id so restarting a working bridge does not re-report a + # setup that happened months ago. + if not await claim_milestone( + self._session_factory, f"connector_added:{bridge_id}" + ): + return + + elapsed_since_install = seconds_since_install(self._telemetry.installed_at) + emit_safely( + self._telemetry, + "connector_added", + { + "bridge_platform": normalise_platform(platform), + # -1 where the deployment has no install clock, which is + # distinguishable from "took no time" in a way that 0 is not. + "seconds_since_install": ( + elapsed_since_install if elapsed_since_install is not None else -1.0 + ), + "seconds_since_configured": _seconds_since(configured_at), + "is_first_connector": not self._any_connector_before(bridge_id), + "failed_attempts_before_success": self._connect_failures.pop( + bridge_id, 0 + ), + }, + ) + await self._telemetry.emit_milestone( + "first_connector_added", bridge_platform=normalise_platform(platform) + ) + + def _any_connector_before(self, bridge_id: str) -> bool: + """Whether another bridge was already connected when this one came up.""" + return any(other != bridge_id for other in self._bridges) async def stop(self, bridge_id: str) -> None: bridge_core = self._bridges.get(bridge_id) @@ -638,6 +794,17 @@ async def stop(self, bridge_id: str) -> None: self._held_resources.pop(bridge_id, None) logger.info("Stopped collaboration bridge %s", bridge_id) + if bridge_core is not None: + platform, _ = self._bridge_facts.get(bridge_id, ("none", None)) + emit_safely( + self._telemetry, + "bridge_disconnected", + { + "bridge_platform": normalise_platform(platform), + "reason": "shutdown", + }, + ) + async def restart(self, bridge_id: str) -> None: """Stop and start a bridge so it picks up its stored config. diff --git a/core/switch_core/config.py b/core/switch_core/config.py index ab01ca1f4..cadadddda 100644 --- a/core/switch_core/config.py +++ b/core/switch_core/config.py @@ -164,6 +164,40 @@ class SwitchConfig(BaseSettings): # `tenant_id`. tenant_id: str = "default" + # ── Product telemetry ──────────────────────────────────────────────────── + # Usage reporting to the company relay, which fans out to product + # analytics. Separate from the logging above, which stays inside the + # deployment's own pipeline and is not affected by any of this. + # + # **Off unless switched on, and that default is deliberate.** A Switch + # server may be a customer's, and the usage may be theirs, so reporting it + # is a decision an operator makes rather than one they discover. When this + # is false nothing is collected and no request is made — not a disabled + # exporter that still builds payloads, and not a queue that drains later. + # + # What is reported is fixed in `telemetry/catalogue.py` and explained in + # `docs/old/telemetry-events.md`: counts and durations only, never an + # identifier for a room, tenant, agent, user or message, and never free + # text. The catalogue is enforced at the boundary rather than trusted. + telemetry_enabled: bool = False + + # Where events go. Defaults to the company relay — the same endpoint the + # Switch Console reports to, so one pipeline carries both. Override to + # point a development run at a local listener rather than at production + # analytics. + telemetry_endpoint: str = "https://telemetry.flintai.dev/v1/logs" + + # How long to wait on the relay before giving up on a single event. + # Telemetry is never worth delaying real work for, and a send that is + # already this late is not worth finishing. + telemetry_timeout_seconds: float = 10.0 + + # How often the daily usage snapshot is collected and sent. Hours rather + # than a fixed clock time so a deployment does not have to care which + # timezone it is in; the schedule is anchored to what was last sent, not + # to how long this process has been up. + telemetry_snapshot_interval_hours: float = 24.0 + server_host: str = "0.0.0.0" server_port: int = 8000 @@ -304,6 +338,26 @@ def _validate_logging(self) -> "SwitchConfig": ) if not self.tenant_id.strip(): raise ValueError("TENANT_ID must not be empty.") + if self.telemetry_enabled: + # Checked only when telemetry is on: a deployment that never + # reports should not be refused boot over the shape of a setting + # it does not use. + endpoint = urlsplit(self.telemetry_endpoint) + if endpoint.scheme not in ("http", "https") or not endpoint.netloc: + raise ValueError( + "TELEMETRY_ENDPOINT must be an absolute http(s) URL, got " + f"{self.telemetry_endpoint!r}." + ) + if self.telemetry_timeout_seconds <= 0: + raise ValueError( + "TELEMETRY_TIMEOUT_SECONDS must be positive, got " + f"{self.telemetry_timeout_seconds!r}." + ) + if self.telemetry_snapshot_interval_hours <= 0: + raise ValueError( + "TELEMETRY_SNAPSHOT_INTERVAL_HOURS must be positive, got " + f"{self.telemetry_snapshot_interval_hours!r}." + ) if self.template_max_bytes < 1: raise ValueError( f"TEMPLATE_MAX_BYTES must be at least 1, got {self.template_max_bytes}." diff --git a/core/switch_core/db/models.py b/core/switch_core/db/models.py index f61bfb12f..83bd233ce 100644 --- a/core/switch_core/db/models.py +++ b/core/switch_core/db/models.py @@ -1464,6 +1464,98 @@ class BridgeMessageMap(TenantScoped, Base): ) +# ── Telemetry bookkeeping ──────────────────────────────────────────────────── + + +class DeploymentIdentity(Base): + """Who this installation is to the telemetry relay, and when it began. + + Deliberately **not** tenant-scoped: this identifies the deployment, which + is the thing above tenants rather than one of them. A deployment running + several tenants is one subject, because the alternative is a per-tenant + identifier and that is precisely what the telemetry rule forbids + (`docs/old/telemetry-events.md`). + + Exactly one row. The primary key is pinned to 1 by a check constraint so a + second identity cannot be inserted by accident — two would mean one + installation reporting as two subjects, silently doubling every count + derived from it. + + `client_id` is a random UUID and nothing else: not derived from a hostname, + a licence, an account or any customer value. It is generated once and kept + across restarts and redeploys so the deployment is one subject for its + whole life rather than a new one each boot. + + `installed_at` is null when the identity was created against a database + that already held content — an installation that predates this telemetry + and whose true install date is not recoverable. Milestone events are + suppressed for such a deployment rather than measured from a guess: an + install date inferred from the oldest row would be wrong by an unknown + margin in an unknown direction, and an activation funnel built on it would + read as confident when it is not. The daily counts are unaffected. + """ + + __tablename__ = "deployment_identity" + __table_args__ = ( + CheckConstraint("id = 1", name="ck_deployment_identity_singleton"), + ) + + id: Mapped[int] = mapped_column(Integer, primary_key=True, default=1) + client_id: Mapped[str] = mapped_column(Text, nullable=False, default=_uuid) + installed_at: Mapped[datetime | None] = mapped_column( + DateTime(timezone=True), nullable=True + ) + created_at: Mapped[datetime] = mapped_column( + DateTime(timezone=True), server_default=func.now(), nullable=False + ) + + +class TelemetryMilestone(Base): + """A once-ever telemetry event that has already been reported. + + The activation funnel is built from milestones — first connector, first + room, first room that anyone used — and each is only meaningful if it is + reported the first time it happens and never again. A restart must not + re-emit one, and a deployment must not report "first room created" every + time the server boots and finds a room. + + So the fact of having emitted is a row, not process state. The name is the + primary key, which makes the insert itself the guard: a second emission + collides rather than needing a read-then-write that two workers could + interleave. + + Not tenant-scoped, for the same reason as `DeploymentIdentity` — a + milestone is a fact about the installation. + """ + + __tablename__ = "telemetry_milestones" + + name: Mapped[str] = mapped_column(Text, primary_key=True) + emitted_at: Mapped[datetime] = mapped_column( + DateTime(timezone=True), server_default=func.now(), nullable=False + ) + + +class TelemetrySnapshotWatermark(Base): + """When the daily usage snapshot was last sent. + + A timer started at boot would emit several snapshots on a day with several + restarts and none on a day the server happened to be down at the wrong + moment, so the schedule is anchored to what was actually sent rather than + to uptime. One row, pinned like the identity above. + """ + + __tablename__ = "telemetry_snapshot_watermark" + __table_args__ = ( + CheckConstraint("id = 1", name="ck_telemetry_snapshot_watermark_singleton"), + ) + + id: Mapped[int] = mapped_column(Integer, primary_key=True, default=1) + last_sent_at: Mapped[datetime] = mapped_column( + DateTime(timezone=True), nullable=False + ) + + # ── Feature flags ──────────────────────────────────────────────────────────── diff --git a/core/switch_core/db/rls_ddl.py b/core/switch_core/db/rls_ddl.py index fb433b245..d2667b52f 100644 --- a/core/switch_core/db/rls_ddl.py +++ b/core/switch_core/db/rls_ddl.py @@ -118,7 +118,25 @@ # switch, and a flag that needs to vary per customer is a new scoped table # rather than a nullable column here. Alembic's `alembic_version` needs no # entry: Alembic owns that table and never registers it on this metadata. -GLOBAL_TABLES = frozenset({"users", "oidc_identities", "feature_flags"}) +# +# The three telemetry tables are global because each records a fact about the +# *installation* rather than about anything inside it: which deployment this +# is to the analytics relay, when it was installed, which once-ever milestones +# it has already reported, and when its last usage snapshot went out. None +# holds customer data — that is the whole design of the telemetry catalogue, +# which reports counts and never an identifier — and scoping them would be +# incoherent: a deployment running three tenants has one identity, not three, +# and a milestone reported once per tenant would not be once-ever at all. +GLOBAL_TABLES = frozenset( + { + "users", + "oidc_identities", + "feature_flags", + "deployment_identity", + "telemetry_milestones", + "telemetry_snapshot_watermark", + } +) class UnscopedTableError(RuntimeError): diff --git a/core/switch_core/main.py b/core/switch_core/main.py index 1c0423e2f..7043e89da 100644 --- a/core/switch_core/main.py +++ b/core/switch_core/main.py @@ -120,6 +120,8 @@ from switch_core.provisioning import Provisioning from switch_core.provisioning.postgres import PostgresProvisioning from switch_core.room_service import RoomService +from switch_core.telemetry.reporter import SnapshotReporter +from switch_core.telemetry.setup import build_telemetry from switch_core.tenant_context import no_tenant from switch_core.transport.ephemeral import EphemeralBus from switch_core.transport.invites import InviteBus @@ -188,6 +190,14 @@ async def _connection_sweep_loop(protocol: ProtocolService) -> None: logger.exception("Connection sweep failed") +async def _snapshot_loop(reporter: SnapshotReporter) -> None: + # `no_tenant` for the reason every other long-lived task does it: the + # snapshot binds each tenant in turn as it counts, and must not inherit + # whichever one happened to be bound when the task was created. + with no_tenant(): + await reporter.run_forever() + + class _QuietPollFilter(logging.Filter): _SUPPRESSED = [ "/events?timeout=", @@ -315,6 +325,14 @@ async def run(config: SwitchConfig) -> None: event_buffer = EventBuffer() connector_store = ServerConnectorStore() + # ── Product telemetry ──────────────────────────────────────────────────── + # Built before the services that report through it, and built whether or + # not it is switched on: disabled is a sink that discards, so nothing + # downstream has to ask. + telemetry, installed_at = await build_telemetry( + config, session_factory, switch_core_version() + ) + # ── Resource service ───────────────────────────────────────────────────── resource_service = ResourceService( reference_store=reference_store, @@ -413,6 +431,7 @@ async def run(config: SwitchConfig) -> None: session_factory=session_factory, config=config, client_factory=client_factory, + telemetry=telemetry, ) # ── Room service ───────────────────────────────────────────────────────── @@ -425,6 +444,7 @@ async def run(config: SwitchConfig) -> None: collab_bridge_store=bridge_store, resource_service=resource_service, session_factory=session_factory, + telemetry=telemetry, ) collab_lifecycle._room_service = room_service @@ -524,6 +544,14 @@ async def health_check() -> JSONResponse: # ── Lifespan: start server-side connectors once HTTP is serving ──────── original_lifespan = agent_bridge_app.router.lifespan_context + snapshot_reporter = SnapshotReporter( + telemetry=telemetry, + session_factory=session_factory, + interval_hours=config.telemetry_snapshot_interval_hours, + installed_at=installed_at, + live_session_count=lambda: len(connections.live_agent_ids()), + ) + @asynccontextmanager async def lifespan(app: object) -> AsyncIterator[None]: async with original_lifespan(app): # type: ignore[arg-type] @@ -532,13 +560,19 @@ async def lifespan(app: object) -> AsyncIterator[None]: connection_sweep_task = asyncio.create_task( _connection_sweep_loop(protocol) ) + # Runs whether or not telemetry is enabled: the counts are logged + # either way, so an operator can see what would be reported before + # deciding to report it. + snapshot_task = asyncio.create_task(_snapshot_loop(snapshot_reporter)) await message_listener.start() try: yield finally: sweep_task.cancel() connection_sweep_task.cancel() + snapshot_task.cancel() await message_listener.stop() + await telemetry.aclose() agent_bridge_app.router.lifespan_context = lifespan # type: ignore[assignment] @@ -555,6 +589,11 @@ async def lifespan(app: object) -> AsyncIterator[None]: "Switch is running on http://%s:%d", config.server_host, config.server_port ) + telemetry.emit("deployment_started", tenant_count=len(tenant_ids)) + # The funnel's first step. Claimed once, and only by a deployment that + # knows when it was installed — see telemetry/deployment.py. + await telemetry.emit_milestone("deployment_installed") + server_config = uvicorn.Config( agent_bridge_app, host=config.server_host, diff --git a/core/switch_core/migrations/versions/a7e1c4b90d23_telemetry_bookkeeping.py b/core/switch_core/migrations/versions/a7e1c4b90d23_telemetry_bookkeeping.py new file mode 100644 index 000000000..86f8ea839 --- /dev/null +++ b/core/switch_core/migrations/versions/a7e1c4b90d23_telemetry_bookkeeping.py @@ -0,0 +1,94 @@ +"""telemetry bookkeeping: deployment identity, milestones, snapshot watermark + +Three server-global tables, none tenant-scoped and none carrying row-level +security: each records a fact about the *installation*, which is the thing +above tenants rather than one of them. + +`deployment_identity` is seeded here rather than at first use, and that is the +load-bearing part of this migration. Whether a deployment is new decides +whether it ever reports time-to-value, and the only moment that question can +be answered honestly is before the server has written anything of its own. +`installed_at` is set only when the database is genuinely empty of product +content; an existing deployment gets an identity with a null install date and +reports no milestones at all, rather than a date inferred from its oldest row. +A guess there would be wrong by an unknown margin in an unknown direction, and +every activation figure derived from it would look confident and be false. + +Revision ID: a7e1c4b90d23 +Revises: 5daaea6b674d +Create Date: 2026-09-16 00:00:00.000000 + +""" + +from collections.abc import Sequence + +import sqlalchemy as sa +from alembic import op + +revision: str = "a7e1c4b90d23" +down_revision: str | None = "5daaea6b674d" +branch_labels: str | Sequence[str] | None = None +depends_on: str | Sequence[str] | None = None + + +def upgrade() -> None: + op.create_table( + "deployment_identity", + sa.Column("id", sa.Integer(), primary_key=True), + sa.Column("client_id", sa.Text(), nullable=False), + sa.Column("installed_at", sa.DateTime(timezone=True), nullable=True), + sa.Column( + "created_at", + sa.DateTime(timezone=True), + server_default=sa.func.now(), + nullable=False, + ), + sa.CheckConstraint("id = 1", name="ck_deployment_identity_singleton"), + ) + + op.create_table( + "telemetry_milestones", + sa.Column("name", sa.Text(), primary_key=True), + sa.Column( + "emitted_at", + sa.DateTime(timezone=True), + server_default=sa.func.now(), + nullable=False, + ), + ) + + op.create_table( + "telemetry_snapshot_watermark", + sa.Column("id", sa.Integer(), primary_key=True), + sa.Column("last_sent_at", sa.DateTime(timezone=True), nullable=False), + sa.CheckConstraint("id = 1", name="ck_telemetry_snapshot_watermark_singleton"), + ) + + # The identity row, with the new-versus-existing decision made now. + # + # "Existing" is judged on product content — rooms, agents, messages — not + # on rows the server seeds for itself at boot. A fresh deployment already + # has a tenant, an admin user and a bootstrap key by the time anything + # else runs, so testing for *any* row would classify every new install as + # pre-existing and switch off the activation funnel everywhere. + op.execute( + """ + INSERT INTO deployment_identity (id, client_id, installed_at) + SELECT + 1, + gen_random_uuid()::text, + CASE + WHEN EXISTS (SELECT 1 FROM rooms) + OR EXISTS (SELECT 1 FROM agents) + OR EXISTS (SELECT 1 FROM messages) + THEN NULL + ELSE now() + END + """ + ) + + +def downgrade() -> None: + op.drop_table("telemetry_snapshot_watermark") + op.drop_table("telemetry_milestones") + op.drop_table("deployment_identity") diff --git a/core/switch_core/room_service.py b/core/switch_core/room_service.py index f8f748846..9cf5e8000 100644 --- a/core/switch_core/room_service.py +++ b/core/switch_core/room_service.py @@ -16,7 +16,8 @@ from __future__ import annotations import logging -from typing import TYPE_CHECKING, Any +from datetime import UTC, datetime +from typing import TYPE_CHECKING, Any, Literal from pydantic import BaseModel from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker @@ -36,6 +37,12 @@ from switch_core.db.stores.room_store import RoomStore from switch_core.db.tenant_lookup import all_tenant_ids from switch_core.provisioning import Provisioning +from switch_core.telemetry import TelemetryService, emit_safely +from switch_core.telemetry.snapshot import ( + normalise_channel_type, + normalise_platform, + room_had_human_activity, +) from switch_core.tenant_context import tenant_scope if TYPE_CHECKING: @@ -49,6 +56,19 @@ SYSTEM_CLIENT_TYPES = ("observe", "admin") +def _age_days(created_at: object) -> float: + """How many days old a room is, for reporting. Zero if unknown. + + Takes `object` because the timestamp columns on the models are annotated + `Mapped[str]` while carrying real `datetime`s — so the honest signature is + "whatever the column hands back", checked here rather than trusted. + """ + if not isinstance(created_at, datetime): + return 0.0 + moment = created_at if created_at.tzinfo else created_at.replace(tzinfo=UTC) + return max((datetime.now(UTC) - moment).total_seconds() / 86400.0, 0.0) + + class LinkedRoomSpec(BaseModel): target_room_id: str label: str @@ -111,6 +131,16 @@ class RoomCreateConfig(BaseModel): aliases: dict[str, str] | None = None acting_user_id: str | None = None acting_is_admin: bool = False + # Who asked for this room, as a kind rather than an identity. Not + # derivable from the fields above: `created_by` and `owner_id` hold the + # *agent's owner* on the agent path, so a room an agent provisioned for + # itself is indistinguishable from one that owner made by hand. Telemetry + # counts the two separately — an orchestration spinning up scratch rooms + # is not adoption — and the value is stamped into the room's metadata so + # the distinction survives for later reporting. + created_by_kind: Literal["user", "agent", "system"] = "user" + # Provisioned from a room template rather than created directly. + from_template: bool = False class RoomCreateResult(BaseModel): @@ -127,6 +157,12 @@ class RoomCreateResult(BaseModel): class RoomService: + # Class-level default so a caller that builds this without `__init__` — + # several tests assemble a minimal instance directly — still has the + # attribute. Telemetry is genuinely optional here; `emit_safely` treats + # None as "report nothing". + _telemetry: TelemetryService | None = None + def __init__( self, *, @@ -138,6 +174,7 @@ def __init__( collab_bridge_store: CollaborationBridgeStore, resource_service: ResourceService, session_factory: async_sessionmaker[AsyncSession], + telemetry: TelemetryService | None = None, ) -> None: self._matrix_admin = matrix_admin self._room_store = room_store @@ -147,6 +184,9 @@ def __init__( self._collab_bridge_store = collab_bridge_store self._resource_service = resource_service self._session_factory = session_factory + # Optional because several tests and tooling build a RoomService + # without one; `emit_safely` treats None as "report nothing". + self._telemetry = telemetry async def _resolve_agent_ids(self, config: RoomCreateConfig) -> list[str]: if config.agent_ids is not None: @@ -513,6 +553,10 @@ async def create_room(self, config: RoomCreateConfig) -> RoomCreateResult: owner_id=config.owner_id, read_visibility=config.read_visibility, write_visibility=config.write_visibility, + # Kept for later reporting: which rooms a human made is a + # headline product figure, and nothing else on the row can + # answer it afterwards. A kind, never an identity. + metadata_={"created_by_kind": config.created_by_kind}, ) async with self._session_factory() as session: @@ -603,6 +647,31 @@ async def create_room(self, config: RoomCreateConfig) -> RoomCreateResult: len(system_clients), ) + emit_safely( + self._telemetry, + "room_created", + { + "channel_type": normalise_channel_type(channel_type), + "bridge_platform": await self._bridge_platform(bridge_id), + "agent_count": len(agent_ids), + "human_count": len(config.user_names or []), + "has_instructions": config.instructions is not None, + "created_by_kind": config.created_by_kind, + "from_template": config.from_template, + }, + ) + + if self._telemetry is not None and config.created_by_kind == "user": + # Only a room a person made counts as activation. A room an agent + # provisioned for its own orchestration is not the moment a + # customer got started, and letting it claim the milestone would + # report an activation that never happened. + await self._telemetry.emit_milestone( + "first_room_created", + channel_type=normalise_channel_type(channel_type), + bridge_platform=await self._bridge_platform(bridge_id), + ) + failed_attachments = unreachable_users + await self._attach_after_creation( room.id, config ) @@ -694,6 +763,7 @@ async def add_agents_to_room( agent_names: list[str] | None = None, include_subagents_for: list[str] | None = None, join_event_listeners: list[str] | None = None, + added_by_kind: Literal["user", "agent", "system"] = "user", ) -> None: by_name = agent_ids is None and agent_names is not None if by_name: @@ -763,6 +833,17 @@ async def add_agents_to_room( logger.info("Added %d agents to room %s", len(agent_ids), room_id) + emit_safely( + self._telemetry, + "room_agents_added", + { + # The agents actually added, not the ones asked for: a request + # naming five agents already in the room added none. + "agent_count": len(new_agent_ids), + "added_by_kind": added_by_kind, + }, + ) + async def remove_agents_from_room(self, room_id: str, agent_ids: list[str]) -> None: async with self._session_factory() as session: room = await self._room_store.get(session, room_id) @@ -881,11 +962,59 @@ async def set_room_archived(self, room_id: str, archived: bool) -> None: Raises ValueError if the room does not exist. """ - tenant_id = await self._room_tenant(room_id) - async with tenant_session(self._session_factory, tenant_id) as session: + # The whole row rather than just its tenant: archiving reports how old + # the room was and what it was bridged to, and re-reading it after the + # write would be a second query for something already in hand. + room = await self._load_room(room_id) + async with tenant_session(self._session_factory, room.tenant_id) as session: await self._room_store.set_archived(session, room_id, archived) await session.commit() + if not archived: + return + emit_safely( + self._telemetry, + "room_archived", + { + "bridge_platform": await self._bridge_platform(room.bridge_id), + "age_days": _age_days(room.created_at), + "was_ever_active": await self._was_ever_active(room.tenant_id, room_id), + }, + ) + + async def _bridge_platform(self, bridge_id: str | None) -> str: + """The platform a bridge id names, as the telemetry catalogue spells it. + + `none` for an internal-only room, and also for a bridge id that no + longer resolves — a deleted bridge is not a platform, and guessing one + would be worse than reporting the absence. + """ + if bridge_id is None: + return "none" + async with self._session_factory() as session: + bridge = await self._collab_bridge_store.get(session, bridge_id) + return normalise_platform(bridge.type if bridge else None) + + async def _was_ever_active(self, tenant_id: str, room_id: str) -> bool: + """Whether a human ever posted in this room. + + Asked only when a room is archived, so the cost lands on a rare + operation rather than on every message. A failure answers False rather + than raising: this is one property of one analytics event, and an + archive must not fail because a count did. + """ + try: + async with tenant_session(self._session_factory, tenant_id) as session: + return await room_had_human_activity(session, room_id) + except Exception: + logger.warning( + "Could not determine whether room %s was ever active; " + "reporting it as inactive.", + room_id, + exc_info=True, + ) + return False + async def add_users_to_room(self, room_id: str, user_names: list[str]) -> list[str]: """Add users to a bridged room; returns the names that did not make it (added users are omitted from the result). diff --git a/core/switch_core/rooms_yaml.py b/core/switch_core/rooms_yaml.py index 64468557a..88f14611a 100644 --- a/core/switch_core/rooms_yaml.py +++ b/core/switch_core/rooms_yaml.py @@ -586,6 +586,7 @@ async def provision( user_names=spec.users or None, bridge_id=bridge_id, created_by=user_id, + from_template=True, owner_id=user_id, acting_user_id=user_id, acting_is_admin=is_admin, diff --git a/core/switch_core/telemetry/__init__.py b/core/switch_core/telemetry/__init__.py new file mode 100644 index 000000000..166831924 --- /dev/null +++ b/core/switch_core/telemetry/__init__.py @@ -0,0 +1,23 @@ +"""Product telemetry: what Switch reports about how it is used. + +Counts and durations, never an identifier for a room, tenant, agent, user or +message, and never free text. Off unless an operator switches it on. The events +are declared in :mod:`switch_core.telemetry.catalogue` and explained in +``docs/old/telemetry-events.md``. + +Call sites want two things from this package and nothing else: `emit_safely`, +to report an event from the middle of real work without a catalogue mistake +being able to break it, and the `TelemetryService` that gets handed around. +Everything else here is wiring. +""" + +from switch_core.telemetry.catalogue import TelemetryCatalogueError +from switch_core.telemetry.service import TelemetryService, emit_safely +from switch_core.telemetry.setup import build_telemetry + +__all__ = [ + "TelemetryCatalogueError", + "TelemetryService", + "build_telemetry", + "emit_safely", +] diff --git a/core/switch_core/telemetry/catalogue.py b/core/switch_core/telemetry/catalogue.py new file mode 100644 index 000000000..1592c3c13 --- /dev/null +++ b/core/switch_core/telemetry/catalogue.py @@ -0,0 +1,324 @@ +"""Every event the server may report, and every property each one carries. + +The catalogue is the whole privacy boundary. An event is describable here or it +cannot be sent; a property is declared here or it cannot be sent. There is no +path that takes an arbitrary string and forwards it, which is what makes "the +server never reports a room name" a property of the code rather than a promise +about how carefully call sites are written. + +Two rules follow from that, and both are enforced in :func:`validate`: + +- **The property set is exact.** Not a subset and not a superset — an event + carries every property its spec names, every time. A property that does not + apply carries an explicit ``none`` rather than being left out, so a missing key + is always a bug and never a case the reader has to guess at. +- **Values are closed.** A property is a number, a boolean, or one of a fixed + set of strings. Nothing accepts free text, so no call site can widen the + catalogue by passing something new; a value outside the set raises where the + event is built. + +The design note is ``docs/old/telemetry-events.md``, which explains why each +event exists and what question it answers. This file is the enforceable half of +it and the two are meant to be read together. +""" + +from __future__ import annotations + +from collections.abc import Mapping +from dataclasses import dataclass + +# The wire prefix. One Amplitude project holds several products, so every event +# is namespaced by the one that sent it — the Console sends `switch_console.*` +# against the same relay. +EVENT_NAME_PREFIX = "switch_core" + + +class PropertyType: + """Base for the three kinds of value a property may take.""" + + def check(self, value: object) -> str | None: + """Return a human-readable reason the value is unacceptable, or None.""" + raise NotImplementedError + + +@dataclass(frozen=True) +class _Number(PropertyType): + def check(self, value: object) -> str | None: + # bool is a subclass of int; a boolean where a count belongs is a + # mistake worth naming rather than silently recording as 0 or 1. + if isinstance(value, bool) or not isinstance(value, int | float): + return f"expected a number, got {type(value).__name__}" + if value != value or value in (float("inf"), float("-inf")): + return "expected a finite number" + return None + + +@dataclass(frozen=True) +class _Boolean(PropertyType): + def check(self, value: object) -> str | None: + if not isinstance(value, bool): + return f"expected a boolean, got {type(value).__name__}" + return None + + +@dataclass(frozen=True) +class _OneOf(PropertyType): + values: frozenset[str] + + def check(self, value: object) -> str | None: + if not isinstance(value, str): + return f"expected one of {sorted(self.values)}, got {type(value).__name__}" + if value not in self.values: + return f"expected one of {sorted(self.values)}, got {value!r}" + return None + + +NUMBER = _Number() +BOOLEAN = _Boolean() + + +def one_of(*values: str) -> _OneOf: + return _OneOf(frozenset(values)) + + +class TelemetryCatalogueError(Exception): + """An event does not match the catalogue. + + Always a programming error rather than a runtime condition: the event name, + the property names and the set of values a property may take are all fixed + at author time. Raised rather than logged so it fails in the test that + builds the event, not in production as a silently malformed record. + """ + + +# ── Shared value sets ──────────────────────────────────────────────────────── + +# The five collaboration platforms, plus the absence of one. `none` rather than +# omitting the property: see the module docstring on exact property sets. +BRIDGE_PLATFORM = one_of("slack", "mattermost", "discord", "teams", "telegram", "none") + +CHANNEL_TYPE = one_of("channel_public", "channel_private", "direct", "none") + +# How an agent behaves in a room, as `agents.agent_type` records it. +AGENT_TYPE = one_of("always_on", "session_addressable", "session_passive") + +# The runtime behind an agent, from `known_agent_type` in its metadata. +# `other` covers a runtime Switch has no special knowledge of; `none` covers an +# agent registered without declaring one at all. +KNOWN_AGENT_TYPE = one_of("claude-code", "codex", "opencode", "other", "none") + +ACTOR_KIND = one_of("user", "agent", "system") + +OUTCOME = one_of("success", "failure") + + +# ── The catalogue ──────────────────────────────────────────────────────────── + +_SNAPSHOT_COUNTS = ( + "tenant_count", + "user_count", + "user_active_1d", + "user_active_7d", + "room_count", + "room_agent_created_count", + "room_active_1d", + "room_active_7d", + "room_archived_count", + "room_internal_only_count", + "room_membership_total", + "room_users_mean", + "room_users_max", + "agent_count", + "agent_active_7d", + "agent_claude_code_count", + "agent_codex_count", + "agent_opencode_count", + "agent_other_count", + # Live sessions only. "Sessions started today" is deliberately absent: + # nothing durable records a session opening, so the snapshot could only + # report an in-process tally that a restart silently resets — a number that + # looks like a count and is not one. `agent_session_started` is emitted per + # occurrence instead, and counting those is the analytics tool's job. + "session_live_count", + "connector_slack_count", + "connector_mattermost_count", + "connector_discord_count", + "connector_teams_count", + "connector_telegram_count", + "connector_configured_count", + "message_count_1d", + "message_from_human_1d", + "message_from_agent_1d", + # Turns, not senders. A turn is one message classified by who sent the + # message *before* it in the same room, which is the only way to tell an + # agent answering a person from two agents talking to each other — a + # sender-only count reports both as "from an agent" and hides the + # difference that matters. + "turn_human_to_agent_1d", + "turn_agent_to_human_1d", + "turn_agent_to_agent_1d", + "attachment_count_1d", +) + +# Every milestone answers "how long after install did this first happen", so +# they share a property and differ only in what else they carry. +_SINCE_INSTALL: Mapping[str, PropertyType] = {"seconds_since_install": NUMBER} + + +CATALOGUE: Mapping[str, Mapping[str, PropertyType]] = { + # ── The daily snapshot ─────────────────────────────────────────────────── + # One per deployment per day. Counts are gathered locally, where the server + # legitimately knows the ids, and only totals are reported — which is what + # lets the catalogue answer "how many active rooms" without any room ever + # being identifiable. + "usage_snapshot": {name: NUMBER for name in _SNAPSHOT_COUNTS}, + # ── Milestones ─────────────────────────────────────────────────────────── + # At most once per deployment, ever, and only for deployments installed + # after this shipped. Together they are the activation funnel. + # The funnel's origin. Carries the elapsed time like every other milestone + # — normally a few seconds, since it is claimed on the first boot after + # install, and visibly longer for a deployment that switched reporting on + # some time after it was set up. That difference is worth being able to + # see rather than flatten to zero: it says the funnel's origin is not + # where it appears to be. + "deployment_installed": dict(_SINCE_INSTALL), + "first_connector_added": {**_SINCE_INSTALL, "bridge_platform": BRIDGE_PLATFORM}, + "first_room_created": { + **_SINCE_INSTALL, + "channel_type": CHANNEL_TYPE, + "bridge_platform": BRIDGE_PLATFORM, + }, + "first_room_active": { + **_SINCE_INSTALL, + "bridge_platform": BRIDGE_PLATFORM, + "seconds_since_room_created": NUMBER, + }, + "first_agent_registered": { + **_SINCE_INSTALL, + "known_agent_type": KNOWN_AGENT_TYPE, + }, + "first_session_started": {**_SINCE_INSTALL, "known_agent_type": KNOWN_AGENT_TYPE}, + # ── Lifecycle ──────────────────────────────────────────────────────────── + # The version is already a resource attribute, so this is the upgrade + # curve: which versions are actually running, and how many tenants each + # carries. Deliberately no "did this boot migrate" flag — migrations run + # in a different event loop from the server, so the answer would have to + # be smuggled across on a module global, and it is operational trivia + # rather than something the product wants to know. + "deployment_started": {"tenant_count": NUMBER}, + "room_created": { + "channel_type": CHANNEL_TYPE, + "bridge_platform": BRIDGE_PLATFORM, + "agent_count": NUMBER, + "human_count": NUMBER, + "has_instructions": BOOLEAN, + "created_by_kind": ACTOR_KIND, + "from_template": BOOLEAN, + }, + "room_became_active": { + "seconds_since_room_created": NUMBER, + "bridge_platform": BRIDGE_PLATFORM, + "channel_type": CHANNEL_TYPE, + "agent_count": NUMBER, + "created_by_kind": ACTOR_KIND, + }, + "room_archived": { + "bridge_platform": BRIDGE_PLATFORM, + "age_days": NUMBER, + "was_ever_active": BOOLEAN, + }, + "room_agents_added": {"agent_count": NUMBER, "added_by_kind": ACTOR_KIND}, + "agent_registered": { + "agent_type": AGENT_TYPE, + "known_agent_type": KNOWN_AGENT_TYPE, + "registration_path": one_of("bootstrap", "personal_key", "console", "other"), + "has_parent": BOOLEAN, + }, + "agent_session_started": { + "known_agent_type": KNOWN_AGENT_TYPE, + "start_source": one_of("auto", "manual", "api"), + }, + "agent_session_ended": { + "known_agent_type": KNOWN_AGENT_TYPE, + "duration_seconds": NUMBER, + "reason": one_of( + "normal", "heartbeat_lapsed", "replaced", "room_claimed", "error" + ), + }, + "connector_added": { + "bridge_platform": BRIDGE_PLATFORM, + "seconds_since_install": NUMBER, + "seconds_since_configured": NUMBER, + "is_first_connector": BOOLEAN, + "failed_attempts_before_success": NUMBER, + }, + "bridge_connected": { + "bridge_platform": BRIDGE_PLATFORM, + "outcome": OUTCOME, + # `none` on success, so the property set stays exact either way. + "failure_reason": one_of( + "none", + "auth_failed", + "network", + "platform_error", + "config_invalid", + "unknown", + ), + }, + "bridge_disconnected": { + "bridge_platform": BRIDGE_PLATFORM, + "reason": one_of( + "shutdown", + "restart", + "auth_failed", + "network", + "platform_error", + "unknown", + ), + }, +} + + +PropertyValue = str | int | float | bool + + +def wire_name(event: str) -> str: + """The prefixed name as the relay sees it.""" + return f"{EVENT_NAME_PREFIX}.{event}" + + +def validate(event: str, properties: Mapping[str, PropertyValue]) -> None: + """Raise unless `properties` is exactly what `event` declares. + + Checks the three things that would each, on their own, let something + unintended reach the relay: an event nobody declared, a property nobody + declared, and a value outside the set its property allows. A missing + property is checked too — not for privacy but for the charts, since an + event whose keys vary between emissions cannot be grouped on them. + """ + spec = CATALOGUE.get(event) + if spec is None: + raise TelemetryCatalogueError( + f"{event!r} is not a telemetry event. Add it to CATALOGUE in " + "telemetry/catalogue.py (and to docs/old/telemetry-events.md) " + "rather than sending an undeclared one." + ) + + given = set(properties) + declared = set(spec) + if undeclared := sorted(given - declared): + raise TelemetryCatalogueError( + f"{event!r} does not declare {undeclared}. Every property must be " + "in the catalogue: this is the check that stops an identifier or a " + "free-text value reaching the relay by accident." + ) + if missing := sorted(declared - given): + raise TelemetryCatalogueError( + f"{event!r} is missing {missing}. Every event of a name carries the " + "same keys every time — pass the explicit 'none'/0/False rather " + "than omitting one." + ) + + for name, value in properties.items(): + if reason := spec[name].check(value): + raise TelemetryCatalogueError(f"{event!r}.{name}: {reason}.") diff --git a/core/switch_core/telemetry/deployment.py b/core/switch_core/telemetry/deployment.py new file mode 100644 index 000000000..3d09a876e --- /dev/null +++ b/core/switch_core/telemetry/deployment.py @@ -0,0 +1,119 @@ +"""The deployment's identity, its install clock, and once-ever milestones. + +Three facts about the installation rather than about any tenant in it, which is +why all three live in tables carrying no tenant column and no row-level-security +policy, and are read on a session opened straight from the factory with nothing +bound. + +That is the same shape `users` and `oidc_identities` are read in, and it is +sanctioned for the same reason (`db/session_scope.py`): there is no tenant for a +policy to narrow on, so binding one would be theatre. It is *not* the old +`unscoped_session` hatch — under the restricted runtime role an unbound session +reads nothing rather than everything, and these tables are readable only because +they were never scoped in the first place. The modules here are named in +`tests/switch_core/db/test_tenant_exemption_allowlist.py` so the choice stays +reviewable. + +The install clock is the subtle one. Every time-to-value figure is measured +from `installed_at`, and `installed_at` is null for any deployment that already +existed when this shipped — see the migration for why a guess is worse than +nothing. :func:`seconds_since_install` returns `None` for those, and +every milestone call site treats `None` as "do not report", so a deployment +that cannot be measured honestly stays out of the funnel rather than skewing it. +""" + +from __future__ import annotations + +import logging +from datetime import UTC, datetime + +from sqlalchemy import select +from sqlalchemy.dialects.postgresql import insert as pg_insert +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.db.models import DeploymentIdentity, TelemetryMilestone + +logger = logging.getLogger(__name__) + + +class DeploymentIdentityMissingError(RuntimeError): + """The singleton identity row is absent. + + The migration seeds it, so this means the schema is older than the code or + the row was deleted by hand. Raised rather than repaired at runtime: the + row records *whether this deployment is new*, and only the migration ran + early enough to answer that. Re-creating it here would silently mint a + fresh identity — a new subject in analytics, and an install date of "now" + for a deployment that may be a year old. + """ + + +async def load_deployment_identity( + session_factory: async_sessionmaker[AsyncSession], +) -> tuple[str, datetime | None]: + """The deployment's client id and install date. + + Returns `(client_id, installed_at)`, where `installed_at` is `None` for a + deployment that predates this telemetry. + """ + async with session_factory() as session: + row = ( + await session.execute(select(DeploymentIdentity).limit(1)) + ).scalar_one_or_none() + if row is None: + raise DeploymentIdentityMissingError( + "No deployment_identity row. It is seeded by the telemetry " + "bookkeeping migration; run migrations before starting the " + "server. It is not recreated here because only the migration ran " + "early enough to tell a new deployment from an existing one." + ) + return row.client_id, row.installed_at + + +def seconds_since_install(installed_at: datetime | None) -> float | None: + """Elapsed seconds since install, or `None` if that is not knowable. + + `None` propagates all the way to the call site, which then reports + nothing. Time-to-value describes only deployments watched from their first + boot. + """ + if installed_at is None: + return None + # A row written before this process started could carry a naive datetime + # if the column were ever read through a driver that dropped the zone; + # treating it as UTC is right for a `timestamptz` and avoids a comparison + # that would raise. + if installed_at.tzinfo is None: + installed_at = installed_at.replace(tzinfo=UTC) + return max((datetime.now(UTC) - installed_at).total_seconds(), 0.0) + + +async def claim_milestone( + session_factory: async_sessionmaker[AsyncSession], name: str +) -> bool: + """Take the right to report `name`, once, for this deployment. + + True the first time and False forever after. The insert *is* the guard — + the name is the primary key, so a second caller collides in the database + rather than racing a read-then-write. That matters even on a single-replica + server, where two concurrent requests can reach the same first-time event. + + A failure here returns False rather than raising: not reporting a milestone + is a small loss, and taking down whatever real work was in progress is not. + """ + try: + async with session_factory() as session: + result = await session.execute( + pg_insert(TelemetryMilestone) + .values(name=name) + .on_conflict_do_nothing(index_elements=["name"]) + .returning(TelemetryMilestone.name) + ) + claimed = result.scalar_one_or_none() is not None + await session.commit() + return claimed + except Exception: + logger.exception( + "Could not record the %s telemetry milestone; not reporting it.", name + ) + return False diff --git a/core/switch_core/telemetry/reporter.py b/core/switch_core/telemetry/reporter.py new file mode 100644 index 000000000..80f490896 --- /dev/null +++ b/core/switch_core/telemetry/reporter.py @@ -0,0 +1,167 @@ +"""The background task that sends the daily snapshot. + +One loop, anchored to what was last sent rather than to how long this process +has been up. A timer started at boot would send several snapshots on a day with +several restarts and none on a day the server happened to be down at the wrong +moment; a watermark in the database gives the same cadence whatever the process +does. + +The first pass on a deployment that already has history is the one case worth +knowing about. It sends the snapshot — those are current-state counts and are +correct immediately — but not the room-activation events, because "first human +interaction since the watermark" with no watermark means every room that ever +went active, arriving at once and all dated today. The watermark is set instead, +and the next pass reports normally. +""" + +from __future__ import annotations + +import asyncio +import logging +from datetime import UTC, datetime, timedelta + +from sqlalchemy import select +from sqlalchemy.dialects.postgresql import insert as pg_insert +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.db.models import TelemetrySnapshotWatermark +from switch_core.telemetry.deployment import claim_milestone, seconds_since_install +from switch_core.telemetry.service import TelemetryService +from switch_core.telemetry.snapshot import ( + collect_usage, + newly_active_rooms, + summarise, +) + +logger = logging.getLogger(__name__) + +# How long to wait before the first pass. Long enough that a restart loop +# cannot turn boot into a stream of snapshots, short enough that a developer +# switching telemetry on does not have to wait a day to see whether it works. +_FIRST_PASS_DELAY_SECONDS = 60.0 + +# How often to wake and ask whether a snapshot is due. Well under the interval +# itself, so a deployment that was down over its due time sends promptly on the +# next start rather than waiting a further full period. +_POLL_INTERVAL_SECONDS = 300.0 + + +class SnapshotReporter: + """Collects and sends the usage snapshot on a schedule.""" + + def __init__( + self, + *, + telemetry: TelemetryService, + session_factory: async_sessionmaker[AsyncSession], + interval_hours: float, + installed_at: datetime | None, + live_session_count: object, + ) -> None: + self._telemetry = telemetry + self._session_factory = session_factory + self._interval = timedelta(hours=interval_hours) + self._installed_at = installed_at + # A zero-argument callable rather than the registry itself: the + # reporter has no business knowing what a connection is, and a test + # should not have to build one to check a count. + self._live_session_count = live_session_count + + async def run_forever(self) -> None: + await asyncio.sleep(_FIRST_PASS_DELAY_SECONDS) + while True: + try: + await self.run_once_if_due() + except asyncio.CancelledError: + raise + except Exception: + # One bad pass must not end the loop — a transient database + # error would otherwise switch telemetry off for the life of + # the process, silently. + logger.exception("Usage snapshot pass failed") + await asyncio.sleep(_POLL_INTERVAL_SECONDS) + + async def run_once_if_due(self) -> bool: + """Send a snapshot if one is due. True if one was sent.""" + now = datetime.now(UTC) + last_sent = await self._read_watermark() + if last_sent is not None and now - last_sent < self._interval: + return False + await self.run_once(now=now, since=last_sent) + await self._write_watermark(now) + return True + + async def run_once(self, *, now: datetime, since: datetime | None) -> None: + """Collect and report one snapshot, plus any room that just went live.""" + counts = await collect_usage(self._session_factory, now=now) + + # Skipped entirely on the first pass — see the module docstring. + active = ( + await newly_active_rooms(self._session_factory, since=since, now=now) + if since is not None + else [] + ) + + logger.info("Usage snapshot: %s", summarise(counts, active)) + + self._telemetry.emit( + "usage_snapshot", + **counts.as_event_properties( + session_live_count=int(self._live_session_count()) # type: ignore[operator] + ), + ) + + for room in active: + self._telemetry.emit( + "room_became_active", + seconds_since_room_created=room.seconds_since_room_created, + bridge_platform=room.bridge_platform, + channel_type=room.channel_type, + agent_count=room.agent_count, + created_by_kind=room.created_by_kind, + ) + + await self._report_first_room_active(active, now=now) + + async def _report_first_room_active(self, active: list, *, now: datetime) -> None: + """The activation milestone, from the earliest room in this window. + + Measured from the room's own first interaction rather than from the + moment this pass happened to run, so a snapshot that is late does not + report an activation that was slower than it was. + """ + if not active or self._installed_at is None: + return + elapsed = seconds_since_install(self._installed_at) + if elapsed is None: + return + earliest = min(active, key=lambda room: room.seconds_since_room_created) + if not await claim_milestone(self._session_factory, "first_room_active"): + return + self._telemetry.emit( + "first_room_active", + seconds_since_install=elapsed, + bridge_platform=earliest.bridge_platform, + seconds_since_room_created=earliest.seconds_since_room_created, + ) + + async def _read_watermark(self) -> datetime | None: + async with self._session_factory() as session: + row = ( + await session.execute(select(TelemetrySnapshotWatermark).limit(1)) + ).scalar_one_or_none() + if row is None: + return None + stamp = row.last_sent_at + return stamp.replace(tzinfo=UTC) if stamp.tzinfo is None else stamp + + async def _write_watermark(self, when: datetime) -> None: + async with self._session_factory() as session: + await session.execute( + pg_insert(TelemetrySnapshotWatermark) + .values(id=1, last_sent_at=when) + .on_conflict_do_update( + index_elements=["id"], set_={"last_sent_at": when} + ) + ) + await session.commit() diff --git a/core/switch_core/telemetry/service.py b/core/switch_core/telemetry/service.py new file mode 100644 index 000000000..551e1bdc6 --- /dev/null +++ b/core/switch_core/telemetry/service.py @@ -0,0 +1,200 @@ +"""The one call every site uses to report an event. + +`emit` is deliberately fire-and-forget and deliberately synchronous to call: a +room being created must not wait on an analytics relay, and a call site must +not have to decide whether reporting is worth an `await`. It validates against +the catalogue immediately — that part is cheap and its failures are bugs — and +hands the send to a background task. + +The asymmetry in how failures are treated is the point: + +- **A bad event raises.** An undeclared event, an undeclared property, a value + outside its set: each is a programming error, each is caught by the tests + that build the event, and each would otherwise put something unintended on + the wire. Silence here would defeat the catalogue. +- **A failed send does not.** The relay being slow, unreachable or unhappy is + an operational condition that has nothing to do with the caller, and Switch + continuing to work while analytics is down is the only acceptable behaviour. + It is logged and dropped. +""" + +from __future__ import annotations + +import asyncio +import logging +import time +from collections.abc import Mapping +from datetime import datetime + +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.telemetry.catalogue import PropertyValue, validate, wire_name +from switch_core.telemetry.deployment import claim_milestone, seconds_since_install +from switch_core.telemetry.sink import TelemetryRecord, TelemetrySink + +logger = logging.getLogger(__name__) + + +class TelemetryService: + """Validates, tags and dispatches events. + + Holds a sink unconditionally — :class:`~switch_core.telemetry.sink.NullSink` + when telemetry is off — so that no call site ever tests whether reporting + is enabled. One place decides; everywhere else just reports. + """ + + def __init__( + self, + *, + sink: TelemetrySink, + enabled: bool, + client_id: str, + service_name: str, + version: str | None, + environment: str | None, + session_factory: async_sessionmaker[AsyncSession] | None = None, + installed_at: datetime | None = None, + ) -> None: + self._sink = sink + self._enabled = enabled + # Only the milestone path needs these. Optional so the ordinary + # `emit` is usable from a test that has no database at all. + self._session_factory = session_factory + self._installed_at = installed_at + self._resource = { + "service.name": service_name, + "flint.client_id": client_id, + } + # Omitted rather than sent empty: an absent attribute reads as "not + # configured", where `""` reads as a real environment named nothing. + if version: + self._resource["service.version"] = version + if environment: + self._resource["deployment.environment"] = environment + self._tasks: set[asyncio.Task[None]] = set() + + @property + def enabled(self) -> bool: + return self._enabled + + @property + def installed_at(self) -> datetime | None: + """When this deployment was installed, or None if that is unknown.""" + return self._installed_at + + def emit(self, event: str, **properties: PropertyValue) -> None: + """Report one event. Never blocks; raises only on a malformed event.""" + # Validated even when disabled, so a mistake in a rarely-taken branch + # is caught by whichever test exercises it rather than lying dormant + # until the day a deployment switches telemetry on. + validate(event, properties) + if not self._enabled: + return + self._dispatch( + TelemetryRecord( + name=wire_name(event), + properties=dict(properties), + resource=dict(self._resource), + timestamp_ns=time.time_ns(), + ) + ) + + async def emit_milestone(self, event: str, **properties: PropertyValue) -> None: + """Report a once-ever activation milestone, if it has not been reported. + + Adds `seconds_since_install` and takes the claim that makes it + once-ever, so a call site only has to say which milestone it is and + what else it carries. + + Silently does nothing in three cases, each of them correct: + + - **telemetry is off**, so there is nothing to report and no claim + should be taken — switching it on later must not find every + milestone already used up; + - **the deployment predates this telemetry** and has no install date, + so elapsed time is unknowable and a guess would be worse than + silence (see `telemetry/deployment.py`); + - **the milestone is already claimed**, which is the whole point. + """ + if not self._enabled or self._session_factory is None: + return + elapsed = seconds_since_install(self._installed_at) + if elapsed is None: + return + if not await claim_milestone(self._session_factory, event): + return + self.emit(event, seconds_since_install=elapsed, **properties) + + def _dispatch(self, record: TelemetryRecord) -> None: + try: + loop = asyncio.get_running_loop() + except RuntimeError: + # Reported from somewhere with no event loop — a management + # command, or a test calling a synchronous helper directly. Worth + # a line rather than a crash: the caller was doing something + # legitimate and telemetry is not its job. + logger.debug( + "Telemetry event %s not sent: no running event loop.", record.name + ) + return + + task = loop.create_task(self._send(record)) + # Held for the lifetime of the send. An un-referenced task can be + # garbage-collected mid-flight, which drops the event silently and is + # exactly the kind of bug telemetry code is bad at revealing. + self._tasks.add(task) + task.add_done_callback(self._tasks.discard) + + async def _send(self, record: TelemetryRecord) -> None: + try: + await self._sink.send(record) + except asyncio.CancelledError: + raise + except Exception: + # The sink is expected to swallow its own transport failures, so + # reaching here means a bug in the sink rather than a bad relay. + # Still not allowed to propagate: this runs in a bare task, where + # an exception becomes an unretrievable "task exception was never + # retrieved" at some later garbage collection. + logger.exception("Telemetry sink failed on event %s", record.name) + + async def aclose(self) -> None: + """Let in-flight sends finish, then close the sink. + + Shutdown is the one time waiting is right: the events worth losing + least are the ones emitted just before the process goes away, and the + sink's own timeout already bounds how long this can take. + """ + if self._tasks: + await asyncio.gather(*tuple(self._tasks), return_exceptions=True) + await self._sink.aclose() + + +def emit_safely( + telemetry: TelemetryService | None, + event: str, + properties: Mapping[str, PropertyValue], +) -> None: + """Report an event from a path that must not fail because of telemetry. + + For call sites in the middle of real work — creating a room, opening a + session — where a catalogue bug must not take the operation down with it. + The mistake is still loud, because it is logged with a stack trace at + error level, but it costs the user nothing. + + Paths that can afford to fail (the snapshot task, tests) should call + :meth:`TelemetryService.emit` directly and let the error out. + + `telemetry` is optional because several services are constructed in tests + and in tooling without one. + """ + if telemetry is None: + return + try: + telemetry.emit(event, **dict(properties)) + except Exception: + logger.exception( + "Telemetry event %s could not be reported; continuing. This is a " + "bug in the event, not a relay problem.", + event, + ) diff --git a/core/switch_core/telemetry/setup.py b/core/switch_core/telemetry/setup.py new file mode 100644 index 000000000..bd15007a9 --- /dev/null +++ b/core/switch_core/telemetry/setup.py @@ -0,0 +1,74 @@ +"""Building the telemetry service at boot. + +One function, so `main.py` does not have to know the difference between an +enabled deployment and a disabled one — it asks for a service and gets one +either way. Off is a service holding a sink that discards, not a `None` that +every call site would have to remember to check. +""" + +from __future__ import annotations + +import logging +from datetime import datetime + +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.config import SwitchConfig +from switch_core.telemetry.deployment import load_deployment_identity +from switch_core.telemetry.service import TelemetryService +from switch_core.telemetry.sink import NullSink, OtlpRelaySink, TelemetrySink + +logger = logging.getLogger(__name__) + + +async def build_telemetry( + config: SwitchConfig, + session_factory: async_sessionmaker[AsyncSession], + version: str | None, +) -> tuple[TelemetryService, datetime | None]: + """The telemetry service, and this deployment's install date. + + The install date comes back alongside because the milestone call sites need + it and it is read from the same row as the client id — asking twice would + be two queries for one fact. + + The identity is read even when telemetry is off. It is one query at boot, + and reading it unconditionally means a deployment that switches reporting + on later already has the id it was assigned when it was installed, rather + than minting one on the day it opted in and looking brand new. + """ + client_id, installed_at = await load_deployment_identity(session_factory) + + sink: TelemetrySink + if config.telemetry_enabled: + sink = OtlpRelaySink( + endpoint=config.telemetry_endpoint, + timeout_seconds=config.telemetry_timeout_seconds, + ) + logger.info( + "Product telemetry is ON: usage counts and timings are reported to " + "%s. No room, tenant, agent, user or message is identified in them " + "— see docs/old/telemetry-events.md for exactly what is sent. Set " + "TELEMETRY_ENABLED=false to switch it off.", + config.telemetry_endpoint, + ) + else: + sink = NullSink() + logger.info( + "Product telemetry is off; nothing is collected or sent. Set " + "TELEMETRY_ENABLED=true to report anonymous usage counts." + ) + + return ( + TelemetryService( + sink=sink, + enabled=config.telemetry_enabled, + client_id=client_id, + service_name=config.service_name, + version=version, + environment=config.environment, + session_factory=session_factory, + installed_at=installed_at, + ), + installed_at, + ) diff --git a/core/switch_core/telemetry/sink.py b/core/switch_core/telemetry/sink.py new file mode 100644 index 000000000..b4ce82bba --- /dev/null +++ b/core/switch_core/telemetry/sink.py @@ -0,0 +1,211 @@ +"""Where a validated event actually goes. + +One narrow seam, with the relay behind it. Everything above this file — the +catalogue, the snapshot, the call sites — is about *what* Switch reports; +everything below is about the wire. Keeping the two apart is what lets the +operational-observability work (`CHOO-2807`) replace the transport without +touching a single call site: the sink is the only thing that knows there is an +HTTP request involved at all. + +The wire format is not ours to choose. The relay is already serving Switch +Console, and its expectations are exacting in ways that fail silently rather +than loudly — see :class:`OtlpRelaySink` for the two that bite. +""" + +from __future__ import annotations + +import logging +from dataclasses import dataclass +from typing import Protocol + +import httpx + +from switch_core.telemetry.catalogue import PropertyValue + +logger = logging.getLogger(__name__) + + +@dataclass(frozen=True) +class TelemetryRecord: + """One validated event, ready to send. + + `name` is already prefixed. `properties` has already been checked against + the catalogue: a sink must not have to trust or re-check its caller, and + must never be the thing that decides what is allowed to leave. + """ + + name: str + properties: dict[str, PropertyValue] + resource: dict[str, str] + timestamp_ns: int + + +class TelemetrySink(Protocol): + """The seam. One method, and it never raises.""" + + async def send(self, record: TelemetryRecord) -> None: ... + + async def aclose(self) -> None: ... + + +class NullSink: + """Drops everything, for when telemetry is off. + + The service holds a sink unconditionally so that no call site has to ask + whether telemetry is on — a question every call site would eventually + answer differently. Off is a sink that discards, not a `None` to check. + """ + + async def send(self, record: TelemetryRecord) -> None: + return None + + async def aclose(self) -> None: + return None + + +class OtlpRelaySink: + """Posts one OTLP log record per event to the relay. + + **Log records, not metrics or spans.** The relay routes on log records and + the downstream product-analytics exporter reads them as events; a metric + would be dropped without complaint. + + **The event name goes in two places** — the log record's own `eventName` + field and an `event.name` attribute. The relay's filter reads the + attribute; the exporter reads the field. Sending only one is accepted with + a 200 at every hop and then quietly discarded, which is the single easiest + way to believe this is working when it is not. + + No batching and no retry, matching the Console. A dropped event is a lost + row in an analytics chart, and the alternative — a queue that grows while + the relay is unreachable, on a process that is already the deployment's + single point of failure — costs more than it saves. Failures are logged + with a reason so a deployment reporting nothing is diagnosable rather than + merely silent. + """ + + def __init__(self, *, endpoint: str, timeout_seconds: float) -> None: + self._endpoint = endpoint + self._client = httpx.AsyncClient( + timeout=timeout_seconds, + headers={"User-Agent": "switch-core"}, + ) + + async def send(self, record: TelemetryRecord) -> None: + try: + response = await self._client.post(self._endpoint, json=_payload(record)) + except httpx.TimeoutException: + logger.warning( + "Telemetry event %s was not sent: the relay did not answer in " + "time. The event is dropped; there is no retry.", + record.name, + ) + return + except httpx.HTTPError as exc: + logger.warning( + "Telemetry event %s was not sent: %s. The event is dropped.", + record.name, + type(exc).__name__, + ) + return + + if response.status_code >= 400: + logger.warning( + "Telemetry event %s was refused by the relay with HTTP %d.", + record.name, + response.status_code, + ) + return + + # A 200 does not mean the record was kept: OTLP answers partial + # success in the body. Without this a misconfigured deployment reports + # nothing and looks perfectly healthy doing it. + rejected = _rejected_count(response) + if rejected: + logger.warning( + "The relay accepted the request for telemetry event %s but " + "rejected %d record(s) in it.", + record.name, + rejected, + ) + + async def aclose(self) -> None: + await self._client.aclose() + + +def _rejected_count(response: httpx.Response) -> int: + """How many records the relay rejected inside a 2xx, best effort. + + A body that is absent, empty, or not JSON is the ordinary success case for + some collectors, so none of those are worth a warning of their own. + """ + if not response.content: + return 0 + try: + body = response.json() + except ValueError: + return 0 + if not isinstance(body, dict): + return 0 + partial = body.get("partialSuccess") + if not isinstance(partial, dict): + return 0 + rejected = partial.get("rejectedLogRecords", 0) + # OTLP/JSON renders 64-bit integers as strings. + try: + return int(rejected) + except (TypeError, ValueError): + return 0 + + +def _attribute(key: str, value: PropertyValue) -> dict[str, object]: + """One OTLP key/value. + + Numbers go as `doubleValue` rather than `intValue`, whose OTLP/JSON + encoding is a *string* — which arrives in analytics as text and cannot be + summed or averaged. `bool` is checked before `int` because it is a + subclass of it and would otherwise be reported as 0 and 1. + """ + if isinstance(value, bool): + return {"key": key, "value": {"boolValue": value}} + if isinstance(value, int | float): + return {"key": key, "value": {"doubleValue": float(value)}} + return {"key": key, "value": {"stringValue": value}} + + +def _payload(record: TelemetryRecord) -> dict[str, object]: + attributes = [ + _attribute("event.name", record.name), + *(_attribute(key, value) for key, value in record.properties.items()), + ] + return { + "resourceLogs": [ + { + "resource": { + "attributes": [ + _attribute(key, value) for key, value in record.resource.items() + ] + }, + "scopeLogs": [ + { + "scope": {"name": "switch-core"}, + "logRecords": [ + { + "timeUnixNano": str(record.timestamp_ns), + "observedTimeUnixNano": str(record.timestamp_ns), + "severityNumber": 9, + "severityText": "INFO", + # The name again, as the record's own field. + # Both are required; see the class docstring. + "eventName": record.name, + # Datadog renders this as the log message, and + # a blank one makes the event unreadable there. + "body": {"stringValue": record.name}, + "attributes": attributes, + } + ], + } + ], + } + ] + } diff --git a/core/switch_core/telemetry/snapshot.py b/core/switch_core/telemetry/snapshot.py new file mode 100644 index 000000000..135bd08ff --- /dev/null +++ b/core/switch_core/telemetry/snapshot.py @@ -0,0 +1,572 @@ +"""The daily usage snapshot, and the room-activation events derived with it. + +Most of what the product wants to know — how many users, rooms, agents, +sessions and connectors, and how many of them are actually active — is a count +of things the server already stores. Counting them here, once a day, is what +lets those questions be answered without any room, tenant or person ever being +identified: the ids stay in the database where they belong, and only the +totals leave. + +**Everything is counted per tenant and summed.** Not because the answer is +reported per tenant — it is not, deliberately — but because row-level security +means it has to be. Under the restricted runtime role a session with no tenant +bound reads *nothing* from a scoped table, so a single `SELECT count(*) FROM +rooms` would return zero on a correctly configured deployment and the whole +snapshot would be a page of confident zeroes. `all_tenant_ids` answers the one +question no tenant can be scoped to, and each tenant's rows are then read on a +session bound to it, exactly as the rest of the tree does. + +The room-activation events ride along here rather than being emitted from the +message path, and that is a deliberate trade. Detecting "this room just became +active" at write time would mean a per-room flag and three extra queries on the +hottest path in the server, to learn something nobody needs within a day. +Asking the message table once a day instead costs nothing at write time, needs +no new state, and is exactly as accurate — the timestamps it reads were always +there. +""" + +from __future__ import annotations + +import logging +from collections.abc import Sequence +from dataclasses import dataclass, field +from datetime import UTC, datetime, timedelta +from typing import Any + +from sqlalchemy import Select, and_, case, distinct, exists, func, select +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.db.models import ( + Agent, + Client, + ClientRoom, + CollaborationBridge, + Message, + MessageAttachment, + Room, + User, +) +from switch_core.db.session_scope import tenant_session +from switch_core.db.tenant_lookup import all_tenant_ids + +logger = logging.getLogger(__name__) + +# `clients.type` for a human. One puppet per external user per bridge, created +# when a person first speaks on a bridged channel — so this is the only row in +# the schema that stands for "a person did something", and every "human" count +# below is a count of these. +HUMAN_CLIENT_TYPE = "user" +AGENT_CLIENT_TYPE = "agent" + +# The platforms reported individually. Fixed rather than derived from what is +# configured, so a deployment with no Discord bridge reports zero rather than +# omitting the property — the catalogue requires every key every time. +PLATFORMS = ("slack", "mattermost", "discord", "teams", "telegram") + +_DAY = timedelta(days=1) +_WEEK = timedelta(days=7) + + +@dataclass +class UsageCounts: + """The snapshot's numbers, accumulated across tenants.""" + + tenant_count: int = 0 + user_count: int = 0 + user_active_1d: int = 0 + user_active_7d: int = 0 + room_count: int = 0 + room_agent_created_count: int = 0 + room_active_1d: int = 0 + room_active_7d: int = 0 + room_archived_count: int = 0 + room_internal_only_count: int = 0 + room_membership_total: int = 0 + room_users_max: int = 0 + agent_count: int = 0 + agent_active_7d: int = 0 + agent_claude_code_count: int = 0 + agent_codex_count: int = 0 + agent_opencode_count: int = 0 + agent_other_count: int = 0 + connector_configured_count: int = 0 + connector_counts: dict[str, int] = field( + default_factory=lambda: dict.fromkeys(PLATFORMS, 0) + ) + message_count_1d: int = 0 + message_from_human_1d: int = 0 + message_from_agent_1d: int = 0 + turn_human_to_agent_1d: int = 0 + turn_agent_to_human_1d: int = 0 + turn_agent_to_agent_1d: int = 0 + attachment_count_1d: int = 0 + + def as_event_properties(self, *, session_live_count: int) -> dict[str, float]: + """Flatten to exactly the properties `usage_snapshot` declares.""" + properties: dict[str, float] = { + "tenant_count": self.tenant_count, + "user_count": self.user_count, + "user_active_1d": self.user_active_1d, + "user_active_7d": self.user_active_7d, + "room_count": self.room_count, + "room_agent_created_count": self.room_agent_created_count, + "room_active_1d": self.room_active_1d, + "room_active_7d": self.room_active_7d, + "room_archived_count": self.room_archived_count, + "room_internal_only_count": self.room_internal_only_count, + "room_membership_total": self.room_membership_total, + "room_users_mean": ( + round(self.room_membership_total / self.room_count, 2) + if self.room_count + else 0.0 + ), + "room_users_max": self.room_users_max, + "agent_count": self.agent_count, + "agent_active_7d": self.agent_active_7d, + "agent_claude_code_count": self.agent_claude_code_count, + "agent_codex_count": self.agent_codex_count, + "agent_opencode_count": self.agent_opencode_count, + "agent_other_count": self.agent_other_count, + "session_live_count": session_live_count, + "connector_configured_count": self.connector_configured_count, + "message_count_1d": self.message_count_1d, + "message_from_human_1d": self.message_from_human_1d, + "message_from_agent_1d": self.message_from_agent_1d, + "turn_human_to_agent_1d": self.turn_human_to_agent_1d, + "turn_agent_to_human_1d": self.turn_agent_to_human_1d, + "turn_agent_to_agent_1d": self.turn_agent_to_agent_1d, + "attachment_count_1d": self.attachment_count_1d, + } + for platform in PLATFORMS: + properties[f"connector_{platform}_count"] = self.connector_counts[platform] + return properties + + +@dataclass(frozen=True) +class NewlyActiveRoom: + """A room whose first human interaction happened in the window just read.""" + + seconds_since_room_created: float + bridge_platform: str + channel_type: str + agent_count: int + created_by_kind: str + + +def _human_interaction(since: datetime) -> Select[tuple[str]]: + """Room ids a human spoke in since `since`. + + "Interaction" is a human posting in a room that has an agent in it. Both + halves matter: a message from a bridge relay or the admin client is not a + person, and a person talking in a room with no agent is not using the + product this telemetry is about. Two agents talking to each other is + likewise not activity, which is why this keys on the human side only. + """ + room_has_an_agent = ( + select(ClientRoom.room_id) + .join(Client, Client.id == ClientRoom.client_id) + .where( + ClientRoom.room_id == Message.room_id, + Client.type == AGENT_CLIENT_TYPE, + ) + ) + return ( + select(distinct(Message.room_id)) + .join(Client, Client.id == Message.sender_client_id) + .where( + Message.sent_at >= since, + Client.type == HUMAN_CLIENT_TYPE, + exists(room_has_an_agent), + ) + ) + + +def _active_humans(since: datetime) -> Select[tuple[str | None]]: + """Distinct human clients who interacted since `since`.""" + room_has_an_agent = ( + select(ClientRoom.room_id) + .join(Client, Client.id == ClientRoom.client_id) + .where( + ClientRoom.room_id == Message.room_id, + Client.type == AGENT_CLIENT_TYPE, + ) + ) + return ( + select(distinct(Message.sender_client_id)) + .join(Client, Client.id == Message.sender_client_id) + .where( + Message.sent_at >= since, + Client.type == HUMAN_CLIENT_TYPE, + exists(room_has_an_agent), + ) + ) + + +async def _count(session: AsyncSession, query: Select[Any]) -> int: + result = await session.execute(select(func.count()).select_from(query.subquery())) + return int(result.scalar_one()) + + +async def _scalar(session: AsyncSession, query: Select[Any]) -> int: + result = await session.execute(query) + return int(result.scalar_one() or 0) + + +async def collect_tenant_counts( + session: AsyncSession, counts: UsageCounts, now: datetime +) -> None: + """Add one tenant's numbers to `counts`. + + The session must already be bound to that tenant: every query here relies + on row-level security to narrow it, rather than naming the tenant itself. + """ + day_ago = now - _DAY + week_ago = now - _WEEK + + counts.user_active_1d += await _count(session, _active_humans(day_ago)) + counts.user_active_7d += await _count(session, _active_humans(week_ago)) + counts.room_active_1d += await _count(session, _human_interaction(day_ago)) + counts.room_active_7d += await _count(session, _human_interaction(week_ago)) + + # Rooms, split by who made them. `created_by_kind` is stamped into the + # room's metadata at creation; rooms made before that existed carry + # nothing, and are counted as user-created — the conservative reading, + # since the agent-created room is the newer path. + agent_made = Room.metadata_["created_by_kind"].astext == "agent" + counts.room_count += await _scalar( + session, + select(func.count()) + .select_from(Room) + .where(Room.archived_at.is_(None), ~agent_made | agent_made.is_(None)), + ) + counts.room_agent_created_count += await _scalar( + session, + select(func.count()) + .select_from(Room) + .where(Room.archived_at.is_(None), agent_made), + ) + counts.room_archived_count += await _scalar( + session, + select(func.count()).select_from(Room).where(Room.archived_at.is_not(None)), + ) + counts.room_internal_only_count += await _scalar( + session, + select(func.count()) + .select_from(Room) + .where(Room.archived_at.is_(None), Room.bridge_id.is_(None)), + ) + + # Human membership per room, as a total and a maximum. The mean is derived + # from the total rather than averaged per tenant, so a deployment with one + # busy tenant and one idle one reports the real figure instead of the mean + # of two means. + per_room = ( + select(func.count(ClientRoom.client_id).label("members")) + .join(Client, Client.id == ClientRoom.client_id) + .join(Room, Room.id == ClientRoom.room_id) + .where(Client.type == HUMAN_CLIENT_TYPE, Room.archived_at.is_(None)) + .group_by(ClientRoom.room_id) + .subquery() + ) + membership = await session.execute( + select( + func.coalesce(func.sum(per_room.c.members), 0), + func.coalesce(func.max(per_room.c.members), 0), + ) + ) + total, largest = membership.one() + counts.room_membership_total += int(total) + counts.room_users_max = max(counts.room_users_max, int(largest)) + + # Agents, split by the runtime behind them. + runtime = Agent.metadata_["known_agent_type"].astext + by_runtime = await session.execute( + select(runtime, func.count()).select_from(Agent).group_by(runtime) + ) + for name, count in by_runtime.all(): + if name == "claude-code": + counts.agent_claude_code_count += count + elif name == "codex": + counts.agent_codex_count += count + elif name == "opencode": + counts.agent_opencode_count += count + else: + counts.agent_other_count += count + counts.agent_count += count + + counts.agent_active_7d += await _count( + session, + select(distinct(Message.sender_client_id)) + .join(Client, Client.id == Message.sender_client_id) + .where(Message.sent_at >= week_ago, Client.type == AGENT_CLIENT_TYPE), + ) + + # Connectors, by platform. Configured, not connected — whether each is + # currently up is process state, added by the caller. + by_platform = await session.execute( + select(CollaborationBridge.type, func.count()) + .select_from(CollaborationBridge) + .group_by(CollaborationBridge.type) + ) + for platform, count in by_platform.all(): + counts.connector_configured_count += count + if platform in counts.connector_counts: + counts.connector_counts[platform] += count + + # Messages in the last day, and who sent them. Only live messages: `seq` + # is negative for reconstructed history, and a backfill is not traffic. + counts.message_count_1d += await _scalar( + session, + select(func.count()) + .select_from(Message) + .where(Message.sent_at >= day_ago, Message.seq > 0), + ) + by_sender = await session.execute( + select(Client.type, func.count()) + .select_from(Message) + .join(Client, Client.id == Message.sender_client_id) + .where(Message.sent_at >= day_ago, Message.seq > 0) + .group_by(Client.type) + ) + for client_type, count in by_sender.all(): + if client_type == HUMAN_CLIENT_TYPE: + counts.message_from_human_1d += count + elif client_type == AGENT_CLIENT_TYPE: + counts.message_from_agent_1d += count + + await _collect_turns(session, counts, day_ago) + + counts.attachment_count_1d += await _scalar( + session, + select(func.count()) + .select_from(MessageAttachment) + .join(Message, Message.id == MessageAttachment.message_id) + .where(Message.sent_at >= day_ago), + ) + + +async def _collect_turns( + session: AsyncSession, counts: UsageCounts, since: datetime +) -> None: + """Who replied to whom, in the window. + + A turn is a message paired with the one before it in the same room, so the + pairing is read off `seq` — which is a total order within a room with no + ties, assigned in commit order, and therefore the only ordering where + "the previous message" means what it says. A timestamp would tie. + + Only three pairings are counted, and the ones left out are deliberate: + human→human is two people talking with no agent involved, and a turn whose + predecessor is a bridge relay or the admin client is machinery rather than + conversation. The first message in a room has no predecessor and is not a + turn at all. + + The window is applied to the *current* message, not the pair, so a reply + this morning to a question asked last night still counts — which is the + right reading of "turns today", and avoids a turn falling through the gap + between two windows. + """ + kind = case( + (Client.type == HUMAN_CLIENT_TYPE, "human"), + (Client.type == AGENT_CLIENT_TYPE, "agent"), + else_="other", + ) + paired = ( + select( + kind.label("sender"), + func.lag(kind) + .over(partition_by=Message.room_id, order_by=Message.seq) + .label("previous"), + Message.sent_at.label("sent_at"), + ) + .select_from(Message) + .join(Client, Client.id == Message.sender_client_id) + .where(Message.seq > 0) + .subquery() + ) + rows = await session.execute( + select(paired.c.sender, paired.c.previous, func.count()) + .where(paired.c.sent_at >= since, paired.c.previous.is_not(None)) + .group_by(paired.c.sender, paired.c.previous) + ) + for sender, previous, count in rows.all(): + if sender == "agent" and previous == "human": + counts.turn_human_to_agent_1d += count + elif sender == "human" and previous == "agent": + counts.turn_agent_to_human_1d += count + elif sender == "agent" and previous == "agent": + counts.turn_agent_to_agent_1d += count + + +async def room_had_human_activity(session: AsyncSession, room_id: str) -> bool: + """Whether a human has ever posted in this room. + + The session must already be bound to the room's tenant. + """ + found = await session.execute( + select(Message.id) + .join(Client, Client.id == Message.sender_client_id) + .where( + Message.room_id == room_id, + Message.seq > 0, + Client.type == HUMAN_CLIENT_TYPE, + ) + .limit(1) + ) + return found.scalar_one_or_none() is not None + + +async def collect_usage( + session_factory: async_sessionmaker[AsyncSession], *, now: datetime | None = None +) -> UsageCounts: + """Every tenant's numbers, summed into one set of deployment totals.""" + moment = now or datetime.now(UTC) + counts = UsageCounts() + tenant_ids = await all_tenant_ids(session_factory) + counts.tenant_count = len(tenant_ids) + for tenant_id in tenant_ids: + async with tenant_session(session_factory, tenant_id) as session: + await collect_tenant_counts(session, counts, moment) + # `users` carries no tenant, so it is counted once for the deployment + # rather than per tenant — summing a global table over tenants would + # multiply it by however many there are. + async with session_factory() as session: + counts.user_count = await _scalar( + session, select(func.count()).select_from(User) + ) + return counts + + +async def newly_active_rooms( + session_factory: async_sessionmaker[AsyncSession], + *, + since: datetime, + now: datetime | None = None, +) -> list[NewlyActiveRoom]: + """Rooms whose *first* human interaction happened after `since`. + + The window is what makes this once-per-room without storing anything: a + room qualifies only if its earliest human message falls inside it, and each + window starts where the last one ended. A room that was already active + before `since` has an earlier first message and is skipped for good. + + The cost of that is a room can be reported late — up to one window — and + cannot be reported at all if the deployment was down when the window that + covered it would have run. Both are acceptable for a figure nobody reads + inside a day, and neither can produce a duplicate. + """ + moment = now or datetime.now(UTC) + found: list[NewlyActiveRoom] = [] + + for tenant_id in await all_tenant_ids(session_factory): + async with tenant_session(session_factory, tenant_id) as session: + first_interaction = ( + select( + Message.room_id.label("room_id"), + func.min(Message.sent_at).label("first_at"), + ) + .join(Client, Client.id == Message.sender_client_id) + .where(Client.type == HUMAN_CLIENT_TYPE, Message.seq > 0) + .group_by(Message.room_id) + .subquery() + ) + agent_count = ( + select(func.count()) + .select_from(ClientRoom) + .join(Client, Client.id == ClientRoom.client_id) + .where( + ClientRoom.room_id == Room.id, + Client.type == AGENT_CLIENT_TYPE, + ) + .scalar_subquery() + ) + rows = await session.execute( + select( + Room.created_at, + first_interaction.c.first_at, + Room.channel_type, + Room.bridge_id, + Room.metadata_["created_by_kind"].astext, + agent_count, + ) + .join(first_interaction, first_interaction.c.room_id == Room.id) + .where( + and_( + first_interaction.c.first_at > since, + first_interaction.c.first_at <= moment, + ) + ) + ) + + platforms = await _bridge_platforms(session) + for created_at, first_at, channel_type, bridge_id, kind, agents in rows: + found.append( + NewlyActiveRoom( + seconds_since_room_created=max( + (first_at - created_at).total_seconds(), 0.0 + ), + bridge_platform=platforms.get(bridge_id, "none"), + channel_type=normalise_channel_type(channel_type), + agent_count=int(agents or 0), + created_by_kind=kind or "user", + ) + ) + return found + + +async def _bridge_platforms(session: AsyncSession) -> dict[str | None, str]: + """Bridge id → platform, for the tenant this session is bound to.""" + rows = await session.execute( + select(CollaborationBridge.id, CollaborationBridge.type) + ) + return {bridge_id: platform for bridge_id, platform in rows.all()} + + +def normalise_channel_type(channel_type: str | None) -> str: + """A `rooms.channel_type` as the catalogue spells it. + + The column predates the catalogue and carries a value the closed set does + not: `group`, the pre-rename name for a private channel (see the + `rename channel types` migration). Mapped rather than passed through, + because an unmapped value would raise at the point of emission and take a + room creation down with it. + """ + if channel_type in ("channel_public", "channel_private", "direct"): + return str(channel_type) + if channel_type == "group": + return "channel_private" + if channel_type == "channel": + return "channel_public" + return "none" + + +def normalise_platform(platform: str | None) -> str: + """A bridge type as the catalogue spells it.""" + return platform if platform in PLATFORMS else "none" + + +def normalise_known_agent_type(metadata: dict | None) -> str: + """The runtime behind an agent, as the catalogue spells it.""" + if not metadata: + return "none" + declared = metadata.get("known_agent_type") + if declared is None: + return "none" + if declared in ("claude-code", "codex", "opencode"): + return str(declared) + return "other" + + +def summarise(counts: UsageCounts, active: Sequence[NewlyActiveRoom]) -> str: + """A one-line log of what a snapshot pass found, for the server's own log. + + Worth logging even when telemetry is switched off: an operator asking "what + would this send?" should be able to answer it from the log rather than by + reading the code or by turning reporting on to find out. + """ + return ( + f"rooms={counts.room_count} active_7d={counts.room_active_7d} " + f"users={counts.user_count} active_users_7d={counts.user_active_7d} " + f"agents={counts.agent_count} messages_1d={counts.message_count_1d} " + f"newly_active_rooms={len(active)}" + ) diff --git a/core/tests/switch_core/db/test_tenant_exemption_allowlist.py b/core/tests/switch_core/db/test_tenant_exemption_allowlist.py index 64c129911..cc61bd725 100644 --- a/core/tests/switch_core/db/test_tenant_exemption_allowlist.py +++ b/core/tests/switch_core/db/test_tenant_exemption_allowlist.py @@ -81,6 +81,15 @@ # came off this list with `tenant_of_client`: both were built from a # `clients` row that already named the tenant, so they carry it instead of # asking for it. + # + # The usage snapshot counts every tenant's rooms, messages and agents and + # reports one deployment-wide total. That is the same boot-style fan-out + # `main` does: enumerate the tenants, then bind each one in turn and read + # its rows under its own policy. It has to ask, because a session with + # nothing bound reads nothing — a snapshot written without this would + # report a page of zeroes on a correctly configured deployment and look + # perfectly healthy doing it. + "switch_core.telemetry.snapshot", } # Every module allowed to open a session straight from the factory. Not short, @@ -122,6 +131,18 @@ # from the exemption, so neither has a session left that says nothing. # `switch_core.main` came off it earlier, when the tenant-zero fallback # went. + # + # ── Telemetry bookkeeping: three tables that carry no tenant and no + # policy, named in `rls_ddl.GLOBAL_TABLES`. Each records a fact about the + # *installation* — which deployment this is, when it was installed, which + # once-ever milestones it has reported, when the last snapshot went out — + # so there is no tenant for a policy to narrow on and binding one would be + # theatre. Same shape, and same reasoning, as reading `users`. + "switch_core.telemetry.deployment", + "switch_core.telemetry.reporter", + # Its own reads are the per-tenant fan-out above; this is the one global + # read beside them, the deployment's user count. + "switch_core.telemetry.snapshot", } # Calls that end in `session_factory` but hand one back rather than open a diff --git a/core/tests/switch_core/db/test_tenant_schema_catalogue.py b/core/tests/switch_core/db/test_tenant_schema_catalogue.py index c2b32c10d..d06f2a7dc 100644 --- a/core/tests/switch_core/db/test_tenant_schema_catalogue.py +++ b/core/tests/switch_core/db/test_tenant_schema_catalogue.py @@ -96,7 +96,19 @@ async def test_the_global_table_list_is_exactly_these(self) -> None: scoped table, not a nullable column there. `alembic_version` is global too but is not in this metadata: Alembic owns it. """ - assert set(GLOBAL_TABLES) == {"users", "oidc_identities", "feature_flags"} + assert set(GLOBAL_TABLES) == { + "users", + "oidc_identities", + "feature_flags", + # Facts about the installation, not about anything in it: which + # deployment this is to the analytics relay and when it was + # installed, which once-ever milestones it has reported, and when + # its last usage snapshot went out. A deployment running three + # tenants has one identity, not three. + "deployment_identity", + "telemetry_milestones", + "telemetry_snapshot_watermark", + } async def test_scoped_is_everything_else(self) -> None: scoped = _scoped_tables() diff --git a/core/tests/switch_core/telemetry/test_catalogue.py b/core/tests/switch_core/telemetry/test_catalogue.py new file mode 100644 index 000000000..f55a65f66 --- /dev/null +++ b/core/tests/switch_core/telemetry/test_catalogue.py @@ -0,0 +1,176 @@ +"""The catalogue is the privacy boundary, so these are the tests that matter. + +Everything here is about what *cannot* reach the relay. The counterpart to the +Console's own catalogue test, which tries to smuggle a room name into every +event and asserts it never arrives — the same trick is played below, because +the rule ("no identifier for anything inside a deployment") is only a rule if +something enforces it. +""" + +from __future__ import annotations + +import pytest + +from switch_core.telemetry.catalogue import ( + CATALOGUE, + EVENT_NAME_PREFIX, + TelemetryCatalogueError, + validate, + wire_name, +) + +# Anything that would identify something inside a deployment. None of these is +# a declared property of any event, and none may become one without this test +# being changed deliberately. +FORBIDDEN_PROPERTIES = ( + "room_id", + "room_name", + "tenant_id", + "tenant_name", + "agent_id", + "agent_name", + "user_id", + "user_email", + "message_id", + "message_body", + "channel_id", + "channel_name", + "external_channel_id", + "display_name", + "hostname", + "repo_dir", + "file_path", + "error_message", + "stack_trace", +) + + +def _one_valid_value(spec: object) -> object: + """A value the property will accept, whatever kind it is.""" + kind = type(spec).__name__ + if kind == "_Number": + return 1 + if kind == "_Boolean": + return True + return sorted(spec.values)[0] # type: ignore[attr-defined] + + +def _valid_payload(event: str) -> dict[str, object]: + return {name: _one_valid_value(spec) for name, spec in CATALOGUE[event].items()} + + +class TestNothingIdentifyingCanBeSent: + def test_no_event_declares_an_identifying_property(self) -> None: + """The rule, stated against the catalogue rather than against a payload. + + A property added under one of these names would pass every other test + in this file, because the machinery would happily carry it. This is + the one that says it may not exist at all. + """ + offenders = { + f"{event}.{name}" + for event, spec in CATALOGUE.items() + for name in spec + if name in FORBIDDEN_PROPERTIES + } + assert not offenders, ( + f"{sorted(offenders)} name something inside a deployment. Telemetry " + "reports counts and durations only — see docs/old/telemetry-events.md. " + "If a new property genuinely needs to identify something, that is a " + "decision for the InfoSec review, not for this file." + ) + + @pytest.mark.parametrize("event", sorted(CATALOGUE)) + def test_an_identifier_smuggled_alongside_valid_properties_is_refused( + self, event: str + ) -> None: + """The Console's trick: a real payload with one extra field.""" + payload = _valid_payload(event) + payload["room_name"] = "incident-response" + with pytest.raises(TelemetryCatalogueError, match="does not declare"): + validate(event, payload) # type: ignore[arg-type] + + def test_an_undeclared_event_is_refused(self) -> None: + with pytest.raises(TelemetryCatalogueError, match="not a telemetry event"): + validate("room_secretly_inspected", {}) + + +class TestThePropertySetIsExact: + @pytest.mark.parametrize("event", sorted(CATALOGUE)) + def test_a_declared_payload_is_accepted(self, event: str) -> None: + validate(event, _valid_payload(event)) # type: ignore[arg-type] + + @pytest.mark.parametrize( + "event", sorted(event for event in CATALOGUE if CATALOGUE[event]) + ) + def test_a_missing_property_is_refused(self, event: str) -> None: + """Every event of a name carries the same keys every time. + + Not a privacy rule but a charting one: a property that is sometimes + absent cannot be grouped on, and the absence is invisible in the tool. + """ + payload = _valid_payload(event) + payload.pop(sorted(payload)[0]) + with pytest.raises(TelemetryCatalogueError, match="is missing"): + validate(event, payload) # type: ignore[arg-type] + + +class TestValuesAreClosed: + def test_a_value_outside_its_set_is_refused(self) -> None: + payload = _valid_payload("bridge_connected") + payload["bridge_platform"] = "irc" + with pytest.raises(TelemetryCatalogueError, match="expected one of"): + validate("bridge_connected", payload) # type: ignore[arg-type] + + def test_free_text_where_a_set_belongs_is_refused(self) -> None: + """The case that matters: an exception message reaching `failure_reason`.""" + payload = _valid_payload("bridge_connected") + payload["failure_reason"] = "SlackApiError: invalid_auth for team acme-corp" + with pytest.raises(TelemetryCatalogueError, match="expected one of"): + validate("bridge_connected", payload) # type: ignore[arg-type] + + def test_a_boolean_is_not_a_number(self) -> None: + """`bool` subclasses `int`, so a count set to True would otherwise pass + and be reported as 1.""" + payload = _valid_payload("usage_snapshot") + payload["room_count"] = True + with pytest.raises(TelemetryCatalogueError, match="expected a number"): + validate("usage_snapshot", payload) # type: ignore[arg-type] + + def test_a_number_is_not_a_string(self) -> None: + payload = _valid_payload("usage_snapshot") + payload["room_count"] = "lots" + with pytest.raises(TelemetryCatalogueError, match="expected a number"): + validate("usage_snapshot", payload) # type: ignore[arg-type] + + def test_a_non_finite_count_is_refused(self) -> None: + """A mean over zero rooms must not arrive as NaN.""" + payload = _valid_payload("usage_snapshot") + payload["room_users_mean"] = float("nan") + with pytest.raises(TelemetryCatalogueError, match="finite"): + validate("usage_snapshot", payload) # type: ignore[arg-type] + + +class TestNaming: + def test_every_event_is_snake_case(self) -> None: + offenders = [ + event + for event in CATALOGUE + if not event.replace("_", "").isalnum() or event != event.lower() + ] + assert not offenders + + def test_every_property_is_snake_case(self) -> None: + offenders = [ + f"{event}.{name}" + for event, spec in CATALOGUE.items() + for name in spec + if not name.replace("_", "").isalnum() or name != name.lower() + ] + assert not offenders + + def test_the_wire_name_is_prefixed_by_product(self) -> None: + """One Amplitude project holds several products, so the prefix is what + keeps `room_created` here apart from the Console's.""" + assert wire_name("room_created") == f"{EVENT_NAME_PREFIX}.room_created" + assert EVENT_NAME_PREFIX == "switch_core" diff --git a/core/tests/switch_core/telemetry/test_deployment_and_reporter.py b/core/tests/switch_core/telemetry/test_deployment_and_reporter.py new file mode 100644 index 000000000..050c796c8 --- /dev/null +++ b/core/tests/switch_core/telemetry/test_deployment_and_reporter.py @@ -0,0 +1,322 @@ +"""Deployment identity, once-ever milestones, and the snapshot schedule. + +Against real Postgres, because all three are claims about durability: an +identity that survives a restart, a milestone that cannot fire twice, and a +schedule anchored to what was sent rather than to how long the process has +been up. None of those can be tested against a mock — the second in particular +relies on a primary-key collision being the guard. +""" + +from __future__ import annotations + +import uuid +from datetime import UTC, datetime, timedelta + +import pytest +from sqlalchemy import delete +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.db.models import DeploymentIdentity, TelemetrySnapshotWatermark +from switch_core.telemetry.deployment import ( + DeploymentIdentityMissingError, + claim_milestone, + load_deployment_identity, + seconds_since_install, +) +from switch_core.telemetry.reporter import SnapshotReporter +from switch_core.telemetry.service import TelemetryService +from switch_core.telemetry.sink import TelemetryRecord + +NOW = datetime(2026, 9, 16, 12, 0, tzinfo=UTC) + + +class _RecordingSink: + def __init__(self) -> None: + self.sent: list[TelemetryRecord] = [] + + async def send(self, record: TelemetryRecord) -> None: + self.sent.append(record) + + async def aclose(self) -> None: + return None + + +async def _seed_identity( + session_factory: async_sessionmaker[AsyncSession], + *, + installed_at: datetime | None, +) -> None: + async with session_factory() as session: + await session.execute(delete(DeploymentIdentity)) + session.add( + DeploymentIdentity( + id=1, client_id=str(uuid.uuid4()), installed_at=installed_at + ) + ) + await session.commit() + + +class TestDeploymentIdentity: + async def test_the_identity_is_read_back( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await _seed_identity(session_factory, installed_at=NOW) + + client_id, installed_at = await load_deployment_identity(session_factory) + + assert uuid.UUID(client_id) + assert installed_at is not None + + async def test_a_missing_identity_raises_rather_than_minting_one( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """Only the migration ran early enough to tell a new deployment from an + existing one. Re-creating the row here would give a year-old + installation an install date of today and a brand-new analytics + identity.""" + async with session_factory() as session: + await session.execute(delete(DeploymentIdentity)) + await session.commit() + + with pytest.raises(DeploymentIdentityMissingError): + await load_deployment_identity(session_factory) + + async def test_only_one_identity_can_exist( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """Two would mean one installation reporting as two subjects, silently + doubling every count derived from it.""" + await _seed_identity(session_factory, installed_at=NOW) + + with pytest.raises(Exception): + async with session_factory() as session: + session.add(DeploymentIdentity(id=2, client_id=str(uuid.uuid4()))) + await session.commit() + + +class TestTheInstallClock: + def test_a_deployment_with_no_install_date_is_unmeasurable(self) -> None: + """Not zero — `None`, which every milestone call site treats as "do not + report". A pre-existing deployment stays out of the funnel rather than + appearing to have activated instantly.""" + assert seconds_since_install(None) is None + + def test_elapsed_time_is_measured_from_the_install(self) -> None: + elapsed = seconds_since_install(datetime.now(UTC) - timedelta(hours=2)) + assert elapsed is not None + assert 7100 < elapsed < 7300 + + def test_a_naive_timestamp_is_read_as_utc(self) -> None: + """A `timestamptz` read back without a zone must not raise on + comparison.""" + naive = (datetime.now(UTC) - timedelta(minutes=5)).replace(tzinfo=None) + elapsed = seconds_since_install(naive) + assert elapsed is not None and elapsed > 0 + + +class TestMilestonesFireOnce: + async def test_the_first_claim_wins_and_the_second_does_not( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + assert await claim_milestone(session_factory, "first_room_created") is True + assert await claim_milestone(session_factory, "first_room_created") is False + + async def test_different_milestones_do_not_collide( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + assert await claim_milestone(session_factory, "first_room_created") is True + assert await claim_milestone(session_factory, "first_connector_added") is True + + async def test_a_milestone_survives_a_restart( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """The claim is a row, not process state — otherwise every restart + would re-report "first room created" on finding a room.""" + await claim_milestone(session_factory, "deployment_installed") + assert await claim_milestone(session_factory, "deployment_installed") is False + + +class TestEmitMilestone: + def _service( + self, + sink: _RecordingSink, + session_factory: async_sessionmaker[AsyncSession], + *, + enabled: bool = True, + installed_at: datetime | None = None, + ) -> TelemetryService: + return TelemetryService( + sink=sink, # type: ignore[arg-type] + enabled=enabled, + client_id="deployment-uuid", + service_name="switch-core", + version="1.0.0", + environment=None, + session_factory=session_factory, + installed_at=installed_at, + ) + + async def test_a_milestone_is_reported_once_with_its_elapsed_time( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + sink = _RecordingSink() + service = self._service( + sink, session_factory, installed_at=datetime.now(UTC) - timedelta(hours=1) + ) + + await service.emit_milestone("first_connector_added", bridge_platform="slack") + await service.emit_milestone("first_connector_added", bridge_platform="slack") + await service.aclose() + + assert len(sink.sent) == 1 + assert sink.sent[0].name == "switch_core.first_connector_added" + assert 3500 < float(sink.sent[0].properties["seconds_since_install"]) < 3700 + + async def test_a_deployment_with_no_install_date_reports_no_milestone( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + sink = _RecordingSink() + service = self._service(sink, session_factory, installed_at=None) + + await service.emit_milestone("first_connector_added", bridge_platform="slack") + await service.aclose() + + assert sink.sent == [] + + async def test_a_disabled_deployment_does_not_use_up_its_claims( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """Switching telemetry on later must not find every milestone already + spent.""" + sink = _RecordingSink() + off = self._service( + sink, session_factory, enabled=False, installed_at=datetime.now(UTC) + ) + + await off.emit_milestone("first_connector_added", bridge_platform="slack") + + assert await claim_milestone(session_factory, "first_connector_added") is True + + +class TestTheSnapshotSchedule: + def _reporter( + self, + sink: _RecordingSink, + session_factory: async_sessionmaker[AsyncSession], + *, + interval_hours: float = 24.0, + ) -> SnapshotReporter: + service = TelemetryService( + sink=sink, # type: ignore[arg-type] + enabled=True, + client_id="deployment-uuid", + service_name="switch-core", + version="1.0.0", + environment=None, + session_factory=session_factory, + installed_at=datetime.now(UTC) - timedelta(days=1), + ) + return SnapshotReporter( + telemetry=service, + session_factory=session_factory, + interval_hours=interval_hours, + installed_at=service.installed_at, + live_session_count=lambda: 2, + ) + + async def _clear_watermark( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + await session.execute(delete(TelemetrySnapshotWatermark)) + await session.commit() + + async def test_the_first_pass_sends_a_snapshot_and_sets_the_watermark( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await self._clear_watermark(session_factory) + sink = _RecordingSink() + reporter = self._reporter(sink, session_factory) + + assert await reporter.run_once_if_due() is True + + names = [record.name for record in sink.sent] + assert "switch_core.usage_snapshot" in names + + async def test_a_second_pass_inside_the_interval_does_nothing( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await self._clear_watermark(session_factory) + sink = _RecordingSink() + reporter = self._reporter(sink, session_factory) + + await reporter.run_once_if_due() + sent_after_first = len(sink.sent) + + assert await reporter.run_once_if_due() is False + assert len(sink.sent) == sent_after_first + + async def test_the_schedule_follows_the_watermark_not_the_process( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """A restart must not send a second snapshot the same day, and a + deployment that was down over its due time must send promptly rather + than waiting a further full period.""" + await self._clear_watermark(session_factory) + sink = _RecordingSink() + first = self._reporter(sink, session_factory) + await first.run_once_if_due() + + # A brand-new reporter, as a restart would build. + restarted = self._reporter(_RecordingSink(), session_factory) + assert await restarted.run_once_if_due() is False + + async def test_a_lapsed_watermark_sends_again( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + await session.execute(delete(TelemetrySnapshotWatermark)) + session.add( + TelemetrySnapshotWatermark( + id=1, last_sent_at=datetime.now(UTC) - timedelta(days=3) + ) + ) + await session.commit() + + sink = _RecordingSink() + reporter = self._reporter(sink, session_factory) + + assert await reporter.run_once_if_due() is True + + async def test_the_first_pass_reports_no_room_activations( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """With no watermark, "first interaction since then" means every room + that ever went active, arriving at once and all dated today.""" + await self._clear_watermark(session_factory) + sink = _RecordingSink() + reporter = self._reporter(sink, session_factory) + + await reporter.run_once_if_due() + + assert not [ + record + for record in sink.sent + if record.name == "switch_core.room_became_active" + ] + + async def test_the_snapshot_carries_the_live_session_count( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await self._clear_watermark(session_factory) + sink = _RecordingSink() + reporter = self._reporter(sink, session_factory) + + await reporter.run_once_if_due() + + snapshot = next( + record + for record in sink.sent + if record.name == "switch_core.usage_snapshot" + ) + assert snapshot.properties["session_live_count"] == 2 diff --git a/core/tests/switch_core/telemetry/test_service_and_sink.py b/core/tests/switch_core/telemetry/test_service_and_sink.py new file mode 100644 index 000000000..a75d76732 --- /dev/null +++ b/core/tests/switch_core/telemetry/test_service_and_sink.py @@ -0,0 +1,284 @@ +"""Consent, the wire format, and what happens when the relay misbehaves.""" + +from __future__ import annotations + +import asyncio +import json + +import httpx +import pytest + +from switch_core.telemetry.catalogue import TelemetryCatalogueError +from switch_core.telemetry.service import TelemetryService, emit_safely +from switch_core.telemetry.sink import NullSink, OtlpRelaySink, TelemetryRecord + + +class _RecordingSink: + def __init__(self) -> None: + self.sent: list[TelemetryRecord] = [] + self.closed = False + + async def send(self, record: TelemetryRecord) -> None: + self.sent.append(record) + + async def aclose(self) -> None: + self.closed = True + + +def _service(sink: object, *, enabled: bool = True) -> TelemetryService: + return TelemetryService( + sink=sink, # type: ignore[arg-type] + enabled=enabled, + client_id="deployment-uuid", + service_name="switch-core", + version="1.2.3", + environment="pilot", + ) + + +class TestConsent: + async def test_nothing_is_sent_when_telemetry_is_off(self) -> None: + sink = _RecordingSink() + service = _service(sink, enabled=False) + + service.emit("deployment_started", tenant_count=1) + await service.aclose() + + assert sink.sent == [] + + async def test_a_bad_event_is_still_caught_when_telemetry_is_off(self) -> None: + """Validation runs regardless, so a mistake in a rarely-taken branch is + found by whichever test exercises it rather than lying dormant until + the day a deployment switches reporting on.""" + service = _service(_RecordingSink(), enabled=False) + with pytest.raises(TelemetryCatalogueError): + service.emit("deployment_started", tenant_count="one") # type: ignore[arg-type] + + async def test_events_are_sent_when_telemetry_is_on(self) -> None: + sink = _RecordingSink() + service = _service(sink) + + service.emit("deployment_started", tenant_count=2) + await service.aclose() + + assert [record.name for record in sink.sent] == [ + "switch_core.deployment_started" + ] + + +class TestTagging: + async def test_every_event_carries_the_deployment_and_service(self) -> None: + sink = _RecordingSink() + service = _service(sink) + + service.emit("deployment_started", tenant_count=1) + await service.aclose() + + assert sink.sent[0].resource == { + "service.name": "switch-core", + "flint.client_id": "deployment-uuid", + "service.version": "1.2.3", + "deployment.environment": "pilot", + } + + async def test_an_unset_environment_is_omitted_rather_than_empty(self) -> None: + """An absent attribute reads as "not configured"; an empty string reads + as a real environment named nothing.""" + sink = _RecordingSink() + service = TelemetryService( + sink=sink, # type: ignore[arg-type] + enabled=True, + client_id="deployment-uuid", + service_name="switch-core", + version=None, + environment=None, + ) + + service.emit("deployment_started", tenant_count=1) + await service.aclose() + + assert "deployment.environment" not in sink.sent[0].resource + assert "service.version" not in sink.sent[0].resource + + +class TestFailuresDoNotReachTheCaller: + async def test_a_sink_that_raises_does_not_surface(self) -> None: + class _Broken: + async def send(self, record: TelemetryRecord) -> None: + raise RuntimeError("relay on fire") + + async def aclose(self) -> None: + return None + + service = _service(_Broken()) + service.emit("deployment_started", tenant_count=1) + await service.aclose() # must not raise + + def test_emit_safely_swallows_a_catalogue_mistake(self) -> None: + """A bad event must not take down the room creation that reported it.""" + service = _service(_RecordingSink()) + emit_safely(service, "deployment_started", {"tenant_count": "one"}) + + def test_emit_safely_tolerates_no_service_at_all(self) -> None: + emit_safely(None, "deployment_started", {"tenant_count": 1}) + + def test_emit_outside_an_event_loop_does_not_raise(self) -> None: + """Reported from a management command or a sync helper.""" + service = _service(_RecordingSink()) + service.emit("deployment_started", tenant_count=1) + + +class TestTheWireFormat: + """The relay's expectations, which fail silently rather than loudly.""" + + async def _capture(self, handler: object) -> dict: + captured: dict = {} + + def _handle(request: httpx.Request) -> httpx.Response: + captured.update(json.loads(request.content)) + return handler(request) # type: ignore[operator] + + sink = OtlpRelaySink( + endpoint="https://relay.example/v1/logs", timeout_seconds=5 + ) + sink._client = httpx.AsyncClient(transport=httpx.MockTransport(_handle)) + await sink.send( + TelemetryRecord( + name="switch_core.usage_snapshot", + properties={"room_count": 7, "from_template": True, "kind": "user"}, + resource={"service.name": "switch-core"}, + timestamp_ns=1_700_000_000_000_000_000, + ) + ) + await sink.aclose() + return captured + + async def test_the_event_name_is_sent_in_both_required_places(self) -> None: + """The relay filters on the attribute and the exporter reads the field. + Sending only one is accepted with a 200 and silently discarded.""" + body = await self._capture(lambda request: httpx.Response(200)) + record = body["resourceLogs"][0]["scopeLogs"][0]["logRecords"][0] + + assert record["eventName"] == "switch_core.usage_snapshot" + attributes = {a["key"]: a["value"] for a in record["attributes"]} + assert attributes["event.name"] == {"stringValue": "switch_core.usage_snapshot"} + + async def test_a_count_is_a_number_not_a_string(self) -> None: + """OTLP renders `intValue` as a JSON string, which arrives in analytics + as text and cannot be summed.""" + body = await self._capture(lambda request: httpx.Response(200)) + record = body["resourceLogs"][0]["scopeLogs"][0]["logRecords"][0] + attributes = {a["key"]: a["value"] for a in record["attributes"]} + + assert attributes["room_count"] == {"doubleValue": 7.0} + + async def test_a_boolean_stays_a_boolean(self) -> None: + body = await self._capture(lambda request: httpx.Response(200)) + record = body["resourceLogs"][0]["scopeLogs"][0]["logRecords"][0] + attributes = {a["key"]: a["value"] for a in record["attributes"]} + + assert attributes["from_template"] == {"boolValue": True} + + async def test_the_body_carries_the_name_so_the_log_line_is_not_blank( + self, + ) -> None: + body = await self._capture(lambda request: httpx.Response(200)) + record = body["resourceLogs"][0]["scopeLogs"][0]["logRecords"][0] + + assert record["body"] == {"stringValue": "switch_core.usage_snapshot"} + + async def test_no_credential_is_sent(self) -> None: + """The relay takes none, and holds the vendor keys itself.""" + seen: dict[str, str] = {} + + def _handle(request: httpx.Request) -> httpx.Response: + seen.update(request.headers) + return httpx.Response(200) + + sink = OtlpRelaySink( + endpoint="https://relay.example/v1/logs", timeout_seconds=5 + ) + sink._client = httpx.AsyncClient(transport=httpx.MockTransport(_handle)) + await sink.send(TelemetryRecord("switch_core.x", {}, {"service.name": "s"}, 1)) + await sink.aclose() + + assert "authorization" not in seen + assert "x-api-key" not in seen + + +class TestTheRelayMisbehaving: + async def _send_against(self, handler: object) -> None: + sink = OtlpRelaySink( + endpoint="https://relay.example/v1/logs", timeout_seconds=5 + ) + sink._client = httpx.AsyncClient( + transport=httpx.MockTransport(handler) # type: ignore[arg-type] + ) + await sink.send(TelemetryRecord("switch_core.x", {}, {"service.name": "s"}, 1)) + await sink.aclose() + + async def test_a_refusal_is_swallowed(self) -> None: + await self._send_against(lambda request: httpx.Response(503)) + + async def test_a_network_error_is_swallowed(self) -> None: + def _boom(request: httpx.Request) -> httpx.Response: + raise httpx.ConnectError("no route") + + await self._send_against(_boom) + + async def test_a_timeout_is_swallowed(self) -> None: + def _slow(request: httpx.Request) -> httpx.Response: + raise httpx.ReadTimeout("too slow") + + await self._send_against(_slow) + + async def test_a_partial_success_inside_a_200_is_noticed( + self, caplog: pytest.LogCaptureFixture + ) -> None: + """A 200 does not mean the record was kept. Without reading the body a + misconfigured deployment reports nothing and looks healthy doing it.""" + with caplog.at_level("WARNING"): + await self._send_against( + lambda request: httpx.Response( + 200, json={"partialSuccess": {"rejectedLogRecords": "3"}} + ) + ) + + assert "rejected 3 record(s)" in caplog.text + + async def test_an_empty_200_is_not_treated_as_a_rejection(self) -> None: + await self._send_against(lambda request: httpx.Response(200)) + + +class TestNullSink: + async def test_it_discards_and_closes(self) -> None: + sink = NullSink() + await sink.send(TelemetryRecord("switch_core.x", {}, {}, 1)) + await sink.aclose() + + +class TestShutdown: + async def test_in_flight_sends_are_awaited(self) -> None: + """The events worth losing least are the ones emitted just before the + process goes away.""" + started = asyncio.Event() + + class _Slow: + def __init__(self) -> None: + self.finished = False + + async def send(self, record: TelemetryRecord) -> None: + started.set() + await asyncio.sleep(0.05) + self.finished = True + + async def aclose(self) -> None: + return None + + sink = _Slow() + service = _service(sink) + service.emit("deployment_started", tenant_count=1) + await started.wait() + await service.aclose() + + assert sink.finished diff --git a/core/tests/switch_core/telemetry/test_snapshot.py b/core/tests/switch_core/telemetry/test_snapshot.py new file mode 100644 index 000000000..3db49668d --- /dev/null +++ b/core/tests/switch_core/telemetry/test_snapshot.py @@ -0,0 +1,557 @@ +"""The usage snapshot against real Postgres. + +These are the numbers that go in front of the business, so the tests are about +the definitions rather than about the plumbing: what counts as active, who +counts as a human, which room counts as one somebody made, and what a "turn" +between two participants actually is. A mock cannot check any of that — the +window function behind the turn counts, the JSONB read behind the +created-by split and the row-level-security fan-out all only exist in the +database. +""" + +from __future__ import annotations + +import uuid +from datetime import UTC, datetime, timedelta + +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.db.models import ( + Agent, + ApiKey, + Client, + ClientRoom, + CollaborationBridge, + Message, + Room, + User, +) +from switch_core.telemetry.snapshot import ( + UsageCounts, + collect_tenant_counts, + collect_usage, + newly_active_rooms, + normalise_channel_type, + normalise_known_agent_type, + normalise_platform, + room_had_human_activity, +) + +NOW = datetime(2026, 9, 16, 12, 0, tzinfo=UTC) + + +async def _room( + session: AsyncSession, + *, + created_by_kind: str | None = "user", + created_at: datetime | None = None, + archived: bool = False, + bridge_id: str | None = None, + channel_type: str = "channel_public", +) -> Room: + room = Room( + matrix_room_id=f"!{uuid.uuid4().hex[:10]}:test", + name=f"room-{uuid.uuid4().hex[:6]}", + description="a room", + channel_type=channel_type, + bridge_id=bridge_id, + created_at=created_at or (NOW - timedelta(days=30)), + archived_at=NOW if archived else None, + metadata_=({"created_by_kind": created_by_kind} if created_by_kind else None), + ) + session.add(room) + await session.flush() + return room + + +async def _client(session: AsyncSession, client_type: str) -> Client: + client = Client( + matrix_user_id=f"@{client_type}-{uuid.uuid4().hex[:8]}:test", + display_name=f"{client_type} client", + type=client_type, + ) + session.add(client) + await session.flush() + return client + + +async def _agent(session: AsyncSession, runtime: str | None) -> Agent: + """An agent with the client and api-key rows its foreign keys require.""" + slug = uuid.uuid4().hex[:10] + owner = User( + name="owner", email=f"owner-{slug}@test", role="user", password_hash="x" + ) + session.add(owner) + await session.flush() + key = ApiKey( + user_id=owner.id, + key_hash=f"hash-{slug}", + encrypted_key="enc", + label="test", + type="agent", + ) + backing = Client( + matrix_user_id=f"@agent-{slug}:test", display_name="agent", type="agent" + ) + session.add_all([key, backing]) + await session.flush() + agent = Agent( + name=f"agent-{uuid.uuid4().hex[:6]}", + description="d", + agent_type="session_addressable", + connector_type="http", + integration_profile={}, + client_id=backing.id, + api_key_id=key.id, + metadata_=({"known_agent_type": runtime} if runtime else None), + ) + session.add(agent) + await session.flush() + return agent + + +async def _join(session: AsyncSession, client: Client, room: Room) -> None: + session.add(ClientRoom(client_id=client.id, room_id=room.id)) + await session.flush() + + +async def _say( + session: AsyncSession, + room: Room, + sender: Client, + *, + seq: int, + when: datetime | None = None, +) -> Message: + message = Message( + room_id=room.id, + seq=seq, + transport_event_id=f"$evt-{uuid.uuid4().hex}", + sender_id=sender.matrix_user_id, + sender_client_id=sender.id, + event_type="m.room.message", + msgtype="m.text", + body="hello", + content={"body": "hello"}, + sent_at=when or (NOW - timedelta(hours=1)), + ) + session.add(message) + await session.flush() + return message + + +async def _counts(session: AsyncSession) -> UsageCounts: + counts = UsageCounts() + await collect_tenant_counts(session, counts, NOW) + return counts + + +class TestWhatCountsAsActive: + async def test_a_human_talking_to_an_agent_makes_the_room_active( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + human = await _client(session, "user") + agent = await _client(session, "agent") + await _join(session, human, room) + await _join(session, agent, room) + await _say(session, room, human, seq=1) + + counts = await _counts(session) + + assert counts.room_active_1d == 1 + assert counts.user_active_1d == 1 + + async def test_two_agents_talking_is_not_activity( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """The product question is whether people are using it. An orchestration + chatting to itself all night must not read as adoption.""" + async with session_factory() as session: + room = await _room(session) + one = await _client(session, "agent") + two = await _client(session, "agent") + await _join(session, one, room) + await _join(session, two, room) + await _say(session, room, one, seq=1) + await _say(session, room, two, seq=2) + + counts = await _counts(session) + + assert counts.room_active_1d == 0 + assert counts.user_active_1d == 0 + + async def test_a_human_in_a_room_with_no_agent_is_not_activity( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + human = await _client(session, "user") + await _join(session, human, room) + await _say(session, room, human, seq=1) + + counts = await _counts(session) + + assert counts.room_active_1d == 0 + + async def test_a_bridge_relay_is_not_a_person( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """`bridge`, `admin` and `observe` are machinery. Counting them as + users would make every bridged deployment look busier than it is.""" + async with session_factory() as session: + room = await _room(session) + agent = await _client(session, "agent") + await _join(session, agent, room) + for machinery in ("bridge", "admin", "observe"): + relay = await _client(session, machinery) + await _join(session, relay, room) + await _say(session, room, relay, seq=100 + len(machinery)) + + counts = await _counts(session) + + assert counts.user_active_1d == 0 + assert counts.room_active_1d == 0 + + async def test_the_day_and_week_windows_differ( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + human = await _client(session, "user") + agent = await _client(session, "agent") + await _join(session, human, room) + await _join(session, agent, room) + await _say(session, room, human, seq=1, when=NOW - timedelta(days=3)) + + counts = await _counts(session) + + assert counts.room_active_1d == 0 + assert counts.room_active_7d == 1 + + +class TestRoomsAreCountedByWhoMadeThem: + async def test_a_user_created_room_is_the_headline_figure( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + await _room(session, created_by_kind="user") + await _room(session, created_by_kind="agent") + + counts = await _counts(session) + + assert counts.room_count == 1 + assert counts.room_agent_created_count == 1 + + async def test_a_room_predating_the_stamp_counts_as_user_created( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """The conservative reading: agent-created is the newer path, so an + unstamped room is far more likely to be one a person made.""" + async with session_factory() as session: + await _room(session, created_by_kind=None) + + counts = await _counts(session) + + assert counts.room_count == 1 + assert counts.room_agent_created_count == 0 + + async def test_archived_rooms_leave_the_live_count( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + await _room(session) + await _room(session, archived=True) + + counts = await _counts(session) + + assert counts.room_count == 1 + assert counts.room_archived_count == 1 + + +class TestTurns: + """Who is actually talking to whom.""" + + async def test_an_agent_answering_a_person_is_a_human_to_agent_turn( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + human = await _client(session, "user") + agent = await _client(session, "agent") + await _say(session, room, human, seq=1) + await _say(session, room, agent, seq=2) + await _say(session, room, human, seq=3) + + counts = await _counts(session) + + assert counts.turn_human_to_agent_1d == 1 + assert counts.turn_agent_to_human_1d == 1 + assert counts.turn_agent_to_agent_1d == 0 + + async def test_two_agents_are_agent_to_agent_turns( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """The distinction a sender-only count cannot make: both of these are + "a message from an agent", and only one is a conversation with a + person.""" + async with session_factory() as session: + room = await _room(session) + one = await _client(session, "agent") + two = await _client(session, "agent") + await _say(session, room, one, seq=1) + await _say(session, room, two, seq=2) + await _say(session, room, one, seq=3) + + counts = await _counts(session) + + assert counts.turn_agent_to_agent_1d == 2 + assert counts.turn_human_to_agent_1d == 0 + + async def test_the_first_message_in_a_room_is_not_a_turn( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + human = await _client(session, "user") + await _say(session, room, human, seq=1) + + counts = await _counts(session) + + assert counts.turn_human_to_agent_1d == 0 + assert counts.turn_agent_to_human_1d == 0 + assert counts.turn_agent_to_agent_1d == 0 + + async def test_turns_do_not_pair_across_rooms( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """Two rooms interleaved in time must not make each other's messages + look like replies.""" + async with session_factory() as session: + first = await _room(session) + second = await _room(session) + human = await _client(session, "user") + agent = await _client(session, "agent") + await _say(session, first, human, seq=1) + await _say(session, second, agent, seq=1) + + counts = await _counts(session) + + assert counts.turn_human_to_agent_1d == 0 + + +class TestMessageCounts: + async def test_messages_are_split_by_sender_kind( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + human = await _client(session, "user") + agent = await _client(session, "agent") + await _say(session, room, human, seq=1) + await _say(session, room, agent, seq=2) + await _say(session, room, agent, seq=3) + + counts = await _counts(session) + + assert counts.message_count_1d == 3 + assert counts.message_from_human_1d == 1 + assert counts.message_from_agent_1d == 2 + + async def test_backfilled_history_is_not_traffic( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """Reconstructed history is numbered below zero. Importing a year of + Slack must not read as a year's usage arriving today.""" + async with session_factory() as session: + room = await _room(session) + human = await _client(session, "user") + await _say(session, room, human, seq=-1) + await _say(session, room, human, seq=-2) + + counts = await _counts(session) + + assert counts.message_count_1d == 0 + + +class TestAgentsAndConnectors: + async def test_agents_are_split_by_runtime( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + for runtime in ("claude-code", "codex", "opencode", "something-new", None): + await _agent(session, runtime) + + counts = await _counts(session) + + assert counts.agent_count == 5 + assert counts.agent_claude_code_count == 1 + assert counts.agent_codex_count == 1 + assert counts.agent_opencode_count == 1 + assert counts.agent_other_count == 2 + + async def test_connectors_are_counted_per_platform( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + for platform in ("slack", "slack", "teams"): + client = await _client(session, "bridge") + session.add( + CollaborationBridge( + type=platform, + display_name=f"{platform} workspace", + client_id=client.id, + status="active", + ) + ) + await session.flush() + + counts = await _counts(session) + + assert counts.connector_counts["slack"] == 2 + assert counts.connector_counts["teams"] == 1 + assert counts.connector_counts["discord"] == 0 + assert counts.connector_configured_count == 3 + + +class TestMembership: + async def test_only_humans_count_towards_users_in_rooms( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + for _ in range(3): + await _join(session, await _client(session, "user"), room) + await _join(session, await _client(session, "agent"), room) + await _join(session, await _client(session, "bridge"), room) + + counts = await _counts(session) + + assert counts.room_membership_total == 3 + assert counts.room_users_max == 3 + + +class TestNewlyActiveRooms: + async def test_a_room_reports_when_a_person_first_speaks_in_it( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + created = NOW - timedelta(hours=5) + async with session_factory() as session: + room = await _room(session, created_at=created) + human = await _client(session, "user") + await _say(session, room, human, seq=1, when=NOW - timedelta(hours=2)) + await session.commit() + + found = await newly_active_rooms( + session_factory, since=NOW - timedelta(hours=4), now=NOW + ) + + assert len(found) == 1 + assert found[0].seconds_since_room_created == 3 * 3600 + assert found[0].created_by_kind == "user" + + async def test_a_room_already_active_before_the_window_is_not_reported_again( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """What makes this once-per-room without storing anything: the room + qualifies only if its *earliest* human message is inside the window.""" + async with session_factory() as session: + room = await _room(session, created_at=NOW - timedelta(days=10)) + human = await _client(session, "user") + await _say(session, room, human, seq=1, when=NOW - timedelta(days=9)) + await _say(session, room, human, seq=2, when=NOW - timedelta(hours=1)) + await session.commit() + + found = await newly_active_rooms( + session_factory, since=NOW - timedelta(hours=4), now=NOW + ) + + assert found == [] + + async def test_an_agent_only_room_never_becomes_active( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + room = await _room(session) + agent = await _client(session, "agent") + await _say(session, room, agent, seq=1, when=NOW - timedelta(hours=1)) + await session.commit() + + found = await newly_active_rooms( + session_factory, since=NOW - timedelta(hours=4), now=NOW + ) + + assert found == [] + + +class TestRoomHadHumanActivity: + async def test_it_reports_whether_a_person_ever_posted( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + quiet = await _room(session) + busy = await _room(session) + human = await _client(session, "user") + await _say(session, busy, human, seq=1) + + assert await room_had_human_activity(session, busy.id) is True + assert await room_had_human_activity(session, quiet.id) is False + + +class TestTheDeploymentTotal: + async def test_users_are_counted_once_for_the_deployment( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """`users` carries no tenant, so summing it per tenant would multiply + it by however many tenants there are.""" + async with session_factory() as session: + await _room(session) + await session.commit() + + counts = await collect_usage(session_factory, now=NOW) + + assert counts.tenant_count >= 1 + assert counts.room_count == 1 + + +class TestTheDerivedProperties: + def test_the_mean_is_zero_rather_than_a_division_by_zero(self) -> None: + counts = UsageCounts() + properties = counts.as_event_properties(session_live_count=0) + assert properties["room_users_mean"] == 0.0 + + def test_every_platform_reports_even_with_none_configured(self) -> None: + """The catalogue requires every key every time, so a deployment with no + Discord bridge reports zero rather than omitting the property.""" + properties = UsageCounts().as_event_properties(session_live_count=0) + for platform in ("slack", "mattermost", "discord", "teams", "telegram"): + assert properties[f"connector_{platform}_count"] == 0 + + def test_the_properties_match_the_catalogue_exactly(self) -> None: + from switch_core.telemetry.catalogue import CATALOGUE + + properties = UsageCounts().as_event_properties(session_live_count=3) + assert set(properties) == set(CATALOGUE["usage_snapshot"]) + + +class TestNormalising: + def test_the_pre_rename_channel_type_is_mapped(self) -> None: + """`group` predates the catalogue's vocabulary; passing it through + would raise at emission and take a room creation down with it.""" + assert normalise_channel_type("group") == "channel_private" + assert normalise_channel_type("channel") == "channel_public" + assert normalise_channel_type("channel_public") == "channel_public" + assert normalise_channel_type(None) == "none" + assert normalise_channel_type("something-new") == "none" + + def test_an_unknown_platform_becomes_none(self) -> None: + assert normalise_platform("slack") == "slack" + assert normalise_platform(None) == "none" + assert normalise_platform("irc") == "none" + + def test_a_runtime_switch_does_not_know_becomes_other(self) -> None: + assert normalise_known_agent_type({"known_agent_type": "codex"}) == "codex" + assert normalise_known_agent_type({"known_agent_type": "zed"}) == "other" + assert normalise_known_agent_type({}) == "none" + assert normalise_known_agent_type(None) == "none" diff --git a/deploy/remote/helm/switch/templates/_helpers.tpl b/deploy/remote/helm/switch/templates/_helpers.tpl index eac995c80..64f72d25a 100644 --- a/deploy/remote/helm/switch/templates/_helpers.tpl +++ b/deploy/remote/helm/switch/templates/_helpers.tpl @@ -590,6 +590,14 @@ Include with `nindent 12`. - name: ENVIRONMENT value: {{ . | quote }} {{- end }} +- name: TELEMETRY_ENABLED + value: {{ .Values.switchCore.telemetry.enabled | quote }} +{{- if .Values.switchCore.telemetry.enabled }} +- name: TELEMETRY_ENDPOINT + value: {{ .Values.switchCore.telemetry.endpoint | quote }} +- name: TELEMETRY_SNAPSHOT_INTERVAL_HOURS + value: {{ .Values.switchCore.telemetry.snapshotIntervalHours | quote }} +{{- end }} # switch-core sits behind the cluster/ALB and enforces its own # BearerAuthMiddleware, so fastmcp's browser-oriented DNS-rebinding # Host/Origin guard (default-on since mcp 1.28) only rejects the diff --git a/deploy/remote/helm/switch/values.yaml b/deploy/remote/helm/switch/values.yaml index 75fffe8dc..379574aaf 100644 --- a/deploy/remote/helm/switch/values.yaml +++ b/deploy/remote/helm/switch/values.yaml @@ -117,6 +117,26 @@ switchCore: environment: "" serviceName: switch-core + # Anonymous product telemetry: usage counts and timings reported to the + # Flint relay, which is the same pipeline Switch Console reports to. + # + # Off by default, and that is deliberate — this deployment's usage may be + # yours rather than ours, so reporting it is a choice you make rather than + # one you discover. When it is off nothing is collected and no request is + # made. + # + # Nothing that identifies anything inside the deployment is ever sent: no + # room, tenant, agent, user or message id, no names, no message content, and + # no free text of any kind. What is sent is counts (how many rooms, how many + # active users, how much traffic) and durations (how long from install to a + # working connector). The full list is in docs/old/telemetry-events.md and + # is enforced in code, not just documented. + telemetry: + enabled: false + endpoint: https://telemetry.flintai.dev/v1/logs + # How often the usage snapshot is collected and sent. + snapshotIntervalHours: 24 + # Public base URL the gateway is served on (used for links / OIDC redirects). frontendBaseUrl: "" # Public origin (scheme + host, no path) of the gateway HTTP API itself, used From 90e2965904fca80dc807238cecac341b41cd7af5 Mon Sep 17 00:00:00 2001 From: Christian McDermott Date: Wed, 16 Sep 2026 16:05:14 -0400 Subject: [PATCH 4/5] fix(telemetry): correct the arithmetic an adversarial review found wrong MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Six blocking defects, all in the numbers rather than the design. Sixty-six candidates were raised across six reviewers and twenty-five survived refutation; these are the ones that changed behaviour. **The per-tenant fan-out never named its tenant.** Every query leaned on row-level security to narrow it, and the policy is exactly what does not apply on an owner connection — so a deployment with N tenants reported N times its size, and `room_became_active` fired once per tenant per room. `db/tenant_lookup.py` states this rule and every other fan-out in the tree follows it. The single-tenant tests could not fail on it, because with one tenant N is one; there is now a two-tenant regression test, and reverting one predicate makes it fail. **The activation milestone was wrong four ways at once**, and it fires once, so every wrong value was permanent. It measured from the moment the snapshot happened to run rather than from the interaction — always late, always in the same direction. It picked the fastest-activating room in the batch rather than the earliest. It did not filter to user-created rooms, so an agent's scratch room could consume the deployment's activation. And it claimed the milestone outside the enabled gate, so a deployment with telemetry off spent the claim and could never report it after opting in. Nothing exercised the method; it now has its own test file. **A telemetry lookup could fail a committed room creation.** The bridge query sat inside the argument list, so it was evaluated before the guard meant to contain it. Resolved once, ahead of the block, and the helper itself no longer raises. **`room_users_mean` could exceed `room_users_max`** — the numerator counted every room and the denominator only user-created ones. Impossible for any one population, so it read as a broken metric. **The headline room count included bridge-adopted channels.** This change introduced a third origin and the filter said "not agent", so on a Slack-heavy deployment "rooms a person created" was dominated by channels Switch was merely invited to. Split three ways. **"When telemetry is off nothing is collected" was false**, including in the Helm chart a customer reads: the snapshot loop ran regardless. It is now gated, and the interval is validated whether or not reporting is on, since zero would have meant "never not due" rather than "disabled". Also: an agent archiving a room reported nothing, because it wrote to the store directly and bypassed the service that reports; the two bridge events now share one reason set, so a classifier value only one of them declared can no longer fail validation at the moment a bridge drops; `stop()` no longer reports a disconnection for a bridge that never connected, and `restart()` says so; and the design note has been corrected to match the code in the five places it had already drifted. Refs CHOO-2806. Co-Authored-By: Claude Opus 5 (1M context) --- .../bridges/agent/protocol/service.py | 7 +- .../collaboration/lifecycle_service.py | 22 +- core/switch_core/config.py | 17 +- core/switch_core/main.py | 17 +- core/switch_core/room_service.py | 41 ++- core/switch_core/telemetry/catalogue.py | 32 ++- core/switch_core/telemetry/reporter.py | 53 +++- core/switch_core/telemetry/snapshot.py | 205 ++++++++++---- .../agent/protocol/test_room_detail.py | 10 + .../telemetry/test_first_room_active.py | 250 ++++++++++++++++++ .../switch_core/telemetry/test_snapshot.py | 73 ++++- .../telemetry/test_snapshot_multi_tenant.py | 156 +++++++++++ docs/old/telemetry-events.md | 74 ++++-- 13 files changed, 829 insertions(+), 128 deletions(-) create mode 100644 core/tests/switch_core/telemetry/test_first_room_active.py create mode 100644 core/tests/switch_core/telemetry/test_snapshot_multi_tenant.py diff --git a/core/switch_core/bridges/agent/protocol/service.py b/core/switch_core/bridges/agent/protocol/service.py index 7e66a9e90..2a02a15b3 100644 --- a/core/switch_core/bridges/agent/protocol/service.py +++ b/core/switch_core/bridges/agent/protocol/service.py @@ -3501,8 +3501,11 @@ async def set_room_archived( await self.require_room_member(agent_id, room_id) async with self.session_factory() as session: await self._require_room_action(session, agent_id, room_id, "write") - await self.room_store.set_archived(session, room_id, archived) - await session.commit() + # Through RoomService rather than straight at the store: archiving is + # reported, and writing the row here instead would make an agent's + # archive the one kind nothing observes while the snapshot's archived + # count rose anyway. + await self.room_service.set_room_archived(room_id, archived) return await self.get_room_detail(agent_id, room_id) async def list_all_agents(self, agent_id: str) -> list[Agent]: diff --git a/core/switch_core/bridges/collaboration/lifecycle_service.py b/core/switch_core/bridges/collaboration/lifecycle_service.py index 5f7d347fc..b14afa984 100644 --- a/core/switch_core/bridges/collaboration/lifecycle_service.py +++ b/core/switch_core/bridges/collaboration/lifecycle_service.py @@ -93,6 +93,7 @@ class CollaborationBridgeLifecycleService: _telemetry: TelemetryService | None = None _connect_failures: dict[str, int] = {} _bridge_facts: dict[str, tuple[str, object]] = {} + _connected: set[str] = set() def __init__( self, @@ -137,6 +138,10 @@ def __init__( # reporting never depends on what that object exposes — a stand-in # supplied by a test is still a legitimate bridge to run. self._bridge_facts: dict[str, tuple[str, object]] = {} + # Bridges that reached the platform, as opposed to merely having + # been started. `_bridges` is populated before the connection is + # attempted, so it cannot answer this. + self._connected: set[str] = set() # bridge_id -> the host resource it holds exclusively while running # (see CollaborationAdapter.exclusive_resource). Lets a second # claimant be refused by name instead of failing on the resource. @@ -681,6 +686,7 @@ async def _run_bridge( # until shutdown, so this is the one point that means # "connected". connected = True + self._connected.add(bridge_id) await self._report_connector_up(bridge_id, platform, configured_at) await bridge_client.start() except Exception as exc: @@ -691,6 +697,7 @@ async def _run_bridge( # Told apart by whether the adapter ever came up: a failure # before that never connected at all, and reporting it as a # disconnection would invent an uptime the bridge never had. + self._connected.discard(bridge_id) if connected: emit_safely( self._telemetry, @@ -781,8 +788,10 @@ def _any_connector_before(self, bridge_id: str) -> bool: """Whether another bridge was already connected when this one came up.""" return any(other != bridge_id for other in self._bridges) - async def stop(self, bridge_id: str) -> None: + async def stop(self, bridge_id: str, *, reason: str = "shutdown") -> None: bridge_core = self._bridges.get(bridge_id) + was_connected = bridge_id in self._connected + self._connected.discard(bridge_id) if bridge_core: await bridge_core.stop() @@ -794,14 +803,19 @@ async def stop(self, bridge_id: str) -> None: self._held_resources.pop(bridge_id, None) logger.info("Stopped collaboration bridge %s", bridge_id) - if bridge_core is not None: + # Only for a bridge that actually reached the platform. `_bridges` + # membership is set by `start()` before the connection is attempted, so + # on its own it would report a disconnection for a bridge that never + # connected — the same distinction `_run_bridge` keeps with its + # `connected` flag. + if bridge_core is not None and was_connected: platform, _ = self._bridge_facts.get(bridge_id, ("none", None)) emit_safely( self._telemetry, "bridge_disconnected", { "bridge_platform": normalise_platform(platform), - "reason": "shutdown", + "reason": reason, }, ) @@ -810,7 +824,7 @@ async def restart(self, bridge_id: str) -> None: An adapter is built from the config it was given at start, so an edit is inert until the bridge is rebuilt.""" - await self.stop(bridge_id) + await self.stop(bridge_id, reason="restart") await self.start(bridge_id) logger.info("Restarted collaboration bridge %s", bridge_id) diff --git a/core/switch_core/config.py b/core/switch_core/config.py index cadadddda..55c0d6522 100644 --- a/core/switch_core/config.py +++ b/core/switch_core/config.py @@ -338,6 +338,17 @@ def _validate_logging(self) -> "SwitchConfig": ) if not self.tenant_id.strip(): raise ValueError("TENANT_ID must not be empty.") + # Checked whether or not telemetry is on, unlike the endpoint and the + # timeout below: 0 is a plausible reading of "disable the snapshot" and + # would instead mean "never not due", running the whole fan-out every + # poll. A setting whose wrong value is a busy loop is worth refusing + # even on a deployment that is not using it yet. + if self.telemetry_snapshot_interval_hours <= 0: + raise ValueError( + "TELEMETRY_SNAPSHOT_INTERVAL_HOURS must be positive, got " + f"{self.telemetry_snapshot_interval_hours!r}. Set " + "TELEMETRY_ENABLED=false to switch reporting off." + ) if self.telemetry_enabled: # Checked only when telemetry is on: a deployment that never # reports should not be refused boot over the shape of a setting @@ -353,11 +364,7 @@ def _validate_logging(self) -> "SwitchConfig": "TELEMETRY_TIMEOUT_SECONDS must be positive, got " f"{self.telemetry_timeout_seconds!r}." ) - if self.telemetry_snapshot_interval_hours <= 0: - raise ValueError( - "TELEMETRY_SNAPSHOT_INTERVAL_HOURS must be positive, got " - f"{self.telemetry_snapshot_interval_hours!r}." - ) + if self.template_max_bytes < 1: raise ValueError( f"TEMPLATE_MAX_BYTES must be at least 1, got {self.template_max_bytes}." diff --git a/core/switch_core/main.py b/core/switch_core/main.py index 7043e89da..837653afe 100644 --- a/core/switch_core/main.py +++ b/core/switch_core/main.py @@ -560,17 +560,24 @@ async def lifespan(app: object) -> AsyncIterator[None]: connection_sweep_task = asyncio.create_task( _connection_sweep_loop(protocol) ) - # Runs whether or not telemetry is enabled: the counts are logged - # either way, so an operator can see what would be reported before - # deciding to report it. - snapshot_task = asyncio.create_task(_snapshot_loop(snapshot_reporter)) + # Only when telemetry is on. "Off" is documented — in the Helm + # chart a customer reads — as nothing being collected, and running + # the per-tenant fan-out anyway would make that false: it is a + # seven-day scan over `messages` per tenant, per interval, for an + # analytics payload the deployment has declined. + snapshot_task = ( + asyncio.create_task(_snapshot_loop(snapshot_reporter)) + if telemetry.enabled + else None + ) await message_listener.start() try: yield finally: sweep_task.cancel() connection_sweep_task.cancel() - snapshot_task.cancel() + if snapshot_task is not None: + snapshot_task.cancel() await message_listener.stop() await telemetry.aclose() diff --git a/core/switch_core/room_service.py b/core/switch_core/room_service.py index 9cf5e8000..849932252 100644 --- a/core/switch_core/room_service.py +++ b/core/switch_core/room_service.py @@ -647,12 +647,19 @@ async def create_room(self, config: RoomCreateConfig) -> RoomCreateResult: len(system_clients), ) + # Resolved once, before the reporting block, and never inside an + # argument list: an `await` in the dict passed to `emit_safely` is + # evaluated *before* that function is entered, so a database hiccup in + # a telemetry lookup would escape the guard meant to contain it and + # fail a room creation that has already committed. + platform = await self._bridge_platform(bridge_id) + emit_safely( self._telemetry, "room_created", { "channel_type": normalise_channel_type(channel_type), - "bridge_platform": await self._bridge_platform(bridge_id), + "bridge_platform": platform, "agent_count": len(agent_ids), "human_count": len(config.user_names or []), "has_instructions": config.instructions is not None, @@ -669,7 +676,7 @@ async def create_room(self, config: RoomCreateConfig) -> RoomCreateResult: await self._telemetry.emit_milestone( "first_room_created", channel_type=normalise_channel_type(channel_type), - bridge_platform=await self._bridge_platform(bridge_id), + bridge_platform=platform, ) failed_attachments = unreachable_users + await self._attach_after_creation( @@ -970,7 +977,7 @@ async def set_room_archived(self, room_id: str, archived: bool) -> None: await self._room_store.set_archived(session, room_id, archived) await session.commit() - if not archived: + if not archived or self._telemetry is None: return emit_safely( self._telemetry, @@ -985,14 +992,28 @@ async def set_room_archived(self, room_id: str, archived: bool) -> None: async def _bridge_platform(self, bridge_id: str | None) -> str: """The platform a bridge id names, as the telemetry catalogue spells it. - `none` for an internal-only room, and also for a bridge id that no - longer resolves — a deleted bridge is not a platform, and guessing one - would be worse than reporting the absence. + `none` for an internal-only room, for a bridge id that no longer + resolves, and for a lookup that failed — a deleted bridge is not a + platform, and guessing one would be worse than reporting the absence. + + Never raises. This is read only to label an analytics event, and the + operations it labels — creating a room, archiving one — must not fail + because a telemetry lookup did. Skipped entirely when nothing is + listening, so an opted-out deployment pays no query for it. """ - if bridge_id is None: + if bridge_id is None or self._telemetry is None: + return "none" + try: + async with self._session_factory() as session: + bridge = await self._collab_bridge_store.get(session, bridge_id) + except Exception: + logger.warning( + "Could not resolve the platform of bridge %s for telemetry; " + "reporting it as unknown.", + bridge_id, + exc_info=True, + ) return "none" - async with self._session_factory() as session: - bridge = await self._collab_bridge_store.get(session, bridge_id) return normalise_platform(bridge.type if bridge else None) async def _was_ever_active(self, tenant_id: str, room_id: str) -> bool: @@ -1005,7 +1026,7 @@ async def _was_ever_active(self, tenant_id: str, room_id: str) -> bool: """ try: async with tenant_session(self._session_factory, tenant_id) as session: - return await room_had_human_activity(session, room_id) + return await room_had_human_activity(session, tenant_id, room_id) except Exception: logger.warning( "Could not determine whether room %s was ever active; " diff --git a/core/switch_core/telemetry/catalogue.py b/core/switch_core/telemetry/catalogue.py index 1592c3c13..176bcaaab 100644 --- a/core/switch_core/telemetry/catalogue.py +++ b/core/switch_core/telemetry/catalogue.py @@ -111,6 +111,14 @@ class TelemetryCatalogueError(Exception): OUTCOME = one_of("success", "failure") +# Why a bridge failed, shared by the connect and disconnect events because one +# classifier (`bridges/collaboration/lifecycle_service._failure_reason`) feeds +# both. `none` belongs only to the success case and is stripped where the event +# has no success case. +BRIDGE_FAILURE_REASON = one_of( + "none", "auth_failed", "network", "platform_error", "config_invalid", "unknown" +) + # ── The catalogue ──────────────────────────────────────────────────────────── @@ -119,8 +127,13 @@ class TelemetryCatalogueError(Exception): "user_count", "user_active_1d", "user_active_7d", + # Rooms, split three ways rather than two. `room_count` is the headline — + # rooms a person made — and the other two exist so that folding a channel + # Switch was merely invited to, or one an agent made for its own + # orchestration, into that figure is not possible by accident. "room_count", "room_agent_created_count", + "room_system_created_count", "room_active_1d", "room_active_7d", "room_archived_count", @@ -256,24 +269,19 @@ class TelemetryCatalogueError(Exception): "bridge_platform": BRIDGE_PLATFORM, "outcome": OUTCOME, # `none` on success, so the property set stays exact either way. - "failure_reason": one_of( - "none", - "auth_failed", - "network", - "platform_error", - "config_invalid", - "unknown", - ), + "failure_reason": BRIDGE_FAILURE_REASON, }, "bridge_disconnected": { "bridge_platform": BRIDGE_PLATFORM, + # The deliberate-shutdown reasons, plus every failure reason + # `bridge_connected` can carry. One classifier feeds both events, so a + # value it can produce and only one of them declares is an event that + # fails validation at the moment a bridge drops — which is precisely + # the event worth not losing. "reason": one_of( "shutdown", "restart", - "auth_failed", - "network", - "platform_error", - "unknown", + *sorted(BRIDGE_FAILURE_REASON.values - {"none"}), ), }, } diff --git a/core/switch_core/telemetry/reporter.py b/core/switch_core/telemetry/reporter.py index 80f490896..77196174a 100644 --- a/core/switch_core/telemetry/reporter.py +++ b/core/switch_core/telemetry/reporter.py @@ -18,6 +18,7 @@ import asyncio import logging +from collections.abc import Callable from datetime import UTC, datetime, timedelta from sqlalchemy import select @@ -25,9 +26,10 @@ from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker from switch_core.db.models import TelemetrySnapshotWatermark -from switch_core.telemetry.deployment import claim_milestone, seconds_since_install +from switch_core.telemetry.deployment import claim_milestone from switch_core.telemetry.service import TelemetryService from switch_core.telemetry.snapshot import ( + as_utc, collect_usage, newly_active_rooms, summarise, @@ -56,7 +58,7 @@ def __init__( session_factory: async_sessionmaker[AsyncSession], interval_hours: float, installed_at: datetime | None, - live_session_count: object, + live_session_count: Callable[[], int], ) -> None: self._telemetry = telemetry self._session_factory = session_factory @@ -107,7 +109,7 @@ async def run_once(self, *, now: datetime, since: datetime | None) -> None: self._telemetry.emit( "usage_snapshot", **counts.as_event_properties( - session_live_count=int(self._live_session_count()) # type: ignore[operator] + session_live_count=int(self._live_session_count()) ), ) @@ -121,26 +123,49 @@ async def run_once(self, *, now: datetime, since: datetime | None) -> None: created_by_kind=room.created_by_kind, ) - await self._report_first_room_active(active, now=now) + await self._report_first_room_active(active) - async def _report_first_room_active(self, active: list, *, now: datetime) -> None: - """The activation milestone, from the earliest room in this window. + async def _report_first_room_active(self, active: list) -> None: + """The activation milestone: the first room a person actually used. - Measured from the room's own first interaction rather than from the - moment this pass happened to run, so a snapshot that is late does not - report an activation that was slower than it was. + Three things here are easy to get wrong and all three matter, because + the milestone fires once and whatever it reports is permanent. + + **Measured from the interaction, not from this pass.** A snapshot runs + on an interval, so it learns about an activation up to a whole interval + after it happened — and always late, never early. Reporting + `now - installed_at` would add that lag to every deployment's headline + activation time in the same direction. + + **The earliest room, not the quickest.** A batch can contain several + newly-active rooms; the one that activated *first* is the deployment's + activation. The one that went from creation to use fastest is a + different and much smaller number. + + **User-created rooms only**, matching `first_room_created` and the + design note. A room an agent provisioned for its own orchestration is + not a customer getting started, and it must not be allowed to consume + the claim. """ - if not active or self._installed_at is None: + by_a_person = [room for room in active if room.created_by_kind == "user"] + if not by_a_person or self._installed_at is None: return - elapsed = seconds_since_install(self._installed_at) - if elapsed is None: + # Not `emit_milestone`, because the elapsed time is computed from the + # room rather than from now — so the enabled gate it would have applied + # is applied here instead. Without it a deployment with telemetry off + # would spend the claim and never be able to report this again. + if not self._telemetry.enabled: return - earliest = min(active, key=lambda room: room.seconds_since_room_created) + + earliest = min(by_a_person, key=lambda room: room.first_active_at) + elapsed = ( + earliest.first_active_at - as_utc(self._installed_at) + ).total_seconds() if not await claim_milestone(self._session_factory, "first_room_active"): return self._telemetry.emit( "first_room_active", - seconds_since_install=elapsed, + seconds_since_install=max(elapsed, 0.0), bridge_platform=earliest.bridge_platform, seconds_since_room_created=earliest.seconds_since_room_created, ) diff --git a/core/switch_core/telemetry/snapshot.py b/core/switch_core/telemetry/snapshot.py index 135bd08ff..962b159e4 100644 --- a/core/switch_core/telemetry/snapshot.py +++ b/core/switch_core/telemetry/snapshot.py @@ -77,6 +77,7 @@ class UsageCounts: user_active_7d: int = 0 room_count: int = 0 room_agent_created_count: int = 0 + room_system_created_count: int = 0 room_active_1d: int = 0 room_active_7d: int = 0 room_archived_count: int = 0 @@ -110,6 +111,7 @@ def as_event_properties(self, *, session_live_count: int) -> dict[str, float]: "user_active_7d": self.user_active_7d, "room_count": self.room_count, "room_agent_created_count": self.room_agent_created_count, + "room_system_created_count": self.room_system_created_count, "room_active_1d": self.room_active_1d, "room_active_7d": self.room_active_7d, "room_archived_count": self.room_archived_count, @@ -146,6 +148,11 @@ def as_event_properties(self, *, session_live_count: int) -> dict[str, float]: class NewlyActiveRoom: """A room whose first human interaction happened in the window just read.""" + # When the room actually went active. Carried rather than derived, because + # the activation milestone is measured from this and not from the moment + # the snapshot pass happened to run — a pass is up to a whole interval + # late, and always late in the same direction. + first_active_at: datetime seconds_since_room_created: float bridge_platform: str channel_type: str @@ -153,7 +160,21 @@ class NewlyActiveRoom: created_by_kind: str -def _human_interaction(since: datetime) -> Select[tuple[str]]: +def _room_has_an_agent(tenant_id: str) -> Select[tuple[str]]: + """Correlated subquery: the message's room has an agent in it.""" + return ( + select(ClientRoom.room_id) + .join(Client, Client.id == ClientRoom.client_id) + .where( + ClientRoom.room_id == Message.room_id, + ClientRoom.tenant_id == tenant_id, + Client.type == AGENT_CLIENT_TYPE, + Client.tenant_id == tenant_id, + ) + ) + + +def _human_interaction(tenant_id: str, since: datetime) -> Select[tuple[str]]: """Room ids a human spoke in since `since`. "Interaction" is a human posting in a room that has an agent in it. Both @@ -162,42 +183,30 @@ def _human_interaction(since: datetime) -> Select[tuple[str]]: product this telemetry is about. Two agents talking to each other is likewise not activity, which is why this keys on the human side only. """ - room_has_an_agent = ( - select(ClientRoom.room_id) - .join(Client, Client.id == ClientRoom.client_id) - .where( - ClientRoom.room_id == Message.room_id, - Client.type == AGENT_CLIENT_TYPE, - ) - ) return ( select(distinct(Message.room_id)) .join(Client, Client.id == Message.sender_client_id) .where( + Message.tenant_id == tenant_id, Message.sent_at >= since, Client.type == HUMAN_CLIENT_TYPE, - exists(room_has_an_agent), + Client.tenant_id == tenant_id, + exists(_room_has_an_agent(tenant_id)), ) ) -def _active_humans(since: datetime) -> Select[tuple[str | None]]: +def _active_humans(tenant_id: str, since: datetime) -> Select[tuple[str | None]]: """Distinct human clients who interacted since `since`.""" - room_has_an_agent = ( - select(ClientRoom.room_id) - .join(Client, Client.id == ClientRoom.client_id) - .where( - ClientRoom.room_id == Message.room_id, - Client.type == AGENT_CLIENT_TYPE, - ) - ) return ( select(distinct(Message.sender_client_id)) .join(Client, Client.id == Message.sender_client_id) .where( + Message.tenant_id == tenant_id, Message.sent_at >= since, Client.type == HUMAN_CLIENT_TYPE, - exists(room_has_an_agent), + Client.tenant_id == tenant_id, + exists(_room_has_an_agent(tenant_id)), ) ) @@ -213,58 +222,85 @@ async def _scalar(session: AsyncSession, query: Select[Any]) -> int: async def collect_tenant_counts( - session: AsyncSession, counts: UsageCounts, now: datetime + session: AsyncSession, tenant_id: str, counts: UsageCounts, now: datetime ) -> None: """Add one tenant's numbers to `counts`. - The session must already be bound to that tenant: every query here relies - on row-level security to narrow it, rather than naming the tenant itself. + The session must already be bound to `tenant_id`, **and** every query names + the tenant explicitly as well. That looks redundant and is not: the policy + is what does not apply on an owner connection, so a read that leans on it + alone returns every tenant's rows on every pass and a fan-out over N + tenants counts each row N times. `db/tenant_lookup.py` states the rule and + every other fan-out in the tree follows it — this is a count, so the + duplication would be silent rather than visible. """ day_ago = now - _DAY week_ago = now - _WEEK - counts.user_active_1d += await _count(session, _active_humans(day_ago)) - counts.user_active_7d += await _count(session, _active_humans(week_ago)) - counts.room_active_1d += await _count(session, _human_interaction(day_ago)) - counts.room_active_7d += await _count(session, _human_interaction(week_ago)) + counts.user_active_1d += await _count(session, _active_humans(tenant_id, day_ago)) + counts.user_active_7d += await _count(session, _active_humans(tenant_id, week_ago)) + counts.room_active_1d += await _count( + session, _human_interaction(tenant_id, day_ago) + ) + counts.room_active_7d += await _count( + session, _human_interaction(tenant_id, week_ago) + ) - # Rooms, split by who made them. `created_by_kind` is stamped into the - # room's metadata at creation; rooms made before that existed carry - # nothing, and are counted as user-created — the conservative reading, - # since the agent-created room is the newer path. - agent_made = Room.metadata_["created_by_kind"].astext == "agent" + # Rooms, split three ways by who made them, because there are three kinds + # and they mean different things. `created_by_kind` is stamped into the + # room's metadata at creation; a room made before that existed carries + # nothing and is counted as user-created — the conservative reading, since + # both other paths are newer than the stamp. + # + # `system` is the one worth naming: a channel Switch adopted because it was + # invited to it on the platform. Folding those into the headline would make + # "rooms a human created" mean "channels this workspace happens to have" on + # any deployment with a busy Slack. + kind = Room.metadata_["created_by_kind"].astext + live = (Room.tenant_id == tenant_id, Room.archived_at.is_(None)) counts.room_count += await _scalar( session, select(func.count()) .select_from(Room) - .where(Room.archived_at.is_(None), ~agent_made | agent_made.is_(None)), + .where(*live, (kind == "user") | kind.is_(None)), ) counts.room_agent_created_count += await _scalar( - session, - select(func.count()) - .select_from(Room) - .where(Room.archived_at.is_(None), agent_made), + session, select(func.count()).select_from(Room).where(*live, kind == "agent") + ) + counts.room_system_created_count += await _scalar( + session, select(func.count()).select_from(Room).where(*live, kind == "system") ) counts.room_archived_count += await _scalar( session, - select(func.count()).select_from(Room).where(Room.archived_at.is_not(None)), + select(func.count()) + .select_from(Room) + .where(Room.tenant_id == tenant_id, Room.archived_at.is_not(None)), ) counts.room_internal_only_count += await _scalar( session, - select(func.count()) - .select_from(Room) - .where(Room.archived_at.is_(None), Room.bridge_id.is_(None)), + select(func.count()).select_from(Room).where(*live, Room.bridge_id.is_(None)), ) # Human membership per room, as a total and a maximum. The mean is derived # from the total rather than averaged per tenant, so a deployment with one # busy tenant and one idle one reports the real figure instead of the mean # of two means. + # + # Counted over the same population as `room_count` — user-created rooms — + # because the mean is derived from this total divided by that count. Over + # different populations the pair can report a mean above the maximum, which + # is impossible for any one set of rooms and reads as a broken metric. per_room = ( select(func.count(ClientRoom.client_id).label("members")) .join(Client, Client.id == ClientRoom.client_id) .join(Room, Room.id == ClientRoom.room_id) - .where(Client.type == HUMAN_CLIENT_TYPE, Room.archived_at.is_(None)) + .where( + ClientRoom.tenant_id == tenant_id, + Client.tenant_id == tenant_id, + Client.type == HUMAN_CLIENT_TYPE, + *live, + (kind == "user") | kind.is_(None), + ) .group_by(ClientRoom.room_id) .subquery() ) @@ -281,7 +317,10 @@ async def collect_tenant_counts( # Agents, split by the runtime behind them. runtime = Agent.metadata_["known_agent_type"].astext by_runtime = await session.execute( - select(runtime, func.count()).select_from(Agent).group_by(runtime) + select(runtime, func.count()) + .select_from(Agent) + .where(Agent.tenant_id == tenant_id) + .group_by(runtime) ) for name, count in by_runtime.all(): if name == "claude-code": @@ -298,7 +337,12 @@ async def collect_tenant_counts( session, select(distinct(Message.sender_client_id)) .join(Client, Client.id == Message.sender_client_id) - .where(Message.sent_at >= week_ago, Client.type == AGENT_CLIENT_TYPE), + .where( + Message.tenant_id == tenant_id, + Message.sent_at >= week_ago, + Client.type == AGENT_CLIENT_TYPE, + Client.tenant_id == tenant_id, + ), ) # Connectors, by platform. Configured, not connected — whether each is @@ -306,6 +350,7 @@ async def collect_tenant_counts( by_platform = await session.execute( select(CollaborationBridge.type, func.count()) .select_from(CollaborationBridge) + .where(CollaborationBridge.tenant_id == tenant_id) .group_by(CollaborationBridge.type) ) for platform, count in by_platform.all(): @@ -319,13 +364,20 @@ async def collect_tenant_counts( session, select(func.count()) .select_from(Message) - .where(Message.sent_at >= day_ago, Message.seq > 0), + .where( + Message.tenant_id == tenant_id, Message.sent_at >= day_ago, Message.seq > 0 + ), ) by_sender = await session.execute( select(Client.type, func.count()) .select_from(Message) .join(Client, Client.id == Message.sender_client_id) - .where(Message.sent_at >= day_ago, Message.seq > 0) + .where( + Message.tenant_id == tenant_id, + Message.sent_at >= day_ago, + Message.seq > 0, + Client.tenant_id == tenant_id, + ) .group_by(Client.type) ) for client_type, count in by_sender.all(): @@ -334,19 +386,23 @@ async def collect_tenant_counts( elif client_type == AGENT_CLIENT_TYPE: counts.message_from_agent_1d += count - await _collect_turns(session, counts, day_ago) + await _collect_turns(session, tenant_id, counts, day_ago) counts.attachment_count_1d += await _scalar( session, select(func.count()) .select_from(MessageAttachment) .join(Message, Message.id == MessageAttachment.message_id) - .where(Message.sent_at >= day_ago), + .where( + MessageAttachment.tenant_id == tenant_id, + Message.tenant_id == tenant_id, + Message.sent_at >= day_ago, + ), ) async def _collect_turns( - session: AsyncSession, counts: UsageCounts, since: datetime + session: AsyncSession, tenant_id: str, counts: UsageCounts, since: datetime ) -> None: """Who replied to whom, in the window. @@ -381,7 +437,11 @@ async def _collect_turns( ) .select_from(Message) .join(Client, Client.id == Message.sender_client_id) - .where(Message.seq > 0) + .where( + Message.tenant_id == tenant_id, + Client.tenant_id == tenant_id, + Message.seq > 0, + ) .subquery() ) rows = await session.execute( @@ -398,18 +458,23 @@ async def _collect_turns( counts.turn_agent_to_agent_1d += count -async def room_had_human_activity(session: AsyncSession, room_id: str) -> bool: +async def room_had_human_activity( + session: AsyncSession, tenant_id: str, room_id: str +) -> bool: """Whether a human has ever posted in this room. - The session must already be bound to the room's tenant. + The session must already be bound to `tenant_id`; the predicate is named + anyway, for the reason `collect_tenant_counts` gives. """ found = await session.execute( select(Message.id) .join(Client, Client.id == Message.sender_client_id) .where( + Message.tenant_id == tenant_id, Message.room_id == room_id, Message.seq > 0, Client.type == HUMAN_CLIENT_TYPE, + Client.tenant_id == tenant_id, ) .limit(1) ) @@ -426,7 +491,7 @@ async def collect_usage( counts.tenant_count = len(tenant_ids) for tenant_id in tenant_ids: async with tenant_session(session_factory, tenant_id) as session: - await collect_tenant_counts(session, counts, moment) + await collect_tenant_counts(session, tenant_id, counts, moment) # `users` carries no tenant, so it is counted once for the deployment # rather than per tenant — summing a global table over tenants would # multiply it by however many there are. @@ -466,7 +531,12 @@ async def newly_active_rooms( func.min(Message.sent_at).label("first_at"), ) .join(Client, Client.id == Message.sender_client_id) - .where(Client.type == HUMAN_CLIENT_TYPE, Message.seq > 0) + .where( + Message.tenant_id == tenant_id, + Client.tenant_id == tenant_id, + Client.type == HUMAN_CLIENT_TYPE, + Message.seq > 0, + ) .group_by(Message.room_id) .subquery() ) @@ -476,7 +546,9 @@ async def newly_active_rooms( .join(Client, Client.id == ClientRoom.client_id) .where( ClientRoom.room_id == Room.id, + ClientRoom.tenant_id == tenant_id, Client.type == AGENT_CLIENT_TYPE, + Client.tenant_id == tenant_id, ) .scalar_subquery() ) @@ -492,6 +564,7 @@ async def newly_active_rooms( .join(first_interaction, first_interaction.c.room_id == Room.id) .where( and_( + Room.tenant_id == tenant_id, first_interaction.c.first_at > since, first_interaction.c.first_at <= moment, ) @@ -502,13 +575,14 @@ async def newly_active_rooms( for created_at, first_at, channel_type, bridge_id, kind, agents in rows: found.append( NewlyActiveRoom( + first_active_at=as_utc(first_at), seconds_since_room_created=max( (first_at - created_at).total_seconds(), 0.0 ), - bridge_platform=platforms.get(bridge_id, "none"), + bridge_platform=normalise_platform(platforms.get(bridge_id)), channel_type=normalise_channel_type(channel_type), agent_count=int(agents or 0), - created_by_kind=kind or "user", + created_by_kind=normalise_actor_kind(kind), ) ) return found @@ -522,6 +596,25 @@ async def _bridge_platforms(session: AsyncSession) -> dict[str | None, str]: return {bridge_id: platform for bridge_id, platform in rows.all()} +def as_utc(moment: datetime) -> datetime: + """A timestamp column as an aware UTC datetime.""" + return moment if moment.tzinfo else moment.replace(tzinfo=UTC) + + +def normalise_actor_kind(kind: str | None) -> str: + """A stamped `created_by_kind` as the catalogue spells it. + + Rooms predating the stamp carry nothing and read as `user`, the same + conservative default the room counts use. Anything unrecognised reads as + `system` rather than raising: an unknown origin is machinery, and a room + creation must not fail because a later kind was added without touching + this file. + """ + if kind in ("user", "agent", "system"): + return str(kind) + return "user" if kind is None else "system" + + def normalise_channel_type(channel_type: str | None) -> str: """A `rooms.channel_type` as the catalogue spells it. diff --git a/core/tests/switch_core/bridges/agent/protocol/test_room_detail.py b/core/tests/switch_core/bridges/agent/protocol/test_room_detail.py index ef476aff5..9f26e4d24 100644 --- a/core/tests/switch_core/bridges/agent/protocol/test_room_detail.py +++ b/core/tests/switch_core/bridges/agent/protocol/test_room_detail.py @@ -174,6 +174,16 @@ async def _fake_roles(agent_id: str, room_id: str) -> list[dict[str, Any]]: return resolved_roles svc.list_room_roles = _fake_roles # type: ignore[assignment] + + # Archiving goes through RoomService rather than straight at the store, so + # that an agent's archive is reported like any other. This stand-in keeps + # the fake store as the thing under test. + class _RoomServiceStub: + async def set_room_archived(self, room_id: str, archived: bool) -> None: + async with _session_factory() as session: + await svc.room_store.set_archived(session, room_id, archived) + + svc.room_service = _RoomServiceStub() # type: ignore[assignment] return svc diff --git a/core/tests/switch_core/telemetry/test_first_room_active.py b/core/tests/switch_core/telemetry/test_first_room_active.py new file mode 100644 index 000000000..44bf95810 --- /dev/null +++ b/core/tests/switch_core/telemetry/test_first_room_active.py @@ -0,0 +1,250 @@ +"""The activation milestone, which fires once and is permanent if wrong. + +A review found four independent defects in seven lines of this method, none of +which any test would have caught because nothing exercised it. Each case below +pins one of them. + +The value matters more than most: `first_room_active` is the end of the +activation funnel, it is claimed once per deployment ever, and a wrong number +cannot be corrected by a later pass. +""" + +from __future__ import annotations + +from datetime import UTC, datetime, timedelta + +from sqlalchemy import delete +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.db.models import TelemetryMilestone +from switch_core.telemetry.deployment import claim_milestone +from switch_core.telemetry.reporter import SnapshotReporter +from switch_core.telemetry.service import TelemetryService +from switch_core.telemetry.sink import TelemetryRecord +from switch_core.telemetry.snapshot import NewlyActiveRoom + +INSTALLED = datetime(2026, 9, 1, 0, 0, tzinfo=UTC) + + +class _RecordingSink: + def __init__(self) -> None: + self.sent: list[TelemetryRecord] = [] + + async def send(self, record: TelemetryRecord) -> None: + self.sent.append(record) + + async def aclose(self) -> None: + return None + + +def _room( + *, + first_active_at: datetime, + since_created: float = 60.0, + kind: str = "user", + platform: str = "slack", +) -> NewlyActiveRoom: + return NewlyActiveRoom( + first_active_at=first_active_at, + seconds_since_room_created=since_created, + bridge_platform=platform, + channel_type="channel_public", + agent_count=1, + created_by_kind=kind, + ) + + +def _reporter( + sink: _RecordingSink, + session_factory: async_sessionmaker[AsyncSession], + *, + enabled: bool = True, +) -> SnapshotReporter: + service = TelemetryService( + sink=sink, # type: ignore[arg-type] + enabled=enabled, + client_id="deployment-uuid", + service_name="switch-core", + version="1.0.0", + environment=None, + session_factory=session_factory, + installed_at=INSTALLED, + ) + return SnapshotReporter( + telemetry=service, + session_factory=session_factory, + interval_hours=24.0, + installed_at=INSTALLED, + live_session_count=lambda: 0, + ) + + +async def _clear(session_factory: async_sessionmaker[AsyncSession]) -> None: + async with session_factory() as session: + await session.execute(delete(TelemetryMilestone)) + await session.commit() + + +async def _report(reporter: SnapshotReporter, rooms: list) -> None: + """Report, then let the fire-and-forget send actually run. + + `emit` hands the send to a background task by design, so a test that + inspects the sink immediately races it. + """ + await reporter._report_first_room_active(rooms) + await reporter._telemetry.aclose() + + +def _milestone(sink: _RecordingSink) -> TelemetryRecord | None: + return next( + (r for r in sink.sent if r.name == "switch_core.first_room_active"), None + ) + + +class TestItIsMeasuredFromTheInteraction: + async def test_the_elapsed_time_is_install_to_activation_not_install_to_now( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """The snapshot runs on an interval, so it always learns about an + activation late — and always in the same direction. Measuring to `now` + would add a day to every deployment's headline activation figure.""" + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory) + + activated = INSTALLED + timedelta(hours=3) + await _report(reporter, [_room(first_active_at=activated)]) + + record = _milestone(sink) + assert record is not None + assert record.properties["seconds_since_install"] == 3 * 3600 + + +class TestItPicksTheEarliestRoom: + async def test_the_first_room_to_activate_wins_not_the_quickest( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """A batch can hold several. The deployment activated when the first of + them did; the one that went from creation to use fastest is a different + and much smaller number.""" + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory) + + earliest = _room( + first_active_at=INSTALLED + timedelta(hours=2), + since_created=9999.0, + platform="teams", + ) + quickest = _room( + first_active_at=INSTALLED + timedelta(days=5), + since_created=1.0, + platform="slack", + ) + + await _report(reporter, [quickest, earliest]) + + record = _milestone(sink) + assert record is not None + assert record.properties["seconds_since_install"] == 2 * 3600 + assert record.properties["bridge_platform"] == "teams" + + +class TestOnlyARoomAPersonMade: + async def test_an_agent_created_room_does_not_activate_the_deployment( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """An orchestration spinning up a scratch room is not a customer + getting started, and must not consume the once-ever claim.""" + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory) + + await _report( + reporter, + [_room(first_active_at=INSTALLED + timedelta(hours=1), kind="agent")], + ) + + assert _milestone(sink) is None + # And the claim is still available for the real activation. + assert await claim_milestone(session_factory, "first_room_active") is True + + async def test_a_system_adopted_room_does_not_either( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory) + + await _report( + reporter, + [_room(first_active_at=INSTALLED + timedelta(hours=1), kind="system")], + ) + + assert _milestone(sink) is None + + async def test_the_user_room_is_chosen_from_a_mixed_batch( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory) + + await _report( + reporter, + [ + _room(first_active_at=INSTALLED + timedelta(hours=1), kind="agent"), + _room( + first_active_at=INSTALLED + timedelta(hours=4), + kind="user", + platform="discord", + ), + ], + ) + + record = _milestone(sink) + assert record is not None + assert record.properties["seconds_since_install"] == 4 * 3600 + assert record.properties["bridge_platform"] == "discord" + + +class TestTheClaimIsNotSpentWhenNobodyIsListening: + async def test_a_disabled_deployment_keeps_its_claim( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """Otherwise a deployment that opts in later has already used up the + milestone and can never report its activation.""" + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory, enabled=False) + + await _report(reporter, [_room(first_active_at=INSTALLED + timedelta(hours=1))]) + + assert sink.sent == [] + assert await claim_milestone(session_factory, "first_room_active") is True + + +class TestItFiresOnce: + async def test_a_second_batch_reports_nothing( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory) + + await _report(reporter, [_room(first_active_at=INSTALLED + timedelta(hours=1))]) + await _report(reporter, [_room(first_active_at=INSTALLED + timedelta(hours=2))]) + + assert len([r for r in sink.sent if r.name.endswith("first_room_active")]) == 1 + + async def test_a_deployment_with_no_install_date_reports_nothing( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await _clear(session_factory) + sink = _RecordingSink() + reporter = _reporter(sink, session_factory) + reporter._installed_at = None + + await _report(reporter, [_room(first_active_at=INSTALLED + timedelta(hours=1))]) + + assert _milestone(sink) is None diff --git a/core/tests/switch_core/telemetry/test_snapshot.py b/core/tests/switch_core/telemetry/test_snapshot.py index 3db49668d..933cceab1 100644 --- a/core/tests/switch_core/telemetry/test_snapshot.py +++ b/core/tests/switch_core/telemetry/test_snapshot.py @@ -31,6 +31,7 @@ collect_tenant_counts, collect_usage, newly_active_rooms, + normalise_actor_kind, normalise_channel_type, normalise_known_agent_type, normalise_platform, @@ -140,9 +141,12 @@ async def _say( return message -async def _counts(session: AsyncSession) -> UsageCounts: +TENANT_ZERO = "00000000-0000-0000-0000-000000000000" + + +async def _counts(session: AsyncSession, tenant_id: str = TENANT_ZERO) -> UsageCounts: counts = UsageCounts() - await collect_tenant_counts(session, counts, NOW) + await collect_tenant_counts(session, tenant_id, counts, NOW) return counts @@ -495,8 +499,10 @@ async def test_it_reports_whether_a_person_ever_posted( human = await _client(session, "user") await _say(session, busy, human, seq=1) - assert await room_had_human_activity(session, busy.id) is True - assert await room_had_human_activity(session, quiet.id) is False + assert await room_had_human_activity(session, TENANT_ZERO, busy.id) is True + assert ( + await room_had_human_activity(session, TENANT_ZERO, quiet.id) is False + ) class TestTheDeploymentTotal: @@ -555,3 +561,62 @@ def test_a_runtime_switch_does_not_know_becomes_other(self) -> None: assert normalise_known_agent_type({"known_agent_type": "zed"}) == "other" assert normalise_known_agent_type({}) == "none" assert normalise_known_agent_type(None) == "none" + + +class TestTheThreeRoomOrigins: + """A bridge-adopted channel is not a room a person made. + + The headline figure was written as "not agent-created", which quietly + folded in the third kind this change introduces — every channel Switch was + invited to on a platform. On a busy Slack that is most of them. + """ + + async def test_each_origin_is_counted_separately( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + async with session_factory() as session: + await _room(session, created_by_kind="user") + await _room(session, created_by_kind="agent") + await _room(session, created_by_kind="system") + await _room(session, created_by_kind="system") + + counts = await _counts(session) + + assert counts.room_count == 1 + assert counts.room_agent_created_count == 1 + assert counts.room_system_created_count == 2 + + async def test_the_mean_cannot_exceed_the_maximum( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """Numerator and denominator must count the same rooms. Over different + populations the pair can report a mean above the maximum, which is + impossible for any one set and reads as a broken metric.""" + async with session_factory() as session: + mine = await _room(session, created_by_kind="user") + theirs = await _room(session, created_by_kind="agent") + await _join(session, await _client(session, "user"), mine) + # An agent-created room legitimately holds people. + for _ in range(5): + await _join(session, await _client(session, "user"), theirs) + + counts = await _counts(session) + + properties = counts.as_event_properties(session_live_count=0) + assert properties["room_users_mean"] <= properties["room_users_max"] + assert counts.room_membership_total == 1 + + +class TestNormaliseActorKind: + def test_an_unstamped_room_reads_as_user(self) -> None: + assert normalise_actor_kind(None) == "user" + + def test_the_three_kinds_pass_through(self) -> None: + assert normalise_actor_kind("user") == "user" + assert normalise_actor_kind("agent") == "agent" + assert normalise_actor_kind("system") == "system" + + def test_an_unknown_kind_reads_as_system_rather_than_raising(self) -> None: + """A later kind added without touching this file must not be able to + fail a room creation at the point of emission.""" + assert normalise_actor_kind("imported") == "system" diff --git a/core/tests/switch_core/telemetry/test_snapshot_multi_tenant.py b/core/tests/switch_core/telemetry/test_snapshot_multi_tenant.py new file mode 100644 index 000000000..58fe16a26 --- /dev/null +++ b/core/tests/switch_core/telemetry/test_snapshot_multi_tenant.py @@ -0,0 +1,156 @@ +"""The snapshot's counts must not multiply by the number of tenants. + +This is the regression test for the defect a review found: every query in +`collect_tenant_counts` leaned on row-level security to narrow it, and the +policy is exactly what does *not* apply on an owner connection. A fan-out that +binds each tenant in turn then reads every tenant's rows on every pass, so a +deployment with N tenants reported N times its real size — silently, because a +count has no shape that looks wrong. + +`db/tenant_lookup.py` states the rule and every other fan-out in the tree +follows it. These tests exist because the single-tenant tests next door cannot +fail on it: with one tenant, N == 1. + +The default `session_factory` fixture connects as the owner, which is the +connection where the bug was reachable — so this file needs no special +harness to reproduce it. That is the point: CI runs the vulnerable shape. +""" + +from __future__ import annotations + +import uuid +from datetime import UTC, datetime, timedelta + +from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker + +from switch_core.db.models import ( + TENANT_ZERO_ID, + Client, + ClientRoom, + Message, + Room, + Tenant, +) +from switch_core.db.session_scope import tenant_session +from switch_core.telemetry.snapshot import collect_usage, newly_active_rooms + +NOW = datetime(2026, 9, 16, 12, 0, tzinfo=UTC) +OTHER_TENANT = "11111111-1111-1111-1111-111111111111" + + +async def _make_tenant(session_factory: async_sessionmaker[AsyncSession]) -> None: + async with session_factory() as session: + session.add( + Tenant(id=OTHER_TENANT, name="second", slug=f"s-{uuid.uuid4().hex[:8]}") + ) + await session.commit() + + +async def _room_with_a_conversation( + session_factory: async_sessionmaker[AsyncSession], + tenant_id: str, + *, + first_at: datetime, +) -> None: + """One room, one human, one agent, one human message.""" + async with tenant_session(session_factory, tenant_id) as session: + room = Room( + matrix_room_id=f"!{uuid.uuid4().hex[:10]}:test", + name=f"room-{uuid.uuid4().hex[:6]}", + description="a room", + channel_type="channel_public", + created_at=NOW - timedelta(days=2), + metadata_={"created_by_kind": "user"}, + ) + human = Client( + matrix_user_id=f"@human-{uuid.uuid4().hex[:8]}:test", + display_name="a person", + type="user", + ) + agent = Client( + matrix_user_id=f"@agent-{uuid.uuid4().hex[:8]}:test", + display_name="an agent", + type="agent", + ) + session.add_all([room, human, agent]) + await session.flush() + session.add_all( + [ + ClientRoom(client_id=human.id, room_id=room.id), + ClientRoom(client_id=agent.id, room_id=room.id), + ] + ) + session.add( + Message( + room_id=room.id, + seq=1, + transport_event_id=f"$evt-{uuid.uuid4().hex}", + sender_id=human.matrix_user_id, + sender_client_id=human.id, + event_type="m.room.message", + msgtype="m.text", + body="hello", + content={"body": "hello"}, + sent_at=first_at, + ) + ) + await session.commit() + + +class TestCountsDoNotMultiplyByTenant: + async def test_two_tenants_with_one_room_each_report_two_rooms( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + await _make_tenant(session_factory) + await _room_with_a_conversation( + session_factory, TENANT_ZERO_ID, first_at=NOW - timedelta(hours=1) + ) + await _room_with_a_conversation( + session_factory, OTHER_TENANT, first_at=NOW - timedelta(hours=1) + ) + + counts = await collect_usage(session_factory, now=NOW) + + assert counts.tenant_count == 2 + # Two, not four. Without the tenant predicate each pass saw both rooms. + assert counts.room_count == 2 + assert counts.room_active_1d == 2 + assert counts.user_active_1d == 2 + assert counts.message_count_1d == 2 + assert counts.room_membership_total == 2 + + async def test_one_tenants_room_is_not_counted_by_the_other( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """The sharper version: the second tenant owns nothing at all, so every + count must be exactly what the first tenant has.""" + await _make_tenant(session_factory) + await _room_with_a_conversation( + session_factory, TENANT_ZERO_ID, first_at=NOW - timedelta(hours=1) + ) + + counts = await collect_usage(session_factory, now=NOW) + + assert counts.tenant_count == 2 + assert counts.room_count == 1 + assert counts.room_active_7d == 1 + assert counts.user_active_7d == 1 + assert counts.message_count_1d == 1 + + +class TestRoomActivationIsNotReportedPerTenant: + async def test_a_room_is_reported_once_not_once_per_tenant( + self, session_factory: async_sessionmaker[AsyncSession] + ) -> None: + """`room_became_active` is emitted per returned row, so a duplicate here + is a duplicated analytics event, not just a wrong count.""" + await _make_tenant(session_factory) + await _room_with_a_conversation( + session_factory, TENANT_ZERO_ID, first_at=NOW - timedelta(hours=1) + ) + + found = await newly_active_rooms( + session_factory, since=NOW - timedelta(hours=4), now=NOW + ) + + assert len(found) == 1 diff --git a/docs/old/telemetry-events.md b/docs/old/telemetry-events.md index 148aefdce..6dc5da2cb 100644 --- a/docs/old/telemetry-events.md +++ b/docs/old/telemetry-events.md @@ -8,9 +8,12 @@ structured logging, the export path itself, server health, tracing and alerting — is `CHOO-2807` and lands first. The two meet at one seam, described under [What this needs from the export path](#what-this-needs-from-the-export-path). -Nothing here is built yet. This note fixes the taxonomy so that the events can -be added to the export path without reworking it, and so that the question -"what does Switch phone home?" has one answer that can be read in a minute. +This is the reference for what the server reports: the events, their exact +properties, and the rule that keeps identifiers out of them. It is enforced +rather than merely documented — `core/switch_core/telemetry/catalogue.py` is the +same catalogue in executable form, and an event that does not match it raises +where it is built. Read them together; the code is authoritative on the shape +and this is authoritative on why. ## What we are trying to learn @@ -194,7 +197,10 @@ Counted distinctly per window, so one person in six rooms is one active user. **Active room** — a room with at least one interaction in the window. Reported over both one day and seven, because a weekly figure flatters a product used -intensely on Mondays and a daily one punishes it. +intensely on Mondays and a daily one punishes it. Counted over rooms of every +origin, unlike the headline `room_count` — a bridge-adopted channel people +actually use is real usage even though it is not a room anybody created in +Switch. **Room created by a user** — a room a human made, through the gateway or the Console. This is the headline "Rooms" figure. Rooms an agent provisioned for @@ -216,6 +222,11 @@ Agent runtimes (Claude Code, Codex, OpenCode) are counted too, under `agent_*_count`, but they are not what "connector" means in the time-to-value metrics below. +**Room created by the system** — a channel Switch adopted because it was invited +to it on a platform, rather than one anybody asked for. Counted separately from +both of the above, because folding these into the headline would make "rooms a +person created" read as "channels this workspace happens to have". + ## The catalogue Event names are `snake_case`, past tense, prefixed `switch_core.` on the wire. @@ -234,8 +245,9 @@ never invisible. | `user_count` | number | user accounts that exist | | `user_active_1d` | number | distinct humans who interacted in 24h | | `user_active_7d` | number | same over 7 days | -| `room_count` | number | **the headline figure** — unarchived rooms created by a user | -| `room_agent_created_count` | number | unarchived rooms an agent created | +| `room_count` | number | **the headline figure** — unarchived rooms a *person* created | +| `room_agent_created_count` | number | unarchived rooms an agent created for itself | +| `room_system_created_count` | number | unarchived channels Switch adopted after being invited to them on a platform | | `room_active_1d` | number | user-created rooms with an interaction in 24h | | `room_active_7d` | number | same over 7 days | | `room_archived_count` | number | archived rooms, both kinds | @@ -250,7 +262,6 @@ never invisible. | `agent_opencode_count` | number | | | `agent_other_count` | number | including agents with no known runtime | | `session_live_count` | number | sessions live at snapshot time | -| `session_started_1d` | number | sessions opened in 24h | | `connector_slack_count` | number | connected bridges by platform | | `connector_mattermost_count` | number | | | `connector_discord_count` | number | | @@ -260,11 +271,29 @@ never invisible. | `message_count_1d` | number | messages in 24h | | `message_from_human_1d` | number | of those, sent by humans | | `message_from_agent_1d` | number | of those, sent by agents | +| `turn_human_to_agent_1d` | number | agent messages answering a person | +| `turn_agent_to_human_1d` | number | person messages answering an agent | +| `turn_agent_to_agent_1d` | number | agent messages answering another agent | | `attachment_count_1d` | number | attachments in 24h | Per-platform counts are separate properties rather than one map because the platform set is closed and small, and because Amplitude charts a property far -more easily than it charts a nested object. +more easily than it charts a nested object. They count **configured** bridges, +whether or not each is currently connected — which is up is process state, and +`bridge_connected` / `bridge_disconnected` are how that is reported. + +**Turns rather than senders.** A turn is one message classified by who sent the +message *before* it in the same room. That is the only way to tell an agent +answering a person from two agents talking among themselves: a sender-only count +reports both as "from an agent" and hides the difference that matters. The +pairing reads off `seq`, which is a total order within a room with no ties; +human-to-human is not counted, and neither is a turn whose predecessor was a +bridge relay or the admin client. + +**No count of sessions started.** Nothing durable records a session opening, so +the snapshot could only report an in-process tally that a restart silently +resets — a number that looks like a count and is not one. +`agent_session_started` is emitted per occurrence instead. The three `message_*_1d` figures come from the message table, which is deliberately a *parallel* record of the bus rather than the authoritative one: a @@ -393,10 +422,12 @@ the snapshot says two bridges are down right now, the events say one platform has flapped forty times today. That is the difference between noticing and diagnosing. -**`deployment_started`** — `migrated` (boolean, whether the boot applied -migrations), `tenant_count`. The version is already a resource attribute, so -this gives an upgrade curve across installations: which versions are actually -running. +**`deployment_started`** — `tenant_count`. The version is already a resource +attribute, so this gives an upgrade curve across installations: which versions +are actually running. Deliberately no "did this boot apply migrations" flag: +migrations run in a different event loop from the server, so the answer would +have to be carried across on a module global, and it is operational trivia +rather than something the product wants to know. ### Closed value sets @@ -406,6 +437,16 @@ running. `outcome`: `success` | `failure`. `failure_reason` is an enumerated code per event, `none` on success — never an exception message. +`bridge_connected.failure_reason` and `bridge_disconnected.reason` share one +set, because one classifier feeds both. A value that classifier can produce and +only one of the two declares is an event that fails validation at the moment a +bridge drops — which is precisely the event worth not losing. + +Where a duration cannot be known — a deployment with no install clock, a bridge +whose configuration timestamp is unreadable — the property carries `-1` rather +than `0`, so "we could not tell" is distinguishable from "it happened +instantly". + Any property whose value is not in its set is a bug. It should raise where the event is built rather than be coerced, dropped, or sent as `unknown` — a silently-widening value set is how an analytics catalogue stops being @@ -454,10 +495,11 @@ operational ones, which is why it belongs to the shared path rather than here. ## Open questions -- **Snapshot scheduling.** A daily snapshot from a singleton server is a - background task, but a deployment that restarts frequently could emit several - in a day or none. It needs a "last sent" watermark in the database rather than - a timer from boot. +- **Query cost at scale.** The snapshot is roughly fifteen queries per tenant, + including two seven-day `DISTINCT` scans over `messages` and a window function + over the message table. Nobody has run it against a production-sized dataset. + That is the open question most worth answering before this is switched on for + a large deployment. - **Cost of the snapshot.** Several of its counts are distinct-count queries over the message table across a seven-day window. On a large deployment that is not free, and it should be measured before it runs daily on a live From 9e917f97b2b562b245790a2aa1f116edf5e61a25 Mon Sep 17 00:00:00 2001 From: Christian McDermott Date: Thu, 17 Sep 2026 09:19:55 -0400 Subject: [PATCH 5/5] feat(telemetry): emit the agent half of the funnel, and pin that none is missed MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Five catalogue entries had no call site anywhere: `agent_registered`, `agent_session_started`, `agent_session_ended`, `first_agent_registered` and `first_session_started`. Between them they are the agent half of the activation funnel and two of the metrics the business asked for, so the funnel broke at the first agent step and every deployment would have appeared to drop out there. Worse than an absent entry, because the absence is visible in the code and the silence is only visible in an empty chart — where the first reading is "no usage", not "not instrumented". The catalogue also justified omitting a session count from the snapshot on the grounds that `agent_session_started` covered it, which made sessions measured nowhere at all. Registration reports only a genuinely new agent: a re-registration rotates a key on one that already existed, and counting it would make a CLI that re-registers on every launch look like adoption. The path is threaded through so bootstrap, console and personal-key registrations are distinguishable. Sessions are reported where the stream opens, and only for a fresh connection — a supervisor reattaching gets the same Connection back, and counting that would turn one long session into a session per reconnect. The end is reported from the sweep, which is how a session actually ends: nothing calls close() on a clean disconnect, the socket goes away and the sweep reaps it. The registry's prose reason is mapped into the closed set in one place, so a new reason added there degrades to `error` rather than failing validation at the moment a session drops. Two declared properties are dropped rather than faked. `start_source` on a session start: the server sees an authenticated connection whether a person launched it or Switch Console spawned it, and a property with one value on every emission is a dimension that cannot segment anything. `known_agent_type` on a session end: the connection registry is the only thing that knows a session ended and holds no runtime, the client's self-declared artifact is free text and may not be sent, and looking the agent up would put a query on the connection sweep. Starts carry the runtime, so the mix is still available. A new test walks the catalogue against the call sites in both directions, so the next entry added without an emitter fails at once. Refs CHOO-2806. Co-Authored-By: Claude Opus 5 (1M context) --- .../switch_core/bridges/agent/api/handlers.py | 69 +++++++++++++- core/switch_core/bridges/agent/app.py | 3 + .../bridges/agent/protocol/service.py | 33 +++++++ core/switch_core/main.py | 7 ++ core/switch_core/telemetry/catalogue.py | 20 +++- .../api/test_events_endpoint_dispatch.py | 6 +- .../telemetry/test_every_event_is_emitted.py | 95 +++++++++++++++++++ 7 files changed, 225 insertions(+), 8 deletions(-) create mode 100644 core/tests/switch_core/telemetry/test_every_event_is_emitted.py diff --git a/core/switch_core/bridges/agent/api/handlers.py b/core/switch_core/bridges/agent/api/handlers.py index 6069d9511..8c0efb11d 100644 --- a/core/switch_core/bridges/agent/api/handlers.py +++ b/core/switch_core/bridges/agent/api/handlers.py @@ -2,6 +2,7 @@ import hashlib import logging +import time from datetime import UTC, datetime from typing import Annotated, Any, cast @@ -79,6 +80,7 @@ ) from switch_core.bridges.agent.protocol.connections import ( ClientDeclaration, + Connection, ConnectionError_, DeliveryFilter, NoStreamAttachedError, @@ -99,6 +101,8 @@ from switch_core.db.stores.feature_flag_store import FeatureFlagStore from switch_core.feature_flags import is_known_flag from switch_core.gateway.known_agents import KNOWN_AGENTS +from switch_core.telemetry import emit_safely +from switch_core.telemetry.snapshot import normalise_known_agent_type from switch_core.version import switch_core_version logger = logging.getLogger(__name__) @@ -734,6 +738,47 @@ def _resolve_start_cursor( ) from exc +def report_session_ended( + protocol: ProtocolService, conn: Connection | None, *, reason: str | None = None +) -> None: + """Report a session closing, wherever it was closed. + + Takes the `Connection` the registry hands back rather than an id, so the + duration and the reason come from the row that just closed and a caller + cannot disagree with the registry about either. `None` — the connection was + already gone — reports nothing: something else closed it and reported it. + + The reason is mapped from the registry's own free-text string into the + catalogue's closed set, here rather than at each call site, so a new reason + added in the registry becomes `error` instead of failing validation at the + moment a session drops. + """ + if conn is None: + return + emit_safely( + protocol.telemetry, + "agent_session_ended", + { + "duration_seconds": max(time.monotonic() - conn.opened_at, 0.0), + "reason": _SESSION_END_REASONS.get( + reason or conn.closed_reason or "", "error" + ), + }, + ) + + +# The registry records why it closed a connection as prose. These are the +# strings it actually uses; anything else is reported as `error` rather than +# rejected, because a lost session event is worse than an imprecise one. +_SESSION_END_REASONS = { + "heartbeat lapsed": "heartbeat_lapsed", + "room already claimed": "room_claimed", + "invalid room subscription": "error", + "replaced": "replaced", + "shutdown": "normal", +} + + async def _open_event_stream( *, agent: Agent, @@ -802,6 +847,21 @@ async def _open_event_stream( # reason an agent could not connect. await protocol.record_client_declaration(agent.id, connection_id, declaration) + # A fresh connection, not a supervisor reattaching to one it already had — + # `open()` hands back the existing Connection in that case, and counting it + # would turn one long session into a session per reconnect. + if conn.stream_generation == 0: + runtime = normalise_known_agent_type(agent.metadata_) + emit_safely( + protocol.telemetry, + "agent_session_started", + {"known_agent_type": runtime}, + ) + if protocol.telemetry is not None: + await protocol.telemetry.emit_milestone( + "first_session_started", known_agent_type=runtime + ) + # Rooms are claimed before the stream starts, not after it opens. A client # reconnecting already knows which room it was in; making it re-subscribe # afterwards would race the catch-up, and buffered events for that room @@ -823,10 +883,15 @@ async def _open_event_stream( # stream 409s and retries forever. protocol.connections.claim_room(conn, room_id, takeover=True) except (ValueError, PermissionError) as exc: - protocol.connections.close(conn.id, "invalid room subscription") + report_session_ended( + protocol, + protocol.connections.close(conn.id, "invalid room subscription"), + ) raise HTTPException(status_code=403, detail=str(exc)) from exc except ConnectionError_ as exc: - protocol.connections.close(conn.id, "room already claimed") + report_session_ended( + protocol, protocol.connections.close(conn.id, "room already claimed") + ) raise HTTPException(status_code=409, detail=str(exc)) from exc return StreamingResponse( diff --git a/core/switch_core/bridges/agent/app.py b/core/switch_core/bridges/agent/app.py index 2b3601b8c..612af7c20 100644 --- a/core/switch_core/bridges/agent/app.py +++ b/core/switch_core/bridges/agent/app.py @@ -32,6 +32,7 @@ from switch_core.db.stores.task_store import TaskStore from switch_core.request_context import RequestContextMiddleware from switch_core.room_service import RoomService +from switch_core.telemetry import TelemetryService logger = logging.getLogger(__name__) @@ -53,6 +54,7 @@ def create_agent_bridge_app( session_factory: object, config: SwitchConfig, connections: ConnectionRegistry | None = None, + telemetry: TelemetryService | None = None, ) -> tuple[FastAPI, ProtocolService]: # One registry for the whole process: the live connection set is the source # of truth for reachability, so every service must see the same one. The @@ -105,6 +107,7 @@ def create_agent_bridge_app( bridge_store=bridge_store, session_factory=session_factory, # type: ignore[arg-type] config=config, + telemetry=telemetry, ) app = FastAPI(title="Switch Agent Bridge API") diff --git a/core/switch_core/bridges/agent/protocol/service.py b/core/switch_core/bridges/agent/protocol/service.py index 2a02a15b3..88a713990 100644 --- a/core/switch_core/bridges/agent/protocol/service.py +++ b/core/switch_core/bridges/agent/protocol/service.py @@ -98,6 +98,8 @@ ToolCallReport as MatrixToolCallReport, ) from switch_core.messages.recorded_types import MEMBERSHIP_EVENT_TYPE +from switch_core.telemetry import TelemetryService, emit_safely +from switch_core.telemetry.snapshot import normalise_known_agent_type from switch_core.tenant_context import current_tenant_id, tenant_scope from switch_core.transport import ( TransportError, @@ -237,6 +239,10 @@ def _describe_room(room: Room) -> RoomDescriptor: class ProtocolService: + # Class-level default: several tests assemble a minimal instance without + # `__init__`, and `emit_safely` treats None as "report nothing". + telemetry: TelemetryService | None = None + def __init__( self, *, @@ -256,7 +262,9 @@ def __init__( bridge_store: CollaborationBridgeStore, session_factory: async_sessionmaker[AsyncSession], config: SwitchConfig, + telemetry: TelemetryService | None = None, ) -> None: + self.telemetry = telemetry self.agent_store = agent_store self.agent_session_store = agent_session_store self.agent_runtime_state_store = AgentRuntimeStateStore() @@ -309,6 +317,7 @@ async def register_agent( overwrite: bool = False, addressable_by_agent_ids: list[str] | None = None, owner_only: bool = True, + registration_path: str = "other", ) -> RegistrationResult: """Register or re-register an agent. @@ -378,6 +387,11 @@ async def register_agent( api_key_hash = hashlib.sha256(api_key.encode()).hexdigest() encrypted_key = encrypt_token(api_key, self.config.jwt_secret_key) + # Reported only for a genuinely new agent: a re-registration rotates a + # key on an agent that already existed, and counting it would make a + # CLI that re-registers on every launch look like adoption. + newly_registered = False + async with self.session_factory() as session: existing = await self.agent_store.get_by_name(session, name) if existing and not overwrite: @@ -444,6 +458,24 @@ async def register_agent( ), ) logger.info("Registered agent: %s (%s)", name, agent_id) + newly_registered = True + + if newly_registered: + runtime = normalise_known_agent_type(metadata) + emit_safely( + self.telemetry, + "agent_registered", + { + "agent_type": agent_type, + "known_agent_type": runtime, + "registration_path": registration_path, + "has_parent": parent_agent_id is not None, + }, + ) + if self.telemetry is not None: + await self.telemetry.emit_milestone( + "first_agent_registered", known_agent_type=runtime + ) await self._create_bridge_identities(tenant_id, name, description) @@ -537,6 +569,7 @@ async def register_agent_with_token( overwrite=overwrite, addressable_by_agent_ids=addressable_by_agent_ids, owner_only=owner_only, + registration_path="bootstrap", ) async def _create_agent( diff --git a/core/switch_core/main.py b/core/switch_core/main.py index 837653afe..24e6addbf 100644 --- a/core/switch_core/main.py +++ b/core/switch_core/main.py @@ -22,6 +22,7 @@ ) from sqlalchemy.pool import NullPool +from switch_core.bridges.agent.api.handlers import report_session_ended from switch_core.bridges.agent.app import create_agent_bridge_app from switch_core.bridges.agent.protocol.connections import ( HEARTBEAT_TTL_SECONDS, @@ -186,6 +187,11 @@ async def _connection_sweep_loop(protocol: ProtocolService) -> None: conn.agent_id, conn.beats, ) + # The ordinary way a session ends: nothing calls close() on a + # clean client disconnect, the socket just goes away and the + # sweep reaps it. Reported here rather than inside the registry + # so the registry stays free of anything but connection state. + report_session_ended(protocol, conn) except Exception: logger.exception("Connection sweep failed") @@ -482,6 +488,7 @@ async def run(config: SwitchConfig) -> None: session_factory=session_factory, config=config, connections=connections, + telemetry=telemetry, ) # ── Server-side connector lifecycle ───────────────────────────────────── connector_lifecycle = ServerSideConnectorLifecycleService( diff --git a/core/switch_core/telemetry/catalogue.py b/core/switch_core/telemetry/catalogue.py index 176bcaaab..ef18cee06 100644 --- a/core/switch_core/telemetry/catalogue.py +++ b/core/switch_core/telemetry/catalogue.py @@ -247,12 +247,22 @@ class TelemetryCatalogueError(Exception): "registration_path": one_of("bootstrap", "personal_key", "console", "other"), "has_parent": BOOLEAN, }, - "agent_session_started": { - "known_agent_type": KNOWN_AGENT_TYPE, - "start_source": one_of("auto", "manual", "api"), - }, + # Deliberately only the runtime. How a session was *started* — a person + # launching it against one Switch Console spawned automatically — is not + # visible from here: the server sees an authenticated connection either + # way. A property that is the same value on every emission is a dimension + # that cannot segment anything, which is worse than not having it, so if + # that distinction is wanted it belongs on a Console-side event that knows + # the answer. + "agent_session_started": {"known_agent_type": KNOWN_AGENT_TYPE}, + # Duration and cause, and deliberately not the runtime. The connection + # registry is the only thing that knows a session has ended, and it holds + # no runtime — the client's self-declared `artifact` is free text, which + # may not be sent, and looking the agent up would put a database query on + # a path that runs from the connection sweep. Session *starts* carry the + # runtime, so the mix is available from those; what this answers is how + # long sessions last and why they stop. "agent_session_ended": { - "known_agent_type": KNOWN_AGENT_TYPE, "duration_seconds": NUMBER, "reason": one_of( "normal", "heartbeat_lapsed", "replaced", "room_claimed", "error" diff --git a/core/tests/switch_core/bridges/agent/api/test_events_endpoint_dispatch.py b/core/tests/switch_core/bridges/agent/api/test_events_endpoint_dispatch.py index 6e5563d2a..39cf4c759 100644 --- a/core/tests/switch_core/bridges/agent/api/test_events_endpoint_dispatch.py +++ b/core/tests/switch_core/bridges/agent/api/test_events_endpoint_dispatch.py @@ -30,6 +30,9 @@ class _Protocol: def __init__(self) -> None: self.event_buffer = EventBuffer() self.connections = ConnectionRegistry() + # Opening and closing a stream reports a session; None means report + # nothing, which is what these tests want. + self.telemetry = None self.polled = False self.recorded: list[tuple[str, str, ClientDeclaration]] = [] @@ -47,7 +50,8 @@ async def require_room_member(self, agent_id: str, room_id: str) -> None: def _agent() -> Any: - return SimpleNamespace(id=AGENT_ID) + # `metadata_` carries the agent's runtime, which opening a stream reports. + return SimpleNamespace(id=AGENT_ID, metadata_={"known_agent_type": "claude-code"}) async def _call(protocol: _Protocol, **kw: Any) -> Any: diff --git a/core/tests/switch_core/telemetry/test_every_event_is_emitted.py b/core/tests/switch_core/telemetry/test_every_event_is_emitted.py new file mode 100644 index 000000000..34baa97ed --- /dev/null +++ b/core/tests/switch_core/telemetry/test_every_event_is_emitted.py @@ -0,0 +1,95 @@ +"""Every declared event is actually emitted somewhere. + +A catalogue entry with no call site is a metric the product believes it has and +does not. That is worse than an absent entry, because the absence is visible in +the code and the silence is only visible in an empty chart six weeks later — +and the reader's first assumption will be that usage is zero, not that nothing +is reporting. + +Five entries were in exactly that state when a coverage review looked: +`agent_registered`, `agent_session_started`, `agent_session_ended`, +`first_agent_registered` and `first_session_started` — between them the whole +agent half of the funnel, and two of the metrics the business asked for. +""" + +from __future__ import annotations + +import ast +from pathlib import Path + +import switch_core +from switch_core.telemetry.catalogue import CATALOGUE + +_PACKAGE_ROOT = Path(switch_core.__file__).resolve().parent +_CATALOGUE = _PACKAGE_ROOT / "telemetry" / "catalogue.py" + + +def _emitted_names() -> set[str]: + """Every string literal passed as the first argument to an emit call. + + Matched on the call rather than on the bare string, so a name that appears + only in a comment, a docstring or a reason map does not count as an + emitter. The three shapes in the tree are `telemetry.emit("x", ...)`, + `await telemetry.emit_milestone("x", ...)` and + `emit_safely(target, "x", {...})`. + """ + emitters = {"emit", "emit_milestone", "emit_safely"} + found: set[str] = set() + for path in _PACKAGE_ROOT.rglob("*.py"): + if path == _CATALOGUE: + continue + tree = ast.parse(path.read_text(), filename=str(path)) + for node in ast.walk(tree): + if not isinstance(node, ast.Call) or not node.args: + continue + func = node.func + name = ( + func.attr + if isinstance(func, ast.Attribute) + else func.id + if isinstance(func, ast.Name) + else None + ) + if name not in emitters: + continue + # `emit_safely` takes the service first, so scan the leading + # arguments rather than assuming a position. + for arg in node.args[:2]: + if isinstance(arg, ast.Constant) and isinstance(arg.value, str): + found.add(arg.value) + return found + + +def test_no_declared_event_is_left_unemitted() -> None: + declared = set(CATALOGUE) + unemitted = sorted(declared - _emitted_names()) + assert not unemitted, ( + f"{unemitted} are declared in the telemetry catalogue and emitted " + "nowhere. An event nobody sends is a metric the product believes it " + "has: the chart is empty and reads as 'no usage' rather than 'not " + "instrumented'. Either wire it up, or delete the entry and the row it " + "claims in docs/old/telemetry-events.md." + ) + + +def test_no_event_is_emitted_without_being_declared() -> None: + """The other direction. `validate()` already raises at runtime on an + undeclared name, but that only fires if the branch is taken — this catches + a typo in a rarely-reached call site at import time instead.""" + declared = set(CATALOGUE) + # Names passed to an emit call that are not events: `emit_safely`'s first + # argument is a service, never a literal, so anything found here should be + # an event name. + undeclared = sorted(name for name in _emitted_names() if name not in declared) + assert not undeclared, ( + f"{undeclared} are emitted but not declared in the catalogue. " + "`validate()` would reject them at runtime; declare them, or fix the " + "name." + ) + + +def test_the_detector_would_notice_a_new_unemitted_entry() -> None: + """The test above only proves today's tree is clean; this proves it can + fail. Without it, a broken detector reads as a clean catalogue.""" + pretend = set(CATALOGUE) | {"room_abandoned"} + assert sorted(pretend - _emitted_names()) == ["room_abandoned"]