Stop logging "Rendering" twice per template at debug level on Rails 7.2 to 8.1 - #59
Merged
Merged
Conversation
logtail-rack 0.2.8 times responses with the monotonic clock, which Timecop doesn't freeze, so "Completed 200 OK in 0.0ms" no longer holds. The last CI run on main still resolved logtail-rack 0.2.7. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Since Rails 7.1, ActionView::LogSubscriber.attach_to subscribes ActionView::LogSubscriber::Start listeners that log "Rendering ..." at debug level. The integration removes them, but on Rails 7.2 to 8.1 they survive, so every template render logs "Rendering" twice at debug level. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Rails 7.2 made ActionView::LogSubscriber::Start silenceable, and it counts as silenced while ActionView::Base.logger is nil, as it is at boot. listeners_for skips silenced listeners, so the cleanup in attach_to found none and every render logged "Rendering" twice at debug level. Look them up with all_listeners_for where ActiveSupport has it, and collect them with flat_map: all_listeners_for returns the notifier's cached array, which concat would modify. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This was referenced Oct 1, 2026
Merged
PetrHeinz
marked this pull request as ready for review
October 2, 2026 09:20
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.
At debug level, Rails 7.2, 8.0 and 8.1 apps log every template render twice as "Rendering …", next to our single "Rendered …" line. Rails 7.1 and edge log none, which is what the subscriber intends. Evidence: one request in this repo's spec app on Rails 8.1.4 at debug level logs
Rendering spec/support/rails/templates/template.htmltwice, thenRendered spec/support/rails/templates/template.html (0.1ms).Since Rails 7.1,
ActionView::LogSubscriber.attach_tosubscribes twoActionView::LogSubscriber::Startlisteners (template and layout) next to the subscriber, and those log the "Rendering" lines.LogtailLogSubscriber.attach_toremoves them after callingsuper, but it looks them up withlisteners_for, which skips silenced listeners. Rails 7.2 madeStartsilenceable (logger.nil? || !logger.debug?), andActionView::Base.loggeris still nil when the integration runs at boot. So nothing is found, and both Rails' own pair and the pair oursupercall adds stay subscribed.all_listeners_forwhere ActiveSupport has it (7.1+), falling back tolisteners_for.flat_mapinstead ofconcat-ing onto the first lookup:all_listeners_forreturns the notifier's cached array, soconcatwould write into its cache.Startlistener is left forrender_template.action_viewandrender_layout.action_view, and a request at debug level logs one "Rendered" line and no "Rendering" line.Behaviour and compatibility:
log_rendering_start.Startlogs nothing anyway, or on other Rails versions.Targets the logtail-rails 0.2.15 patch release. No dependencies on the other gems.
Commits and CI:
Expect real response durations in the request specsis unrelated test maintenance that every logtail-rails PR needs right now: logtail-rack 0.2.8 times responses with the monotonic clock, which Timecop doesn't freeze, so three specs expecting "in 0.0ms" fail on every CI leg (main's last run still resolved logtail-rack 0.2.7). Keep Rails requests and their logs working with json 3 on Rails 8.0 and older #62 carries the identical commit, so the two merge cleanly in either order.🤖 Generated with Claude Code