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.
This commit is contained in:
David Heinemeier Hansson
2024-09-20 07:42:31 -07:00
parent a4e5dbe5d4
commit 384b36d158
9 changed files with 45 additions and 19 deletions

View File

@@ -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, 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 :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 :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) def logs(name)
with_accessory(name) do |accessory, hosts| with_accessory(name) do |accessory, hosts|
grep = options[:grep] grep = options[:grep]
grep_options = options[:grep_options] grep_options = options[:grep_options]
timestamps = !options[:skip_timestamps]
if options[:follow] if options[:follow]
run_locally do run_locally do
info "Following logs on #{hosts}..." info "Following logs on #{hosts}..."
info 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(grep: grep, grep_options: grep_options) exec accessory.follow_logs(timestamps: timestamps, grep: grep, grep_options: grep_options)
end end
else else
since = options[:since] since = options[:since]
lines = options[:lines].presence || ((since || grep) ? nil : 100) # Default to 100 lines if since or grep isn't set lines = options[:lines].presence || ((since || grep) ? nil : 100) # Default to 100 lines if since or grep isn't set
on(hosts) do 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 end
end end

View File

@@ -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, 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 :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 :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 def logs
# FIXME: Catch when app containers aren't running # FIXME: Catch when app containers aren't running
grep = options[:grep] grep = options[:grep]
grep_options = options[:grep_options] grep_options = options[:grep_options]
since = options[:since] since = options[:since]
timestamps = !options[:skip_timestamps]
if options[:follow] if options[:follow]
lines = options[:lines].presence || ((since || grep) ? nil : 10) # Default to 10 lines if since or grep isn't set 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 role = KAMAL.roles_on(KAMAL.primary_host).first
app = KAMAL.app(role: role, host: host) app = KAMAL.app(role: role, host: host)
info 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, 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 end
else else
lines = options[:lines].presence || ((since || grep) ? nil : 100) # Default to 100 lines if since or grep isn't set 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| roles.each do |role|
begin 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 rescue SSHKit::Command::Failed
puts_by_host host, "Nothing found" puts_by_host host, "Nothing found"
end end

View File

@@ -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 :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 :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 :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 def logs
grep = options[:grep] grep = options[:grep]
timestamps = !options[:skip_timestamps]
if options[:follow] if options[:follow]
run_locally do run_locally do
info "Following logs on #{KAMAL.primary_host}..." info "Following logs on #{KAMAL.primary_host}..."
info 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, grep: grep) exec KAMAL.proxy.follow_logs(host: KAMAL.primary_host, timestamps: timestamps, grep: grep)
end end
else else
since = options[:since] since = options[:since]
lines = options[:lines].presence || ((since || grep) ? nil : 100) # Default to 100 lines if since or grep isn't set 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| 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 end
end end

View File

@@ -39,16 +39,16 @@ class Kamal::Commands::Accessory < Kamal::Commands::Base
end 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 \ 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) ("grep '#{grep}'#{" #{grep_options}" if grep_options}" if grep)
end end
def follow_logs(grep: nil, grep_options: nil) def follow_logs(timestamps: true, grep: nil, grep_options: nil)
run_over_ssh \ run_over_ssh \
pipe \ 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) (%(grep "#{grep}"#{" #{grep_options}" if grep_options}) if grep)
end end

View File

@@ -6,11 +6,11 @@ module Kamal::Commands::App::Logging
("grep '#{grep}'#{" #{grep_options}" if grep_options}" if grep) ("grep '#{grep}'#{" #{grep_options}" if grep_options}" if grep)
end 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 \ run_over_ssh \
pipe( pipe(
current_running_container_id, 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) (%(grep "#{grep}"#{" #{grep_options}" if grep_options}) if grep)
), ),
host: host host: host

View File

@@ -35,15 +35,17 @@ class Kamal::Commands::Proxy < Kamal::Commands::Base
[ :cut, "-d:", "-f2" ] [ :cut, "-d:", "-f2" ]
end 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 \ 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) ("grep '#{grep}'#{" #{grep_options}" if grep_options}" if grep)
end 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( 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) (%(grep "#{grep}"#{" #{grep_options}" if grep_options}) if grep)
).join(" "), host: host ).join(" "), host: host
end end

View File

@@ -130,12 +130,20 @@ class CommandsAccessoryTest < ActiveSupport::TestCase
assert_equal \ assert_equal \
"docker logs app-mysql --since 5m --tail 100 --timestamps 2>&1 | grep 'thing' -C 2", "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(" ") 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 end
test "follow logs" do test "follow logs" do
assert_equal \ assert_equal \
"ssh -t root@1.1.1.5 -p 22 'docker logs app-mysql --timestamps --tail 10 --follow 2>&1'", "ssh -t root@1.1.1.5 -p 22 'docker logs app-mysql --timestamps --tail 10 --follow 2>&1'",
new_command(:mysql).follow_logs 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 end
test "remove container" do test "remove container" do

View File

@@ -191,6 +191,10 @@ class CommandsAppTest < ActiveSupport::TestCase
assert_equal \ 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\"'", "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") 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 end

View File

@@ -77,6 +77,12 @@ class CommandsProxyTest < ActiveSupport::TestCase
new_command.logs(lines: 10).join(" ") new_command.logs(lines: 10).join(" ")
end 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 test "proxy logs with grep hello!" do
assert_equal \ assert_equal \
"docker logs kamal-proxy --timestamps 2>&1 | grep 'hello!'", "docker logs kamal-proxy --timestamps 2>&1 | grep 'hello!'",