Improve logs in NfsSecondaryStorageResource class, (#7211)

Co-authored-by: SadiJr <sadi@scclouds.com.br>

Author: SadiJr

services/secondary-storage/server/src/main/java/org/apache/cloudstack/storage/resource/NfsSecondaryStorageResource.java

@@ -159,6 +159,7 @@
 import com.cloud.storage.template.VhdProcessor;
 import com.cloud.storage.template.VmdkProcessor;
 import com.cloud.utils.EncryptionUtil;
+import com.cloud.utils.LogUtils;
 import com.cloud.utils.NumbersUtil;
 import com.cloud.utils.Pair;
 import com.cloud.utils.SwiftUtil;
@@ -272,6 +273,7 @@ public static String retrieveNfsVersionFromParams(Map<String, Object> params) {
 
     @Override
     public Answer executeRequest(Command cmd) {
+        s_logger.debug(LogUtils.logGsonWithoutException("Executing command %s [%s].", cmd.getClass().getSimpleName(), cmd));
         if (cmd instanceof DownloadProgressCommand) {
             return _dlMgr.handleDownloadCommand(this, (DownloadProgressCommand)cmd);
         } else if (cmd instanceof DownloadCommand) {
@@ -406,13 +408,17 @@ public Answer execute(GetDatadisksCommand cmd) {
         NfsTO nfsImageStore = (NfsTO)srcStore;
         String secondaryStorageUrl = nfsImageStore.getUrl();
         assert (secondaryStorageUrl != null);
+
         String templateUrl = secondaryStorageUrl + File.separator + srcData.getPath();
+        String templateDetails = ReflectionToStringBuilderUtils.reflectOnlySelectedFields(template, "uuid", "path", "name");
+        s_logger.debug(String.format("Trying to get disks of template [%s], using path [%s].", templateDetails, templateUrl));
+
         Pair<String, String> templateInfo = decodeTemplateRelativePathAndNameFromUrl(secondaryStorageUrl, templateUrl, template.getName());
         String templateRelativeFolderPath = templateInfo.first();
 
         try {
             String secondaryMountPoint = getRootDir(secondaryStorageUrl, _nfsVersion);
-            s_logger.info("MDOVE Secondary storage mount point: " + secondaryMountPoint);
+            s_logger.info(String.format("Trying to find template [%s] in secondary storage root mount point [%s].", templateDetails, secondaryMountPoint));
 
             String srcOVAFileName = getTemplateOnSecStorageFilePath(secondaryMountPoint, templateRelativeFolderPath, templateInfo.second(), ImageFormat.OVA.getFileExtension());
 
@@ -423,39 +429,46 @@ public Answer execute(GetDatadisksCommand cmd) {
                 command.add("--no-same-permissions");
                 command.add("-xf", srcOVAFileName);
                 command.setWorkDir(secondaryMountPoint + File.separator + templateRelativeFolderPath);
-                s_logger.info("Executing command: " + command.toString());
+
+                s_logger.info(String.format("Trying to decompress OVA file [%s] using command [%s].", srcOVAFileName, command.toString()));
                 String result = command.execute();
                 if (result != null) {
-                    String msg = "Unable to unpack snapshot OVA file at: " + srcOVAFileName;
+                    String msg = String.format("Unable to unpack snapshot OVA file [%s] due to [%s].", srcOVAFileName, result);
                     s_logger.error(msg);
                     throw new Exception(msg);
                 }
 
+                String directory = secondaryMountPoint + File.separator + templateRelativeFolderPath;
                 command = new Script("chmod", 0, s_logger);
                 command.add("-R");
-                command.add("666", secondaryMountPoint + File.separator + templateRelativeFolderPath);
+                command.add("666", directory);
+
+                s_logger.debug(String.format("Trying to add, recursivelly, permission 666 to directory [%s] using command [%s].", directory, command.toString()));
                 result = command.execute();
                 if (result != null) {
-                    s_logger.warn("Unable to set permissions for " + secondaryMountPoint + File.separator + templateRelativeFolderPath + " due to " + result);
+                    s_logger.warn(String.format("Unable to set permissions 666 for directory [%s] due to [%s].", directory, result));
                 }
             }
 
             Script command = new Script("cp", _timeout, s_logger);
             command.add(ovfFilePath);
             command.add(ovfFilePath + ORIGINAL_FILE_EXTENSION);
+            s_logger.debug(String.format("Trying to copy file from [%s] to [%s] using command [%s].", ovfFilePath, ovfFilePath + ORIGINAL_FILE_EXTENSION, command.toString()));
             String result = command.execute();
             if (result != null) {
-                String msg = "Unable to rename original OVF, error msg: " + result;
+                String msg = String.format("Unable to copy original OVF file [%s] to [%s] due to [%s].", ovfFilePath, ovfFilePath + ORIGINAL_FILE_EXTENSION, result);
                 s_logger.error(msg);
             }
 
-            s_logger.debug("Reading OVF " + ovfFilePath + " to retrive the number of disks present in OVA");
+            s_logger.debug(String.format("Reading OVF file [%s] to retrive the number of disks present in OVA file.", ovfFilePath));
             OVFHelper ovfHelper = new OVFHelper();
 
             List<DatadiskTO> disks = ovfHelper.getOVFVolumeInfoFromFile(ovfFilePath, configurationId);
+            s_logger.debug(LogUtils.logGsonWithoutException("Found %s disks reading OVF file [%s] and using configuration id [%s]. The disks specifications are [%s].",
+                    disks.size(), ovfFilePath, configurationId, disks));
             return new GetDatadisksAnswer(disks);
         } catch (Exception e) {
-            String msg = "Get Datadisk Template Count failed due to " + e.getMessage();
+            String msg = String.format("Failed to get disks from template [%s] due to [%s].", templateDetails, e.getMessage());
             s_logger.error(msg, e);
             return new GetDatadisksAnswer(msg);
         }
@@ -584,7 +597,7 @@ public Answer execute(MoveVolumeCommand cmd) {
      *  Template url may or may not end with .ova extension
      */
     public static Pair<String, String> decodeTemplateRelativePathAndNameFromUrl(String storeUrl, String templateUrl, String defaultName) {
-
+        s_logger.debug(String.format("Trying to get template relative path and name from URL [%s].", templateUrl));
         String templateName = null;
         String mountPoint = null;
         if (templateUrl.endsWith(".ova")) {
@@ -598,6 +611,7 @@ public static Pair<String, String> decodeTemplateRelativePathAndNameFromUrl(Stri
             templateName = templateUrl.substring(index + 1).replace(".ova", "");
 
             if (templateName == null || templateName.isEmpty()) {
+                s_logger.debug(String.format("Cannot find template name from URL [%s]. Using default name [%s].", templateUrl, defaultName));
                 templateName = defaultName;
             }
         } else {
@@ -608,11 +622,13 @@ public static Pair<String, String> decodeTemplateRelativePathAndNameFromUrl(Stri
             templateName = defaultName;
         }
 
+        s_logger.debug(String.format("Template relative path [%s] and name [%s] found from URL [%s].", mountPoint, templateName, templateUrl));
         return new Pair<String, String>(mountPoint, templateName);
     }
 
     public static String getTemplateOnSecStorageFilePath(String secStorageMountPoint, String templateRelativeFolderPath, String templateName, String fileExtension) {
-
+        s_logger.debug(String.format("Trying to find template [%s] with file extension [%s] in secondary storage mount point [%s] using relative folder path [%s].",
+                templateName, fileExtension, secStorageMountPoint, templateRelativeFolderPath));
         StringBuffer sb = new StringBuffer();
         sb.append(secStorageMountPoint);
         if (!secStorageMountPoint.endsWith("/")) {
@@ -699,17 +715,27 @@ private void writeMetaOvaForTemplate(final String installFullPath, final String
     }
 
     private String getOVFFilePath(String srcOVAFileName) {
+        s_logger.debug(String.format("Trying to get OVF file from OVA path [%s].", srcOVAFileName));
+
         File file = new File(srcOVAFileName);
         assert (_storage != null);
         String[] files = _storage.listFiles(file.getParent());
-        if (files != null) {
-            for (String fileName : files) {
-                if (fileName.toLowerCase().endsWith(".ovf")) {
-                    File ovfFile = new File(fileName);
-                    return file.getParent() + File.separator + ovfFile.getName();
-                }
+
+        if (files == null) {
+            s_logger.warn(String.format("Cannot find any files in parent directory [%s] of OVA file [%s].", file.getParent(), srcOVAFileName));
+            return null;
+        }
+
+        s_logger.debug(String.format("Found [%s] files in parent directory of OVA file [%s]. Files found are [%s].", files.length + 1, file.getParent(), StringUtils.join(files, ", ")));
+        for (String fileName : files) {
+            if (fileName.toLowerCase().endsWith(".ovf")) {
+                File ovfFile = new File(fileName);
+                String ovfFilePath = file.getParent() + File.separator + ovfFile.getName();
+                s_logger.debug(String.format("Found OVF file [%s] from OVA file [%s].", ovfFilePath, srcOVAFileName));
+                return ovfFilePath;
             }
         }
+        s_logger.warn(String.format("Cannot find any OVF file in parent directory [%s] of OVA file [%s].", file.getParent(), srcOVAFileName));
         return null;
     }
 
@@ -2616,13 +2642,13 @@ synchronized public String getRootDir(String secUrl, String nfsVersion) {
             return _parent;
         }
         try {
+            s_logger.debug(String.format("Trying to get root directory from secondary storage URL [%s] using NFS version [%s].", secUrl, nfsVersion));
             URI uri = new URI(secUrl);
             String dir = mountUri(uri, nfsVersion);
             return _parent + "/" + dir;
         } catch (Exception e) {
-            String msg = "GetRootDir for " + secUrl + " failed due to " + e.toString();
-            s_logger.error(msg, e);
-            throw new CloudRuntimeException(msg);
+            String msg = String.format("Failed to get root directory from secondary storage URL [%s], using NFS version [%s], due to [%s].", secUrl, nfsVersion, e.getMessage());
+            throw new CloudRuntimeException(msg, e);
         }
     }