[ https://issues.apache.org/jira/browse/MESOS-4869?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Benjamin Mahler reassigned MESOS-4869: -------------------------------------- Assignee: Benjamin Mahler > /usr/libexec/mesos/mesos-health-check using/leaking a lot of memory > ------------------------------------------------------------------- > > Key: MESOS-4869 > URL: https://issues.apache.org/jira/browse/MESOS-4869 > Project: Mesos > Issue Type: Bug > Affects Versions: 0.27.1 > Reporter: Anthony Scalisi > Assignee: Benjamin Mahler > Priority: Critical > Labels: health-check > Fix For: 0.26.1, 0.25.1, 0.24.2, 0.28.1, 0.27.3 > > > We switched our health checks in Marathon from HTTP to COMMAND: > {noformat} > "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 > } > ] > {noformat} > 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: > !https://i.imgur.com/gbRf804.png! > Here is a *docker ps* on it: > {noformat} > 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 > {noformat} > Here is a *docker stats* on it: > {noformat} > 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 > {noformat} > Not much else is running on the slave, yet the used memory doesn't map to the > tasks memory: > {noformat} > Mem:16047M used:13340M buffers:1139M cache:776M > {noformat} > 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: > {noformat} > 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 > {noformat} > The memory usage is really bad: > {noformat} > 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 > {noformat} > 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): > {noformat} > 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 > {noformat} > 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 :) -- This message was sent by Atlassian JIRA (v6.3.4#6332)