Show container logs and healthcheck status on failure

Author: djmb

lib/kamal/cli/app.rb

@@ -15,7 +15,7 @@ def boot
           end
 
           #  Primary hosts and roles are returned first, so they can open the barrier
-          barrier = Kamal::Cli::Healthcheck::Barrier.new if KAMAL.roles.many?
+          barrier = Kamal::Cli::Healthcheck::Barrier.new
 
           on(KAMAL.hosts, **KAMAL.boot_strategy) do |host|
             KAMAL.roles_on(host).each do |role|

lib/kamal/cli/app/boot.rb

@@ -1,6 +1,6 @@
 class Kamal::Cli::App::Boot
   attr_reader :host, :role, :version, :barrier, :sshkit
-  delegate :execute, :capture_with_info, :info, to: :sshkit
+  delegate :execute, :capture_with_info, :capture_with_pretty_json, :info, :error, to: :sshkit
   delegate :uses_cord?, :assets?, :running_traefik?, to: :role
 
   def initialize(host, role, sshkit, version, barrier)
@@ -43,7 +43,11 @@ def start_new_version
 
       reach_barrier
     rescue => e
-      close_barrier if barrier_role?
+      if barrier_role? && barrier.close
+        info "Deploy failed, so closed barrier (#{host})"
+        error capture_with_info(*app.logs(version: version))
+        error capture_with_info(*app.container_health_log(version: version))
+      end
       execute *app.stop(version: version), raise_on_non_zero_exit: false
 
       raise
@@ -80,14 +84,10 @@ def wait_for_barrier
       barrier.wait
       info "Barrier opened (#{host})"
     rescue Kamal::Cli::Healthcheck::Error
-      info "Barrier closed, shutting down new container... (#{host})"
+      info "Barrier closed, shutting down new container (#{host})..."
       raise
     end
 
-    def close_barrier
-      barrier&.close
-    end
-
     def barrier_role?
       role == KAMAL.primary_role
     end

lib/kamal/commands/app/containers.rb

@@ -1,4 +1,6 @@
 module Kamal::Commands::App::Containers
+  DOCKER_HEALTH_LOG_FORMAT    = "'{{json .State.Health}}'"
+
   def list_containers
     docker :container, :ls, "--all", *filter_args
   end
@@ -20,4 +22,10 @@ def rename_container(version:, new_version:)
   def remove_containers
     docker :container, :prune, "--force", *filter_args
   end
+
+  def container_health_log(version:)
+    pipe \
+      container_id_for(container_name: container_name(version)),
+      xargs(docker(:inspect, "--format", DOCKER_HEALTH_LOG_FORMAT))
+  end
 end

lib/kamal/commands/app/logging.rb

@@ -1,7 +1,7 @@
 module Kamal::Commands::App::Logging
-  def logs(since: nil, lines: nil, grep: nil)
+  def logs(version: nil, since: nil, lines: nil, grep: nil)
     pipe \
-      current_running_container_id,
+      version ? container_id_for_version(version) : current_running_container_id,
       "xargs docker logs#{" --since #{since}" if since}#{" --tail #{lines}" if lines} 2>&1",
       ("grep '#{grep}'" if grep)
   end

lib/kamal/commands/base.rb

@@ -3,7 +3,6 @@ class Base
     delegate :sensitive, :argumentize, to: Kamal::Utils
 
     DOCKER_HEALTH_STATUS_FORMAT = "'{{if .State.Health}}{{.State.Health.Status}}{{else}}{{.State.Status}}{{end}}'"
-    DOCKER_HEALTH_LOG_FORMAT    = "'{{json .State.Health}}'"
 
     attr_accessor :config
 

test/cli/app_test.rb

@@ -136,8 +136,8 @@ class CliAppTest < CliTestCase
       run_command("boot", config: :with_roles, host: nil, allow_execute_error: true).tap do |output|
         assert_match "Waiting at web barrier (1.1.1.3)...", output
         assert_match "Waiting at web barrier (1.1.1.4)...", output
-        assert_match "Barrier closed, shutting down new container... (1.1.1.3)", output
-        assert_match "Barrier closed, shutting down new container... (1.1.1.4)", output
+        assert_match "Barrier closed, shutting down new container (1.1.1.3)...", output
+        assert_match "Barrier closed, shutting down new container (1.1.1.4)...", output
         assert_match "Running docker container ls --all --filter name=^app-web-latest$ --quiet | xargs docker stop on 1.1.1.1", output
         assert_match "Running docker container ls --all --filter name=^app-web-latest$ --quiet | xargs docker stop on 1.1.1.2", output
         assert_match "Running docker container ls --all --filter name=^app-workers-latest$ --quiet | xargs docker stop on 1.1.1.3", output

test/integration/broken_deploy_test.rb

@@ -15,10 +15,20 @@ class BrokenDeployTest < IntegrationTest
 
     second_version = break_app
 
-    kamal :deploy, raise_on_error: false
+    output = kamal :deploy, raise_on_error: false, capture: true
 
+    assert_failed_deploy output
     assert_app_is_up version: first_version
     assert_container_running host: :vm3, name: "app-workers-#{first_version}"
     assert_container_not_running host: :vm3, name: "app-workers-#{second_version}"
   end
+
+  private
+    def assert_failed_deploy(output)
+      assert_match "Waiting at web barrier (vm3)...", output
+      assert_match /Deploy failed, so closed barrier \(vm[12]\)/, output
+      assert_match "Barrier closed, shutting down new container (vm3)...", output
+      assert_match "nginx: [emerg] unexpected end of file, expecting \";\" or \"}\" in /etc/nginx/conf.d/default.conf:2", output
+      assert_match 'ERROR {"Status":"unhealthy","FailingStreak":0,"Log":[]}', output
+    end
 end