[
https://issues.apache.org/jira/browse/MESOS-2605?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14494989#comment-14494989
]
Michael Park commented on MESOS-2605:
-------------------------------------
Reporting recent findings.
{code:title=master}
Apr 14 18:49:40 ip-10-168-90-31.ec2.internal mesos-master[1226]: W0414
18:49:40.078554 1248 master.cpp:4015] Executor
executor.journalnode.NodeExecutor.1429034850690 of framework
20150408-055737-526034954-5050-1226-0393 possibly unknown to the slave
20150408-055737-526034954-5050-1226-S9 at slave(1)@10.154.8.101:5051
(ec2-54-237-83-163.compute-1.amazonaws.com)
{code}
{code:title=slave}
Apr 14 18:49:36 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:36.802649 18193 slave.cpp:4305] Recovering executor
'executor.journalnode.NodeExecutor.1429034850690' of framework
20150408-055737-526034954-5050-1226-0393
/* ... */
Apr 14 18:49:36 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:36.832767 18188 status_update_manager.cpp:205] Recovering executor
'executor.journalnode.NodeExecutor.1429034850690' of framework
20150408-055737-526034954-5050-1226-0393
/* ... */
Apr 14 18:49:37 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:36.857517 18189 docker.cpp:470] Recovering container
'5338e6cf-03ac-4882-a08e-48bfd6d797dc' for executor
'executor.journalnode.NodeExecutor.1429034850690' of framework
20150408-055737-526034954-5050-1226-0393
/* ... */
Apr 14 18:49:37 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:36.870594 18190 containerizer.cpp:350] Recovering container
'5338e6cf-03ac-4882-a08e-48bfd6d797dc' for executor
'executor.journalnode.NodeExecutor.1429034850690' of framework
20150408-055737-526034954-5050-1226-0393
{code}
So we somehow we're calling {{recover}} in {{docker.cpp}} as well as
{{containerizer.cpp}}. But based on the fact that HDFS doesn't use {{docker}}
at all, along with this log:
{code}
Apr 14 18:07:30 ip-10-154-8-101.ec2.internal mesos-slave[11172]: I0414
18:07:30.708111 11187 containerizer.cpp:472] Starting container
'5338e6cf-03ac-4882-a08e-48bfd6d797dc' for executor
'executor.journalnode.NodeExecutor.1429034850690' of framework
'20150408-055737-526034954-5050-1226-0393'
{code}
We should only be calling it for {{containerizer.cpp}} only.
The slave proceeds to log the following sequence of events, which shows that we
try to docker recover the containers and when we can't find them, we terminate
the executor.
{code}
Apr 14 18:49:37 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:37.602605 18186 slave.cpp:3738] Sending reconnect request to executor
executor.journalnode.NodeExecutor.1429034850690 of framework
20150408-055737-526034954-5050-1226-0393 at executor(1)@10.154.8.101:60097
/* ... */
Apr 14 18:49:37 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:37.611616 18186 slave.cpp:2321] Re-registering executor
executor.journalnode.NodeExecutor.1429034850690 of framework
20150408-055737-526034954-5050-1226-0393
/* ... */
Apr 14 18:49:37 ip-10-154-8-101.ec2.internal mesos-slave[18180]: E0414
18:49:37.862635 18190 slave.cpp:2456] Failed to update resources for container
5338e6cf-03ac-4882-a08e-48bfd6d797dc of executor
'executor.journalnode.NodeExecutor.1429034850690' of framework
20150408-055737-526034954-5050-1226-0393, destroying container: Failed to
'docker inspect mesos-5338e6cf-03ac-4882-a08e-48bfd6d797dc': exit status =
exited with status 1 stderr = Error: No such image or container:
mesos-5338e6cf-03ac-4882-a08e-48bfd6d797dc
/* ... */
Apr 14 18:49:37 ip-10-154-8-101.ec2.internal mesos-slave[18180]: E0414
18:49:37.976002 18187 slave.cpp:3191] Termination of executor
'executor.journalnode.NodeExecutor.1429034850690' of framework
'20150408-055737-526034954-5050-1226-0393' failed: Failed to kill the Docker
container: Failed to 'docker stop -t 0
mesos-5338e6cf-03ac-4882-a08e-48bfd6d797dc': exit status = exited with status 1
stderr = Error response from daemon: No such container:
mesos-5338e6cf-03ac-4882-a08e-48bfd6d797dc
/* ... */
Apr 14 18:49:37 ip-10-154-8-101.ec2.internal mesos-slave[18180]: E0414
18:49:37.977609 18187 slave.cpp:2653] Failed to update resources for container
5338e6cf-03ac-4882-a08e-48bfd6d797dc of executor
executor.journalnode.NodeExecutor.1429034850690 running task
task.journalnode.journalnode.NodeExecutor.1429034850690 on status update for
terminal task, destroying container: Container
'5338e6cf-03ac-4882-a08e-48bfd6d797dc' not found
/* ... */
Apr 14 18:49:40 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:40.079958 18188 slave.cpp:949] MPARK: Slave::doReliableRegistration
Apr 14 18:49:40 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:40.080099 18188 slave.cpp:1053] MPARK: Executor
'executor.namenode.NameNodeExecutor.1429034908782' is terminated!
Apr 14 18:49:40 ip-10-154-8-101.ec2.internal mesos-slave[18180]: I0414
18:49:40.080118 18188 slave.cpp:1053] MPARK: Executor
'executor.journalnode.NodeExecutor.1429034850690' is terminated!
{code}
> The slave sometimes does not send active executors during reregistration
> ------------------------------------------------------------------------
>
> Key: MESOS-2605
> URL: https://issues.apache.org/jira/browse/MESOS-2605
> Project: Mesos
> Issue Type: Bug
> Affects Versions: 0.22.0
> Reporter: Elizabeth Lingg
> Assignee: Michael Park
> Labels: mesosphere
>
> The slave sometimes does not send active executors during reregistration.
> Framework checkpointing is enabled, and the executor successfully
> reregisters. However, the tasks in that executor are LOST (by abnormal
> executor termination) because the executor is removed by the mesos master as
> unknown. See the example below,
> task.journalnode.journalnode.NodeExecutor.1428609184051.
> See the Slave Logs here for the Task:
> {code}
> Apr 09 19:53:06 ip-10-168-119-78.ec2.internal mesos-slave[25116]: I0409
> 19:53:06.778790 25126 status_update_manager.cpp:317] Received status update
> TASK_RUNNING (UUID: 4eb22075-c319-463d-8f70-94db9caa69c6) for task
> task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008
> Apr 09 19:53:06 ip-10-168-119-78.ec2.internal mesos-slave[25116]: I0409
> 19:53:06.779013 25126 status_update_manager.hpp:346] Checkpointing UPDATE for
> status update TASK_RUNNING (UUID: 4eb22075-c319-463d-8f70-94db9caa69c6) for
> task task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008
> Apr 09 19:53:06 ip-10-168-119-78.ec2.internal mesos-slave[25116]: I0409
> 19:53:06.781788 25123 slave.cpp:2753] Forwarding the update TASK_RUNNING
> (UUID: 4eb22075-c319-463d-8f70-94db9caa69c6) for task
> task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008 to [email protected]:5050
> Apr 09 19:53:06 ip-10-168-119-78.ec2.internal mesos-slave[25116]: I0409
> 19:53:06.781889 25123 slave.cpp:2686] Sending acknowledgement for status
> update TASK_RUNNING (UUID: 4eb22075-c319-463d-8f70-94db9caa69c6) for task
> task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008 to executor(1)@10.168.119.78:47638
> Apr 09 19:53:06 ip-10-168-119-78.ec2.internal mesos-slave[25116]: I0409
> 19:53:06.784503 25124 status_update_manager.cpp:389] Received status update
> acknowledgement (UUID: 4eb22075-c319-463d-8f70-94db9caa69c6) for task
> task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008
> Apr 09 19:53:06 ip-10-168-119-78.ec2.internal mesos-slave[25116]: I0409
> 19:53:06.784567 25124 status_update_manager.hpp:346] Checkpointing ACK for
> status update TASK_RUNNING (UUID: 4eb22075-c319-463d-8f70-94db9caa69c6) for
> task task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008
> {code}
> Master Logs:
> {code}
> Apr 09 20:19:43 ip-10-142-250-253.ec2.internal mesos-master[1047]: W0409
> 20:19:43.008666 1067 master.cpp:4015] Executor
> executor.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008 possibly unknown to the slave
> 20150407-233647-2059219722-5050-1659-S5 at slave(1)@10.168.119.78:5051
> (ec2-54-237-57-237.compute-1.amazonaws.com)
> Apr 09 20:19:43 ip-10-142-250-253.ec2.internal mesos-master[1047]: I0409
> 20:19:43.008652 1074 hierarchical.hpp:648] Recovered cpus(*):0.1;
> mem(*):1536 (total allocatable: cpus(*):3.5; mem(*):21113; disk(*):142210;
> ports(*):[3889-5044, 5046-5049, 2182-2958, 2960-3887, 1025-2180, 8082-9041,
> 9043-9159, 9161-9999, 5052-6999, 7002-7198, 7200-8079, 10001-65535]) on slave
> 20150407-233647-2059219722-5050-1659-S5 from framework
> 20150408-002100-4261056010-5050-1047-0008
> Apr 09 20:19:43 ip-10-142-250-253.ec2.internal mesos-master[1047]: I0409
> 20:19:43.008712 1067 master.cpp:4714] Removing executor
> 'executor.journalnode.NodeExecutor.1428609184051' with resources cpus(*):0.1;
> mem(*):1536 of framework 20150408-002100-4261056010-5050-1047-0008 on slave
> 20150407-233647-2059219722-5050-1659-S5 at slave(1)@10.168.119.78:5051
> (ec2-54-237-57-237.compute-1.amazonaws.com)
> Apr 09 20:19:43 ip-10-142-250-253.ec2.internal mesos-master[1047]: I0409
> 20:19:43.010372 1067 master.cpp:3295] Status update TASK_LOST (UUID:
> e5532567-e5b2-4fca-87aa-f3f98e371640) for task
> task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008 from slave
> 20150407-233647-2059219722-5050-1659-S5 at slave(1)@10.168.119.78:5051
> (ec2-54-237-57-237.compute-1.amazonaws.com)
> Apr 09 20:19:43 ip-10-142-250-253.ec2.internal mesos-master[1047]: I0409
> 20:19:43.013746 1067 master.cpp:3295] Status update TASK_LOST (UUID:
> e5532567-e5b2-4fca-87aa-f3f98e371640) for task
> task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008 from slave
> 20150407-233647-2059219722-5050-1659-S5 at slave(1)@10.168.119.78:5051
> (ec2-54-237-57-237.compute-1.amazonaws.com)
> Apr 09 20:19:43 ip-10-142-250-253.ec2.internal mesos-master[1047]: I0409
> 20:19:43.013767 1067 master.cpp:3336] Forwarding status update TASK_LOST
> (UUID: e5532567-e5b2-4fca-87aa-f3f98e371640) for task
> task.journalnode.journalnode.NodeExecutor.1428609184051 of framework
> 20150408-002100-4261056010-5050-1047-0008
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
