From b470d840ba24dc825c6b29b4047a9679af7504b6 Mon Sep 17 00:00:00 2001 From: Russell Smith Date: Fri, 29 May 2026 15:07:37 -0700 Subject: [PATCH] Log broadcasts once per event instead of once per subscriber. Fixes #73 `Cable::Server#send_to_channels` logged a "transmitting" line inside the per-subscriber loop, so a single broadcast to a stream with N connected clients produced N identical log lines. A busy chat room could emit dozens of duplicate entries for one message, flooding production logs. Move the log outside the loop and emit a single line per broadcast that includes the number of subscribers it was delivered to. Skips logging entirely when there are no live subscribers. Co-Authored-By: Claude Opus 4.8 (1M context) --- spec/cable/server_spec.cr | 29 +++++++++++++++++++++++++++++ src/cable/server.cr | 9 ++++++++- 2 files changed, 37 insertions(+), 1 deletion(-) diff --git a/spec/cable/server_spec.cr b/spec/cable/server_spec.cr index a505ec0..44c30ae 100644 --- a/spec/cable/server_spec.cr +++ b/spec/cable/server_spec.cr @@ -1,4 +1,5 @@ require "../spec_helper" +require "log/spec" include RequestHelpers @@ -47,6 +48,34 @@ describe Cable::Server do end end + describe "#send_to_channels" do + it "logs a single line per broadcast regardless of the number of subscribers" do + Cable.reset_server + Cable.temp_config(backend_class: Cable::DevBackend) do + connection_1 = creates_new_connection("aa") + connection_2 = creates_new_connection("bb") + + Cable.server.add_connection(connection_1) + Cable.server.add_connection(connection_2) + + # Both connections stream from the same identifier ("chat_room_a") + connection_1.subscribe(subscribe_payload("room_a")) + connection_2.subscribe(subscribe_payload("room_a")) + + logs = Log.capture("cable") do + Cable.server.send_to_channels("chat_room_a", {"message" => "hi"}.to_json) + end + + logs.check(:info, /Transmitting .* to 2 subscribers \(via streamed from chat_room_a\)/) + logs.empty + + connection_1.close + connection_2.close + end + Cable.reset_server + end + end + describe "#subscribed_channels_for" do it "accurately returns active channel subscriptions for a specificic token" do Cable.reset_server diff --git a/src/cable/server.cr b/src/cable/server.cr index 2e35744..684c4b3 100644 --- a/src/cable/server.cr +++ b/src/cable/server.cr @@ -135,6 +135,7 @@ module Cable return unless @channels.has_key?(channel_identifier) parsed_message = safe_decode_message(message) + transmitted = 0 begin @channels[channel_identifier].each do |channel| @@ -143,13 +144,19 @@ module Cable if channel.connection.closed? channel.close else - Cable::Logger.info { "#{channel.class} transmitting #{parsed_message} (via streamed from #{channel.stream_identifier})" } channel.connection.socket.send({ identifier: channel.identifier, message: parsed_message, }.to_json) + transmitted += 1 end end + + # Log once per broadcast event rather than once per subscriber, so a + # message fanned out to N connections produces a single log line. + if transmitted > 0 + Cable::Logger.info { "Transmitting #{parsed_message} to #{transmitted} subscriber#{"s" if transmitted > 1} (via streamed from #{channel_identifier})" } + end rescue e : IO::Error Cable.settings.on_error.call(e, "IO::Error Exception: #{e.message}: #{parsed_message} -> Cable::Server#send_to_channels(channel, message)", nil) end