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 bc296ae29..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( @@ -2363,6 +2396,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 +2492,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 @@ -3497,8 +3534,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/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..b14afa984 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,12 @@ 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]] = {} + _connected: set[str] = set() + def __init__( self, *, @@ -68,6 +110,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 +119,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 +130,18 @@ 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]] = {} + # 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. @@ -528,6 +584,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,21 +672,126 @@ 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 + self._connected.add(bridge_id) + 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. + self._connected.discard(bridge_id) + 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. - async def stop(self, bridge_id: str) -> None: + 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, *, 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() @@ -638,12 +803,28 @@ async def stop(self, bridge_id: str) -> None: self._held_resources.pop(bridge_id, None) logger.info("Stopped collaboration bridge %s", bridge_id) + # 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": reason, + }, + ) + async def restart(self, bridge_id: str) -> None: """Stop and start a bridge so it picks up its stored config. 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 ab01ca1f4..55c0d6522 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,33 @@ 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 + # 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.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..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, @@ -120,6 +121,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 @@ -184,10 +187,23 @@ 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") +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 +331,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 +437,7 @@ async def run(config: SwitchConfig) -> None: session_factory=session_factory, config=config, client_factory=client_factory, + telemetry=telemetry, ) # ── Room service ───────────────────────────────────────────────────────── @@ -425,6 +450,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 @@ -462,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( @@ -524,6 +551,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 +567,26 @@ async def lifespan(app: object) -> AsyncIterator[None]: connection_sweep_task = asyncio.create_task( _connection_sweep_loop(protocol) ) + # 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() + if snapshot_task is not None: + snapshot_task.cancel() await message_listener.stop() + await telemetry.aclose() agent_bridge_app.router.lifespan_context = lifespan # type: ignore[assignment] @@ -555,6 +603,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..849932252 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,38 @@ 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": platform, + "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=platform, + ) + failed_attachments = unreachable_users + await self._attach_after_creation( room.id, config ) @@ -694,6 +770,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 +840,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 +969,73 @@ 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 or self._telemetry is None: + 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, 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 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" + 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, tenant_id, 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..ef18cee06 --- /dev/null +++ b/core/switch_core/telemetry/catalogue.py @@ -0,0 +1,342 @@ +"""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") + +# 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 ──────────────────────────────────────────────────────────── + +_SNAPSHOT_COUNTS = ( + "tenant_count", + "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", + "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, + }, + # 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": { + "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": 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", + *sorted(BRIDGE_FAILURE_REASON.values - {"none"}), + ), + }, +} + + +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..77196174a --- /dev/null +++ b/core/switch_core/telemetry/reporter.py @@ -0,0 +1,192 @@ +"""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 collections.abc import Callable +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 +from switch_core.telemetry.service import TelemetryService +from switch_core.telemetry.snapshot import ( + as_utc, + 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: Callable[[], int], + ) -> 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()) + ), + ) + + 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) + + async def _report_first_room_active(self, active: list) -> None: + """The activation milestone: the first room a person actually used. + + 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. + """ + 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 + # 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(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=max(elapsed, 0.0), + 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..962b159e4 --- /dev/null +++ b/core/switch_core/telemetry/snapshot.py @@ -0,0 +1,665 @@ +"""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_system_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_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, + "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.""" + + # 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 + agent_count: int + created_by_kind: 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 + 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. + """ + 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, + Client.tenant_id == tenant_id, + exists(_room_has_an_agent(tenant_id)), + ) + ) + + +def _active_humans(tenant_id: str, since: datetime) -> Select[tuple[str | None]]: + """Distinct human clients who interacted since `since`.""" + 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, + Client.tenant_id == tenant_id, + exists(_room_has_an_agent(tenant_id)), + ) + ) + + +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, tenant_id: str, counts: UsageCounts, now: datetime +) -> None: + """Add one tenant's numbers to `counts`. + + 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(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 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(*live, (kind == "user") | kind.is_(None)), + ) + counts.room_agent_created_count += await _scalar( + 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.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(*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( + 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() + ) + 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) + .where(Agent.tenant_id == tenant_id) + .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.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 + # currently up is process state, added by the caller. + 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(): + 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.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.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(): + 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, 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( + MessageAttachment.tenant_id == tenant_id, + Message.tenant_id == tenant_id, + Message.sent_at >= day_ago, + ), + ) + + +async def _collect_turns( + session: AsyncSession, tenant_id: str, 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.tenant_id == tenant_id, + Client.tenant_id == tenant_id, + 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, tenant_id: str, room_id: str +) -> bool: + """Whether a human has ever posted in this room. + + 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) + ) + 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, 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. + 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( + Message.tenant_id == tenant_id, + Client.tenant_id == tenant_id, + 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, + ClientRoom.tenant_id == tenant_id, + Client.type == AGENT_CLIENT_TYPE, + Client.tenant_id == tenant_id, + ) + .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_( + Room.tenant_id == tenant_id, + 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( + first_active_at=as_utc(first_at), + seconds_since_room_created=max( + (first_at - created_at).total_seconds(), 0.0 + ), + bridge_platform=normalise_platform(platforms.get(bridge_id)), + channel_type=normalise_channel_type(channel_type), + agent_count=int(agents or 0), + created_by_kind=normalise_actor_kind(kind), + ) + ) + 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 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. + + 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/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/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/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_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"] 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_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..933cceab1 --- /dev/null +++ b/core/tests/switch_core/telemetry/test_snapshot.py @@ -0,0 +1,622 @@ +"""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_actor_kind, + 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 + + +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, tenant_id, 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, TENANT_ZERO, busy.id) is True + assert ( + await room_had_human_activity(session, TENANT_ZERO, 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" + + +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/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 diff --git a/docs/old/telemetry-events.md b/docs/old/telemetry-events.md new file mode 100644 index 000000000..6dc5da2cb --- /dev/null +++ b/docs/old/telemetry-events.md @@ -0,0 +1,512 @@ +# 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). + +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 + +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. + +**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 + +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. 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 +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. + +**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. + +**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. +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 | **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 | +| `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 | +| `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 | +| `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. 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 +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). 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 generated on an empty database | — | +| `first_connector_added` | any bridge first reaches connected | `bridge_platform` | +| `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 +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 | +| `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 +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`** — `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 + +`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. + +`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 +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 + +- **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 + 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.