Document structured logging and define failure ownership - #748
Open
tony wants to merge 35 commits into
Open
Conversation
why: tmux_cmd reported two different strings depending on which module logged it — the full argument vector in common.py, the arguments alone in neo.py — so a consumer parsing the documented field saw two shapes. The same command line also carried environment values verbatim, putting any token passed as environment= into DEBUG logs. what: - Add _internal/log_context.py: describe_command() walks tmux's global flags per the getopt string in tmux.c, so a flag that takes a value is never read as the subcommand, and redacts environment values - Redact at the seam rather than at each call site, so set-environment and any future env-carrying command are covered; -e stays untouched where tmux treats it as a boolean (select-pane, copy-mode) - Derive tmux_subcommand and a new tmux_socket for every command record - Drop neo.py's duplicate query records, now fully superseded - Log ERROR in raise_if_stderr, where libtmux decides a command failed, carrying the exit code and socket the exception message cannot - Cover the tmux CLI grammar and redaction with table-driven tests
why: Five near-identical blocks hand-rolled the same lifecycle extra dict, each repeating the "coerce to str, omit when None" invariant, so the invariant could drift per call site with nothing to catch it. what: - Route lifecycle records through log_context.object_extra(), which holds that invariant in one place and is unit-tested - Tag session created with tmux_target, which it was missing - Give the hooks parse warning an extra; its %s always interpolated the blank line that triggered it - Drop exc_info from the query_list lookup debug records: a missing field is normal control flow for a filter, not a traceback
why: Closes #744. Nothing in the docs mentioned logging, so the only way to configure it was to read the source and infer a strategy — which is what the reporter had to do while diagnosing libtmux on a platform it does not support. what: - Add docs/topics/logging.md: turning it on, diagnosing a failure, which logger emits what, the full tmux_ field schema, reading records with caplog, and recipes for JSON output and OpenTelemetry - Document the Formatter trap that drops records whose format string names a field they lack, with the defaults= fix - Expose caplog through doctest_namespace so the page's examples run as tests rather than drifting from the code - Record the new tmux_socket key and the failure-record rule in AGENTS
why: Killing a session through Server.kill_session() emitted no lifecycle record while Session.kill() emitted one, so whether the operation appeared in logs depended on which entry point a caller happened to use. what: - Emit the same "session killed" INFO record from Server.kill_session() - Cover it alongside the other lifecycle records
why: The session fixture asked tmux to switch a client even when none was attached, which is a command failure. Now that libtmux logs failures at ERROR, pytest replays that record into the captured-log section of every failing test that uses the fixture, where it reads as the cause of the failure rather than as fixture noise. what: - Attempt the switch only when a client exists; keep the suppression for the race where one detaches in between - Assert fixture setup leaves no ERROR records behind
why: raise_if_stderr() has 85 call sites, so its ERROR record reported common.py for every one of them. That leaves %(filename)s, %(funcName)s, and OpenTelemetry's code.filepath naming the helper rather than the tmux operation that failed — the one thing the record exists to locate. what: - Log with stacklevel=2 so the record names the calling wrapper - Parse bundled global flags: -2Lsock is -2 -L sock to getopt, and the socket was being dropped - Warn once per option rather than once per malformed entry, counting the skipped entries in tmux_option_skipped - Give the control-mode client the same command records as any other tmux subprocess, and warn when one must be killed after declining to exit; fold its two duplicate terminate paths into one
why: The level table listed only parse failures under WARNING, which stopped being the whole story once the control-mode client gained a record for being killed. what: - Name the control-mode kill alongside the parse warnings
why: A tmux command line carries whatever the caller passed it, and send_keys payloads routinely contain newlines. One of those ended the DEBUG record early in any line-oriented log, leaving the rest of the argument to read as a record of its own — 66 of the 10,545 commands a full test run issues already carry control characters. what: - Quote an argument holding control characters into shell $'…' form, which bash and zsh expand back to the original bytes, so the command line still pastes and reproduces the call on a single line - Render terminal escape sequences rather than passing them through to whatever reads the log - Leave object names alone: tmux rejects control characters in them before libtmux logs anything, so there is nothing to guard
why: A command past tmux's own size limit is rejected by tmux, but its whole payload was still written to three records, so one oversized set_buffer() could put hundreds of kilobytes into a DEBUG log. what: - Cap tmux_cmd at MAX_IMSGSIZE, the largest command tmux will run, so every command tmux accepted stays reproducible from its record and only a rejected one arrives shortened - Report the pre-cap length as tmux_cmd_len, matching how the stdout and stderr caps already report theirs
why: tmux_stdout and tmux_stderr hold lists, so a %s in a format string renders a Python repr rather than the lines a reader expects. what: - Show the repr and how to join the lines instead
why: The cap measures the quoted command line while tmux measures the raw one, and quoting expands — a single quote becomes five characters. A payload of 4000 quotes is a command tmux accepts whose record still shortens, so "every command tmux ran is reproducible" was not true. what: - Describe what the cap actually guarantees, and name quote expansion - Point at comparing tmux_cmd_len to spot a shortened record - Filter rather than index in the example, as the page advises
why: Redaction only covered what libtmux sends. tmux returns the same values on stdout, so getenv() and show_environment() wrote to a DEBUG record the very value set_environment() kept out of one — an ordinary call leaking the secret a careful one had protected. what: - Redact values in the output of show-environment, so its records show the names and the calls still return what they always did - Cover the round trip in one test rather than one per direction
why: capture-pane, show-buffer, and list-buffers return whatever was on a screen or in a paste buffer, and every line went into a DEBUG record — so capturing a pane logged its contents, including anything typed at a prompt. The caller already holds that value as a return value, so the record only duplicated it, at size. what: - Report tmux_stdout_len alone for content-returning subcommands, the line HTTP clients draw between a content length and a body - Leave control output alone, so list rows and message results still reach a debug record
why: The command line is the bulk of debug volume, because libtmux queries tmux with large -F templates and records each command twice so either line stands alone. A reader wanting lifecycle events without that had no way to know which logger to raise. what: - Name the cost and point at the per-logger lever that avoids it
why: The filter-placement example set a level on the shared libtmux logger and never restored it, so every test after the docs page ran with libtmux at DEBUG. It also removed its filter by index, which is the wrong one if anything else added a filter first. what: - Restore the previous level and remove the filter by identity - Say why in the prose, since a level on a shared logger outlives the code that set it - Note which output rule wins when a subcommand matches both
why: When tmux returns a row that does not split into the fields the template asked for, the exception names only zip() — not tmux, not the subcommand, not the field. The log filled none of that in: tmux itself succeeded, so the command records showed a clean exit and nothing at all reported the failure, even at DEBUG. what: - Log ERROR with the subcommand and the field counts before the parse raises; a count one over expected is what identifies a value holding the separator rows are split on - Keep the ValueError as-is. Converting it to LibTmuxException would let the lenient list accessors swallow it, turning a loud failure into a silent empty result - Correct the AGENTS note that said a missing format field raises KeyError; Formatter.format raises ValueError and the record is dropped
why: libtmux raises roughly as many advisories through warnings.warn as it logs — a deprecated method, a flag the running tmux is too old for, an argument being ignored. None reach a logging handler, so an application configured exactly as the topic describes received none of them, and the level table promised the opposite. what: - Show captureWarnings() routing them to the py.warnings logger, proved both ways as a doctest - Note that warnings deduplicate per source location and log records do not, so a single warning may stand for many occurrences - Correct the level table: WARNING covers what libtmux resolved itself, not deprecations
why: tmux_cmd_len rode on all 17,468 records of a suite run to make truncation detectable, but the shortened line already ends in an ellipsis, and across 10,545 real commands nothing truncated at all. The cap earns its place; the companion key did not. what: - Keep the cap and the ellipsis, drop tmux_cmd_len from the schema - Prove the logging path holds no shared mutable state, and pin it: the handler lock makes logging thread-safe, so the only race libtmux could add is one list reaching two records - Document threads and asyncio, including the QueueHandler formatter that drops records before they reach the queue
why: Command spellings and specialized failure paths could bypass the logging safety contract, while lifecycle records did not consistently identify their tmux server. what: - Resolve protected command families without rewriting raw subcommands - Withhold sensitive content and escape Unicode log boundaries - Centralize failure records while preserving public exceptions - Attach socket context and prove concurrent record isolation
why: The logging guide and changelog must describe the final safety boundaries without overstating tmux transport or shell guarantees. what: - Make configuration and integration examples independently executable - Document sensitive-output, alias, and handler-filter boundaries - Align failure, socket, and bounded-command changelog entries
why: Bundled tmux environment flags and default aliases could bypass the logging safety policy, while health probes reported expected executable failures. what: - Parse boolean option clusters before environment values - Cover output-bearing default aliases - Keep executable failures quiet only in health-check context - Add regression coverage for accepted spellings and binaries
why: The guide overstated quiet failures and alias coverage, and did not explain how fixture-backed examples execute. what: - Explain the Python shell and pytest execution contexts - State unusable-binary, bundled-option, and alias boundaries - Align the unreleased changelog with the final behavior
why: The root AGENTS.md is now a router that points at src/libtmux/AGENTS.md for this package's logging conventions. This branch's logging documentation was written against the old layout, where the root file still held the conventions themselves. what: - Relocate the branch's logging-doc additions into src/libtmux/AGENTS.md, matching that file's heading depth and wrap - Cover where the schema is built, redaction in both directions, the handler-filter constraint, thread safety, and failure records - Add the tmux_option_skipped and tmux_socket keys, route deprecations through warnings.warn, and correct the missing-field failure mode to ValueError
why: Propagated failures already carry their context in exceptions, while logging before every raise required suppression state and duplicate call-site plumbing. what: - Remove low-level log-before-raise and ContextVar suppression - Emit one ERROR where lenient server accessors return an empty result - Restore optimistic fixture switching without an extra tmux query - Keep health checks and propagated failures quiet
why: Command-specific redaction duplicated tmux grammar and still required policy updates for aliases and future commands. Operation metadata is useful without retaining caller arguments or process output. what: - Replace the redaction engine with a compact operation summarizer - Omit command operands and stdout/stderr bodies from records - Preserve socket, subcommand, exit code, and line-count metadata - Reuse the same safe summary for subprocess and control-mode logs
why: The logging suite repeated tmux setup, record filtering, and schema assertions for each lifecycle method, obscuring the actual contract. what: - Cover lifecycle call sites through one shared capture helper and matrix - Retain all-except, propagation, privacy, fixture, and warning contracts - Remove redundant payload variants and mutable-state concurrency coverage - Prove the consolidated lifecycle test fails on a missing context field
why: The guide, changelog, and package policy still described deleted redaction machinery and repeated generic Python logging recipes. what: - Document operand and output-body omission as the privacy boundary - Describe boundary-only errors and the reduced structured schema - Keep concise activation, formatter, warning, and caplog examples - Collapse the changelog to the branch's net behavior
Codecov Report❌ Patch coverage is Additional details and impacted files@@ Coverage Diff @@
## master #748 +/- ##
==========================================
+ Coverage 52.37% 53.53% +1.16%
==========================================
Files 26 27 +1
Lines 3729 3743 +14
Branches 747 740 -7
==========================================
+ Hits 1953 2004 +51
+ Misses 1472 1459 -13
+ Partials 304 280 -24 ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
why: List accessors promise an empty result for tmux failures, but non-executable and malformed binaries escaped as raw OSError values. what: - Translate process-launch OSError values to TmuxCommandNotFound - Cover missing, non-executable, and malformed tmux binaries
why: Caller-controlled lifecycle identities could contain Unicode line separators and split rendered records. what: - Escape non-printable lifecycle identities in object_extra - Exercise the target field with a live tmux session name
why: Resource-related process launch failures were mislabeled as a missing tmux executable and lost their diagnostics. what: - Reserve TmuxCommandNotFound for unavailable executables - Retain other launch errors as LibTmuxException causes
why: tmux 3.3a stores Unicode session names as escaped bytes, so the live delete-by-name step failed before reaching the log assertion. what: - Restore a portable name for the live lifecycle flow - Check the forged target at the shared context boundary
why: The branch replaced released command and output fields with a summary and presented payload omission as a privacy boundary. That reduced diagnostics and made application logging policy a producer concern. what: - Restore complete one-line commands and bounded output snapshots - Stop derived metadata parsing when a global option is unknown - Include bounded exception text where list accessors swallow failures - Document handler filters, formatter field selection, and payload cost
why: Unusable executable paths were normalized for lenient accessors, but the translation discarded the operating-system message and cause. Server.raise_if_dead() also exposed different exception types. what: - Preserve ENOENT, EACCES, and ENOEXEC diagnostics on domain exceptions - Align tmux_cmd and raise_if_dead without changing successful calls - Keep lenient accessors empty and attach their diagnostics - Cover default, missing, non-executable, malformed, and E2BIG cases
why: The test asked select() about the raw descriptor, then read from TextIOWrapper's user-space buffer. tmux writes a whole control block in one burst, so the expected line could be buffered while select() timed out. what: - Read decoded lines on a daemon thread through a bounded queue - Preserve reader exceptions and distinguish EOF from timeout - Verify the Unicode case across tmux 3.2a through 3.7
why: The branch wrapped every unrelated launch OSError in LibTmuxException. That changed trunk behavior for E2BIG and similar failures even though only unavailable executables need normalization. what: - Re-raise unrelated launch OSError values unchanged from direct APIs - Catch and log those errors only at lenient list boundaries - Document direct and lenient exception behavior - Cover all three list accessors and supported tmux builds
tony
changed the title
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closes #744.
Summary
tmux_fields, assert on records withcaplog, and select emitted fields through standard-library handlers and formatters.ERRORwhen they return an empty result.TmuxCommandNotFoundwhile preserving operating-system diagnostics; unrelated launch failures remain native.Changes by area
Command and lifecycle records
tmux_cmdproduces dispatch and completion records with a complete one-line argv, best-effort subcommand and socket context, exit status, bounded output snapshots, and total line counts.Failure handling
Server.sessions,Server.attached_sessions, andServer.clientsretain their empty-result contract and emit one bounded diagnostic where the failure is swallowed.Server.is_alive()remains quiet, whileServer.raise_if_dead()retains loud failure semantics.TmuxCommandNotFoundpreserves the operating-system message and cause when execution was attempted; unrelated resource errors remainOSError.Recoverable diagnostics
terminal-features,terminal-overrides, andcommand-aliasentries produce one aggregate warning per option with the skipped-entry count.Server.kill_session()emits the same lifecycle schema as object-level session operations.Documentation
caplogassertions.caplogfixture.Design decisions
DEBUGrecords retain complete command operands and bounded output snapshots. libtmux does not guess which values are secrets; handlers and formatters decide which fields reach each destination.Verification
$ uv run ruff format . --check$ uv run ruff check .$ uv run mypy$ uv run pytest --reruns=0$ just build-docsTest plan