Enhance log messages with host name (#4575)

* Enhance log messages with hostName

* Use host.toString() on most of host logs.

* Remove redundant "Host" in logs and enhance logs

* duplicated "for"

* Adopt String.format, and enhance code

* Address reviews enhancing log messages

Update server/src/main/java/com/cloud/resource/ResourceManagerImpl.java
    -- server/src/main/java/com/cloud/vm/UserVmManagerImpl.java
    -- server/src/main/java/com/cloud/resource/RollingMaintenanceManagerImpl.java

Co-authored-by: Daniel Augusto Veronezi Salvador <38945620+GutoVeronezi@users.noreply.github.com>

* Fix String.format issue and change log message from debug to warn

* Fix checkstyle issue

* Fix string.format log

* Address review: enhance logs

* Enhance log of hosts in maintenance avoid list

* Remove "VM" on logs as vm.toString() already appends VM-<details>

* Add more details of the VM when postStateTransitionEvent

* Address reviewer and enhance VMInstanceVO.toString()

Co-authored-by: Daniel Augusto Veronezi Salvador <38945620+GutoVeronezi@users.noreply.github.com>

Author: GabrielBrascher

engine/orchestration/src/main/java/com/cloud/agent/manager/ClusteredAgentManagerImpl.java

@@ -286,7 +286,7 @@ protected AgentAttache createAttacheForConnect(final HostVO host, final Link lin
 
     @Override
     protected AgentAttache createAttacheForDirectConnect(final Host host, final ServerResource resource) {
-        s_logger.debug("create ClusteredDirectAgentAttache for " + host.getId());
+        s_logger.debug(String.format("Create ClusteredDirectAgentAttache for %s.", host));
         final DirectAgentAttache attache = new ClusteredDirectAgentAttache(this, host.getId(), host.getName(), _nodeId, resource, host.isInMaintenanceStates());
         AgentAttache old = null;
         synchronized (_agents) {

engine/orchestration/src/main/java/com/cloud/vm/VirtualMachineManagerImpl.java

@@ -4346,19 +4346,25 @@ private void orchestrateMigrateForScale(final String vmUuid, final long srcHostI
             throws ResourceUnavailableException, ConcurrentOperationException {
 
         VMInstanceVO vm = _vmDao.findByUuid(vmUuid);
-        s_logger.info("Migrating " + vm + " to " + dest);
+        s_logger.info(String.format("Migrating %s to %s", vm, dest));
 
         vm.getServiceOfferingId();
         final long dstHostId = dest.getHost().getId();
         final Host fromHost = _hostDao.findById(srcHostId);
+        Host srcHost = _hostDao.findById(srcHostId);
         if (fromHost == null) {
-            s_logger.info("Unable to find the host to migrate from: " + srcHostId);
-            throw new CloudRuntimeException("Unable to find the host to migrate from: " + srcHostId);
+            String logMessageUnableToFindHost = String.format("Unable to find host to migrate from %s.", srcHost);
+            s_logger.info(logMessageUnableToFindHost);
+            throw new CloudRuntimeException(logMessageUnableToFindHost);
         }
 
-        if (fromHost.getClusterId().longValue() != dest.getCluster().getId()) {
-            s_logger.info("Source and destination host are not in same cluster, unable to migrate to host: " + dstHostId);
-            throw new CloudRuntimeException("Source and destination host are not in same cluster, unable to migrate to host: " + dest.getHost().getId());
+        Host dstHost = _hostDao.findById(dstHostId);
+        long destHostClusterId = dest.getCluster().getId();
+        long fromHostClusterId = fromHost.getClusterId();
+        if (fromHostClusterId != destHostClusterId) {
+            String logMessageHostsOnDifferentCluster = String.format("Source and destination host are not in same cluster, unable to migrate to %s", srcHost);
+            s_logger.info(logMessageHostsOnDifferentCluster);
+            throw new CloudRuntimeException(logMessageHostsOnDifferentCluster);
         }
 
         final VirtualMachineGuru vmGuru = getVmGuru(vm);
@@ -4475,23 +4481,24 @@ private void orchestrateMigrateForScale(final String vmUuid, final long srcHostI
                     try {
                         _agentMgr.send(srcHostId, new Commands(cleanup(vm.getInstanceName())), null);
                     } catch (final AgentUnavailableException e) {
-                        s_logger.error("AgentUnavailableException while cleanup on source host: " + srcHostId);
+                        s_logger.error(String.format("Unable to cleanup source %s. ", srcHost), e);
                     }
                     cleanup(vmGuru, new VirtualMachineProfileImpl(vm), work, Event.AgentReportStopped, true);
                     throw new CloudRuntimeException("Unable to complete migration for " + vm);
                 }
             } catch (final OperationTimedoutException e) {
-                s_logger.debug("Error while checking the vm " + vm + " on host " + dstHostId, e);
+                s_logger.debug(String.format("Error while checking the %s on %s", vm, dstHost), e);
             }
 
             migrated = true;
         } finally {
             if (!migrated) {
                 s_logger.info("Migration was unsuccessful.  Cleaning up: " + vm);
 
-                _alertMgr.sendAlert(alertType, fromHost.getDataCenterId(), fromHost.getPodId(),
-                        "Unable to migrate vm " + vm.getInstanceName() + " from host " + fromHost.getName() + " in zone " + dest.getDataCenter().getName() + " and pod " +
-                                dest.getPod().getName(), "Migrate Command failed.  Please check logs.");
+                String alertSubject = String.format("Unable to migrate %s from %s in Zone [%s] and Pod [%s].",
+                        vm.getInstanceName(), fromHost, dest.getDataCenter().getName(), dest.getPod().getName());
+                String alertBody = "Migrate Command failed. Please check logs.";
+                _alertMgr.sendAlert(alertType, fromHost.getDataCenterId(), fromHost.getPodId(), alertSubject, alertBody);
                 try {
                     _agentMgr.send(dstHostId, new Commands(cleanup(vm.getInstanceName())), null);
                 } catch (final AgentUnavailableException ae) {
@@ -4841,6 +4848,8 @@ private void handlePowerOnReportWithNoPendingJobsOnVM(final VMInstanceVO vm) {
         //    3) handle out of sync stationary states, marking VM from Stopped to Running with
         //       alert messages
         //
+        Host host = _hostDao.findById(vm.getHostId());
+        Host poweredHost = _hostDao.findById(vm.getPowerHostId());
         switch (vm.getState()) {
         case Starting:
             s_logger.info("VM " + vm.getInstanceName() + " is at " + vm.getState() + " and we received a power-on report while there is no pending jobs on it");
@@ -4862,7 +4871,7 @@ private void handlePowerOnReportWithNoPendingJobsOnVM(final VMInstanceVO vm) {
         case Running:
             try {
                 if (vm.getHostId() != null && vm.getHostId().longValue() != vm.getPowerHostId().longValue()) {
-                    s_logger.info("Detected out of band VM migration from host " + vm.getHostId() + " to host " + vm.getPowerHostId());
+                    s_logger.info(String.format("Detected out of band VM migration from %s to %s", host, poweredHost));
                 }
                 stateTransitTo(vm, VirtualMachine.Event.FollowAgentPowerOnReport, vm.getPowerHostId());
             } catch (final NoTransitionException e) {

engine/schema/src/main/java/com/cloud/dc/ClusterVO.java

@@ -196,4 +196,9 @@ public void setUuid(String uuid) {
     public PartitionType partitionType() {
         return PartitionType.Cluster;
     }
+
+    @Override
+    public String toString() {
+        return String.format("Cluster {id: \"%s\", name: \"%s\", uuid: \"%s\"}", id, name, uuid);
+    }
 }

engine/schema/src/main/java/com/cloud/vm/VMInstanceVO.java

@@ -506,7 +506,7 @@ public void setRemoved(Date removed) {
 
     @Override
     public String toString() {
-        return String.format("VM instance {\"id\": \"%s\", \"name\": \"%s\", \"uuid\": \"%s\", \"type\"=\"%s\"}", id, getInstanceName(), uuid, type);
+        return String.format("VM instance {id: \"%s\", name: \"%s\", uuid: \"%s\", type=\"%s\"}", id, getInstanceName(), uuid, type);
     }
 
     @Override

server/src/main/java/com/cloud/capacity/CapacityManagerImpl.java

@@ -926,8 +926,11 @@ public boolean postStateTransitionEvent(StateMachine2.Transition<State, Event> t
       State oldState = transition.getCurrentState();
       State newState = transition.getToState();
       Event event = transition.getEvent();
-      s_logger.debug("VM state transitted from :" + oldState + " to " + newState + " with event: " + event + "vm's original host id: " + vm.getLastHostId() +
-              " new host id: " + vm.getHostId() + " host id before state transition: " + oldHostId);
+      Host lastHost = _hostDao.findById(vm.getLastHostId());
+      Host oldHost = _hostDao.findById(oldHostId);
+      Host newHost = _hostDao.findById(vm.getHostId());
+      s_logger.debug(String.format("%s state transited from [%s] to [%s] with event [%s]. VM's original host: %s, new host: %s, host before state transition: %s", vm, oldState,
+                newState, event, lastHost, newHost, oldHost));
 
       if (oldState == State.Starting) {
         if (newState != State.Running) {

server/src/main/java/com/cloud/network/element/VirtualRouterElement.java

@@ -411,12 +411,13 @@ public boolean stopVpn(final RemoteAccessVpn vpn) throws ResourceUnavailableExce
         if (canHandle(network, Service.Vpn)) {
             final List<DomainRouterVO> routers = _routerDao.listByNetworkAndRole(network.getId(), Role.VIRTUAL_ROUTER);
             if (routers == null || routers.isEmpty()) {
-                s_logger.debug("Virtual router elemnt doesn't need stop vpn on the backend; virtual router doesn't " + "exist in the network " + network.getId());
+                s_logger.debug(String.format("There is no virtual router in network [uuid: %s, name: %s], it is not necessary to stop the VPN on backend.",
+                        network.getUuid(), network.getName()));
                 return true;
             }
             return _routerMgr.deleteRemoteAccessVpn(network, vpn, routers);
         } else {
-            s_logger.debug("Element " + getName() + " doesn't handle removeVpn command");
+            s_logger.debug(String.format("Element %s doesn't handle removeVpn command", getName()));
             return false;
         }
     }