Details
Critical Description
We switched our health checks in Marathon from HTTP to COMMAND:
"healthChecks": [
{
"protocol": "COMMAND",
"path": "/ops/ping",
"command": { "value": "curl --silent -f -X GET http://$HOST:$PORT0/ops/ping > /dev/null" },
"gracePeriodSeconds": 90,
"intervalSeconds": 2,
"portIndex": 0,
"timeoutSeconds": 5,
"maxConsecutiveFailures": 3
}
]
All our applications have the same health check (and /ops/ping endpoint).
Even though we have the issue on all our Meos slaves, I'm going to focus on a particular one: mesos-slave-i-e3a9c724.
The slave has 16 gigs of memory, with about 12 gigs allocated for 8 tasks:
Here is a docker ps on it:
root@mesos-slave-i-e3a9c724 # docker ps CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 4f7c0aa8d03a java:8 "/bin/sh -c 'JAVA_OPT" 6 hours ago Up 6 hours 0.0.0.0:31926->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.3dbb1004-5bb8-432f-8fd8-b863bd29341d 66f2fc8f8056 java:8 "/bin/sh -c 'JAVA_OPT" 6 hours ago Up 6 hours 0.0.0.0:31939->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.60972150-b2b1-45d8-8a55-d63e81b8372a f7382f241fce java:8 "/bin/sh -c 'JAVA_OPT" 6 hours ago Up 6 hours 0.0.0.0:31656->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.39731a2f-d29e-48d1-9927-34ab8c5f557d 880934c0049e java:8 "/bin/sh -c 'JAVA_OPT" 24 hours ago Up 24 hours 0.0.0.0:31371->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.23dfe408-ab8f-40be-bf6f-ce27fe885ee0 5eab1f8dac4a java:8 "/bin/sh -c 'JAVA_OPT" 46 hours ago Up 46 hours 0.0.0.0:31500->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.5ac75198-283f-4349-a220-9e9645b313e7 b63740fe56e7 java:8 "/bin/sh -c 'JAVA_OPT" 46 hours ago Up 46 hours 0.0.0.0:31382->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.5d417f16-df24-49d5-a5b0-38a7966460fe 5c7a9ea77b0e java:8 "/bin/sh -c 'JAVA_OPT" 2 days ago Up 2 days 0.0.0.0:31186->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.b05043c5-44fc-40bf-aea2-10354e8f5ab4 53065e7a31ad java:8 "/bin/sh -c 'JAVA_OPT" 2 days ago Up 2 days 0.0.0.0:31839->8080/tcp mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.f0a3f4c5-ecdb-4f97-bede-d744feda670c
Here is a docker stats on it:
root@mesos-slave-i-e3a9c724 # docker stats CONTAINER CPU % MEM USAGE / LIMIT MEM % NET I/O BLOCK I/O 4f7c0aa8d03a 2.93% 797.3 MB / 1.611 GB 49.50% 1.277 GB / 1.189 GB 155.6 kB / 151.6 kB 53065e7a31ad 8.30% 738.9 MB / 1.611 GB 45.88% 419.6 MB / 554.3 MB 98.3 kB / 61.44 kB 5c7a9ea77b0e 4.91% 1.081 GB / 1.611 GB 67.10% 423 MB / 526.5 MB 3.219 MB / 61.44 kB 5eab1f8dac4a 3.13% 1.007 GB / 1.611 GB 62.53% 2.737 GB / 2.564 GB 6.566 MB / 118.8 kB 66f2fc8f8056 3.15% 768.1 MB / 1.611 GB 47.69% 258.5 MB / 252.8 MB 1.86 MB / 151.6 kB 880934c0049e 10.07% 735.1 MB / 1.611 GB 45.64% 1.451 GB / 1.399 GB 573.4 kB / 94.21 kB b63740fe56e7 12.04% 629 MB / 1.611 GB 39.06% 10.29 GB / 9.344 GB 8.102 MB / 61.44 kB f7382f241fce 6.21% 505 MB / 1.611 GB 31.36% 153.4 MB / 151.9 MB 5.837 MB / 94.21 kB
Not much else is running on the slave, yet the used memory doesn't map to the tasks memory:
Mem:16047M used:13340M buffers:1139M cache:776M
If I exec into the container (java:8 image), I can see correctly the shell calls to execute the curl specified in the health check as expected and exit correctly.
The only change we noticed since the memory usage woes was related to moving to Mesos doing the health checks instead, so I decided to take a look:
root@mesos-slave-i-e3a9c724 # ps awwx | grep health_check | grep -v grep
2504 ? Sl 47:33 /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:53432 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.f0a3f4c5-ecdb-4f97-bede-d744feda670c sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_email-green.b086206a-e000-11e5-a617-02429957d388
4220 ? Sl 47:26 /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:54982 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.b05043c5-44fc-40bf-aea2-10354e8f5ab4 sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_chat-green.ed53ec41-e000-11e5-a617-02429957d388
7444 ? Sl 1:31 /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:59422 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.60972150-b2b1-45d8-8a55-d63e81b8372a sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_identity-green.aeb2ef3b-e219-11e5-a617-02429957d388
10368 ? Sl 1:30 /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:40981 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.3dbb1004-5bb8-432f-8fd8-b863bd29341d sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_channel-green.c6fbd2ac-e219-11e5-a617-02429957d388
12399 ? Sl 9:45 /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:44815 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.23dfe408-ab8f-40be-bf6f-ce27fe885ee0 sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_integration-green.143865d5-e17d-11e5-a617-02429957d388
13538 ? Sl 24:54 /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:56598 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.5d417f16-df24-49d5-a5b0-38a7966460fe sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_metric-green.75296986-e0c7-11e5-a617-02429957d388
32034 ? Sl 1:31 /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:48119 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.39731a2f-d29e-48d1-9927-34ab8c5f557d sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_push-green.601337e6-e219-11e5-a617-02429957d388
The memory usage is really bad:
root@mesos-slave-i-e3a9c724 # ps -eo size,pid,user,command --sort -size | grep health_check | awk '{ hr=$1/1024 ; printf("%13.2f Mb ",hr) } { for ( x=4 ; x<=NF ; x++ ) { printf("%s ",$x) } print "" }'
2185.39 Mb /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:53432 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.f0a3f4c5-ecdb-4f97-bede-d744feda670c sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_email-green.b086206a-e000-11e5-a617-02429957d388
2185.39 Mb /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:54982 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.b05043c5-44fc-40bf-aea2-10354e8f5ab4 sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_chat-green.ed53ec41-e000-11e5-a617-02429957d388
1673.39 Mb /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:56598 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.5d417f16-df24-49d5-a5b0-38a7966460fe sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_metric-green.75296986-e0c7-11e5-a617-02429957d388
1161.39 Mb /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:44815 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.23dfe408-ab8f-40be-bf6f-ce27fe885ee0 sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_integration-green.143865d5-e17d-11e5-a617-02429957d388
649.39 Mb /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:59422 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.60972150-b2b1-45d8-8a55-d63e81b8372a sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_identity-green.aeb2ef3b-e219-11e5-a617-02429957d388
649.39 Mb /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:40981 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.3dbb1004-5bb8-432f-8fd8-b863bd29341d sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_channel-green.c6fbd2ac-e219-11e5-a617-02429957d388
649.39 Mb /usr/libexec/mesos/mesos-health-check --executor=(1)@10.92.32.63:48119 --health_check_json={"command":{"shell":true,"value":"docker exec mesos-29e183be-f611-41b4-824c-2d05b052231b-S6.39731a2f-d29e-48d1-9927-34ab8c5f557d sh -c \" curl --silent -f -X GET http:\/\/$HOST:$PORT0\/ops\/ping > \/dev\/null \""},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":90.0,"interval_seconds":2.0,"timeout_seconds":5.0} --task_id=prod_talkk_push-green.601337e6-e219-11e5-a617-02429957d388
0.32 Mb grep --color=auto health_check
Killing the mesos-health-check process for each container fix our memory issues (but I'm assuming health checks won't be reported anymore or something):
root@mesos-slave-i-e3a9c724 # date ; free -m ; ps awwx | grep health_check | grep -v grep | awk '{print $1}' | xargs -I% -P1 kill % ; date ; free -m
Fri Mar 4 21:20:55 UTC 2016
total used free shared buffers cached
Mem: 16047 13538 2508 0 1140 774
-/+ buffers/cache: 11623 4423
Swap: 0 0 0
Fri Mar 4 21:20:56 UTC 2016
total used free shared buffers cached
Mem: 16047 9101 6945 0 1140 774
-/+ buffers/cache: 7186 8860
Swap: 0 0 0
We're reverting to Marathon doing the health checks for now but would like to emphasize it's happening across all our slaves (not an isolated issue).
Thanks for looking into it 
Attachments
Issue Links
- is related to
-
MESOS-5021 Memory leak in subprocess when 'environment' argument is provided.
-
- Resolved
-