[jira] [Created] (MESOS-9887) Race condition between two terminal task status updates for Docker executor.

["Andrei Budnik (JIRA)" <ji...@apache.org>]

Andrei Budnik created MESOS-9887:
------------------------------------

             Summary: Race condition between two terminal task status updates for Docker executor.
                 Key: MESOS-9887
                 URL: https://issues.apache.org/jira/browse/MESOS-9887
             Project: Mesos
          Issue Type: Bug
          Components: agent, containerization
            Reporter: Andrei Budnik
         Attachments: race_example.txt

h2. Overview

Expected behavior:
 Task successfully finishes and sends TASK_FINISHED status update.

Observed behavior:
 Task successfully finishes, but the agent sends TASK_FAILED with the reason "REASON_EXECUTOR_TERMINATED".

In normal circumstances, Docker executor [sends|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/docker/executor.cpp#L758] final status update TASK_FINISHED to the agent, which then [gets processed|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L5543] by the agent before termination of the executor's process.

However, if the processing of the initial TASK_FINISHED gets delayed, then there is a chance that Docker executor terminates and the agent [triggers|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L6662] TASK_FAILED which will [be handled|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L5816-L5826] prior to the TASK_FINISHED status update.

See attached logs which contain an example of the race condition.
h2. Reproducing bug

1. Add the following code:
{code:java}
  static int c = 0;
  if (++c == 3) { // to skip TASK_STARTING and TASK_RUNNING status updates.
        ::sleep(2);
  }
{code}
to the [`ComposingContainerizerProcess::status`|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/containerizer/composing.cpp#L578]
 and to the [`DockerContainerizerProcess::status`|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/containerizer/docker.cpp#L2167].

2. Recompile mesos

3. Launch mesos master and agent locally

4. Launch a simple Docker task via `mesos-execute`:
{code}
#  cd build
./src/mesos-execute --master="`hostname`:5050" --name="a" --containerizer=docker --docker_image=alpine --resources="cpus:1;mem:32" --command="ls"
{code}
h2. Race condition - description

1. Mesos agent receives TASK_FINISHED status update and then subscribes on [`containerizer->status()`|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L5754-L5761].

2. `containerizer->status()` operation for TASK_FINISHED status update gets delayed in the composing containerizer (e.g. due to switch of the worker thread that executes `status` method).

3. Docker executor terminates and the agent [triggers|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L6662] TASK_FAILED.

4. Docker containerizer destroys the container. A registered callback for the `containerizer->wait` call in the composing containerizer dispatches [lambda function|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/containerizer/composing.cpp#L368-L373] that will clean up `containers_` map.

5. Composing c'zer resumes and dispatches `[status()|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/containerizer/composing.cpp#L579]` method to the Docker containerizer for TASK_FINISHED, which in turn hangs for a few seconds.

6. Corresponding `containerId` gets removed from the `containers_` map of the composing c'zer.

7. Mesos agent subscribes on [`containerizer->status()`|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L5754-L5761] for the TASK_FAILED status update.

8. Composing c'zer returns ["Container not found"|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/containerizer/composing.cpp#L576] for TASK_FAILED.

9. `[Slave::_statusUpdate|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L5826]` stores TASK_FAILED terminal status update in the executor's data structure.

10. Docker executor resumes and finishes processing of `status()` method for TASK_FINISHED. Finally, it returns control to the `Slave::_statusUpdate` continuation. This method [discovers|https://github.com/apache/mesos/blob/0026ea46dc35cbba1f442b8e425c6cbaf81ee8f8/src/slave/slave.cpp#L5808-L5814] that the executor has already been destroyed.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)