I'm including part of the log below. I have the full log saved if needed.
lein parallel-test :only waiter.deployment-errors-test/test-health-check-timed-out
FAIL in (test-health-check-timed-out) (deployment_errors_test.clj:89)
test-health-check-timed-out
router->service-state:
{"2301af2d04-586356b53c4f6dcf"
{:router-id "2301af2d04-586356b53c4f6dcf",
:state
{:scheduler-state
{:id->instance
{:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142
{:extra-ports [],
:service-id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:protocol "http",
:started-at "2018-04-05T19:16:50.759Z",
:port 10010,
:log-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142",
:host "127.0.0.6",
:killed? true,
:pid 5907,
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142",
:healthy? false,
:working-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142",
:flags ["never-passed-health-checks"],
:failed? true},
:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe
{:extra-ports [],
:service-id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:protocol "http",
:started-at "2018-04-05T19:17:10.342Z",
:port 10002,
:log-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe",
:host "127.0.0.4",
:killed? true,
:pid 5949,
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe",
:healthy? false,
:working-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe",
:flags ["never-passed-health-checks"],
:failed? true},
:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f
{:extra-ports [],
:service-id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:protocol "http",
:started-at "2018-04-05T19:17:30.348Z",
:process "java.lang.UNIXProcess@50093915",
:port 10001,
:log-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:host "127.0.0.3",
:pid 5988,
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:healthy? false,
:working-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:flags []}},
:instance-id->failed-health-check-count
{:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f
1},
:instance-id->tracked-failed-instance
{:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142
{:extra-ports [],
:service-id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:protocol "http",
:started-at "2018-04-05T19:16:50.759Z",
:process "java.lang.UNIXProcess@72cfbadb",
:port 10010,
:log-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142",
:host "127.0.0.6",
:pid 5907,
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142",
:healthy? false,
:working-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.4c718e104a-5008eef843df6142",
:flags
["has-responded" "has-connected" "never-passed-health-checks"]},
:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe
{:extra-ports [],
:service-id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:protocol "http",
:started-at "2018-04-05T19:17:10.342Z",
:process "java.lang.UNIXProcess@4469b76e",
:port 10002,
:log-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe",
:host "127.0.0.4",
:pid 5949,
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe",
:healthy? false,
:working-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.5100b51fc7-522c8546277e7abe",
:flags
["has-responded" "has-connected" "never-passed-health-checks"]}},
:instance-id->unhealthy-instance
{:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f
{:extra-ports [],
:service-id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:protocol "http",
:started-at "2018-04-05T19:17:30.348Z",
:process "java.lang.UNIXProcess@50093915",
:port 10001,
:log-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:host "127.0.0.3",
:pid 5988,
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:healthy? false,
:working-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:flags ["has-connected"]}},
:last-update-time "2018-04-05T19:17:35.367Z",
:service
{:environment
{:HOME "/home/travis/build/twosigma/waiter/waiter/scheduler",
:LOGNAME "travis",
:USER "travis",
:WAITER_CPUS "0.1",
:WAITER_MEM_MB "256",
:WAITER_PASSWORD "dec7c87f26cd47c06e4213271b80432a",
:WAITER_USERNAME "waiter"},
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:instances 1,
:service-description
{:max-queue-length 1000000,
:idle-timeout-mins 10,
:mem 256,
:min-instances 1,
:interstitial-secs 0,
:name "testhealthchecktimedouttravis341824",
:grace-period-secs 15,
:env {},
:max-instances 500,
:cmd-type "shell",
:scale-up-factor 0.1,
:concurrency-level 1,
:permitted-user "travis",
:run-as-user "travis",
:ports 1,
:health-check-max-consecutive-failures 1,
:authentication "standard",
:health-check-interval-secs 5,
:scale-down-factor 0.001,
:restart-backoff-factor 2,
:instance-expiry-mins 7200,
:cmd
"/home/travis/build/twosigma/waiter/waiter/bin/ci/../../../kitchen/bin/run.sh -p $PORT0",
:distribution-scheme "balanced",
:scale-factor 1,
:version "version-does-not-matter",
:health-check-url "/sleep?sleep-ms=300000&status=400",
:blacklist-on-503 true,
:metadata {},
:jitter-threshold 0.5,
:expired-instance-restart-rate 0.1,
:backend-proto "http",
:metric-group "waiter_kitchen",
:cpus 0.1},
:task-count 1,
:task-stats {:healthy 0, :running 1, :staged 0, :unhealthy 1},
:mem 256}},
:autoscaler-state
{:expired-instances 0,
:healthy-instances 0,
:instances 1,
:outstanding-requests 1,
:scale-amount 0,
:scale-to-instances 1,
:target-instances 1.0,
:task-count 1},
:scheduler-services-gc-state {},
:autoscaling-multiplexer-state "no-data-available",
:app-maintainer-state
{:last-state-update-time "2018-04-05T19:17:35.367Z",
:maintainer-chan-available true},
:responder-state
{:deployment-error "invalid-health-check-response",
:request-id->work-stealer {},
:work-stealing-queue [],
:instance-id->request-id->use-reason-map {},
:instance-id->consecutive-failures {},
:instance-id->blacklist-expiry-time {},
:instance-id->state
{:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f
{:slots-assigned 0,
:slots-used 0,
:status-tags ["starting" "unhealthy"]}},
:id->instance
{:waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f
{:extra-ports [],
:service-id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4",
:protocol "http",
:started-at "2018-04-05T19:17:30.348Z",
:process "java.lang.UNIXProcess@50093915",
:port 10001,
:log-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:host "127.0.0.3",
:pid 5988,
:id
"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:healthy? false,
:working-directory
"/home/travis/build/twosigma/waiter/waiter/scheduler/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4/waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f",
:flags ["has-connected"]}},
:sorted-instance-ids
["waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4.55a915066a-5c47a4c1dc5b114f"]},
:transient-metrics-gc-state
{:last-modified-time "2018-04-05T19:16:55.250Z",
:state {:alive? false, :outstanding 1, :total 1}},
:local-usage {:last-request-time "2018-04-05T19:16:50.734Z"},
:scheduler-broken-services-gc-state {},
:interstitial-maintainer-state {:available true},
:work-stealing-state
{:iteration 399,
:request-id->work-stealer {},
:router-id->help-required {},
:router-id->metrics
{:2301af2d04-586356b53c4f6dcf
{:last-request-time "2018-04-05T19:16:50.734Z",
:outstanding 0,
:slots-available 0,
:slots-in-use 0,
:slots-received 0,
:total 1}},
:slots {:offerable 0, :offered 0}}}}}
expected: (clojure.string/includes? body__43965__auto__ (waiter.deployment-errors-test/deployment-error->str waiter-url :health-check-timed-out))
actual: (not (clojure.string/includes? "\n Waiter Error 503\n ================\n \n Deployment error: Health check returned an invalid response\n \n Request Info\n ============\n \n Host: 127.0.0.1:9091\n Path: /endpoint\n Query String: \n Method: POST\n CID: test-health-check-timed-out-4c6fdb35ae-3e4ff9a8cd5fc42f\n Time: 2018-04-05T19:16:50.734Z\n Principal: travis\n Service Id: waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4\n \n \n Additional Info\n ===============\n \n {:service-id\n \"waiter-service-testhealthchecktimedouttravis341824-ab0f694fb3515294a9df919e1be7b7a4\",\n :status 503}\n \n Getting Help\n ============\n \n Waiter on GitHub: http://github.com/twosigma/waiter \n \n" "Deployment error: Health check timed out"))
�[34mFINISH:�[0m waiter.deployment-errors-test/test-health-check-timed-out �[36m45s�[0m {:test 8, :pass 819, :fail 1, :error 0}
�[1m�[35mSTART: �[0m waiter.deployment-errors-test/test-invalid-health-check-response
�[34mFINISH:�[0m waiter.request-timeout-test/test-request-queue-timeout-faulty-app �[36m16s�[0m {:test 9, :pass 826, :fail 1, :error 0}
lein parallel-test waiter.busy-instance-test # on thread 0
�[1m�[35mSTART: �[0m waiter.busy-instance-test/test-busy-instance-not-reserved
�[34mFINISH:�[0m waiter.deployment-errors-test/test-invalid-health-check-response �[36m50s�[0m {:test 10, :pass 829, :fail 1, :error 0}
�[1m�[35mSTART: �[0m waiter.deployment-errors-test/test-cannot-connect
�[34mFINISH:�[0m waiter.busy-instance-test/test-busy-instance-not-reserved �[36m45s�[0m {:test 11, :pass 830, :fail 1, :error 0}
lein parallel-test waiter.new-app-test # on thread 0
�[1m�[35mSTART: �[0m waiter.new-app-test/test-new-app-gc
�[34mFINISH:�[0m waiter.deployment-errors-test/test-cannot-connect �[36m37s�[0m {:test 12, :pass 833, :fail 1, :error 0}
lein parallel-test waiter.work-stealing-integration-test # on thread 1
�[1m�[35mSTART: �[0m waiter.work-stealing-integration-test/test-work-stealing-load-balancing
�[34mFINISH:�[0m waiter.new-app-test/test-new-app-gc �[36m88s�[0m {:test 13, :pass 834, :fail 1, :error 0}
�[34mFINISH:�[0m waiter.work-stealing-integration-test/test-work-stealing-load-balancing �[36m111s�[0m {:test 13, :pass 837, :fail 1, :error 0}
Longest running tests:
waiter.streaming-test/test-streaming-timeout-on-default-settings �[36m169s�[0m
waiter.work-stealing-integration-test/test-work-stealing-load-balancing �[36m111s�[0m
waiter.new-app-test/test-new-app-gc �[36m88s�[0m
waiter.deployment-errors-test/test-invalid-health-check-response �[36m50s�[0m
waiter.deployment-errors-test/test-health-check-timed-out �[36m45s�[0m
waiter.busy-instance-test/test-busy-instance-not-reserved �[36m45s�[0m
waiter.autoscaling-test/test-scaling-healthy-app �[36m43s�[0m
waiter.deployment-errors-test/test-cannot-connect �[36m37s�[0m
waiter.autoscaling-test/test-scaling-unhealthy-app �[36m30s�[0m
waiter.instance-reservation-test/test-instance-reservation-for-concurrent-service �[36m27s�[0m
Ran 13 tests containing 838 assertions.
1 failures, 0 errors.
Tests failed.
Error encountered performing task 'parallel-test' with profile(s): 'base,system,user,provided,dev,test-log'
Tests failed.