Repository: mesos Updated Branches: refs/heads/master b70a863d2 -> e43b0c700
Redirect Docker logs. Project: http://git-wip-us.apache.org/repos/asf/mesos/repo Commit: http://git-wip-us.apache.org/repos/asf/mesos/commit/e43b0c70 Tree: http://git-wip-us.apache.org/repos/asf/mesos/tree/e43b0c70 Diff: http://git-wip-us.apache.org/repos/asf/mesos/diff/e43b0c70 Branch: refs/heads/master Commit: e43b0c70037940fa1c42f044d5b6ddde943b3736 Parents: b70a863 Author: Timothy Chen <[email protected]> Authored: Wed Aug 13 10:30:03 2014 -0700 Committer: Benjamin Hindman <[email protected]> Committed: Thu Aug 14 15:56:44 2014 -0700 ---------------------------------------------------------------------- src/docker/docker.cpp | 12 +-- src/slave/containerizer/docker.cpp | 34 ++++++++ src/tests/docker_containerizer_tests.cpp | 107 +++++++++++++++++++++++++- src/tests/environment.cpp | 2 + src/tests/mesos.cpp | 3 + 5 files changed, 151 insertions(+), 7 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/mesos/blob/e43b0c70/src/docker/docker.cpp ---------------------------------------------------------------------- diff --git a/src/docker/docker.cpp b/src/docker/docker.cpp index b6b8aab..8f04bab 100644 --- a/src/docker/docker.cpp +++ b/src/docker/docker.cpp @@ -117,7 +117,7 @@ Try<Docker> Docker::create(const string& path, bool validate) if (hierarchy.isNone()) { return Error("Failed to find a mounted cgroups hierarchy " - "for the 'cpu' subsystem, you probably need " + "for the 'cpu' subsystem; you probably need " "to mount cgroups manually!"); } @@ -136,13 +136,15 @@ Try<Docker> Docker::create(const string& path, bool validate) Future<Option<int> > status = s.get().status(); if (!status.await(Seconds(5))) { - return Error("Docker info failed with time out"); + return Error("Timed out waiting for '" + cmd + "'"); } else if (status.isFailed()) { - return Error("Docker info failed: " + status.failure()); + return Error("Failed to execute '" + cmd + "': " + status.failure()); } else if (!status.get().isSome() || status.get().get() != 0) { - string msg = "Docker info failed to execute"; + string msg = "Failed to execute '" + cmd "': "; if (status.get().isSome()) { - msg += ", exited with status (" + WSTRINGIFY(status.get().get()) + ")"; + msg += "exited with status " + WSTRINGIFY(status.get().get()); + } else { + msg += "unknown exit status"; } return Error(msg); } http://git-wip-us.apache.org/repos/asf/mesos/blob/e43b0c70/src/slave/containerizer/docker.cpp ---------------------------------------------------------------------- diff --git a/src/slave/containerizer/docker.cpp b/src/slave/containerizer/docker.cpp index c18023c..d5292b6 100644 --- a/src/slave/containerizer/docker.cpp +++ b/src/slave/containerizer/docker.cpp @@ -841,6 +841,40 @@ Future<bool> DockerContainerizerProcess::__launch( statuses[containerId] .onAny(defer(self(), &Self::reaped, containerId)); + // Redirect the logs into stdout/stderr. + // + // TODO(benh): This is an intermediate solution for now until we can + // reliably stream the logs either from the CLI or from the REST + // interface directly. The problem is that it's possible that the + // 'docker logs --follow' command will be started AFTER the + // container has already terminated, and thus it will continue + // running forever because the container has stopped. Unfortunately, + // when we later remove the container that still doesn't cause the + // 'logs' process to exit. Thus, we wait some period of time until + // after the container has terminated in order to let any log data + // get flushed, then we kill the 'logs' process ourselves. A better + // solution would be to first "create" the container, then start + // following the logs, then finally "start" the container so that + // when the container terminates Docker will properly close the log + // stream and 'docker logs' will exit. For more information, please + // see: https://github.com/docker/docker/issues/7020 + + string logs = + "logs() {\n" + " " + flags.docker + " logs --follow $1 &\n" + " pid=$!\n" + " " + flags.docker + " wait $1 >/dev/null 2>&1\n" + " sleep 10" // Sleep 10 seconds to make sure the logs are flushed. + " kill -TERM $pid >/dev/null 2>&1 &\n" + "}\n" + "logs " + containerName(containerId); + + subprocess( + logs, + Subprocess::PATH("/dev/null"), + Subprocess::PATH(path::join(directory, "stdout")), + Subprocess::PATH(path::join(directory, "stderr"))); + return true; } http://git-wip-us.apache.org/repos/asf/mesos/blob/e43b0c70/src/tests/docker_containerizer_tests.cpp ---------------------------------------------------------------------- diff --git a/src/tests/docker_containerizer_tests.cpp b/src/tests/docker_containerizer_tests.cpp index 3099063..e0fd62f 100644 --- a/src/tests/docker_containerizer_tests.cpp +++ b/src/tests/docker_containerizer_tests.cpp @@ -92,7 +92,6 @@ public: .WillRepeatedly(Invoke(this, &MockDockerContainerizer::_update)); } - MOCK_METHOD7( launch, process::Future<bool>( @@ -104,7 +103,6 @@ public: const process::PID<slave::Slave>&, bool checkpoint)); - MOCK_METHOD8( launch, process::Future<bool>( @@ -853,3 +851,108 @@ TEST_F(DockerContainerizerTest, DISABLED_ROOT_DOCKER_Recover) AWAIT_READY(reaped.get().status()); } + + +TEST_F(DockerContainerizerTest, ROOT_DOCKER_Logs) +{ + Try<PID<Master> > master = StartMaster(); + ASSERT_SOME(master); + + slave::Flags flags = CreateSlaveFlags(); + + Docker docker = Docker::create(tests::flags.docker, false).get(); + + MockDockerContainerizer dockerContainerizer(flags, docker); + + Try<PID<Slave> > slave = StartSlave(&dockerContainerizer); + ASSERT_SOME(slave); + + MockScheduler sched; + MesosSchedulerDriver driver( + &sched, DEFAULT_FRAMEWORK_INFO, master.get(), DEFAULT_CREDENTIAL); + + Future<FrameworkID> frameworkId; + EXPECT_CALL(sched, registered(&driver, _, _)) + .WillOnce(FutureArg<1>(&frameworkId)); + + Future<vector<Offer> > offers; + EXPECT_CALL(sched, resourceOffers(&driver, _)) + .WillOnce(FutureArg<1>(&offers)) + .WillRepeatedly(Return()); // Ignore subsequent offers. + + driver.start(); + + AWAIT_READY(frameworkId); + + AWAIT_READY(offers); + EXPECT_NE(0u, offers.get().size()); + + const Offer& offer = offers.get()[0]; + + TaskInfo task; + task.set_name(""); + task.mutable_task_id()->set_value("1"); + task.mutable_slave_id()->CopyFrom(offer.slave_id()); + task.mutable_resources()->CopyFrom(offer.resources()); + + string uuid = UUID::random().toString(); + + CommandInfo command; + command.set_value("echo out" + uuid + " ; echo err" + uuid + " 1>&2"); + + ContainerInfo containerInfo; + containerInfo.set_type(ContainerInfo::DOCKER); + + ContainerInfo::DockerInfo dockerInfo; + dockerInfo.set_image("busybox"); + containerInfo.mutable_docker()->CopyFrom(dockerInfo); + + task.mutable_command()->CopyFrom(command); + task.mutable_container()->CopyFrom(containerInfo); + + vector<TaskInfo> tasks; + tasks.push_back(task); + + Future<ContainerID> containerId; + Future<string> directory; + EXPECT_CALL(dockerContainerizer, launch(_, _, _, _, _, _, _, _)) + .WillOnce(DoAll(FutureArg<0>(&containerId), + FutureArg<3>(&directory), + Invoke(&dockerContainerizer, + &MockDockerContainerizer::_launch))); + + Future<TaskStatus> statusRunning; + Future<TaskStatus> statusFinished; + EXPECT_CALL(sched, statusUpdate(&driver, _)) + .WillOnce(FutureArg<1>(&statusRunning)) + .WillOnce(FutureArg<1>(&statusFinished)) + .WillRepeatedly(DoDefault()); + + driver.launchTasks(offers.get()[0].id(), tasks); + + AWAIT_READY_FOR(containerId, Seconds(60)); + AWAIT_READY(directory); + AWAIT_READY_FOR(statusRunning, Seconds(60)); + EXPECT_EQ(TASK_RUNNING, statusRunning.get().state()); + AWAIT_READY_FOR(statusFinished, Seconds(60)); + EXPECT_EQ(TASK_FINISHED, statusFinished.get().state()); + + // Now check that the proper output is in stderr and stdout (which + // might also contain other things, hence the use of a UUID). + Try<string> read = os::read(path::join(directory.get(), "stderr")); + + ASSERT_SOME(read); + EXPECT_TRUE(strings::contains(read.get(), "err" + uuid)); + EXPECT_FALSE(strings::contains(read.get(), "out" + uuid)); + + read = os::read(path::join(directory.get(), "stdout")); + + ASSERT_SOME(read); + EXPECT_TRUE(strings::contains(read.get(), "out" + uuid)); + EXPECT_FALSE(strings::contains(read.get(), "err" + uuid)); + + driver.stop(); + driver.join(); + + Shutdown(); +} http://git-wip-us.apache.org/repos/asf/mesos/blob/e43b0c70/src/tests/environment.cpp ---------------------------------------------------------------------- diff --git a/src/tests/environment.cpp b/src/tests/environment.cpp index a6cc772..2274251 100644 --- a/src/tests/environment.cpp +++ b/src/tests/environment.cpp @@ -309,6 +309,8 @@ void Environment::TearDown() directories.clear(); // Make sure we haven't left any child processes lying around. + // TODO(benh): Look for processes in the same group or session that + // might have been reparented. Try<os::ProcessTree> pstree = os::pstree(0); if (pstree.isSome() && !pstree.get().children.empty()) { http://git-wip-us.apache.org/repos/asf/mesos/blob/e43b0c70/src/tests/mesos.cpp ---------------------------------------------------------------------- diff --git a/src/tests/mesos.cpp b/src/tests/mesos.cpp index 5bd8ba0..0f759a7 100644 --- a/src/tests/mesos.cpp +++ b/src/tests/mesos.cpp @@ -165,6 +165,9 @@ slave::Flags MesosTest::CreateSlaveFlags() flags.registration_backoff_factor = Milliseconds(10); + // Make sure that the slave uses the same 'docker' as the tests. + flags.docker = tests::flags.docker; + return flags; }
