Fix up comments and docstrings from review

- get_thread_id/main_thread claimed to return an 'OS thread id'; restore
  the historical caveat that threading.get_ident is not an OS tid and is
  stable across Synapse's single fork() (which is also why the new
  per-thread cache stays correct across it).

- Explain skip_from_py_object on ContextResourceUsage (pyo3 0.28 makes the
  Clone-pyclass FromPyObject opt-in/out explicit; we build -D warnings).

- Note that __repr__ diverges from the historical Python repr for
  exponent-form floats, and that main_thread is settable only for tests.

- Promote create_deferred's cancellation limitation to a TODO and
  cross-reference run_python_awaitable's finished-context defence.

- Carry the dropped Python docstrings into the .pyi stub (start/stop 'do
  not call directly', get_resource_usage returns a *copy*, __init__ args,
  the sentinel usage guidance), and note that tag is typed str while the
  runtime deliberately also accepts None.

- tests: fix the stale rust/src/logcontext.rs path, explain why 'synapse'
  is in _RUST_LOGGER_ROOTS (the crate is named synapse) and the Python-
  namespace collision hazard, drop a stale deferred.rs:223 FIXME
  reference, explain the 50000-iteration pump bound, and rename prepare's
  parameter to match the base class (pyright).

- docs: name the helper (LogContext::capture/scope) instead of 'the
  provided helper'.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01JFbRtswu7rsHrttJFauUUb

docs/log_contexts.md

@@ -572,9 +572,10 @@ What Rust code *does* need to be aware of: when you spawn a future onto the toki
 runtime, the current logcontext must be captured and carried along so that log
 records emitted while the future is polled (including any `log::` records from
 dependencies, and any Python invoked back from Rust) are attributed correctly.
-Use the provided helper that captures the caller's logcontext at the FFI boundary
-and scopes it onto the spawned task (this is what `create_deferred` does) rather
-than a bare `tokio::spawn`. `current_context()` resolves the task's captured
+Use the provided helper — `LogContext::capture(py)` plus `LogContext::scope` in
+`rust/src/logging/context.rs` — which captures the caller's logcontext at the FFI
+boundary and scopes it onto the spawned task (this is what `create_deferred`
+does), rather than a bare `tokio::spawn`. `current_context()` resolves the task's captured
 context first, so `LoggingContextFilter` — and therefore `pyo3-log` — just works
 on worker threads, with no per-log-record stamping.
 

rust/src/deferred.rs

@@ -73,7 +73,13 @@ fn logging_context_module(py: Python<'_>) -> PyResult<&Bound<'_, PyAny>> {
 /// Creates a twisted deferred from the given future, spawning the task on the
 /// tokio runtime.
 ///
-/// Does not handle deferred cancellation or contextvars.
+/// Does not handle contextvars.
+///
+/// TODO: propagate deferred cancellation to the tokio task (via
+/// `JoinHandle::abort`). Until then a cancelled request leaves its task
+/// running, so the task can outlive the request's logcontext —
+/// `run_python_awaitable` defends against the resulting finished-context case,
+/// but the work itself is wasted.
 pub fn create_deferred<'py, F, O>(
     py: Python<'py>,
     reactor: &Bound<'py, PyAny>,

rust/src/logging/context.rs

@@ -213,6 +213,10 @@ impl LogContext {
 /// (Measure, request/background-process metrics, task scheduler, ...) are
 /// unaffected. Keeping this native lets the switch machinery do its rusage
 /// accounting without allocating a Python object per operation.
+// `skip_from_py_object`: pyo3 0.28 requires `Clone` pyclasses to explicitly
+// opt in or out of a generated extract-by-clone `FromPyObject` (a bare
+// `#[pyclass]` is a deprecation warning, and we build with `-D warnings`).
+// Nothing extracts this type by value, so opt out.
 #[pyclass(skip_from_py_object, get_all, set_all)]
 #[derive(Clone, Default)]
 pub struct ContextResourceUsage {
@@ -272,7 +276,10 @@ impl ContextResourceUsage {
 
     fn __repr__(&self) -> String {
         // Matches the historical Python `__repr__` (values were interpolated with
-        // `%r`, i.e. `repr()`, inside single quotes).
+        // `%r`, i.e. `repr()`, inside single quotes) — except Rust's float
+        // formatting for exponent-form values (`1e-7` where Python writes
+        // `1e-07`). The only consumer of the string form is Measure's "Failed to
+        // save metrics!" warning, so we don't chase exact parity there.
         format!(
             "<ContextResourceUsage ru_stime='{:?}', ru_utime='{:?}', \
              db_txn_count='{}', db_txn_duration_sec='{:?}', \
@@ -330,7 +337,14 @@ thread_local! {
     static CACHED_THREAD_ID: Cell<Option<u64>> = const { Cell::new(None) };
 }
 
-/// The current OS thread id, matching Python's `threading.get_ident()`.
+/// This thread's `threading.get_ident()` value.
+///
+/// Note that (as the historical Python comment warned) `get_ident` is *not* an
+/// OS-level tid: on Linux it returns the same value either side of a `fork()`
+/// call. Synapse forks in exactly one place, so contexts created before the
+/// fork still pass the `main_thread` affinity check after it — and for the same
+/// reason the per-thread cache below stays correct across that fork. Getting a
+/// real tid isn't worth the hoop-jumping.
 fn get_thread_id(py: Python<'_>) -> PyResult<u64> {
     CACHED_THREAD_ID.with(|cell| {
         if let Some(id) = cell.get() {
@@ -459,8 +473,10 @@ pub struct LoggingContext {
     /// string for the same reason as `name` (read per log record).
     #[pyo3(get, set)]
     server_name: Py<PyString>,
-    /// The OS thread id (`threading.get_ident()`) this context was created on;
-    /// activity on any other thread is an error.
+    /// The `threading.get_ident()` value of the thread this context was created
+    /// on (see [`get_thread_id`] for why it is not a real OS tid); activity on
+    /// any other thread is an error. Settable only so tests can simulate
+    /// activity on the wrong thread.
     #[pyo3(get, set)]
     main_thread: u64,
     /// Whether `__exit__` has run. Re-activating a finished context is an error.

synapse/synapse_rust/logcontext.pyi

@@ -58,6 +58,8 @@ class LoggingContext:
     main_thread: int
     finished: bool
     request: Optional[ContextRequest]
+    # Deliberately narrower than the runtime: the setter also accepts None (see
+    # the Rust field docs for why), but all in-tree code treats this as str.
     tag: str
     scope: "Optional[_LogContextScope]"
     _resource_usage: ContextResourceUsage
@@ -69,7 +71,17 @@ class LoggingContext:
         server_name: str,
         parent_context: "Optional[LoggingContext]" = None,
         request: Optional[ContextRequest] = None,
-    ) -> None: ...
+    ) -> None:
+        """
+        Args:
+            name: Name for the context for logging.
+            server_name: The name of the server this context is associated with
+                (`config.server.server_name` or `hs.hostname`).
+            parent_context: The parent of the new context.
+            request: Synapse Request Context object. Useful to associate all the
+                logs happening to a given request.
+        """
+
     def __str__(self) -> str: ...
     def __enter__(self) -> "LoggingContext": ...
     def __exit__(
@@ -78,17 +90,56 @@ class LoggingContext:
         value: Optional[BaseException],
         traceback: Optional[TracebackType],
     ) -> None: ...
-    def start(self, rusage: "Optional[tuple[float, float]]") -> None: ...
-    def stop(self, rusage: "Optional[tuple[float, float]]") -> None: ...
-    def get_resource_usage(self) -> ContextResourceUsage: ...
-    def add_cputime(self, utime_delta: float, stime_delta: float) -> None: ...
-    def add_database_transaction(self, duration_sec: float) -> None: ...
-    def add_database_scheduled(self, sched_sec: float) -> None: ...
-    def record_event_fetch(self, event_count: int) -> None: ...
+    def start(self, rusage: "Optional[tuple[float, float]]") -> None:
+        """Record that this logcontext is currently running.
+
+        Should not be called directly: use `set_current_context`.
+
+        Args:
+            rusage: The thread CPU usage `(ru_utime, ru_stime)` at the point of
+                switching to this context, or None if the platform doesn't
+                track it.
+        """
+
+    def stop(self, rusage: "Optional[tuple[float, float]]") -> None:
+        """Record that this logcontext is no longer running.
+
+        Should not be called directly: use `set_current_context`.
+
+        Args:
+            rusage: The thread CPU usage `(ru_utime, ru_stime)` at the point of
+                switching away from this context, or None if the platform
+                doesn't track it.
+        """
+
+    def get_resource_usage(self) -> ContextResourceUsage:
+        """Get the resources used by this logcontext so far.
+
+        Returns:
+            A *copy* of the object tracking resource usage so far.
+        """
+
+    def add_cputime(self, utime_delta: float, stime_delta: float) -> None:
+        """Update the CPU time usage of this context (and any parents, recursively)."""
+
+    def add_database_transaction(self, duration_sec: float) -> None:
+        """Record the use of a database transaction and how long it took."""
+
+    def add_database_scheduled(self, sched_sec: float) -> None:
+        """Record a use of the database pool (the time taken to get a connection)."""
+
+    def record_event_fetch(self, event_count: int) -> None:
+        """Record a number of events being fetched from the db."""
 
 class _Sentinel:
     """The root "no logcontext" marker. A falsy singleton (see `SENTINEL_CONTEXT`)
-    whose fields are inert defaults and whose methods are no-ops."""
+    whose fields are inert defaults and whose methods are no-ops.
+
+    This should only be used for tasks outside of Synapse, like when we yield
+    control back to the Twisted reactor (event loop), so we don't leak the
+    current logging context to other tasks that are scheduled next. Nothing from
+    the Synapse homeserver should be logged with the sentinel context — we
+    should always know which server the logs are coming from."""
 
     previous_context: None
     finished: bool

tests/synapse_rust/test_logcontext.py

@@ -13,9 +13,9 @@
 """Cross-language logcontext attribution for Rust.
 
 The current logcontext lives in the Rust slot (`synapse.synapse_rust.logcontext`
-/ `rust/src/logcontext.rs`), visible from both Python (reactor/threadpool threads)
-and Rust (tokio tasks). These tests exercise the two guarantees that gives us,
-through real production code paths:
+/ `rust/src/logging/context.rs`), visible from both Python (reactor/threadpool
+threads) and Rust (tokio tasks). These tests exercise the two guarantees that
+gives us, through real production code paths:
 
 1. Log records emitted from Rust while a task is being polled (e.g. reqwest
    connecting) are attributed to the logcontext that was current when Python
@@ -51,9 +51,17 @@ from tests.unittest import HomeserverTestCase
 
 logger = logging.getLogger(__name__)
 
-# Loggers whose records originate on tokio worker threads inside Rust. Anything
-# emitted here while a task is being polled should be attributed to the caller's
-# logcontext, never the sentinel.
+# Log-target roots that Rust code emits under while running on tokio worker
+# threads: the reqwest dependency stack, plus "synapse"/"synapse_rust" because
+# the Rust crate is itself named `synapse` (see rust/Cargo.toml). Anything
+# emitted under these while a task is being polled should be attributed to the
+# caller's logcontext, never the sentinel.
+#
+# NB: bare "synapse" also matches every *Python* `synapse.*` record, so the
+# attribution assertion below implicitly relies on nothing else logging during
+# the pump (MemoryReactor with `advance(0)`, so no timed background work fires).
+# If this test starts flaking on unrelated records, tighten this filter rather
+# than weakening the assertion.
 _RUST_LOGGER_ROOTS = frozenset(
     {"reqwest", "hyper", "hyper_util", "h2", "rustls", "synapse_rust", "synapse"}
 )
@@ -92,7 +100,9 @@ class RustLogContextTestCase(HomeserverTestCase):
             for callbable, args, kwargs in triggers:
                 callbable(*args, **kwargs)
 
-    def prepare(self, reactor: MemoryReactor, clock: Clock, hs: HomeServer) -> None:
+    def prepare(
+        self, reactor: MemoryReactor, clock: Clock, homeserver: HomeServer
+    ) -> None:
         self.user_id = self.register_user("user1", "pass")
 
     def _check_current_logcontext(self, expected: str) -> None:
@@ -116,6 +126,9 @@ class RustLogContextTestCase(HomeserverTestCase):
             body(result)
 
             with PreserveLoggingContext():
+                # Generous upper bound (the work is a real HTTP round-trip or DB
+                # hop on a possibly-loaded CI box); the loop exits early via
+                # `result["done"]`, and we fail below if it never gets set.
                 for _ in range(50000):
                     if result.get("done"):
                         break
@@ -207,8 +220,9 @@ class RustLogContextTestCase(HomeserverTestCase):
     def test_db_callback_runs_in_caller_logcontext(self) -> None:
         """The Rust `/versions` handler's per-user feature lookup calls back into
         Python via `run_python_awaitable`; the DB transaction it runs must be
-        accounted against the caller's logcontext (the resolved
-        `deferred.rs:223` FIXME)."""
+        accounted against the caller's logcontext. (Before the Rust storage
+        port, a FIXME in `run_python_awaitable` meant this ran in the
+        sentinel and the accounting was lost.)"""
         versions_handler = self.hs.get_rust_handlers().versions
 
         def body(result: dict[str, object]) -> None: