feat(logger): log to a rolling file via the new Logfami library - #143
Merged
Merged
Conversation
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
TwitchChat called `_log.w()` for dropped chat messages, but TwitchLogger had no warn level, so the branch raised a runtime error instead of logging. It also passed the ResponseDropReason object where a String is expected; the message now formats code and message like TwitchBot does. Adds a test that scans every TwitchLogger call site in the addon and fails on members the logger doesn't have. Refs #123 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
TwitchLogger no longer prints itself. Every message becomes a read-only
record shaped after the OpenTelemetry log data model (TwitchLogRecord),
which TwitchLoggerManager hands to all registered handlers. A handler is
a plain Callable, so an external logging solution can subscribe without
knowing any Twitcher class:
TwitchLoggerManager.add_handler(callable, TwitchLogLevel.Severity.INFO)
The console output moves into TwitchConsoleLogHandler, installed on load,
and keeps the exact legacy format and per-context settings. Each handler
filters on its own, so a future file handler receives messages even
while the console for that context is off.
- TwitchLogLevel: OpenTelemetry severity numbers plus OFF threshold
- TwitchLogHandlerEntry: handler with a global or per-scope threshold
- TwitchLogger: i/w/e/d accept optional attributes; wants(level) lets
callers skip building messages nobody receives
- Manager: copy-on-write handler list, drops records logged from inside
a handler, prunes handlers whose object got freed
- TwitchChat checks wants(WARN) instead of the console flag
Refs #123
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
Logfami is a new library under addons/twitcher/lib/logfami/ with no dependency on Twitcher or any other addon. Records flow through one or more pipelines, each with its own filter, processors, formatter and sink. - LogfamiLevel: OpenTelemetry severity numbers, text and syslog mapping - LogfamiRecord: OpenTelemetry-shaped record; from_dict/to_dict read the same dictionary contract Twitcher's log handlers receive - LogfamiResource: service.name, service.version, godot.version, os.type, process.pid and runtime (editor, headless, game) - LogfamiClock / LogfamiFixedClock: injectable time source - LogfamiProcessor, LogfamiFormatter, LogfamiSink: abstract extension points; LogfamiMemorySink for tests and in-game viewers - LogfamiPipeline: level and scope filter, processors work on a copy - Logfami: entry point with log_message, as_handler (record dictionaries) and as_triple (set_logger(error, info, debug) libraries); drops records produced while writing one Tests include a scan that fails on any Twitcher reference inside the library, and a code style test enforcing the CLAUDE.md rules (no ':=', word boolean operators, line length, one statement per line, return types) on the logger and Logfami folders. Refs #123 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
- LogfamiTextFormatter: human readable lines for support log files,
"<RFC 3339> <LEVEL> [scope#instance] body {attributes}", with a
"# session.start" header listing the resource
- LogfamiJsonLinesFormatter: one JSON object per line with
OpenTelemetry field names; the resource goes into a session.start
header record, or into every line with include_resource
- LogfamiLogfmtFormatter: key=value lines with go-logfmt quoting
- LogfamiTime: RFC 3339 UTC timestamps with milliseconds
- LogfamiEscaper: escapes control characters and the Unicode line
separators, so untrusted text like chat messages can't start a
forged log line (OWASP log injection)
Formatters own the one-record-one-line guarantee instead of an optional
processor, so no configuration can switch it off.
Golden-file tests render one set of edge-case records (instance,
injected line break, quotes and '=', unicode with nested attributes,
an empty record) with each formatter and compare against hand-written
expected output.
Refs #123
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
LogfamiRedactor masks secrets in the body and in every text attribute
before a record is formatted, so log files can be shared for support.
Default rules, each pinned by tests that also check everyday messages
stay untouched ("Token got authorized", "OAuth settings are invalid"):
- Bearer / OAuth authorization headers (token needs a digit, so the
plain words don't match)
- Twitch IRC passwords (oauth:...)
- access_token, refresh_token, client_secret, password, ... as
key=value, query string or JSON
- OAuth authorization codes in redirect URLs (?code=...)
- opt-in: any long token mixing letters and digits
Attributes whose key contains token, secret, password, authorization,
cookie or api_key are masked as a whole, recursively through nested
dictionaries and arrays.
Refs #123
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
LogfamiFileSink writes formatted lines to a file that rotates per session and by size, keeping a bounded number of files: app.log (current), app.1.log, app.2.log. Every file starts with the formatter's session header, also after a size rotation, so each file is self-describing when a user sends it in. - LogfamiFileSinkConfig: Resource with directory, base name, extension (defaults to the formatter's), max_lines (1000), max_files (3), rotate_on_start and the flush policy (every line, or on warn and every N lines) - LogfamiRotationPolicy: archive naming and the shift-and-drop rotation, deleting before renaming so it works on Windows too - LogfamiFileBackend with LogfamiFsFileBackend (FileAccess/DirAccess) and LogfamiMemoryFileBackend (tests; refuses to rename onto an existing file, like Windows) - Mutex-guarded writes; a failing directory, open or write reports one push_warning and drops further lines instead of breaking the game - get_absolute_file_path() and get_existing_file_paths() for "send me your log files" Refs #123 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
LogfamiStdoutSink prints lines to standard output, where container log collectors pick them up (twelve-factor app). Errors can optionally go to stderr from a configurable level. Printers are injectable for tests. Refs #123 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
LogfamiEngineCapture extends Godot's Logger and forwards push_error, push_warning, script and shader errors to Logfami under the scope "godot", with the source location as OpenTelemetry code.function, code.filepath and code.lineno attributes. Printed messages are only forwarded when capture_messages is on, since other loggers already print their own lines. Output Logfami produces while writing (a sink warning, a stdout line) reaches the capture again and is dropped by Logfami's per-thread write guard instead of looping; a test pins that. Refs #123 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
Closes the loop for #123: every Twitcher log record at info and above now lands in user://logs/twitcher.log, also when the console output of its context is off, so users can send the file in for support. - TwitchLogfamiBridge: the only place connecting Twitcher to Logfami. Installed by the first TwitchLogger registration, it builds the pipelines from the settings, subscribes Logfami as a handler and offers get_log_file_path(), get_log_folder_path() and open_log_folder() - TwitchLogSettings: twitcher/logs/file/{level,format,directory, max_lines,max_files,redact}, twitcher/logs/stdout/{level,format} and twitcher/logs/capture_engine; defaults: file at info as text, 1000 lines x 3 files, redaction on - stdout "auto" (default) turns on JSON Lines with the resource on every line for headless and dedicated server builds only; while it's active the console handler is removed so lines don't print twice - The editor writes twitcher_editor.log, so it never clashes with the game's file in the shared user:// folder - Twitcher.VERSION in code (exported games don't ship plugin.cfg), pinned to plugin.cfg by a test; sent as twitcher.version - Project > Tools > Twitcher > Open Log Folder in the editor - TwitcherTest disables auto-install in its _static_init, so test runs never write the real log file or print JSON, in any GUT runner The text formatter now quotes key=value values containing spaces, like logfmt, after a real run showed godot.version="4.7-stable (official)" was ambiguous in the header. Closes #123 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
A node registering a lambda as log handler crashed the game on quit (malloc_consolidate abort, reproduced in a minimal scene): Godot frees a lambda together with its script before static variables such as the handler registry, which still referenced it. TwitchLoggerManager now removes lambda handlers (and handlers with a lambda level resolver) when the scene tree's root leaves the tree. That happens after every node logged its last lines and before scripts are freed. Bound methods, like the Logfami bridge's handler, were never affected and stay registered. The same crash exists for lambdas passed to the lib set_logger() statics (BufferedHTTPClient etc.) on master; that is left for a separate change. Refs #123 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
Three independent reviews of #143 found the following; all are fixed here and covered by tests (394 passing, 375 before). Behaviour - The log file bridge now installs on the first log call instead of when a logger registers. Static loggers register while scripts load, so `auto_install = false` could never run early enough; now an autoload's _init suffices. uninstall() also turns auto_install off so the next log call doesn't bring the bridge back. - The shutdown sweep for lambda handlers no longer silently gives up when the main loop doesn't exist yet (a `-s` script's _init); it retries once the loop is up, so that case no longer crashes on quit. It also removes only lambdas: bound methods were swept as well because Callable.is_custom() is true for them. Commit 28fad22's message described the sweep as lambda-only; this makes it so. - The console decides per emitting logger again. Two loggers sharing a context name (Twitcher does for "Http") were governed by whichever registered last. Scoped resolvers receive the logger as a second argument. - LogfamiFileSink reads its whole config at construction (half of it was read live) and counts existing lines when appending, so rotate_on_start = false can't overshoot max_lines. Design and style - Serialization lives in the sinks (documented on LogfamiSink); the pipeline no longer holds a lock around user code, and processors are copy-on-write. - Nested attribute values render as sorted JSON in every format (LogfamiValue); text and logfmt used GDScript's str() of a Dictionary before. - os.type follows OpenTelemetry ("darwin" for macOS). - Member order per the style guide in four files; `warning` accepted as a level text on both sides, pinned by a test that the Twitch and Logfami levels never drift; one DEFAULT_FILE_DIRECTORY constant; unused TwitchLogger.color/string_to_hex_color removed; plain @export instead of a res:// folder picker for a user:// directory; lib/README.md lists logfami as a Twitcher dependency. Tests - No longer coupled to the headless runner (they computed expectations from the runtime they ran in); no more reads of private manager state (handler_count(), remove_lambda_handlers() are public); _console, _dispatching_threads and the deferred-watch flag are StaticStateGuard slots. - The style test now covers @abstract functions, `!`, one-line `for` and the helper and fixture scripts added by this branch. Refs #123 Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
Twitcher.VERSION duplicates the version in plugin.cfg (exported games don't ship plugin.cfg), which made every release a two-file edit that a test only catches after the fact. - Release workflow (workflow_dispatch, one `version` input): refuses an existing tag, writes the version into plugin.cfg and Twitcher.VERSION, runs the GUT suite, commits "chore: release X", tags X, pushes, publishes the GitHub release with generated notes and posts to Discord. The notification is part of the workflow because releases created with GITHUB_TOKEN don't trigger release-notification.yaml. - Version guard workflow: a tag pushed by hand must match both files. - .github/scripts/set-version.sh and check-version.sh hold the logic; the input is validated before it reaches sed, and inputs reach shell steps only through environment variables. Verified locally: check passes on 2.5.1, fails with file-pointed errors on a mismatch, set-version rejects "v2.6", writes both files, and the existing GUT test fails when one file drifts. Both workflows pass actionlint 1.7.7. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
…pture The file sink reports failures with push_warning. With LogfamiEngineCapture installed that warning re-enters the same Logfami and reaches the sink that just failed. Two tests show this ends after exactly one warning, both when the failure happens at session start (outside the per-thread write guard; the sink is already closed and has_failed() stops a second warning) and mid-write (inside the guard; the re-entered record is dropped). Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
Godot frees a lambda together with the script that defines it, which at shutdown happens before static variables of other scripts are cleared. A lambda passed to set_logger of the http and oOuch libraries stayed in their static logger dictionary and crashed the game on quit. LambdaLoggerCleanup connects the root's tree_exiting signal once a lambda is registered and drops the lambda entries there. When called from a SceneTree script's _init, the main loop isn't set yet, so the connection is deferred. BufferedHTTPClient now extends Node instead of Twitcher, so the http library no longer depends on Twitcher. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Review question on #143: LogfamiFsFileBackend.line_count() reads the whole file. Its only caller is LogfamiFileSink._open() on the append branch, reached once from start_session() when rotate_on_start is false. Size rotations open a fresh file and don't count. Twitcher's own setup keeps rotate_on_start = true, so it never reads the file. The doc comment says so, the memory backend counts its calls, and a test pins zero reads for a rotating session and exactly one for an appending session across several size rotations. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
… core TwitchLogLevel duplicated LogfamiLevel (same enum, texts and threshold parsing) and TwitchLogRecord redefined LogfamiRecord's keys, guarded by a drift test. The duplication was meant to keep Twitcher core free of Logfami, but the manager already reaches Logfami through the bridge, and the core depends on its other inner libraries directly as well. - TwitchLogLevel removed; every call site uses LogfamiLevel, which has the same API (Severity, OFF, to_text, threshold_from_text, base_of) - TwitchLogRecord's key constants and KEYS alias LogfamiRecord's; the documented dictionary contract for handlers is unchanged - LogfamiRecord.KEYS lists the keys in to_dict() order, pinned by a test - The drift test and the TwitchLogLevel tests go; LogfamiLevel's own tests cover the same cases - CLAUDE.md architecture note updated The one-way rule still holds: Logfami never references Twitcher. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
kanimaru
commented
Oct 3, 2026
Review on #143: `Callable(TwitchLoggerManager, &"name")` resolves the method at runtime, so a rename slips past the parser. The static methods are referenced as `TwitchLoggerManager.name` now, which the analyzer checks. The one remaining by-name construction is in the handler entry test, where that form is the thing under test. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
kanimaru
pushed a commit
that referenced
this pull request
Oct 3, 2026
Three independent reviews of #143 found the following; all are fixed here and covered by tests (394 passing, 375 before). Behaviour - The log file bridge now installs on the first log call instead of when a logger registers. Static loggers register while scripts load, so `auto_install = false` could never run early enough; now an autoload's _init suffices. uninstall() also turns auto_install off so the next log call doesn't bring the bridge back. - The shutdown sweep for lambda handlers no longer silently gives up when the main loop doesn't exist yet (a `-s` script's _init); it retries once the loop is up, so that case no longer crashes on quit. It also removes only lambdas: bound methods were swept as well because Callable.is_custom() is true for them. Commit 28fad22's message described the sweep as lambda-only; this makes it so. - The console decides per emitting logger again. Two loggers sharing a context name (Twitcher does for "Http") were governed by whichever registered last. Scoped resolvers receive the logger as a second argument. - LogfamiFileSink reads its whole config at construction (half of it was read live) and counts existing lines when appending, so rotate_on_start = false can't overshoot max_lines. Design and style - Serialization lives in the sinks (documented on LogfamiSink); the pipeline no longer holds a lock around user code, and processors are copy-on-write. - Nested attribute values render as sorted JSON in every format (LogfamiValue); text and logfmt used GDScript's str() of a Dictionary before. - os.type follows OpenTelemetry ("darwin" for macOS). - Member order per the style guide in four files; `warning` accepted as a level text on both sides, pinned by a test that the Twitch and Logfami levels never drift; one DEFAULT_FILE_DIRECTORY constant; unused TwitchLogger.color/string_to_hex_color removed; plain @export instead of a res:// folder picker for a user:// directory; lib/README.md lists logfami as a Twitcher dependency. Tests - No longer coupled to the headless runner (they computed expectations from the runtime they ran in); no more reads of private manager state (handler_count(), remove_lambda_handlers() are public); _console, _dispatching_threads and the deferred-watch flag are StaticStateGuard slots. - The style test now covers @abstract functions, `!`, one-line `for` and the helper and fixture scripts added by this branch. Refs #123 Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
kanimaru
pushed a commit
that referenced
this pull request
Oct 3, 2026
Review question on #143: LogfamiFsFileBackend.line_count() reads the whole file. Its only caller is LogfamiFileSink._open() on the append branch, reached once from start_session() when rotate_on_start is false. Size rotations open a fresh file and don't count. Twitcher's own setup keeps rotate_on_start = true, so it never reads the file. The doc comment says so, the memory backend counts its calls, and a test pins zero reads for a rotating session and exactly one for an appending session across several size rotations. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
kanimaru
pushed a commit
to kanimaru/twitcher-docs
that referenced
this pull request
Oct 3, 2026
Documents the logging changes of kanimaru/twitcher#143: - additional/logger.md: rewritten around the two jobs of the logger (console while developing, log file for support); levels incl. warn, attributes, file settings, finding the file, headless stdout, custom handlers with the record contract. Corrects the claim that console settings apply immediately; they're read when a logger is created. - additional/logfami.md: new page for the standalone library: pipelines, formats, resource, redaction, sinks, engine capture, extending. - introduction/support.md: "Send Us Your Log File" with the user data paths per operating system. - additional/index.md and the sidebar: Logger (missing from the sidebar before) and Logfami. Code samples were run in Godot 4.7; the site builds without dead links. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA
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
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 #123
Why
Users who report problems can now send a log file. Twitcher writes everything at info and above to
user://logs/twitcher.log, even when the console output for a context is off (the default, and typical for exported games). Secrets are redacted before anything is written.What changed
Twitcher core: logging is now swappable (
addons/twitcher/logger/)TwitchLoggerno longer prints directly. Each message becomes a read-only record (OpenTelemetry log data model, contract intwitch_log_record.gd) thatTwitchLoggerManagerhands to handlers. A handler is a plainCallable, so any logging solution can subscribe without knowing Twitcher classes.TwitchConsoleLogHandler. Its output is pinned to the legacy format by a test, and it decides per emitting logger instance, as before.i/w/e/d(text, attributes = {})pluswants(level).TwitchLoggerManager.remove_lambda_handlers()is public for-sscripts that quit before their first frame.Logfami: new standalone library (
addons/twitcher/lib/logfami/, no Twitcher dependency, enforced by a test)oauth:passwords,access_token/client_secret/… as key=value, query string or JSON, and?code=in URLsOS.add_loggerBridge (
TwitchLogfamiBridge,TwitchLogSettings)TwitchLogfamiBridge.auto_install = falsein an autoload's_initis a working opt-out even though static loggers register at script load.uninstall()turns auto-install off too.twitcher/logs/file/*,twitcher/logs/stdout/*,twitcher/logs/capture_enginestdout/level = auto(default) prints JSON Lines only on headless and dedicated server builds, and switches the console handler off meanwhile to avoid duplicatestwitcher_editor.log, separate from the game's fileTwitchLogfamiBridge.get_log_file_path()/open_log_folder()for in-game support buttonsRelease workflow (
.github/workflows/release.yml)Twitcher.VERSIONduplicates the version inplugin.cfg(exported games don't shipplugin.cfg). Instead of a two-file manual bump, the new Release workflow takes oneversioninput, writes both files, runs the suite, commits, tags, publishes the GitHub release and posts to Discord (the notification is in the workflow becauseGITHUB_TOKEN-created releases don't triggerrelease-notification.yaml).masterrejects pushes from Actions.Fixes found on the way
TwitchChatcalled the non-existent_log.w()with aResponseDropReasonobject, which raised a runtime error when a chat message was dropped. A new test scans every logger call site for unknown members.Other
Twitcher.VERSIONconstant, pinned toplugin.cfgby a testCLAUDE.mdwith the style rules (no:=, Godot style guide), the release procedure and conventional commitstest/unit/test_code_style.gdenforces the style rules on the logger, Logfami, helper and fixture scriptsExample output
Review round
Three independent reviews (correctness, design/style/tests, docs-vs-code) ran against the branch; every finding is addressed in
34260a4. The ones with user-visible effect: the opt-out that couldn't work, the quit crash that remained for-sscripts, the console governed by the last-registered logger instead of the emitting one, androtate_on_start = falseovershootingmax_lines. The rest is API/style/test hygiene; see the commit message.Testing
twitcher_editor.log, nothing on stdout, no script errors), a scene and a-sscript registering a lambda handler that both quit cleanly, lateauto_install = falseinstalling nothingset-version.shrejectsv2.6and writes both files, and the GUT test fails when one file driftsTwitcherTestdisables auto-installNotes for review
godot --importruns as the editor, so it also writestwitcher_editor.log(in CI too). That's harmless.masterfor lambdas passed to the libset_logger()statics (BufferedHTTPClientetc.). Twitcher itself only passes bound methods there; it's left for a separate change.print/push_errorcalls toTwitchLogger, and an OTLP exporter.🤖 Generated with Claude Code
https://claude.ai/code/session_01Q278jksbLv9nSTcfSLAMKA