Improve VMWare logs (#5353)

* Improve VMWare logs

* Address reviews

* Address reviews and add more logs

* Improve VMWare logs

* Address reviews

* Address reviews and add more logs

* Address reviews

* Address reviews

* Try fix tests

* Refactor some logs to try fix tests

* Verifying if GSON is the cause of test exceptions

* Fix checkstyle

Co-authored-by: SadiJr <17a0db2854@firemailbox.club>
Co-authored-by: SadiJr <sadi@scclouds.com.br>

Author: 3 people

core/src/main/java/com/cloud/storage/resource/StorageSubsystemCommandHandlerBase.java

@@ -44,6 +44,7 @@
 import com.cloud.agent.api.to.DiskTO;
 import com.cloud.storage.DataStoreRole;
 import com.cloud.storage.Volume;
+import com.google.gson.Gson;
 
 public class StorageSubsystemCommandHandlerBase implements StorageSubsystemCommandHandler {
     private static final Logger s_logger = Logger.getLogger(StorageSubsystemCommandHandlerBase.class);
@@ -55,6 +56,7 @@ public StorageSubsystemCommandHandlerBase(StorageProcessor processor) {
 
     @Override
     public Answer handleStorageCommands(StorageSubSystemCommand command) {
+        logCommand(command);
         if (command instanceof CopyCommand) {
             return this.execute((CopyCommand)command);
         } else if (command instanceof CreateObjectCommand) {
@@ -170,4 +172,12 @@ protected Answer execute(DettachCommand cmd) {
             return processor.dettachVolume(cmd);
         }
     }
+
+    private void logCommand(Command cmd) {
+        try {
+            s_logger.debug(String.format("Executing command %s: [%s].", cmd.getClass().getSimpleName(), new Gson().toJson(cmd)));
+        } catch (Exception e) {
+            s_logger.debug(String.format("Executing command %s.", cmd.getClass().getSimpleName()));
+        }
+    }
 }

plugins/hypervisors/vmware/src/main/java/com/cloud/hypervisor/vmware/manager/VmwareHostService.java

@@ -29,4 +29,6 @@ public interface VmwareHostService {
     VmwareHypervisorHost getHyperHost(VmwareContext context, Command cmd);
 
     String getWorkerName(VmwareContext context, Command cmd, int workerSequence, DatastoreMO dsMo) throws Exception;
+
+    String createLogMessageException(Throwable e, Command command);
 }

plugins/hypervisors/vmware/src/main/java/com/cloud/hypervisor/vmware/manager/VmwareStorageManagerImpl.java

@@ -21,7 +21,6 @@
 import java.io.FileInputStream;
 import java.io.FileOutputStream;
 import java.io.OutputStreamWriter;
-import java.rmi.RemoteException;
 import java.util.ArrayList;
 import java.util.HashMap;
 import java.util.List;
@@ -85,7 +84,6 @@
 import com.cloud.storage.template.OVAProcessor;
 import com.cloud.utils.NumbersUtil;
 import com.cloud.utils.Pair;
-import com.cloud.utils.StringUtils;
 import com.cloud.utils.Ternary;
 import com.cloud.utils.exception.CloudRuntimeException;
 import com.cloud.utils.script.Script;
@@ -96,6 +94,7 @@ public class VmwareStorageManagerImpl implements VmwareStorageManager {
 
     private String _nfsVersion;
 
+
     @Override
     public boolean execute(VmwareHostService hostService, CreateEntityDownloadURLCommand cmd) {
         DataTO data = cmd.getData();
@@ -296,13 +295,7 @@ public Answer execute(VmwareHostService hostService, PrimaryStorageDownloadComma
 
             return new PrimaryStorageDownloadAnswer(templateUuidName, 0);
         } catch (Throwable e) {
-            if (e instanceof RemoteException) {
-                hostService.invalidateServiceContext(context);
-            }
-
-            String msg = "Unable to execute PrimaryStorageDownloadCommand due to exception";
-            s_logger.error(msg, e);
-            return new PrimaryStorageDownloadAnswer(msg);
+            return new PrimaryStorageDownloadAnswer(hostService.createLogMessageException(e, cmd));
         }
     }
 
@@ -380,22 +373,14 @@ public Answer execute(VmwareHostService hostService, BackupSnapshotCommand cmd)
 
                 try {
                     if (workerVm != null) {
-                        // detach volume and destroy worker vm
                         workerVm.detachAllDisksAndDestroy();
                     }
                 } catch (Throwable e) {
-                    s_logger.warn("Failed to destroy worker VM: " + workerVMName);
+                    s_logger.warn(String.format("Failed to destroy worker VM [%s] due to: [%s].", workerVMName, e.getMessage()), e);
                 }
             }
         } catch (Throwable e) {
-            if (e instanceof RemoteException) {
-                hostService.invalidateServiceContext(context);
-            }
-
-            s_logger.error("Unexpecpted exception ", e);
-
-            details = "BackupSnapshotCommand exception: " + StringUtils.getExceptionStackInfo(e);
-            return new BackupSnapshotAnswer(cmd, false, details, snapshotBackupUuid, true);
+            return new BackupSnapshotAnswer(cmd, false, hostService.createLogMessageException(e, cmd), snapshotBackupUuid, true);
         }
 
         return new BackupSnapshotAnswer(cmd, success, details, snapshotBackupUuid, true);
@@ -433,14 +418,7 @@ public Answer execute(VmwareHostService hostService, CreatePrivateTemplateFromVo
             return new CreatePrivateTemplateAnswer(cmd, true, null, result.first(), result.third(), result.second(), cmd.getUniqueName(), ImageFormat.OVA);
 
         } catch (Throwable e) {
-            if (e instanceof RemoteException) {
-                hostService.invalidateServiceContext(context);
-            }
-
-            s_logger.error("Unexpecpted exception ", e);
-
-            details = "CreatePrivateTemplateFromVolumeCommand exception: " + StringUtils.getExceptionStackInfo(e);
-            return new CreatePrivateTemplateAnswer(cmd, false, details);
+            return new CreatePrivateTemplateAnswer(cmd, false, hostService.createLogMessageException(e, cmd));
         }
     }
 
@@ -461,14 +439,7 @@ public Answer execute(VmwareHostService hostService, CreatePrivateTemplateFromSn
 
             return new CreatePrivateTemplateAnswer(cmd, true, null, result.first(), result.third(), result.second(), uniqeName, ImageFormat.OVA);
         } catch (Throwable e) {
-            if (e instanceof RemoteException) {
-                hostService.invalidateServiceContext(context);
-            }
-
-            s_logger.error("Unexpecpted exception ", e);
-
-            details = "CreatePrivateTemplateFromSnapshotCommand exception: " + StringUtils.getExceptionStackInfo(e);
-            return new CreatePrivateTemplateAnswer(cmd, false, details);
+            return new CreatePrivateTemplateAnswer(cmd, false, hostService.createLogMessageException(e, cmd));
         }
     }
 
@@ -504,13 +475,7 @@ public Answer execute(VmwareHostService hostService, CopyVolumeCommand cmd) {
             }
             return new CopyVolumeAnswer(cmd, true, null, result.first(), result.second());
         } catch (Throwable e) {
-            if (e instanceof RemoteException) {
-                hostService.invalidateServiceContext(context);
-            }
-
-            String msg = "Unable to execute CopyVolumeCommand due to exception";
-            s_logger.error(msg, e);
-            return new CopyVolumeAnswer(cmd, false, "CopyVolumeCommand failed due to exception: " + StringUtils.getExceptionStackInfo(e), null, null);
+            return new CopyVolumeAnswer(cmd, false, hostService.createLogMessageException(e, cmd), null, null);
         }
     }
 
@@ -543,12 +508,7 @@ public Answer execute(VmwareHostService hostService, CreateVolumeFromSnapshotCom
                 success = true;
             }
         } catch (Throwable e) {
-            if (e instanceof RemoteException) {
-                hostService.invalidateServiceContext(context);
-            }
-
-            s_logger.error("Unexpecpted exception ", e);
-            details = "CreateVolumeFromSnapshotCommand exception: " + StringUtils.getExceptionStackInfo(e);
+            details = hostService.createLogMessageException(e, cmd);
         }
 
         return new CreateVolumeFromSnapshotAnswer(cmd, success, details, newVolumeName);
@@ -946,8 +906,12 @@ private void exportVolumeToSecondaryStorage(VirtualMachineMO vmMo, String volume
                 Script command = new Script(false, "mkdir", _timeout, s_logger);
                 command.add("-p");
                 command.add(exportPath);
-                if (command.execute() != null) {
-                    throw new Exception("unable to prepare snapshot backup directory");
+
+                String result = command.execute();
+                if (result != null) {
+                    String errorMessage = String.format("Unable to prepare snapshot backup directory: [%s] due to [%s].", exportPath, result);
+                    s_logger.error(errorMessage);
+                    throw new Exception(errorMessage);
                 }
             }
         }
@@ -968,7 +932,7 @@ private void exportVolumeToSecondaryStorage(VirtualMachineMO vmMo, String volume
                 vmMo.cloneFromCurrentSnapshot(workerVmName, 0, 4, volumeDeviceInfo.second(), VmwareHelper.getDiskDeviceDatastore(volumeDeviceInfo.first()), vmxFormattedVirtualHardwareVersion);
                 clonedVm = vmMo.getRunningHost().findVmOnHyperHost(workerVmName);
                 if (clonedVm == null) {
-                    String msg = "Unable to create dummy VM to export volume. volume path: " + volumePath;
+                    String msg = String.format("Unable to create dummy VM to export volume. volume path: [%s].", volumePath);
                     s_logger.error(msg);
                     throw new Exception(msg);
                 }
@@ -1033,7 +997,6 @@ private Pair<String, String> copyVolumeToSecStorage(VmwareHostService hostServic
                 vmMo.removeSnapshot(exportName, false);
             }
             if (workerVm != null) {
-                //detach volume and destroy worker vm
                 workerVm.detachAllDisksAndDestroy();
             }
         }