Merge pull request #958 from basecamp/optional-timestamps

Add option to skip timestamps on logging output

lib/kamal/cli/accessory.rb

@@ -147,23 +147,25 @@ def exec(name, cmd)
   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

lib/kamal/cli/app.rb

@@ -188,12 +188,14 @@ def images
   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 @@ def logs
         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 @@ def logs
 
         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

lib/kamal/cli/proxy.rb

@@ -140,21 +140,23 @@ def details
   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

lib/kamal/commands/accessory.rb

@@ -39,16 +39,16 @@ def info
   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
 

lib/kamal/commands/app/logging.rb

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

lib/kamal/commands/proxy.rb

@@ -35,15 +35,15 @@ def version
       [ :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

test/cli/app_test.rb

@@ -315,11 +315,11 @@ class CliAppTest < CliTestCase
     SSHKit::Backend::Abstract.any_instance.stubs(:exec)
       .with("ssh -t [email protected] '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

test/cli/proxy_test.rb

@@ -111,11 +111,11 @@ class CliProxyTest < CliTestCase
 
   test "logs" do
     SSHKit::Backend::Abstract.any_instance.stubs(:capture)
-      .with(:docker, :logs, "kamal-proxy", " --tail 100", "--timestamps", "2>&1")
+      .with(:docker, :logs, "kamal-proxy", "--tail 100", "--timestamps", "2>&1")
       .returns("Log entry")
 
     SSHKit::Backend::Abstract.any_instance.stubs(:capture)
-      .with(:docker, :logs, "proxy", " --tail 100", "--timestamps", "2>&1")
+      .with(:docker, :logs, "proxy", "--tail 100", "--timestamps", "2>&1")
       .returns("Log entry")
 
     run_command("logs").tap do |output|

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 [email protected] -p 22 'docker logs app-mysql --timestamps --tail 10 --follow 2>&1'",
       new_command(:mysql).follow_logs
+
+    assert_equal \
+      "ssh -t [email protected] -p 22 'docker logs app-mysql --tail 10 --follow 2>&1'",
+      new_command(:mysql).follow_logs(timestamps: false)
   end
 
   test "remove container" do