This is an automated email from the ASF dual-hosted git repository. qianzhang pushed a commit to branch 1.8.x in repository https://gitbox.apache.org/repos/asf/mesos.git
commit 7687f4ea379cbd17b46c54505246018bb1fd9ef3 Author: Qian Zhang <zhq527...@gmail.com> AuthorDate: Thu Oct 17 17:41:10 2019 +0800 Improved logging in Docker store and registry puller. Review: https://reviews.apache.org/r/71629 --- .../mesos/provisioner/docker/registry_puller.cpp | 42 +++++++++++++--------- .../mesos/provisioner/docker/store.cpp | 12 +++++-- 2 files changed, 36 insertions(+), 18 deletions(-) diff --git a/src/slave/containerizer/mesos/provisioner/docker/registry_puller.cpp b/src/slave/containerizer/mesos/provisioner/docker/registry_puller.cpp index 35b6afb..42b6e3d 100644 --- a/src/slave/containerizer/mesos/provisioner/docker/registry_puller.cpp +++ b/src/slave/containerizer/mesos/provisioner/docker/registry_puller.cpp @@ -305,9 +305,8 @@ Future<Image> RegistryPullerProcess::_pull( port); } - VLOG(1) << "Pulling image '" << normalizedRef - << "' from '" << manifestUri - << "' to '" << directory << "'"; + LOG(INFO) << "Fetching manifest from '" << manifestUri << "' to '" + << directory << "' for image '" << normalizedRef << "'"; // Pass the original 'reference' along to subsequent methods // because metadata manager may already has this reference in @@ -423,6 +422,9 @@ Future<Image> RegistryPullerProcess::___pull( vector<string> layerIds; vector<Future<Nothing>> futures; + LOG(INFO) << "Extracting layers to '" << directory + << "' for image '" << reference << "'"; + // The order of `fslayers` should be [child, parent, ...]. // // The content in the parent will be overwritten by the child if @@ -454,8 +456,8 @@ Future<Image> RegistryPullerProcess::___pull( const string rootfs = paths::getImageLayerRootfsPath(layerPath, backend); const string json = paths::getImageLayerManifestPath(layerPath); - VLOG(1) << "Extracting layer tar ball '" << tar - << " to rootfs '" << rootfs << "'"; + VLOG(1) << "Extracting layer tar ball '" << tar << " to rootfs '" + << rootfs << "' for image '" << reference << "'"; // NOTE: This will create 'layerPath' as well. Try<Nothing> mkdir = os::mkdir(rootfs, true); @@ -511,6 +513,9 @@ Future<Image> RegistryPullerProcess::____pull( vector<string> layerIds; vector<Future<Nothing>> futures; + LOG(INFO) << "Extracting layers to '" << directory + << "' for image '" << reference << "'"; + for (int i = 0; i < manifest.layers_size(); i++) { const string& digest = manifest.layers(i).digest(); if (uniqueIds.contains(digest)) { @@ -530,8 +535,8 @@ Future<Image> RegistryPullerProcess::____pull( const string tar = path::join(directory, digest + "-archive"); const string rootfs = paths::getImageLayerRootfsPath(layerPath, backend); - VLOG(1) << "Moving layer tar ball '" << originalTar - << "' to '" << tar << "'"; + VLOG(1) << "Moving layer tar ball '" << originalTar << "' to '" + << tar << "' for image '" << reference << "'"; // Move layer tar ball to use its name for the extracted layer directory. Try<Nothing> rename = os::rename(originalTar, tar); @@ -541,8 +546,8 @@ Future<Image> RegistryPullerProcess::____pull( "' to '" + tar + "': " + rename.error()); } - VLOG(1) << "Extracting layer tar ball '" << tar - << "' to rootfs '" << rootfs << "'"; + VLOG(1) << "Extracting layer tar ball '" << tar << "' to rootfs '" + << rootfs << "' for image '" << reference << "'"; // NOTE: This will create 'layerPath' as well. Try<Nothing> mkdir = os::mkdir(rootfs, true); @@ -565,7 +570,6 @@ Future<Image> RegistryPullerProcess::____pull( } const string tar = path::join(directory, digest + "-archive"); - Try<Nothing> rm = os::rm(tar); if (rm.isError()) { return Failure( @@ -598,6 +602,9 @@ Future<hashset<string>> RegistryPullerProcess::fetchBlobs( // just need to fetch one of them. hashset<string> blobSums; + LOG(INFO) << "Fetching blobs to '" << directory << "' for image '" + << normalizedRef << "'"; + for (int i = 0; i < manifest.fslayers_size(); i++) { CHECK(manifest.history(i).has_v1()); const spec::v1::ImageManifest& v1 = manifest.history(i).v1(); @@ -611,8 +618,8 @@ Future<hashset<string>> RegistryPullerProcess::fetchBlobs( const string& blobSum = manifest.fslayers(i).blobsum(); - VLOG(1) << "Fetching blob '" << blobSum << "' for layer '" - << v1.id() << "' of image '" << normalizedRef << "'"; + VLOG(1) << "Fetching blob '" << blobSum << "' for layer '" << v1.id() + << "' of image '" << normalizedRef << "' to '" << directory << "'"; blobSums.insert(blobSum); } @@ -636,12 +643,15 @@ Future<hashset<string>> RegistryPullerProcess::fetchBlobs( const string& configDigest = manifest.config().digest(); if (!os::exists(paths::getImageLayerPath(storeDir, configDigest))) { - VLOG(1) << "Fetching config '" << configDigest << "' for image '" - << normalizedRef << "'"; + LOG(INFO) << "Fetching config '" << configDigest << "' to '" << directory + << "' for image '" << normalizedRef << "'"; digests.insert(configDigest); } + LOG(INFO) << "Fetching layers to '" << directory << "' for image '" + << normalizedRef << "'"; + for (int i = 0; i < manifest.layers_size(); i++) { const string& digest = manifest.layers(i).digest(); @@ -651,8 +661,8 @@ Future<hashset<string>> RegistryPullerProcess::fetchBlobs( continue; } - VLOG(1) << "Fetching layer '" << digest << "' for image '" - << normalizedRef << "'"; + VLOG(1) << "Fetching layer '" << digest << "' to '" << directory + << "' for image '" << normalizedRef << "'"; digests.insert(digest); } diff --git a/src/slave/containerizer/mesos/provisioner/docker/store.cpp b/src/slave/containerizer/mesos/provisioner/docker/store.cpp index 5489936..bf2be90 100644 --- a/src/slave/containerizer/mesos/provisioner/docker/store.cpp +++ b/src/slave/containerizer/mesos/provisioner/docker/store.cpp @@ -333,6 +333,7 @@ Future<Image> StoreProcess::_get( } if (!layerMissed) { + LOG(INFO) << "Using cached image '" << reference << "'"; return image.get(); } } @@ -345,6 +346,8 @@ Future<Image> StoreProcess::_get( "Failed to create a staging directory: " + staging.error()); } + LOG(INFO) << "Pulling image '" << reference << "'"; + return metrics.image_pull.time(puller->pull( reference, staging.get(), @@ -352,13 +355,15 @@ Future<Image> StoreProcess::_get( config) .then(defer(self(), &Self::moveLayers, staging.get(), lambda::_1, backend)) .then(defer(self(), [=](const Image& image) { + LOG(INFO) << "Caching image '" << reference << "'"; return metadataManager->put(image); })) .onAny(defer(self(), [=](const Future<Image>& image) { + LOG(INFO) << "Removing staging directory '" << staging.get() << "'"; Try<Nothing> rmdir = os::rmdir(staging.get()); if (rmdir.isError()) { - LOG(WARNING) << "Failed to remove staging directory: " - << rmdir.error(); + LOG(WARNING) << "Failed to remove staging directory '" << staging.get() + << "': " << rmdir.error(); } }))); } @@ -422,6 +427,9 @@ Future<Image> StoreProcess::moveLayers( const Image& image, const string& backend) { + LOG(INFO) << "Moving layers from staging directory '" << staging + << "' to image store for image '" << image.reference() << "'"; + vector<Future<Nothing>> futures; foreach (const string& layerId, image.layer_ids()) { futures.push_back(moveLayer(staging, layerId, backend));