Improve healthcheck logging

README.md

@@ -714,7 +714,7 @@ servers:
 
 The healthcheck allows for an optional `max_attempts` setting, which will attempt the healthcheck up to the specified number of times before failing the deploy. This is useful for applications that take a while to start up. The default is 7.
 
-Note that the HTTP health checks assume that the `curl` command is avilable inside the container. If that's not the case, use the healthcheck's `cmd` option to specify an alternative check that the container supports.
+Note: The HTTP health checks assume that the `curl` command is available inside the container. If that's not the case, use the healthcheck's `cmd` option to specify an alternative check that the container supports.
 
 ## Commands
 

lib/mrsk/cli/healthcheck.rb

@@ -9,6 +9,7 @@ def perform
         Mrsk::Utils::HealthcheckPoller.wait_for_healthy { capture_with_info(*MRSK.healthcheck.status) }
       rescue Mrsk::Utils::HealthcheckPoller::HealthcheckError => e
         error capture_with_info(*MRSK.healthcheck.logs)
+        error capture_with_pretty_json(*MRSK.healthcheck.container_health_log)
         raise
       ensure
         execute *MRSK.healthcheck.stop, raise_on_non_zero_exit: false

lib/mrsk/commands/base.rb

@@ -3,6 +3,7 @@ class Base
     delegate :sensitive, :argumentize, to: Mrsk::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
 

lib/mrsk/commands/healthcheck.rb

@@ -22,6 +22,10 @@ def status
     pipe container_id, xargs(docker(:inspect, "--format", DOCKER_HEALTH_STATUS_FORMAT))
   end
 
+  def container_health_log
+    pipe container_id, xargs(docker(:inspect, "--format", DOCKER_HEALTH_LOG_FORMAT))
+  end
+
   def logs
     pipe container_id, xargs(docker(:logs, "--tail", 50, "2>&1"))
   end

lib/mrsk/sshkit_with_ext.rb

@@ -1,5 +1,6 @@
 require "sshkit"
 require "sshkit/dsl"
+require "json"
 
 class SSHKit::Backend::Abstract
   def capture_with_info(*args, **kwargs)
@@ -9,4 +10,8 @@ def capture_with_info(*args, **kwargs)
   def puts_by_host(host, output, type: "App")
     puts "#{type} Host: #{host}\n#{output}\n\n"
   end
+
+  def capture_with_pretty_json(*args, **kwargs)
+    JSON.pretty_generate(JSON.parse(capture(*args, **kwargs)))
+  end
 end

test/cli/healthcheck_test.rb

@@ -53,6 +53,11 @@ class CliHealthcheckTest < CliTestCase
       .with(:docker, :container, :ls, "--all", "--filter", "name=^healthcheck-app-999$", "--quiet", "|", :xargs, :docker, :logs, "--tail", 50, "2>&1")
       .returns("some log output")
 
+    # Capture container health log when failing
+    SSHKit::Backend::Abstract.any_instance.stubs(:capture_with_pretty_json)
+      .with(:docker, :container, :ls, "--all", "--filter", "name=^healthcheck-app-999$", "--quiet", "|", :xargs, :docker, :inspect, "--format",  "'{{json .State.Health}}'")
+      .returns('{"Status":"unhealthy","Log":[{"ExitCode": 1,"Output": "/bin/sh: 1: curl: not found\n"}]}"')
+
     exception = assert_raises do
       run_command("perform")
     end

test/commands/healthcheck_test.rb

@@ -51,6 +51,12 @@ class CommandsHealthcheckTest < ActiveSupport::TestCase
       new_command.status.join(" ")
   end
 
+  test "container_health_log" do
+    assert_equal \
+      "docker container ls --all --filter name=^healthcheck-app-123$ --quiet | xargs docker inspect --format '{{json .State.Health}}'",
+      new_command.container_health_log.join(" ")
+  end
+
   test "stop" do
     assert_equal \
       "docker container ls --all --filter name=^healthcheck-app-123$ --quiet | xargs docker stop",