From 384b36d158550cc0754f7f11478036b232786f2b Mon Sep 17 00:00:00 2001 From: David Heinemeier Hansson Date: Fri, 20 Sep 2024 07:42:31 -0700 Subject: [PATCH] Add option to skip timestamps on logging output So it is easier to follow live when you are doing debugging, especially early days app setup when you are the only user. --- lib/kamal/cli/accessory.rb | 8 +++++--- lib/kamal/cli/app.rb | 8 +++++--- lib/kamal/cli/proxy.rb | 8 +++++--- lib/kamal/commands/accessory.rb | 8 ++++---- lib/kamal/commands/app/logging.rb | 4 ++-- lib/kamal/commands/proxy.rb | 10 ++++++---- test/commands/accessory_test.rb | 8 ++++++++ test/commands/app_test.rb | 4 ++++ test/commands/proxy_test.rb | 6 ++++++ 9 files changed, 45 insertions(+), 19 deletions(-) diff --git a/lib/kamal/cli/accessory.rb b/lib/kamal/cli/accessory.rb index dd56231e..45efbe6e 100644 --- a/lib/kamal/cli/accessory.rb +++ b/lib/kamal/cli/accessory.rb @@ -147,23 +147,25 @@ class Kamal::Cli::Accessory < Kamal::Cli::Base option :grep, aliases: "-g", desc: "Show lines with grep match only (use this to fetch specific requests by id)" option :grep_options, aliases: "-o", desc: "Additional options supplied to grep" option :follow, aliases: "-f", desc: "Follow logs on primary server (or specific host set by --hosts)" + option :skip_timestamps, aliases: "-T", desc: "Skip appending timestamps to logging output" def logs(name) with_accessory(name) do |accessory, hosts| grep = options[:grep] grep_options = options[:grep_options] + timestamps = !options[:skip_timestamps] if options[:follow] run_locally do info "Following logs on #{hosts}..." - info accessory.follow_logs(grep: grep, grep_options: grep_options) - exec accessory.follow_logs(grep: grep, grep_options: grep_options) + info accessory.follow_logs(timestamps: timestamps, grep: grep, grep_options: grep_options) + exec accessory.follow_logs(timestamps: timestamps, grep: grep, grep_options: grep_options) end else since = options[:since] lines = options[:lines].presence || ((since || grep) ? nil : 100) # Default to 100 lines if since or grep isn't set on(hosts) do - puts capture_with_info(*accessory.logs(since: since, lines: lines, grep: grep, grep_options: grep_options)) + puts capture_with_info(*accessory.logs(timestamps: timestamps, since: since, lines: lines, grep: grep, grep_options: grep_options)) end end end diff --git a/lib/kamal/cli/app.rb b/lib/kamal/cli/app.rb index d70d066b..2382951d 100644 --- a/lib/kamal/cli/app.rb +++ b/lib/kamal/cli/app.rb @@ -188,12 +188,14 @@ class Kamal::Cli::App < Kamal::Cli::Base option :grep, aliases: "-g", desc: "Show lines with grep match only (use this to fetch specific requests by id)" option :grep_options, aliases: "-o", desc: "Additional options supplied to grep" option :follow, aliases: "-f", desc: "Follow log on primary server (or specific host set by --hosts)" + option :skip_timestamps, aliases: "-T", desc: "Skip appending timestamps to logging output" def logs # FIXME: Catch when app containers aren't running grep = options[:grep] grep_options = options[:grep_options] since = options[:since] + timestamps = !options[:skip_timestamps] if options[:follow] lines = options[:lines].presence || ((since || grep) ? nil : 10) # Default to 10 lines if since or grep isn't set @@ -205,8 +207,8 @@ class Kamal::Cli::App < Kamal::Cli::Base role = KAMAL.roles_on(KAMAL.primary_host).first app = KAMAL.app(role: role, host: host) - info app.follow_logs(host: KAMAL.primary_host, lines: lines, grep: grep, grep_options: grep_options) - exec app.follow_logs(host: KAMAL.primary_host, lines: lines, grep: grep, grep_options: grep_options) + info app.follow_logs(host: KAMAL.primary_host, timestamps: timestamps, lines: lines, grep: grep, grep_options: grep_options) + exec app.follow_logs(host: KAMAL.primary_host, timestamps: timestamps, lines: lines, grep: grep, grep_options: grep_options) end else lines = options[:lines].presence || ((since || grep) ? nil : 100) # Default to 100 lines if since or grep isn't set @@ -216,7 +218,7 @@ class Kamal::Cli::App < Kamal::Cli::Base roles.each do |role| begin - puts_by_host host, capture_with_info(*KAMAL.app(role: role, host: host).logs(since: since, lines: lines, grep: grep, grep_options: grep_options)) + puts_by_host host, capture_with_info(*KAMAL.app(role: role, host: host).logs(timestamps: timestamps, since: since, lines: lines, grep: grep, grep_options: grep_options)) rescue SSHKit::Command::Failed puts_by_host host, "Nothing found" end diff --git a/lib/kamal/cli/proxy.rb b/lib/kamal/cli/proxy.rb index d006c8c6..0fc595b0 100644 --- a/lib/kamal/cli/proxy.rb +++ b/lib/kamal/cli/proxy.rb @@ -140,21 +140,23 @@ class Kamal::Cli::Proxy < Kamal::Cli::Base option :lines, type: :numeric, aliases: "-n", desc: "Number of log lines to pull from each server" option :grep, aliases: "-g", desc: "Show lines with grep match only (use this to fetch specific requests by id)" option :follow, aliases: "-f", desc: "Follow logs on primary server (or specific host set by --hosts)" + option :skip_timestamps, aliases: "-T", desc: "Skip appending timestamps to logging output" def logs grep = options[:grep] + timestamps = !options[:skip_timestamps] if options[:follow] run_locally do info "Following logs on #{KAMAL.primary_host}..." - info KAMAL.proxy.follow_logs(host: KAMAL.primary_host, grep: grep) - exec KAMAL.proxy.follow_logs(host: KAMAL.primary_host, grep: grep) + info KAMAL.proxy.follow_logs(host: KAMAL.primary_host, timestamps: timestamps, grep: grep) + exec KAMAL.proxy.follow_logs(host: KAMAL.primary_host, timestamps: timestamps, grep: grep) end else since = options[:since] lines = options[:lines].presence || ((since || grep) ? nil : 100) # Default to 100 lines if since or grep isn't set on(KAMAL.proxy_hosts) do |host| - puts_by_host host, capture(*KAMAL.proxy.logs(since: since, lines: lines, grep: grep)), type: "Proxy" + puts_by_host host, capture(*KAMAL.proxy.logs(timestamps: timestamps, since: since, lines: lines, grep: grep)), type: "Proxy" end end end diff --git a/lib/kamal/commands/accessory.rb b/lib/kamal/commands/accessory.rb index 787f7d43..0c1b9009 100644 --- a/lib/kamal/commands/accessory.rb +++ b/lib/kamal/commands/accessory.rb @@ -39,16 +39,16 @@ class Kamal::Commands::Accessory < Kamal::Commands::Base end - def logs(since: nil, lines: nil, grep: nil, grep_options: nil) + def logs(timestamps: true, since: nil, lines: nil, grep: nil, grep_options: nil) pipe \ - docker(:logs, service_name, (" --since #{since}" if since), (" --tail #{lines}" if lines), "--timestamps", "2>&1"), + docker(:logs, service_name, (" --since #{since}" if since), (" --tail #{lines}" if lines), ("--timestamps" if timestamps), "2>&1"), ("grep '#{grep}'#{" #{grep_options}" if grep_options}" if grep) end - def follow_logs(grep: nil, grep_options: nil) + def follow_logs(timestamps: true, grep: nil, grep_options: nil) run_over_ssh \ pipe \ - docker(:logs, service_name, "--timestamps", "--tail", "10", "--follow", "2>&1"), + docker(:logs, service_name, ("--timestamps" if timestamps), "--tail", "10", "--follow", "2>&1"), (%(grep "#{grep}"#{" #{grep_options}" if grep_options}) if grep) end diff --git a/lib/kamal/commands/app/logging.rb b/lib/kamal/commands/app/logging.rb index be8a4bad..31b1981e 100644 --- a/lib/kamal/commands/app/logging.rb +++ b/lib/kamal/commands/app/logging.rb @@ -6,11 +6,11 @@ module Kamal::Commands::App::Logging ("grep '#{grep}'#{" #{grep_options}" if grep_options}" if grep) end - def follow_logs(host:, lines: nil, grep: nil, grep_options: nil) + def follow_logs(host:, timestamps: true, lines: nil, grep: nil, grep_options: nil) run_over_ssh \ pipe( current_running_container_id, - "xargs docker logs --timestamps#{" --tail #{lines}" if lines} --follow 2>&1", + "xargs docker logs #{"--timestamps" if timestamps}#{" --tail #{lines}" if lines} --follow 2>&1", (%(grep "#{grep}"#{" #{grep_options}" if grep_options}) if grep) ), host: host diff --git a/lib/kamal/commands/proxy.rb b/lib/kamal/commands/proxy.rb index df264a6b..90d03141 100644 --- a/lib/kamal/commands/proxy.rb +++ b/lib/kamal/commands/proxy.rb @@ -35,15 +35,17 @@ class Kamal::Commands::Proxy < Kamal::Commands::Base [ :cut, "-d:", "-f2" ] end - def logs(since: nil, lines: nil, grep: nil, grep_options: nil) + def logs(timestamps: true, since: nil, lines: nil, grep: nil, grep_options: nil) pipe \ - docker(:logs, container_name, (" --since #{since}" if since), (" --tail #{lines}" if lines), "--timestamps", "2>&1"), + docker(:logs, container_name, (" --since #{since}" if since), (" --tail #{lines}" if lines), ("--timestamps" if timestamps), "2>&1"), ("grep '#{grep}'#{" #{grep_options}" if grep_options}" if grep) end - def follow_logs(host:, grep: nil, grep_options: nil) + def follow_logs(host:, timestamps: true, grep: nil, grep_options: nil) run_over_ssh pipe( - docker(:logs, container_name, "--timestamps", "--tail", "10", "--follow", "2>&1"), + docker(:logs, container_name), + ("--timestamps" if timestamps), + "--tail", "10", "--follow", "2>&1"), (%(grep "#{grep}"#{" #{grep_options}" if grep_options}) if grep) ).join(" "), host: host end diff --git a/test/commands/accessory_test.rb b/test/commands/accessory_test.rb index 19fe745d..f3d71ffd 100644 --- a/test/commands/accessory_test.rb +++ b/test/commands/accessory_test.rb @@ -130,12 +130,20 @@ class CommandsAccessoryTest < ActiveSupport::TestCase assert_equal \ "docker logs app-mysql --since 5m --tail 100 --timestamps 2>&1 | grep 'thing' -C 2", new_command(:mysql).logs(since: "5m", lines: 100, grep: "thing", grep_options: "-C 2").join(" ") + + assert_equal \ + "docker logs app-mysql --since 5m --tail 100 2>&1 | grep 'thing' -C 2", + new_command(:mysql).logs(timestamps: false, since: "5m", lines: 100, grep: "thing", grep_options: "-C 2").join(" ") end test "follow logs" do assert_equal \ "ssh -t root@1.1.1.5 -p 22 'docker logs app-mysql --timestamps --tail 10 --follow 2>&1'", new_command(:mysql).follow_logs + + assert_equal \ + "ssh -t root@1.1.1.5 -p 22 'docker logs app-mysql --tail 10 --follow 2>&1'", + new_command(:mysql).follow_logs(timestamps: false) end test "remove container" do diff --git a/test/commands/app_test.rb b/test/commands/app_test.rb index 57f8c2fe..23dd6c86 100644 --- a/test/commands/app_test.rb +++ b/test/commands/app_test.rb @@ -191,6 +191,10 @@ class CommandsAppTest < ActiveSupport::TestCase assert_equal \ "ssh -t root@app-1 -p 22 'sh -c '\\''docker ps --latest --quiet --filter label=service=app --filter label=role=web --filter status=running --filter status=restarting --filter ancestor=$(docker image ls --filter reference=dhh/app:latest --format '\\''\\'\\'''\\''{{.ID}}'\\''\\'\\'''\\'') ; docker ps --latest --quiet --filter label=service=app --filter label=role=web --filter status=running --filter status=restarting'\\'' | head -1 | xargs docker logs --timestamps --tail 123 --follow 2>&1 | grep \"Completed\"'", new_command.follow_logs(host: "app-1", lines: 123, grep: "Completed") + + assert_equal \ + "ssh -t root@app-1 -p 22 'sh -c '\\''docker ps --latest --quiet --filter label=service=app --filter label=role=web --filter status=running --filter status=restarting --filter ancestor=$(docker image ls --filter reference=dhh/app:latest --format '\\''\\'\\'''\\''{{.ID}}'\\''\\'\\'''\\'') ; docker ps --latest --quiet --filter label=service=app --filter label=role=web --filter status=running --filter status=restarting'\\'' | head -1 | xargs docker logs --tail 123 --follow 2>&1 | grep \"Completed\"'", + new_command.follow_logs(host: "app-1", timestamps: false, lines: 123, grep: "Completed") end diff --git a/test/commands/proxy_test.rb b/test/commands/proxy_test.rb index 4a4e029e..4f6275a2 100644 --- a/test/commands/proxy_test.rb +++ b/test/commands/proxy_test.rb @@ -77,6 +77,12 @@ class CommandsProxyTest < ActiveSupport::TestCase new_command.logs(lines: 10).join(" ") end + test "proxy logs without timestamps" do + assert_equal \ + "docker logs kamal-proxy 2>&1", + new_command.logs(timestamps: false).join(" ") + end + test "proxy logs with grep hello!" do assert_equal \ "docker logs kamal-proxy --timestamps 2>&1 | grep 'hello!'",