[Libreoffice-commits] online.git: Branch 'distro/collabora/collabora-online-3-0' - kit/Kit.cpp

[Pranav Kant]

 kit/Kit.cpp |   24 ++++++++++++++++++++++++
 1 file changed, 24 insertions(+)

New commits:
commit 6aa04137a2ed4a725822e1c770358aced2ab5f60
Author: Pranav Kant <pranavk at collabora.co.uk>
Date:   Fri Jan 26 21:04:49 2018 +0530

    kit: start spamming the logs when linking/copying is slowww
    
    This is sometimes the case in docker when the link operation 'copies up'
    things from lower layers to the working docker container's layer. In
    such cases, let the admin know.
    
    Change-Id: Ib72b67304a292c3832838379cc76bcb4a7268cb3
    Reviewed-on: https://gerrit.libreoffice.org/48710
    Reviewed-by: pranavk <pranavk at collabora.co.uk>
    Tested-by: pranavk <pranavk at collabora.co.uk>
    (cherry picked from commit 1d22f7bc548dc48c95390c6f23b67f1972825617)
    Reviewed-on: https://gerrit.libreoffice.org/48711
    Reviewed-by: Michael Meeks <michael.meeks at collabora.com>
    Reviewed-by: Jan Holesovsky <kendy at collabora.com>
    Tested-by: Jan Holesovsky <kendy at collabora.com>

diff --git a/kit/Kit.cpp b/kit/Kit.cpp
index 193b8ccb..d1bbdbed 100644
--- a/kit/Kit.cpp
+++ b/kit/Kit.cpp
@@ -119,6 +119,9 @@ namespace
     LinkOrCopyType linkOrCopyType;
     std::string sourceForLinkOrCopy;
     Path destinationForLinkOrCopy;
+    std::chrono::time_point<std::chrono::steady_clock> linkOrCopyStartTime;
+    bool linkOrCopyVerboseLogging = false;
+    unsigned slowLinkOrCopyLimitInSecs = 10; // after this much seconds, start spamming the logs
 
     bool shouldCopyDir(const char *path)
     {
@@ -150,6 +153,18 @@ namespace
         if (strcmp(fpath, sourceForLinkOrCopy.c_str()) == 0)
             return 0;
 
+        if (!linkOrCopyVerboseLogging)
+        {
+            const auto durationInSecs = std::chrono::duration_cast<std::chrono::seconds>(
+                std::chrono::steady_clock::now() - linkOrCopyStartTime);
+            if (durationInSecs.count() > slowLinkOrCopyLimitInSecs)
+            {
+                LOG_WRN("Linking/copying files from " << sourceForLinkOrCopy << " to " << destinationForLinkOrCopy.toString() <<
+                        " is taking too much time. Enabling verbose link/copy logging at information level.");
+                linkOrCopyVerboseLogging = true;
+            }
+        }
+
         assert(fpath[strlen(sourceForLinkOrCopy.c_str())] == '/');
         const char *relativeOldPath = fpath + strlen(sourceForLinkOrCopy.c_str()) + 1;
         Path newPath(destinationForLinkOrCopy, Path(relativeOldPath));
@@ -159,6 +174,9 @@ namespace
         case FTW_F:
         case FTW_SLN:
             File(newPath.parent()).createDirectories();
+
+            if (linkOrCopyVerboseLogging)
+                LOG_INF("Linking file \"" << fpath << "\" to \"" << newPath.toString() << "\"");
             if (link(fpath, newPath.toString().c_str()) == -1)
             {
                 LOG_SYS("link(\"" << fpath << "\", \"" <<
@@ -222,10 +240,16 @@ namespace
         if (sourceForLinkOrCopy.back() == '/')
             sourceForLinkOrCopy.pop_back();
         destinationForLinkOrCopy = destination;
+        linkOrCopyStartTime = std::chrono::steady_clock::now();
         if (nftw(source.c_str(), linkOrCopyFunction, 10, FTW_ACTIONRETVAL) == -1)
         {
             LOG_ERR("linkOrCopy: nftw() failed for '" << source << "'");
         }
+        if (linkOrCopyVerboseLogging)
+        {
+            LOG_INF("Linking/Copying of files to " << destinationForLinkOrCopy.toString() << " finished.");
+            linkOrCopyVerboseLogging = false;
+        }
     }
 
     void dropCapability(cap_value_t capability)