Marathon: Mesos and Marathon out of sync: orphaned tasks and "ghost" tasks

Created on 22 Sep 2014 · 40Comments · Source: mesosphere/marathon

Hi,

over the stretch of a week I've been deploying Docker containers to a Marathon cluster on Google Compute Engine. I'm now in a state where in the Mesos UI, I can see five running containers under the Marathon framework. In the Marathon UI, I see one running container. Moreover, I cannot seem to kill any of these. Deleting the one container reported by Marathon does not raise any error. I just stays put.
This pretty bad, as I now have to check Mesos for orphaned tasks and I can't rely on Marathon's interface anymore. I'm running Mesos 0.20.0 and Marathon 0.7.0-SNAPSHOT.

One in Marathon

$ http http://10.69.177.224:8080/v2/apps
HTTP/1.1 200 OK
Content-Type: application/json
Server: Jetty(8.y.z-SNAPSHOT)
Transfer-Encoding: chunked

{
    "apps": [
        {
            "args": [], 
            "backoffFactor": 1.15, 
            "backoffSeconds": 1, 
            "cmd": null, 
            "constraints": [], 
            "container": {
                "docker": {
                    "image": "tnolet/mesos-tester"
                }, 
                "type": "DOCKER", 
                "volumes": []
            }, 
            "cpus": 0.2, 
            "dependencies": [], 
            "disk": 0.0, 
            "env": {}, 
            "executor": "", 
            "healthChecks": [], 
            "id": "/vrn-container-3fe5143d", 
            "instances": 1, 
            "mem": 512.0, 
            "ports": [
                32768
            ], 
            "requirePorts": false, 
            "storeUrls": [], 
            "tasksRunning": 1, 
            "tasksStaged": 0, 
            "upgradeStrategy": {
                "minimumHealthCapacity": 1.0
            }, 
            "uris": [], 
            "user": null, 
            "version": "2014-09-16T11:06:40.862Z"
        }
    ]
}

But more in Mesos. Please note that framework_id is indeed pointing to Marathon. It is the only framework installed on this Mesos setup

$ http http://10.69.177.224:5050/master/tasks.json
HTTP/1.1 200 OK
Content-Encoding: gzip
Content-Length: 533
Content-Type: application/json
Date: Sun, 21 Sep 2014 22:15:02 GMT

{
    "tasks": [
        {
            "executor_id": "", 
            "framework_id": "20140917-082040-3769713930-5050-25964-0000", 
            "id": "vrn-container-54e6f672.6dee28a2-3f52-11e4-8a4d-42010a45b1e0", 
            "name": "vrn-container-54e6f672.6dee28a2-3f52-11e4-8a4d-42010a45b1e0", 
            "resources": {
                "cpus": 0.2, 
                "disk": 0, 
                "mem": 512, 
                "ports": "[31191-31191]"
            }, 
            "slave_id": "20140917-082040-3769713930-5050-25964-1", 
            "state": "TASK_RUNNING", 
            "statuses": [
                {
                    "state": "TASK_RUNNING", 
                    "timestamp": 1411058401.67118
                }
            ]
        }, 
        {
            "executor_id": "", 
            "framework_id": "20140917-082040-3769713930-5050-25964-0000", 
            "id": "vrn-container-5845b383.66c60931-3f52-11e4-8a4d-42010a45b1e0", 
            "name": "vrn-container-5845b383.66c60931-3f52-11e4-8a4d-42010a45b1e0", 
            "resources": {
                "cpus": 0.2, 
                "disk": 0, 
                "mem": 512, 
                "ports": "[31391-31391]"
            }, 
            "slave_id": "20140917-082040-3769713930-5050-25964-0", 
            "state": "TASK_RUNNING", 
            "statuses": [
                {
                    "state": "TASK_RUNNING", 
                    "timestamp": 1411058389.67871
                }
            ]
        }, 
        {
            "executor_id": "", 
            "framework_id": "20140917-082040-3769713930-5050-25964-0000", 
            "id": "vrn-container-9308ce3f.c6561b20-3f51-11e4-8a4d-42010a45b1e0", 
            "name": "vrn-container-9308ce3f.c6561b20-3f51-11e4-8a4d-42010a45b1e0", 
            "resources": {
                "cpus": 0.2, 
                "disk": 0, 
                "mem": 512, 
                "ports": "[31034-31034]"
            }, 
            "slave_id": "20140830-114324-3769713930-5050-2099-2", 
            "state": "TASK_RUNNING", 
            "statuses": [
                {
                    "state": "TASK_RUNNING", 
                    "timestamp": 1411058124.13837
                }
            ]
        }, 
        {
            "executor_id": "", 
            "framework_id": "20140917-082040-3769713930-5050-25964-0000", 
            "id": "vrn-container-854730d9.97d559ef-3f51-11e4-8a4d-42010a45b1e0", 
            "name": "vrn-container-854730d9.97d559ef-3f51-11e4-8a4d-42010a45b1e0", 
            "resources": {
                "cpus": 0.2, 
                "disk": 0, 
                "mem": 512, 
                "ports": "[31504-31504]"
            }, 
            "slave_id": "20140917-082040-3769713930-5050-25964-0", 
            "state": "TASK_RUNNING", 
            "statuses": [
                {
                    "state": "TASK_RUNNING", 
                    "timestamp": 1411058042.44566
                }
            ]
        }, 
        {
            "executor_id": "", 
            "framework_id": "20140917-082040-3769713930-5050-25964-0000", 
            "id": "vrn-container-036767c5.c801a9e0-3e77-11e4-9d4b-42010a45b1e0", 
            "name": "vrn-container-036767c5.c801a9e0-3e77-11e4-9d4b-42010a45b1e0", 
            "resources": {
                "cpus": 0.2, 
                "disk": 0, 
                "mem": 512, 
                "ports": "[31438-31438]"
            }, 
            "slave_id": "20140917-082040-3769713930-5050-25964-1", 
            "state": "TASK_KILLED", 
            "statuses": [
                {
                    "state": "TASK_RUNNING", 
                    "timestamp": 1410964494.1324
                }, 
                {
                    "state": "TASK_KILLED", 
                    "timestamp": 1411336361.56436
                }
            ]
        }, 
        {
            "executor_id": "", 
            "framework_id": "20140917-082040-3769713930-5050-25964-0000", 
            "id": "vrn-container-60a6af7c.bd45672f-3e77-11e4-9d4b-42010a45b1e0", 
            "name": "vrn-container-60a6af7c.bd45672f-3e77-11e4-9d4b-42010a45b1e0", 
            "resources": {
                "cpus": 0.2, 
                "disk": 0, 
                "mem": 512, 
                "ports": "[31945-31945]"
            }, 
            "slave_id": "20140917-082040-3769713930-5050-25964-1", 
            "state": "TASK_KILLED", 
            "statuses": [
                {
                    "state": "TASK_RUNNING", 
                    "timestamp": 1410964475.11256
                }, 
                {
                    "state": "TASK_KILLED", 
                    "timestamp": 1411336353.56442
                }
            ]
        }, 
        {
            "executor_id": "", 
            "framework_id": "20140917-082040-3769713930-5050-25964-0000", 
            "id": "vrn-container-3fe5143d.373a74aa-3e49-11e4-9d4b-42010a45b1e0", 
            "name": "vrn-container-3fe5143d.373a74aa-3e49-11e4-9d4b-42010a45b1e0", 
            "resources": {
                "cpus": 0.2, 
                "disk": 0, 
                "mem": 512, 
                "ports": "[31160-31160]"
            }, 
            "slave_id": "20140830-114324-3769713930-5050-2099-2", 
            "state": "TASK_RUNNING", 
            "statuses": [
                {
                    "state": "TASK_RUNNING", 
                    "timestamp": 1410944492.97175
                }
            ]
        }
    ]
}

Source

tnolet

Most helpful comment

@rbucchi I was able to reproduce it in that version as well. I've found a happy version at around a1d330312d66996dd02920112fa3e268d79f7584 which I'm running (with some patches). There was some really great work done on the task state refactor which should really help put this to bed, and the 1.2.0-rc6 release includes it. It's a pretty heavy change so I doubt it will be back ported. I don't have the time right now to test it myself but I've been looking forward to @unterstein 's work here.

You can remove the stale tasks with the zookeeper cli, and then after a marathon restart (across the board) any resource reservations associated with the stale tasks should be released. I have zkCli.sh aliased to zk, and maybe this one-liner could help you:

zk ls /marathon/state | egrep '^\[' | sed 's/, */\n/g' | sed 's/^\[//' | sed 's/\]$//' | grep task:registry | while read task; do echo zk rmr /marathon/state/$task; done

(this won't actually remove anything but will output the zk commands to run in order to remove things)

timcharper on 29 Jul 2016

👍6 ❤3

All 40 comments

Hello,

I have the same issue. Any update on this ?

nelsou on 22 Sep 2014

Hi,

thanks for reporting this. Are you both on 0.7.0-SNAPSHOT? If you setup a new cluster on GCE, you will get 0.7.0-RC4. I couldn't reproduce the issue so far, so it would be nice if you could check if RC4 works for you.

Also, could you check the logs for relevant entries? Why does Marathon drop the task, what's in the Mesos logs?

drexin on 22 Sep 2014

I use 0.6.0.
It happens after we lost a Mesos slave.

I will try 0.7.0

nelsou on 22 Sep 2014

I am also experiencing this pseudorandomly. Unfortunately I don't have any relevant log entries from the last time it happened, but restarting Marathon across the board resolves the issue. I have experienced this while running on 0.7.0-RC3 (and prior). I am updating to 0.7.0 today and will be sure to gather log entries and report back if I run into it again.

normanjoyner on 22 Sep 2014

Hi, I manually resolved this issue by deleting the full Marathon state in Zookeeper. That was the only way that I could find to resolve this. Even restarting the Master, Zookeeper or whatever just kept popping the same five "ophans", probably due to Zookeeper keeping state between restart. I will look for some log entries.

tnolet on 22 Sep 2014

I see the exact same issue (and have since 0.4.0).

I don't know whether marathon is supposed to 'check in' with Mesos
and I don't give it long enough, or whether something is misconfigured,
but after a reboot of the stack marathon assumes the state in zookeeper
reflects reality when there are no tasks running in mesos at all.

Workaround we've found is to scale apps to 0 then back up, but this
is a bit crap as our service discovery layer pulls its config from
marathon so it's often inaccurate until manual intervention.

Happy to provide full mesos/zk/marathon configs if it'd help reproduce?

On 22 September 2014 19:00, Tim Nolet [email protected] wrote:

Hi, I manually resolved this issue by deleting the full Marathon state in
Zookeeper. That was the only way that I could find to resolve this. Even
restarting the Master, Zookeeper or whatever just kept popping the same
five "ophans", probably due to Zookeeper keeping state between restart. I
will look for some log entries.

—
Reply to this email directly or view it on GitHub
https://github.com/mesosphere/marathon/issues/616#issuecomment-56413406.

rasputnik on 23 Sep 2014

Caveat - I actually have the _opposite_ issue. Marathon thinks
tasks are running when they aren't. Same underlying cause I suspect,
marathon just doesn't reconcile its state with Mesos.

On 23 September 2014 09:38, Dick Davies [email protected] wrote:

I see the exact same issue (and have since 0.4.0).

I don't know whether marathon is supposed to 'check in' with Mesos
and I don't give it long enough, or whether something is misconfigured,
but after a reboot of the stack marathon assumes the state in zookeeper
reflects reality when there are no tasks running in mesos at all.

Workaround we've found is to scale apps to 0 then back up, but this
is a bit crap as our service discovery layer pulls its config from
marathon so it's often inaccurate until manual intervention.

Happy to provide full mesos/zk/marathon configs if it'd help reproduce?

On 22 September 2014 19:00, Tim Nolet [email protected] wrote:

Hi, I manually resolved this issue by deleting the full Marathon state in
Zookeeper. That was the only way that I could find to resolve this. Even
restarting the Master, Zookeeper or whatever just kept popping the same
five "ophans", probably due to Zookeeper keeping state between restart. I
will look for some log entries.

—
Reply to this email directly or view it on GitHub
https://github.com/mesosphere/marathon/issues/616#issuecomment-56413406
.

rasputnik on 23 Sep 2014

@rasputnik Hi Dick,

I also have that opposite/reversed issue. I had a Marathon "app" with no corresponding Mesos task. That's what I meant to say in the issue with regards to not being able to delete this specific "app".

tnolet on 23 Sep 2014

Same problem as @tnolet and @rasputnik on Marathon 0.6.0
If a Mesos slave crashes (because of a "no left space on device"), Marathon is out of sync regarding Mesos.

What kind of logs would help you ?

nelsou on 23 Sep 2014

I think this is something wonky in the way reconciliation works, possibly
related to HA?

We're guessing here really - i'm trying to nail down a repeatable config,
will post if i get anywhere.

On 23 September 2014 13:16, Nelson [email protected] wrote:

I tried Marathon 0.8.1.1

Same problem as @tnolet https://github.com/tnolet and @rasputnik
https://github.com/rasputnik
If a Mesos slave crashes (because of a "no left space on device"),
Marathon is out of sync regarding Mesos.

What kind of logs would help you ?

—
Reply to this email directly or view it on GitHub
https://github.com/mesosphere/marathon/issues/616#issuecomment-56510809.

rasputnik on 23 Sep 2014

I have been able to reproduce this. We actually have two issues here. One in Mesos, which does not send us status updates for unknown tasks, which is why the task reconcilation does not work properly and already killed tasks stay in the task list under certain circumstances. The other issue is in Marathon, that during a deployment removes tasks from the task tracker immediately instead of waiting for a TASK_KILLED, so if the master id not reachable during a deployment, Marathon will remove the task from the task tracker, but Mesos will never receive the kill command. Expect a fix soon!

drexin on 23 Sep 2014

Great to see this being addressed, many thanks.

Does this explain the counter example too (why Mesos doesn't always detect that tasks making up an app are actually lost, or would that be a different situation?)
Happy to file a fresh bug if they're unrelated (but would be delighted if we could address both bugs in one shot).

rasputnik on 24 Sep 2014

The fix we merged should address some of these issues. We are scheduled to cut a point release on Friday, so you'll be able to try it out. Closing this issue for now, but please do report back (either here or in a separate issue) if you see additional anomolies. If we can get reproduction steps that would also be very helpful. Thanks for reporting @tnolet, @rasputnik, @normanjoyner and @nelsou.

ConnorDoyle on 25 Sep 2014

Hi,

I'm not sure why this is closed. I have the exact same situation again. Apps running in Marathon with associated tasks, but no tasks running in Mesos. This is quite unnerving and blocking for any serious production usage. This bug is now 1 year old.

Setup:

4 mesos slaves and 2 masters running Mesos 0.25.0
marathon running 0.11.1

output from mesos /tasks endpoint:

{"tasks":[]}

output from marathon's apps/<some app>/tasks endpoint (abbreviated):

{
    "tasks": [
        {
            "id": "mesos-consul.67e0ab0d-7c46-11e5-8886-0242fdc2dab2",
            "host": "mesos01.bva.nu",
            "ports": [
                31866
            ],
            "startedAt": "2015-10-27T01:02:42.310Z",
            "stagedAt": "2015-10-27T01:02:33.930Z",
            "version": "2015-10-01T15:19:10.936Z",
            "slaveId": null,
            "appId": "/mesos-consul"
        }
    ]
}

@ConnorDoyle : Any updates on how/why this happens? Do other Mesos frameworks have this behaviour or is Marathon just not stable yet?

tnolet on 26 Oct 2015

P.S: the only error I can see in the Marathon logs (reported under INFO(!)) is:

[INFO] [10/26/2015 13:28:09.320] [marathon-akka.actor.default-dispatcher-14] [akka://marathon/deadLetters] Message [mesosphere.marathon.MarathonSchedulerActor$TasksReconciled$] from Actor[akka://marathon/user/MarathonScheduler/$a#223371711] to Actor[akka://marathon/deadLetters] was not delivered. [5] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[2015-10-26 13:28:09,323] INFO Syncing tasks for all apps (mesosphere.marathon.SchedulerActions:442)

tnolet on 26 Oct 2015

I have this problem after upgrading for 0.10 to 0.11.1. I have several marathon tasks that do not exist in mesos. I cannot destroy, scale, or anything.

memelet on 1 Nov 2015

I'm running marathon 0.15.1, mesos 0.27 and definitely just had this happen. To fix it, I nuked the ghost tasks in zk and bounced the elected marathon leader. I can definitely trace this back to deployments happening on top of slaves that were being restarted and wiped.

flyinprogrammer on 23 Feb 2016

Hi! If you're effected by this issue, please file a support ticket at [email protected]

jgarcia-mesosphere on 23 Feb 2016

I'm still experiencing this on Marathon 1.0-RC1 and Mesos 0.28.0 any updates to this bug?

jaimelive on 29 Mar 2016

👍5

Effected by this as well. Marathon 0.15.3 Mesos 0.28.0

ianjw11 on 30 Mar 2016

I'm hitting it, too; in a local cluster I've provisioned in VMs. If I bring the whole thing down, then back up, Marathon remembers the tasks but Mesos has no recollection of them. I can't kill them / get Marathon to believe that they're gone. It should be able to query mesos and realize that no such task exists anymore.

I think it might be doing this because the mesos-slave ID might have changed? And Marathon is waiting for that slave to become available again? Would be nice if there was a way to assassinate the mesos-slave somehow.

(_edit_)

They eventually went away. 👍

timcharper on 17 May 2016

I am able to reproduce with Marathon==0.15.5 and Mesos==0.28.2 in a HA setup. Like others have reported before only manually removing information from Zookeeper resolves the issue.

JustinVenus on 9 Jul 2016

same thing happens with marathon 1.1.2/mesos 0.28.2 after few node restarts (cluster of 3) when we were testing resilience of the setup

XANi on 22 Jul 2016

problem still here. I got a three node cluster in HA. If master goes down and up task hang forever and cannot be destroyed or scaled down. Tasks seem killed for mesos, but hanging on deployment in marathon

mesos-0.28.2-2.0.27.centos701406.x86_64
marathon-1.1.2-1.0.482.el7.x86_64
zookeeper-3.4.5

any workaround before fixing?

rbucchi on 29 Jul 2016

zk ls /marathon/state | egrep '^\[' | sed 's/, */\n/g' | sed 's/^\[//' | sed 's/\]$//' | grep task:registry | while read task; do echo zk rmr /marathon/state/$task; done

(this won't actually remove anything but will output the zk commands to run in order to remove things)

timcharper on 29 Jul 2016

👍6 ❤3

@rbucchi in my case dropping GC interval/timeout helped, after dropping it to around hour task disappeared reasonably fast (restarting few nodes in short interval didn't screwed cluster completely)

XANi on 30 Jul 2016

Experienced this issue when my network suddenly crash, now i have 3 staged app and 3 running app (originally scaled 3) and they cant be killed or destroyed.

stalemartyr on 31 Jul 2016

i am experiencing marathon showing tasks / apps that cannot be removed, and that mesos does not show the tasks at all, which occurred when all nodes were restarted.

mesos 1.0.0 / marathon 1.1.2

joelstewart on 17 Aug 2016

@timcharper Thanks for the hint. Manual ZK database cleanup solves the issue.

x-cray on 18 Aug 2016

I still have this with version 1.1.2 of marathon.
There needs to be a strategy after restarting mesos-slave with new configuration

tsaridas on 23 Aug 2016

Same here, needed a config change on the mesos-slaves and now i'm stuck with tasks i cant kill/scale/deploy.

Marathon 1.1.2
Mesos 0.28

erSitzt on 5 Sep 2016

that "fixed" (tasks eventually go away) it for me :--task_lost_expunge_gc 3600000 --task_lost_expunge_interval 900000

XANi on 5 Sep 2016

👍3 ❤1

Same for me...

franktranhb on 6 Sep 2016

I just experienced this problem with Marathon 1.1.12-1.0.488.el7 and mesos 1.0.1-2.0.93.centos701406. Deployments get "stuck" with orphan tasks.

Running the zk-commands from @timcharper fixed my issues.

kjelle on 30 Sep 2016

Check the task_lost values that are coming with the next release, they basically went from24 hours down to a few seconds ...

https://github.com/mesosphere/marathon/blob/master/changelog.md

erSitzt on 30 Sep 2016

👍1

And it just happened again. What we do is call DELETE on a app-group with ?force=true, then wait 20 seconds and then call POST creating the app group.
When we "relaunch" we do this for 85 app groups..

Marathon doesnt seem to handle this too well.. We could possibly replace our brute-method with e.g. 'PUT /v2/groups/{groupId}' :-)

kjelle on 30 Sep 2016

@timcharper 's method not work for me:

[root@zk1 bin]# zk ls /marathon/state | egrep '^\[' | sed 's/, */\n/g' | sed 's/^\[//' | sed 's/\]$//' | grep task:registry | while read task; do echo zk rmr /marathon/state/$task; done
log4j:WARN No appenders could be found for logger (org.apache.zookeeper.ZooKeeper).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

add server option is same

[root@zk1 bin]# zk -server 10.142.55.190:2181,10.142.55.196:2181,10.142.55.202:2181 ls /marathon/state | egrep '^\[' | sed 's/, */\n/g' | sed 's/^\[//' | sed 's/\]$//' | grep task:registry | while read task; do echo zk rmr /marathon/state/$task; done
log4j:WARN No appenders could be found for logger (org.apache.zookeeper.ZooKeeper).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

eromoe on 14 Oct 2016

Marathon 1.11.1 and Mesos 0.28.2: I lost a mesos slave due to a network disconnect. When the slave came back online the marathon launched docker process persisted, but marathon UI did not reflect that and marathon restarted the tasks on another host.... the end result is a marathon app that is running many more instances than what the marathon configuration specifies (and what marathon thinks is running).

Possibly related to this bug?

crumley on 30 Nov 2016

I hit this error on Marathon 1.1.1 and Mesos 0.28.1. Marathon and Mesos are running in docker container. When I restart mesos-slave , Marathon losts this task from UI. After 15mins later, Marathon schedules this task to another mesos-slave. But the old container on the slave which I just restarted is still there. It becomes an orphaned container.

nashasha1 on 1 Dec 2016

👍2

I have the same issue on Marathon 1.1.5 and Mesos 1.1.0. I had 3 instances of an app, distributed on 3 agents. One of these agents went down and I rebooted it. The task appears as lost in Mesos because of an unreachable agent, but Marathon keeps showing the app as healthy (but the container is not up anymore) and I can't kill it (the task reappears a few seconds after). Also, the task doesn't count as an instance (the app scale is 0, even if the task appears as healthy in the UI).