From b45dd9bd25bf0d9f1a60197a1a0808a73bc520b0 Mon Sep 17 00:00:00 2001 From: Eron Nicholson Date: Fri, 24 Jul 2026 11:16:11 -0400 Subject: [PATCH 1/4] Add a console output backend for condensed deploy output MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Register a `console` logger in the output framework that replaces the raw SSHKit command firehose on the terminal with a condensed view: a header panel, one section per deploy phase, a live per-host status line, and a summary panel. Raw output is suppressed on success and replayed for any host that fails; -v/--verbose restores the full firehose. It reconstructs the view from the line stream every backend already receives — CLI phase markers (say), host-tagged SSHKit lines, and the modify.kamal exception payload — so no deploy code needs to know it exists. When active it owns the screen, so the raw stream is routed to a null sink (still teed to other backends, e.g. file). On a TTY it renders concurrent per-host spinners via tty-spinner/pastel; non-TTY output uses a deterministic line-based renderer. Opt in with `output: { console: {} }`. Co-Authored-By: Claude Opus 4.8 (1M context) --- Gemfile.lock | 8 + kamal.gemspec | 2 + lib/kamal/cli/base.rb | 12 +- lib/kamal/commander.rb | 10 +- lib/kamal/configuration/docs/output.yml | 14 ++ lib/kamal/configuration/output.rb | 3 +- lib/kamal/output/console/plain_renderer.rb | 46 +++++ lib/kamal/output/console/renderer.rb | 53 ++++++ lib/kamal/output/console/tty_renderer.rb | 56 ++++++ lib/kamal/output/console_logger.rb | 211 +++++++++++++++++++++ test/configuration/output_test.rb | 24 +++ test/output/console_logger_test.rb | 157 +++++++++++++++ 12 files changed, 592 insertions(+), 4 deletions(-) create mode 100644 lib/kamal/output/console/plain_renderer.rb create mode 100644 lib/kamal/output/console/renderer.rb create mode 100644 lib/kamal/output/console/tty_renderer.rb create mode 100644 lib/kamal/output/console_logger.rb create mode 100644 test/output/console_logger_test.rb diff --git a/Gemfile.lock b/Gemfile.lock index dedaebb60..9f7f5c801 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -9,8 +9,10 @@ PATH dotenv (~> 3.1) ed25519 (~> 1.4) net-ssh (~> 7.3) + pastel (~> 0.8) sshkit (>= 1.23.0, < 2.0) thor (~> 1.3) + tty-spinner (~> 0.9) zeitwerk (>= 2.6.18, < 3.0) GEM @@ -99,6 +101,8 @@ GEM parser (3.3.10.0) ast (~> 2.4.1) racc + pastel (0.8.0) + tty-color (~> 0.5) pp (0.6.3) prettyprint prettyprint (0.2.0) @@ -181,6 +185,10 @@ GEM stringio (3.2.0) thor (1.4.0) tsort (0.2.0) + tty-color (0.6.0) + tty-cursor (0.7.1) + tty-spinner (0.9.3) + tty-cursor (~> 0.7) tzinfo (2.0.6) concurrent-ruby (~> 1.0) unicode-display_width (3.2.0) diff --git a/kamal.gemspec b/kamal.gemspec index e9a8af5de..466414e86 100644 --- a/kamal.gemspec +++ b/kamal.gemspec @@ -21,6 +21,8 @@ Gem::Specification.new do |spec| spec.add_dependency "bcrypt_pbkdf", "~> 1.0" spec.add_dependency "concurrent-ruby", "~> 1.2" spec.add_dependency "base64", "~> 0.2" + spec.add_dependency "tty-spinner", "~> 0.9" + spec.add_dependency "pastel", "~> 0.8" spec.add_development_dependency "debug" spec.add_development_dependency "minitest", "< 6" diff --git a/lib/kamal/cli/base.rb b/lib/kamal/cli/base.rb index 9d99f759e..53fe935bb 100644 --- a/lib/kamal/cli/base.rb +++ b/lib/kamal/cli/base.rb @@ -90,9 +90,17 @@ def modify(lock: false) end end - def say(message = "", *) - super unless options[:raw] + def say(message = "", color = nil, *) + # A console backend renders the markers itself, but only while it's + # active (inside a modify block, i.e. KAMAL.logging). Outside of that + # — e.g. read-only commands — fall back to printing normally. + super unless options[:raw] || (KAMAL.console_output? && KAMAL.logging) + # Expose the color to the console backend so it can tell phase markers + # (say ..., :magenta) apart from the rest of the logged line stream. + Thread.current[:kamal_say_color] = color KAMAL.log(message.to_s) + ensure + Thread.current[:kamal_say_color] = nil end # Raw output is written straight to stdout for piping, so silence SSHKit's diff --git a/lib/kamal/commander.rb b/lib/kamal/commander.rb index 3879268ae..f56997994 100644 --- a/lib/kamal/commander.rb +++ b/lib/kamal/commander.rb @@ -21,6 +21,7 @@ def reset self.lock_wait = false self.lock_wait_timeout = 900 self.lock_wait_interval = 15 + @console_output = false @modify_depth = 0 @specifics = @specific_roles = @specific_hosts = nil @config = @config_kwargs = nil @@ -170,6 +171,10 @@ def holding_lock? self.holding_lock end + def console_output? + @console_output + end + def connected? self.connected end @@ -208,7 +213,10 @@ def configure_output_with(config) config.output.loggers.each { |logger| output_logger.broadcast_to(logger) } - SSHKit.config.output = Kamal::Output::Formatter.new($stdout, output_logger) + # A console backend renders to the screen itself, so drop SSHKit's raw stream (still teed to other backends). + @console_output = config.output.loggers.any? { |logger| logger.is_a?(Kamal::Output::ConsoleLogger) } + formatter_output = @console_output ? File.open(File::NULL, "w") : $stdout + SSHKit.config.output = Kamal::Output::Formatter.new(formatter_output, output_logger) at_exit { @output_logger&.close } rescue => e diff --git a/lib/kamal/configuration/docs/output.yml b/lib/kamal/configuration/docs/output.yml index 77f65f1d2..3f156d0cc 100644 --- a/lib/kamal/configuration/docs/output.yml +++ b/lib/kamal/configuration/docs/output.yml @@ -23,3 +23,17 @@ output: # One log file is created per deploy, named with the timestamp and command. file: path: /var/log/kamal/ + + # Console + # + # Replace the raw command firehose on the terminal with a condensed view: a + # header panel, one section per deploy phase, a live status line per host, + # and a summary panel. The raw output is suppressed on success and replayed + # for any host that fails. Run with -v/--verbose to restore the full firehose. + # + # Both options are optional: + # spinner - show animated per-host spinners on a TTY (default: true) + # color - force color on/off (default: auto-detect from the terminal) + console: + spinner: true + color: true diff --git a/lib/kamal/configuration/output.rb b/lib/kamal/configuration/output.rb index 8fcc5391a..17a9a9485 100644 --- a/lib/kamal/configuration/output.rb +++ b/lib/kamal/configuration/output.rb @@ -3,7 +3,8 @@ class Kamal::Configuration::Output LOGGER_TYPES = { "otel" => "Kamal::Output::OtelLogger", - "file" => "Kamal::Output::FileLogger" + "file" => "Kamal::Output::FileLogger", + "console" => "Kamal::Output::ConsoleLogger" } attr_reader :output_config, :loggers diff --git a/lib/kamal/output/console/plain_renderer.rb b/lib/kamal/output/console/plain_renderer.rb new file mode 100644 index 000000000..045e94610 --- /dev/null +++ b/lib/kamal/output/console/plain_renderer.rb @@ -0,0 +1,46 @@ +# Line-based renderer for non-TTY output (CI, piped, redirected). No cursor +# movement or spinners: phases and per-host results are printed in order as +# they resolve, so the log stays clean and deterministic. +class Kamal::Output::Console::PlainRenderer < Kamal::Output::Console::Renderer + def header(command:, service:, version:, destination:, hosts:, roles:) + target = [ service, version ].compact.join("@") + scope = "#{hosts} #{"host".pluralize(hosts)}, #{roles} #{"role".pluralize(roles)}" + scope += " · #{destination}" if destination + panel(command, [ "#{target} → #{scope}" ]) + end + + def phase(name) + puts + puts pastel.decorate("#{ARROW} #{name}", :bright_magenta, :bold) + end + + def end_phase(statuses) + statuses.each do |host, result| + if result[:status] == :failed + puts " #{pastel.red(FAIL)} #{host} #{pastel.red("failed")}" + else + puts " #{pastel.green(OK)} #{host} #{pastel.dim(format_duration(result[:duration]))}" + end + end + end + + def summary(ok:, failed:, needs_attention:, runtime:, exception:) + counts = [ pastel.green("#{OK} #{ok} ok") ] + counts << pastel.red("#{FAIL} #{failed} failed") if failed > 0 + lines = [ "#{counts.join(" ")} #{pastel.dim(format_duration(runtime))}" ] + lines << pastel.red("needs attention: #{needs_attention.join(", ")}") if needs_attention.any? + panel("Summary", lines, color: failed > 0 ? :red : :green) + end + + def replay(host, lines) + puts + puts pastel.dim("── retained output · #{host} ─────") + lines.each { |line| puts pastel.dim("#{BAR} ") + line } + end + + private + def format_duration(seconds) + return "" unless seconds + "#{sprintf("%.1f", seconds)}s" + end +end diff --git a/lib/kamal/output/console/renderer.rb b/lib/kamal/output/console/renderer.rb new file mode 100644 index 000000000..071f3e430 --- /dev/null +++ b/lib/kamal/output/console/renderer.rb @@ -0,0 +1,53 @@ +require "pastel" + +# Shared formatting for the console renderers: colors, icons, and the rounded +# panels used for the header and summary. Subclasses implement the event +# methods (+header+, +phase+, +host_active+, +end_phase+, +summary+, +replay+) +# that the ConsoleLogger drives. +class Kamal::Output::Console::Renderer + OK = "✔" + FAIL = "✖" + ARROW = "❯" + BAR = "┃" + + def initialize(output:, settings: {}) + @output = output + @settings = settings + @pastel = Pastel.new(enabled: color_enabled?) + end + + def header(command:, service:, version:, destination:, hosts:, roles:); end + def phase(name); end + def host_active(host); end + def end_phase(statuses); end + def summary(ok:, failed:, needs_attention:, runtime:, exception:); end + def replay(host, lines); end + def host_error(host); end + + private + attr_reader :output, :settings, :pastel + + def color_enabled? + return settings["color"] if settings.key?("color") + output.respond_to?(:tty?) && output.tty? + end + + def puts(line = "") + output.puts(line) + end + + # A rounded panel with a highlighted title, sized to its widest line. + def panel(title, lines, color: :magenta) + width = ([ visible_width(title) + 4 ] + lines.map { |line| visible_width(line) }).max + puts + puts pastel.decorate("╭─ ", color) + pastel.decorate(title, color, :bold) + pastel.decorate(" #{"─" * (width - visible_width(title) - 1)}╮", color) + lines.each do |line| + puts pastel.decorate("│ ", color) + line + " " * (width - visible_width(line)) + pastel.decorate(" │", color) + end + puts pastel.decorate("╰#{"─" * (width + 2)}╯", color) + end + + def visible_width(string) + pastel.strip(string.to_s).length + end +end diff --git a/lib/kamal/output/console/tty_renderer.rb b/lib/kamal/output/console/tty_renderer.rb new file mode 100644 index 000000000..29416e083 --- /dev/null +++ b/lib/kamal/output/console/tty_renderer.rb @@ -0,0 +1,56 @@ +require "tty-spinner" + +# Interactive renderer: each phase is a TTY::Spinner::Multi whose children are +# the participating hosts, so their spinners animate concurrently and then +# settle into ✔/✖ status lines when the phase resolves. The header, summary, +# and replay panels are inherited from the plain renderer unchanged. +class Kamal::Output::Console::TtyRenderer < Kamal::Output::Console::PlainRenderer + SPINNER = :dots + + def phase(name) + finish_multi + puts + @multi = TTY::Spinner::Multi.new( + pastel.decorate("#{ARROW} #{name}", :bright_magenta, :bold), + output: output, hide_cursor: true, format: SPINNER + ) + @spinners = {} + end + + def host_active(host) + return unless @multi + spinner = @multi.register( + "[:spinner] #{host}", + format: SPINNER, + success_mark: pastel.green(OK), + error_mark: pastel.red(FAIL) + ) + @spinners[host] = spinner + spinner.auto_spin + end + + def end_phase(statuses) + return super unless @multi + + statuses.each do |host, result| + spinner = @spinners[host] + next unless spinner + + if result[:status] == :failed + spinner.error(pastel.red("failed")) + else + spinner.success(pastel.dim(format_duration(result[:duration]))) + end + end + + finish_multi + end + + private + def finish_multi + return unless @multi + @spinners.each_value { |spinner| spinner.stop if spinner.spinning? } + @multi = nil + @spinners = {} + end +end diff --git a/lib/kamal/output/console_logger.rb b/lib/kamal/output/console_logger.rb new file mode 100644 index 000000000..91ca9c2fd --- /dev/null +++ b/lib/kamal/output/console_logger.rb @@ -0,0 +1,211 @@ +require "set" + +# A console backend for the output framework that replaces the raw SSHKit +# command firehose with a condensed, human-oriented view: a header panel, one +# section per deploy phase, a live status line per host, and a summary panel. +# +# It reconstructs that view purely from the line stream every backend already +# receives (`<<`) plus the modify.kamal start/finish notifications — no deploy +# code needs to know it exists: +# +# * CLI phase markers (`say "Build and push app image...", :magenta`) arrive +# host-less with a color set in the +kamal_say_color+ thread-local; each one +# opens a new phase section. +# * SSHKit command lines arrive tagged with +kamal_host+ (and +kamal_severity+); +# the first line from a host in a phase starts its status line, error-level +# lines mark it failed, and every line is retained for replay on failure. +# * The modify.kamal exception payload names the hosts/roles that blew up, so +# failures are attributed even when the stream itself looks clean. +# +# The raw firehose is still teed to any other configured backend (e.g. file), +# so nothing is lost — it's only suppressed on the terminal. +class Kamal::Output::ConsoleLogger < Kamal::Output::BaseLogger + # Cap the per-host replay buffer so a chatty failure can't pin the whole run + # of output in memory. + MAX_RETAINED_LINES = 100 + + def self.build(settings:, config:) + new(config: config, settings: settings || {}) + end + + def initialize(config:, settings: {}, output: $stdout) + @config = config + @settings = settings + @mutex = Mutex.new + @renderer = build_renderer(output) + reset_state + super() + end + + def <<(message) + host = Thread.current[:kamal_host] + severity = Thread.current[:kamal_severity] + say_color = Thread.current[:kamal_say_color] + + synchronize do + next unless @active + + if host + record_host_output(host.to_s, message, severity) + elsif say_color + begin_phase(message) + end + end + end + + private + attr_reader :config, :settings, :renderer + + def on_start(payload) + synchronize do + reset_state + @active = true + @started_at = clock + renderer.header( + command: full_command(payload), + service: config.service, + version: abbreviated_version, + destination: config.destination, + hosts: config.all_hosts.size, + roles: config.roles.size + ) + end + end + + def on_finish(payload, runtime) + synchronize do + note_exception(payload[:exception]) + end_phase + render_summary(runtime) + @active = false + end + end + + def on_close + synchronize do + end_phase if @active + @active = false + end + end + + def reset_state + @active = false + @started_at = nil + @current_phase = nil + @phase_started_at = nil + @phase_hosts = {} + @errored_hosts = Set.new + @seen_hosts = Set.new + @retained = Hash.new { |hash, key| hash[key] = [] } + end + + # --- Event handling (all called while holding the mutex) --- + + def begin_phase(message) + end_phase + @current_phase = clean_phase(message) + @phase_started_at = clock + @phase_hosts = {} + renderer.phase(@current_phase) + end + + def end_phase + return unless @current_phase + + statuses = @phase_hosts.keys.sort.to_h do |host| + failed = @errored_hosts.include?(host) + [ host, { status: failed ? :failed : :ok, duration: clock - @phase_hosts[host] } ] + end + renderer.end_phase(statuses) + @current_phase = nil + end + + def record_host_output(host, message, severity) + begin_phase("Running") unless @current_phase + note_host(host) + retain(host, message) + mark_failed(host) if error?(severity) + end + + def note_host(host) + @seen_hosts << host + unless @phase_hosts.key?(host) + @phase_hosts[host] = clock + renderer.host_active(host) + end + end + + def mark_failed(host) + return if @errored_hosts.include?(host) + @errored_hosts << host + renderer.host_error(host) if @phase_hosts.key?(host) + end + + def note_exception(exception) + return unless exception + + # exception is [ class_name, message ]; our SSHKit patches embed the failing + # host/role names in the message, so flag every seen host it mentions. + message = Array(exception).join(" ") + @seen_hosts.each { |host| mark_failed(host) if message.include?(host) } + @exception = exception + end + + def render_summary(runtime) + renderer.summary( + ok: (@seen_hosts - @errored_hosts).size, + failed: @errored_hosts.size, + needs_attention: @errored_hosts.to_a.sort, + runtime: runtime, + exception: @exception + ) + + @errored_hosts.sort.each do |host| + lines = @retained[host] + renderer.replay(host, lines) if lines.any? + end + end + + # --- Helpers --- + + def retain(host, message) + buffer = @retained[host] + buffer.concat(message.to_s.split("\n", -1).reject(&:empty?)) + buffer.shift(buffer.size - MAX_RETAINED_LINES) if buffer.size > MAX_RETAINED_LINES + end + + def error?(severity) + severity == Logger::ERROR || severity == Logger::FATAL + end + + def clean_phase(message) + message.to_s.strip.sub(/[.:\s]+\z/, "") + end + + def full_command(payload) + [ payload[:command], payload[:subcommand] ].compact.join(" ") + end + + def abbreviated_version + config.abbreviated_version + rescue + nil + end + + def clock + Process.clock_gettime(Process::CLOCK_MONOTONIC) + end + + def synchronize(&block) + @mutex.synchronize(&block) + end + + def build_renderer(output) + spinner = settings.fetch("spinner", true) && output.respond_to?(:tty?) && output.tty? + if spinner + Kamal::Output::Console::TtyRenderer.new(output: output, settings: settings) + else + Kamal::Output::Console::PlainRenderer.new(output: output, settings: settings) + end + end +end diff --git a/test/configuration/output_test.rb b/test/configuration/output_test.rb index 9a09ebac7..e299e1630 100644 --- a/test/configuration/output_test.rb +++ b/test/configuration/output_test.rb @@ -39,6 +39,30 @@ class ConfigurationOutputTest < ActiveSupport::TestCase assert_kind_of Kamal::Output::FileLogger, @config.output.loggers.first end + test "enabled with console" do + @deploy[:output] = { "console" => {} } + @config = Kamal::Configuration.new(@deploy) + + assert @config.output.enabled? + assert_equal 1, @config.output.loggers.length + assert_kind_of Kamal::Output::ConsoleLogger, @config.output.loggers.first + end + + test "console accepts spinner and color settings" do + @deploy[:output] = { "console" => { "spinner" => false, "color" => false } } + @config = Kamal::Configuration.new(@deploy) + + assert_kind_of Kamal::Output::ConsoleLogger, @config.output.loggers.first + end + + test "console rejects unknown settings" do + @deploy[:output] = { "console" => { "bogus" => true } } + + assert_raises(Kamal::ConfigurationError) do + Kamal::Configuration.new(@deploy) + end + end + test "enabled with both otel and file" do @deploy[:output] = { "otel" => { "endpoint" => "http://otel-gateway:4318" }, diff --git a/test/output/console_logger_test.rb b/test/output/console_logger_test.rb new file mode 100644 index 000000000..07b322258 --- /dev/null +++ b/test/output/console_logger_test.rb @@ -0,0 +1,157 @@ +require "test_helper" + +class OutputConsoleLoggerTest < ActiveSupport::TestCase + setup do + @output = StringIO.new + @logger = Kamal::Output::ConsoleLogger.new(config: config_double, settings: { "color" => false }, output: @output) + end + + teardown { @logger.close } + + test "header panel names the command, service, version and scope" do + start + finish + + assert_match "deploy", rendered + assert_match "myapp@abc1234", rendered + assert_match "3 hosts, 2 roles", rendered + assert_match "production", rendered + end + + test "say markers open phase sections" do + start + say "Build and push app image..." + say "Boot app..." + finish + + assert_match "❯ Build and push app image", rendered + assert_match "❯ Boot app", rendered + end + + test "each active host gets a status line resolved at phase end" do + start + say "Boot app..." + host_line "10.0.0.1", "docker run" + host_line "10.0.0.2", "docker run" + finish + + assert_match "✔ 10.0.0.1", rendered + assert_match "✔ 10.0.0.2", rendered + end + + test "a host with error-level output is marked failed and listed for attention" do + start + say "Boot app..." + host_line "10.0.0.1", "docker run" + host_line "10.0.0.2", "boom: container exited", severity: Logger::ERROR + finish + + assert_match "✔ 10.0.0.1", rendered + assert_match "✖ 10.0.0.2", rendered + assert_match "needs attention: 10.0.0.2", rendered + end + + test "hosts named in the finish exception are marked failed even with clean output" do + start + say "Boot app..." + host_line "10.0.0.1", "docker run" + host_line "10.0.0.2", "docker run" + finish exception: [ "Kamal::Cli::BootError", "Exception while executing on web: 10.0.0.2 did not boot" ] + + assert_match "✖ 10.0.0.2", rendered + assert_match "needs attention: 10.0.0.2", rendered + end + + test "summary counts successes and failures" do + start + say "Boot app..." + host_line "10.0.0.1", "docker run" + host_line "10.0.0.2", "nope", severity: Logger::ERROR + finish + + assert_match "✔ 1 ok", rendered + assert_match "✖ 1 failed", rendered + end + + test "clean run reports all ok and no failure section" do + start + say "Boot app..." + host_line "10.0.0.1", "docker run" + finish + + assert_match "✔ 1 ok", rendered + refute_match "failed", rendered + refute_match "needs attention", rendered + end + + test "retained output is replayed only for failed hosts" do + start + say "Boot app..." + host_line "10.0.0.1", "clean output line" + host_line "10.0.0.2", "failing output line", severity: Logger::ERROR + finish + + assert_match "retained output · 10.0.0.2", rendered + assert_match "failing output line", rendered + refute_match "clean output line", rendered + end + + test "host output before any marker opens an implicit phase" do + start + host_line "10.0.0.1", "docker run" + finish + + assert_match "❯ Running", rendered + assert_match "✔ 10.0.0.1", rendered + end + + test "ignores the line stream before start and after finish" do + host_line "10.0.0.1", "before start" + start + finish + say "After finish..." + + refute_match "before start", rendered + refute_match "After finish", rendered + end + + private + def config_double + Class.new do + def service; "myapp"; end + def destination; "production"; end + def all_hosts; %w[ 10.0.0.1 10.0.0.2 10.0.0.3 ]; end + def roles; %i[ web worker ]; end + def abbreviated_version; "abc1234"; end + end.new + end + + def start(command: "deploy", **payload) + @logger.start("modify.kamal", "id", command: command, destination: "production", **payload) + end + + def finish(exception: nil) + @logger.finish("modify.kamal", "id", exception: exception) + end + + def say(message, color: :magenta) + with_context(say_color: color) { @logger << "#{message}\n" } + end + + def host_line(host, message, severity: nil) + with_context(host: host, severity: severity) { @logger << "#{message}\n" } + end + + def with_context(host: nil, say_color: nil, severity: nil) + Thread.current[:kamal_host] = host + Thread.current[:kamal_say_color] = say_color + Thread.current[:kamal_severity] = severity + yield + ensure + Thread.current[:kamal_host] = Thread.current[:kamal_say_color] = Thread.current[:kamal_severity] = nil + end + + def rendered + @output.string + end +end From 16cdebe119d874abf6dd995ea3621460d0aaa28e Mon Sep 17 00:00:00 2001 From: Eron Nicholson Date: Fri, 24 Jul 2026 11:53:38 -0400 Subject: [PATCH 2/4] Strip phase-marker punctuation without a backtracking regex CodeQL flagged the trailing-strip regex as polynomial ReDoS: end-anchored with + but not start-anchored, so it rescans across start positions. The input is Kamal's own say() markers, not untrusted data, but the linear non-regex strip is clearer and clears the alert. strip already removes whitespace, so only trailing dots/colons remain. Co-Authored-By: Claude Opus 4.8 (1M context) --- lib/kamal/output/console_logger.rb | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/lib/kamal/output/console_logger.rb b/lib/kamal/output/console_logger.rb index 91ca9c2fd..4ce88375c 100644 --- a/lib/kamal/output/console_logger.rb +++ b/lib/kamal/output/console_logger.rb @@ -179,7 +179,9 @@ def error?(severity) end def clean_phase(message) - message.to_s.strip.sub(/[.:\s]+\z/, "") + phase = message.to_s.strip + phase = phase.chop while phase.end_with?(".", ":") + phase end def full_command(payload) From 6cb4f4ba36f8a1ed751cf061c2a0229805955053 Mon Sep 17 00:00:00 2001 From: Eron Nicholson Date: Fri, 24 Jul 2026 13:09:07 -0400 Subject: [PATCH 3/4] Address review: -v firehose, host attribution, dead severity path - Honor -v/--verbose: skip the null sink and disable the console renderer so the raw SSHKit firehose shows; close the null-sink FD at exit. - Attribute exception failures by whole-host token (10.0.0.1 no longer flagged by a failure on 10.0.0.10) and consider all configured hosts, so a host that failed before emitting output is still flagged. - Drop the severity-based failure path: SSHKit logs command output at DEBUG (never ERROR) within host context, so it was dead code; failures are attributed from the modify.kamal exception payload. Co-Authored-By: Claude Opus 4.8 (1M context) --- lib/kamal/commander.rb | 19 ++++++--- lib/kamal/output/console_logger.rb | 36 ++++++++++------ test/output/console_logger_test.rb | 68 +++++++++++++++++++++--------- 3 files changed, 83 insertions(+), 40 deletions(-) diff --git a/lib/kamal/commander.rb b/lib/kamal/commander.rb index f56997994..57fac8636 100644 --- a/lib/kamal/commander.rb +++ b/lib/kamal/commander.rb @@ -22,6 +22,7 @@ def reset self.lock_wait_timeout = 900 self.lock_wait_interval = 15 @console_output = false + @null_output = nil @modify_depth = 0 @specifics = @specific_roles = @specific_hosts = nil @config = @config_kwargs = nil @@ -213,12 +214,20 @@ def configure_output_with(config) config.output.loggers.each { |logger| output_logger.broadcast_to(logger) } - # A console backend renders to the screen itself, so drop SSHKit's raw stream (still teed to other backends). - @console_output = config.output.loggers.any? { |logger| logger.is_a?(Kamal::Output::ConsoleLogger) } - formatter_output = @console_output ? File.open(File::NULL, "w") : $stdout - SSHKit.config.output = Kamal::Output::Formatter.new(formatter_output, output_logger) + # A console backend renders to the screen itself, so drop SSHKit's raw stream + # (still teed to other backends). -v/--verbose skips it to restore the firehose. + console = config.output.loggers.find { |logger| logger.is_a?(Kamal::Output::ConsoleLogger) } + @console_output = !console.nil? && verbosity != :debug + console&.disable! unless @console_output + + if @console_output + @null_output = File.open(File::NULL, "w") + SSHKit.config.output = Kamal::Output::Formatter.new(@null_output, output_logger) + else + SSHKit.config.output = Kamal::Output::Formatter.new($stdout, output_logger) + end - at_exit { @output_logger&.close } + at_exit { @output_logger&.close; @null_output&.close } rescue => e $stderr.puts "Output logger setup failed: #{e.class}: #{e.message}" $stderr.puts e.backtrace.join("\n") if ENV["VERBOSE"] diff --git a/lib/kamal/output/console_logger.rb b/lib/kamal/output/console_logger.rb index 4ce88375c..a709ff131 100644 --- a/lib/kamal/output/console_logger.rb +++ b/lib/kamal/output/console_logger.rb @@ -37,16 +37,21 @@ def initialize(config:, settings: {}, output: $stdout) super() end + # Stay out of the way — used when -v/--verbose asks for the raw firehose + # instead of the condensed view. + def disable! + @disabled = true + end + def <<(message) host = Thread.current[:kamal_host] - severity = Thread.current[:kamal_severity] say_color = Thread.current[:kamal_say_color] synchronize do next unless @active if host - record_host_output(host.to_s, message, severity) + record_host_output(host.to_s, message) elsif say_color begin_phase(message) end @@ -59,8 +64,8 @@ def <<(message) def on_start(payload) synchronize do reset_state + next if @disabled @active = true - @started_at = clock renderer.header( command: full_command(payload), service: config.service, @@ -74,6 +79,7 @@ def on_start(payload) def on_finish(payload, runtime) synchronize do + next unless @active note_exception(payload[:exception]) end_phase render_summary(runtime) @@ -90,9 +96,7 @@ def on_close def reset_state @active = false - @started_at = nil @current_phase = nil - @phase_started_at = nil @phase_hosts = {} @errored_hosts = Set.new @seen_hosts = Set.new @@ -104,7 +108,6 @@ def reset_state def begin_phase(message) end_phase @current_phase = clean_phase(message) - @phase_started_at = clock @phase_hosts = {} renderer.phase(@current_phase) end @@ -120,11 +123,10 @@ def end_phase @current_phase = nil end - def record_host_output(host, message, severity) + def record_host_output(host, message) begin_phase("Running") unless @current_phase note_host(host) retain(host, message) - mark_failed(host) if error?(severity) end def note_host(host) @@ -145,12 +147,22 @@ def note_exception(exception) return unless exception # exception is [ class_name, message ]; our SSHKit patches embed the failing - # host/role names in the message, so flag every seen host it mentions. + # host/role names in the message. Match each candidate host as a whole token + # so 10.0.0.1 isn't flagged by a failure on 10.0.0.10, and include hosts that + # failed before emitting any output (so aren't in @seen_hosts yet). message = Array(exception).join(" ") - @seen_hosts.each { |host| mark_failed(host) if message.include?(host) } + candidate_hosts.each { |host| mark_failed(host) if message.match?(host_token(host)) } @exception = exception end + def candidate_hosts + (config.all_hosts.map(&:to_s) + @seen_hosts.to_a).uniq + end + + def host_token(host) + /(? MAX_RETAINED_LINES end - def error?(severity) - severity == Logger::ERROR || severity == Logger::FATAL - end - def clean_phase(message) phase = message.to_s.strip phase = phase.chop while phase.end_with?(".", ":") diff --git a/test/output/console_logger_test.rb b/test/output/console_logger_test.rb index 07b322258..158b17971 100644 --- a/test/output/console_logger_test.rb +++ b/test/output/console_logger_test.rb @@ -3,7 +3,7 @@ class OutputConsoleLoggerTest < ActiveSupport::TestCase setup do @output = StringIO.new - @logger = Kamal::Output::ConsoleLogger.new(config: config_double, settings: { "color" => false }, output: @output) + @logger = build_logger end teardown { @logger.close } @@ -39,35 +39,46 @@ class OutputConsoleLoggerTest < ActiveSupport::TestCase assert_match "✔ 10.0.0.2", rendered end - test "a host with error-level output is marked failed and listed for attention" do + test "hosts named in the finish exception are marked failed and listed for attention" do start say "Boot app..." host_line "10.0.0.1", "docker run" - host_line "10.0.0.2", "boom: container exited", severity: Logger::ERROR - finish + host_line "10.0.0.2", "docker run" + finish exception: [ "Kamal::Cli::BootError", "Exception while executing on web: 10.0.0.2 did not boot" ] assert_match "✔ 10.0.0.1", rendered assert_match "✖ 10.0.0.2", rendered assert_match "needs attention: 10.0.0.2", rendered end - test "hosts named in the finish exception are marked failed even with clean output" do + test "a host failure isn't misattributed to another whose address is a prefix of it" do + @logger = build_logger(hosts: %w[ 10.0.0.1 10.0.0.10 ]) start say "Boot app..." host_line "10.0.0.1", "docker run" - host_line "10.0.0.2", "docker run" - finish exception: [ "Kamal::Cli::BootError", "Exception while executing on web: 10.0.0.2 did not boot" ] + host_line "10.0.0.10", "docker run" + finish exception: [ "Kamal::Cli::BootError", "Exception while executing on web: 10.0.0.10 did not boot" ] - assert_match "✖ 10.0.0.2", rendered - assert_match "needs attention: 10.0.0.2", rendered + assert_match "✔ 10.0.0.1", rendered + assert_match "✖ 10.0.0.10", rendered + assert_match "needs attention: 10.0.0.10", rendered + refute_match "needs attention: 10.0.0.1\n", rendered + end + + test "a host named in the exception that never emitted output is still flagged" do + start + say "Connect to servers..." + finish exception: [ "SSHKit::Runner::ExecuteError", "Exception while executing as deploy@10.0.0.3: connection refused" ] + + assert_match "needs attention: 10.0.0.3", rendered end test "summary counts successes and failures" do start say "Boot app..." host_line "10.0.0.1", "docker run" - host_line "10.0.0.2", "nope", severity: Logger::ERROR - finish + host_line "10.0.0.2", "docker run" + finish exception: [ "Kamal::Cli::BootError", "Exception while executing on web: 10.0.0.2 did not boot" ] assert_match "✔ 1 ok", rendered assert_match "✖ 1 failed", rendered @@ -88,14 +99,24 @@ class OutputConsoleLoggerTest < ActiveSupport::TestCase start say "Boot app..." host_line "10.0.0.1", "clean output line" - host_line "10.0.0.2", "failing output line", severity: Logger::ERROR - finish + host_line "10.0.0.2", "failing output line" + finish exception: [ "Kamal::Cli::BootError", "Exception while executing on web: 10.0.0.2 did not boot" ] assert_match "retained output · 10.0.0.2", rendered assert_match "failing output line", rendered refute_match "clean output line", rendered end + test "verbose disables the condensed view so the raw firehose shows instead" do + @logger.disable! + start + say "Boot app..." + host_line "10.0.0.1", "docker run" + finish + + assert_empty rendered + end + test "host output before any marker opens an implicit phase" do start host_line "10.0.0.1", "docker run" @@ -116,14 +137,20 @@ class OutputConsoleLoggerTest < ActiveSupport::TestCase end private - def config_double + def build_logger(hosts: %w[ 10.0.0.1 10.0.0.2 10.0.0.3 ]) + Kamal::Output::ConsoleLogger.new(config: config_double(hosts), settings: { "color" => false }, output: @output) + end + + def config_double(hosts) Class.new do + def initialize(hosts); @hosts = hosts; end def service; "myapp"; end def destination; "production"; end - def all_hosts; %w[ 10.0.0.1 10.0.0.2 10.0.0.3 ]; end + attr_reader :hosts + alias_method :all_hosts, :hosts def roles; %i[ web worker ]; end def abbreviated_version; "abc1234"; end - end.new + end.new(hosts) end def start(command: "deploy", **payload) @@ -138,17 +165,16 @@ def say(message, color: :magenta) with_context(say_color: color) { @logger << "#{message}\n" } end - def host_line(host, message, severity: nil) - with_context(host: host, severity: severity) { @logger << "#{message}\n" } + def host_line(host, message) + with_context(host: host) { @logger << "#{message}\n" } end - def with_context(host: nil, say_color: nil, severity: nil) + def with_context(host: nil, say_color: nil) Thread.current[:kamal_host] = host Thread.current[:kamal_say_color] = say_color - Thread.current[:kamal_severity] = severity yield ensure - Thread.current[:kamal_host] = Thread.current[:kamal_say_color] = Thread.current[:kamal_severity] = nil + Thread.current[:kamal_host] = Thread.current[:kamal_say_color] = nil end def rendered From fc03431021433a9ba96be1063bbdf920809a0891 Mon Sep 17 00:00:00 2001 From: Eron Nicholson Date: Fri, 24 Jul 2026 13:33:52 -0400 Subject: [PATCH 4/4] Address review: distinguish phase markers from notices; close null FD on reset - Only magenta say markers open a phase; red/yellow (errors/warnings) and any colorless say now render as notices instead of spurious phases, and a say is flagged by origin so non-magenta messages no longer disappear from the terminal. TTY notices buffer during a phase and flush once its spinners resolve, so the live region isn't corrupted. - Close @null_output before niling it in reset so repeated commands in a long-lived process (aliases) don't leak a /dev/null FD. Co-Authored-By: Claude Opus 4.8 (1M context) --- lib/kamal/cli/base.rb | 12 +++++----- lib/kamal/commander.rb | 1 + lib/kamal/output/console/plain_renderer.rb | 4 ++++ lib/kamal/output/console/renderer.rb | 1 + lib/kamal/output/console/tty_renderer.rb | 18 +++++++++++++++ lib/kamal/output/console_logger.rb | 16 +++++++++++-- test/output/console_logger_test.rb | 26 +++++++++++++++++++--- 7 files changed, 68 insertions(+), 10 deletions(-) diff --git a/lib/kamal/cli/base.rb b/lib/kamal/cli/base.rb index 53fe935bb..2eb0d1623 100644 --- a/lib/kamal/cli/base.rb +++ b/lib/kamal/cli/base.rb @@ -91,15 +91,17 @@ def modify(lock: false) end def say(message = "", color = nil, *) - # A console backend renders the markers itself, but only while it's - # active (inside a modify block, i.e. KAMAL.logging). Outside of that - # — e.g. read-only commands — fall back to printing normally. + # A console backend renders say output itself, but only while it's active + # (inside a modify block, i.e. KAMAL.logging). Outside of that — e.g. + # read-only commands — fall back to printing normally. super unless options[:raw] || (KAMAL.console_output? && KAMAL.logging) - # Expose the color to the console backend so it can tell phase markers - # (say ..., :magenta) apart from the rest of the logged line stream. + # Flag the origin and color so the console backend can tell phase markers + # (say ..., :magenta) from notices (errors/warnings) in the line stream. + Thread.current[:kamal_say] = true Thread.current[:kamal_say_color] = color KAMAL.log(message.to_s) ensure + Thread.current[:kamal_say] = nil Thread.current[:kamal_say_color] = nil end diff --git a/lib/kamal/commander.rb b/lib/kamal/commander.rb index 57fac8636..3662421c2 100644 --- a/lib/kamal/commander.rb +++ b/lib/kamal/commander.rb @@ -22,6 +22,7 @@ def reset self.lock_wait_timeout = 900 self.lock_wait_interval = 15 @console_output = false + @null_output&.close @null_output = nil @modify_depth = 0 @specifics = @specific_roles = @specific_hosts = nil diff --git a/lib/kamal/output/console/plain_renderer.rb b/lib/kamal/output/console/plain_renderer.rb index 045e94610..d3f2b467a 100644 --- a/lib/kamal/output/console/plain_renderer.rb +++ b/lib/kamal/output/console/plain_renderer.rb @@ -24,6 +24,10 @@ def end_phase(statuses) end end + def notice(message, color) + puts color ? pastel.decorate(message, color) : message + end + def summary(ok:, failed:, needs_attention:, runtime:, exception:) counts = [ pastel.green("#{OK} #{ok} ok") ] counts << pastel.red("#{FAIL} #{failed} failed") if failed > 0 diff --git a/lib/kamal/output/console/renderer.rb b/lib/kamal/output/console/renderer.rb index 071f3e430..535635d36 100644 --- a/lib/kamal/output/console/renderer.rb +++ b/lib/kamal/output/console/renderer.rb @@ -20,6 +20,7 @@ def header(command:, service:, version:, destination:, hosts:, roles:); end def phase(name); end def host_active(host); end def end_phase(statuses); end + def notice(message, color); end def summary(ok:, failed:, needs_attention:, runtime:, exception:); end def replay(host, lines); end def host_error(host); end diff --git a/lib/kamal/output/console/tty_renderer.rb b/lib/kamal/output/console/tty_renderer.rb index 29416e083..9f35f01dc 100644 --- a/lib/kamal/output/console/tty_renderer.rb +++ b/lib/kamal/output/console/tty_renderer.rb @@ -29,6 +29,17 @@ def host_active(host) spinner.auto_spin end + # tty-spinner has no safe way to print between its live spinners, so hold + # notices raised during a phase and flush them once the phase resolves. + def notice(message, color) + line = color ? pastel.decorate(message, color) : message + if @multi + (@pending_notices ||= []) << line + else + puts line + end + end + def end_phase(statuses) return super unless @multi @@ -52,5 +63,12 @@ def finish_multi @spinners.each_value { |spinner| spinner.stop if spinner.spinning? } @multi = nil @spinners = {} + flush_notices + end + + def flush_notices + return unless @pending_notices + @pending_notices.each { |line| puts line } + @pending_notices = nil end end diff --git a/lib/kamal/output/console_logger.rb b/lib/kamal/output/console_logger.rb index a709ff131..c310a5e1b 100644 --- a/lib/kamal/output/console_logger.rb +++ b/lib/kamal/output/console_logger.rb @@ -45,6 +45,7 @@ def disable! def <<(message) host = Thread.current[:kamal_host] + say = Thread.current[:kamal_say] say_color = Thread.current[:kamal_say_color] synchronize do @@ -52,8 +53,8 @@ def <<(message) if host record_host_output(host.to_s, message) - elsif say_color - begin_phase(message) + elsif say + record_say(message, say_color) end end end @@ -105,6 +106,17 @@ def reset_state # --- Event handling (all called while holding the mutex) --- + # say ..., :magenta narrates a deploy phase; other colors (:red, :yellow) are + # errors/warnings — surface them as notices rather than opening a phase. + def record_say(message, color) + if color == :magenta + begin_phase(message) + else + text = message.to_s.strip + renderer.notice(text, color) unless text.empty? + end + end + def begin_phase(message) end_phase @current_phase = clean_phase(message) diff --git a/test/output/console_logger_test.rb b/test/output/console_logger_test.rb index 158b17971..87f9880b6 100644 --- a/test/output/console_logger_test.rb +++ b/test/output/console_logger_test.rb @@ -117,6 +117,25 @@ class OutputConsoleLoggerTest < ActiveSupport::TestCase assert_empty rendered end + test "only magenta say markers open phase sections" do + start + say "Build and push app image...", color: :magenta + say "Skipping something", color: :yellow + finish + + assert_match "❯ Build and push app image", rendered + refute_match "❯ Skipping something", rendered + end + + test "non-phase say output is surfaced as a notice, not dropped" do + start + say "Boot app...", color: :magenta + say "Aborted", color: :red + finish + + assert_match "Aborted", rendered + end + test "host output before any marker opens an implicit phase" do start host_line "10.0.0.1", "docker run" @@ -162,19 +181,20 @@ def finish(exception: nil) end def say(message, color: :magenta) - with_context(say_color: color) { @logger << "#{message}\n" } + with_context(say: true, say_color: color) { @logger << "#{message}\n" } end def host_line(host, message) with_context(host: host) { @logger << "#{message}\n" } end - def with_context(host: nil, say_color: nil) + def with_context(host: nil, say: nil, say_color: nil) Thread.current[:kamal_host] = host + Thread.current[:kamal_say] = say Thread.current[:kamal_say_color] = say_color yield ensure - Thread.current[:kamal_host] = Thread.current[:kamal_say_color] = nil + Thread.current[:kamal_host] = Thread.current[:kamal_say] = Thread.current[:kamal_say_color] = nil end def rendered