spacebar/kamal
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge pull request #958 from basecamp/optional-timestamps

Browse Source 
Add option to skip timestamps on logging output
This commit is contained in:
David Heinemeier Hansson
2024-09-20 18:01:14 +02:00
committed by GitHub
parent 6df169a4fb 04d21f45bb
commit 3172adca30
11 changed files with 60 additions and 36 deletions
Download Patch File Download Diff File Expand all files Collapse all files

8
lib/kamal/cli/accessory.rb
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_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

8
lib/kamal/cli/app.rb
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_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

8
lib/kamal/cli/proxy.rb
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 :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

8
lib/kamal/commands/accessory.rb
View File

@@ -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

8
lib/kamal/commands/app/logging.rb
View File

@@ -1,16 +1,16 @@
module Kamal::Commands::App::Logging
def logs(version: nil, since: nil, lines: nil, grep: nil, grep_options: nil)
def logs(version: nil, timestamps: true, since: nil, lines: nil, grep: nil, grep_options: nil)
pipe \
version ? container_id_for_version(version) : current_running_container_id,
"xargs docker logs#{" --since #{since}" if since}#{" --tail #{lines}" if lines} 2>&1",
"xargs docker logs#{" --timestamps" if timestamps}#{" --since #{since}" if since}#{" --tail #{lines}" if lines} 2>&1",
("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

8
lib/kamal/commands/proxy.rb
View File

@@ -35,15 +35,15 @@ 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

6
test/cli/app_test.rb
View File

@@ -315,11 +315,11 @@ class CliAppTest < CliTestCase
SSHKit::Backend::Abstract.any_instance.stubs(:exec)
.with("ssh -t root@1.1.1.1 '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 10 2>&1'")
assert_match "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 100 2>&1", run_command("logs")
assert_match "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 100 2>&1", run_command("logs")
assert_match "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 2>&1 | grep 'hey'", run_command("logs", "--grep", "hey")
assert_match "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 2>&1 | grep 'hey'", run_command("logs", "--grep", "hey")
assert_match "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 2>&1 | grep 'hey' -C 2", run_command("logs", "--grep", "hey", "--grep-options", "-C 2")
assert_match "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 2>&1 | grep 'hey' -C 2", run_command("logs", "--grep", "hey", "--grep-options", "-C 2")
end
test "logs with follow" do

8
test/commands/accessory_test.rb
View File

@@ -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

20
test/commands/app_test.rb
View File

@@ -129,49 +129,49 @@ class CommandsAppTest < ActiveSupport::TestCase
test "logs" do
assert_equal \
"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 2>&1",
"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 2>&1",
new_command.logs.join(" ")
end
test "logs with since" do
assert_equal \
"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 --since 5m 2>&1",
"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 --since 5m 2>&1",
new_command.logs(since: "5m").join(" ")
end
test "logs with lines" do
assert_equal \
"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 100 2>&1",
"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 100 2>&1",
new_command.logs(lines: "100").join(" ")
end
test "logs with since and lines" do
assert_equal \
"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 --since 5m --tail 100 2>&1",
"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 --since 5m --tail 100 2>&1",
new_command.logs(since: "5m", lines: "100").join(" ")
end
test "logs with grep" do
assert_equal \
"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 2>&1 | grep 'my-id'",
"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 2>&1 | grep 'my-id'",
new_command.logs(grep: "my-id").join(" ")
end
test "logs with grep and grep options" do
assert_equal \
"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 2>&1 | grep 'my-id' -C 2",
"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 2>&1 | grep 'my-id' -C 2",
new_command.logs(grep: "my-id", grep_options: "-C 2").join(" ")
end
test "logs with since, grep and grep options" do
assert_equal \
"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 --since 5m 2>&1 | grep 'my-id' -C 2",
"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 --since 5m 2>&1 | grep 'my-id' -C 2",
new_command.logs(since: "5m", grep: "my-id", grep_options: "-C 2").join(" ")
end
test "logs with since and grep" do
assert_equal \
"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 --since 5m 2>&1 | grep 'my-id'",
"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 --since 5m 2>&1 | grep 'my-id'",
new_command.logs(since: "5m", grep: "my-id").join(" ")
end
@@ -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

6
test/commands/proxy_test.rb
View File

@@ -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!'",