Improve debug messages.

org.jdrupes.vmoperator.runner.qemu/src/org/jdrupes/vmoperator/runner/qemu/GuestAgentClient.java

@@ -69,14 +69,14 @@ public class GuestAgentClient extends AgentConnector {
      */
     @Override
     protected void agentConnected() {
-        logger.fine(() -> "guest agent connected");
+        logger.fine(() -> "Guest agent connected");
         connected = true;
         rep().fire(new GuestAgentCommand(new QmpGuestGetOsinfo()));
     }
 
     @Override
     protected void agentDisconnected() {
-        logger.fine(() -> "guest agent disconnected");
+        logger.fine(() -> "Guest agent disconnected");
         connected = false;
     }
 
@@ -88,15 +88,16 @@ public class GuestAgentClient extends AgentConnector {
      */
     @Override
     protected void processInput(String line) throws IOException {
-        logger.fine(() -> "guest agent(in): " + line);
+        logger.finer(() -> "guest agent(in): " + line);
         try {
             var response = mapper.readValue(line, ObjectNode.class);
             if (response.has("return") || response.has("error")) {
                 QmpCommand executed = executing.poll();
-                logger.fine(() -> String.format("(Previous \"guest agent(in)\""
+                logger.finer(() -> String.format("(Previous \"guest agent(in)\""
                     + " is result from executing %s)", executed));
                 if (executed instanceof QmpGuestGetOsinfo) {
                     var osInfo = new OsinfoEvent(response.get("return"));
+                    logger.fine(() -> "Guest agent triggers: " + osInfo);
                     rep().fire(osInfo);
                 }
             }
@@ -120,10 +121,11 @@ public class GuestAgentClient extends AgentConnector {
             return;
         }
         var command = event.command();
-        logger.fine(() -> "guest agent(out): " + command.toString());
+        logger.fine(() -> "Guest handles: " + event);
         String asText;
         try {
             asText = command.asText();
+            logger.finer(() -> "guest agent(out): " + asText);
         } catch (JsonProcessingException e) {
             logger.log(Level.SEVERE, e,
                 () -> "Cannot serialize Json: " + e.getMessage());
@@ -163,8 +165,8 @@ public class GuestAgentClient extends AgentConnector {
         }
         event.suspendHandling();
         suspendedStop = event;
-        logger.fine(() -> "Sending powerdown command, waiting for"
-            + " termination until " + waitUntil);
+        logger.fine(() -> "Attempting shutdown through guest agent,"
+            + " waiting for termination until " + waitUntil);
         powerdownTimer = Components.schedule(t -> {
             logger.fine(() -> "Powerdown timeout reached.");
             synchronized (this) {

org.jdrupes.vmoperator.runner.qemu/src/org/jdrupes/vmoperator/runner/qemu/QemuMonitor.java

@@ -108,24 +108,30 @@ public class QemuMonitor extends QemuConnector {
     @Override
     protected void processInput(String line)
             throws IOException {
-        logger.fine(() -> "monitor(in): " + line);
+        logger.finer(() -> "monitor(in): " + line);
         try {
             var response = mapper.readValue(line, ObjectNode.class);
             if (response.has("QMP")) {
                 monitorReady = true;
+                logger.fine(() -> "QMP connection ready");
                 rep().fire(new MonitorReady());
                 return;
             }
             if (response.has("return") || response.has("error")) {
                 QmpCommand executed = executing.poll();
-                logger.fine(
+                logger.finer(
                     () -> String.format("(Previous \"monitor(in)\" is result "
                         + "from executing %s)", executed));
-                rep().fire(MonitorResult.from(executed, response));
+                var monRes = MonitorResult.from(executed, response);
+                logger.fine(() -> "QMP triggers: " + monRes);
+                rep().fire(monRes);
                 return;
             }
             if (response.has("event")) {
-                MonitorEvent.from(response).ifPresent(rep()::fire);
+                MonitorEvent.from(response).ifPresent(me -> {
+                    logger.fine(() -> "QMP triggers: " + me);
+                    rep().fire(me);
+                });
             }
         } catch (JsonProcessingException e) {
             throw new IOException(e);
@@ -141,7 +147,7 @@ public class QemuMonitor extends QemuConnector {
     public void onClosed(Closed<?> event, SocketIOChannel channel) {
         channel.associated(this, getClass()).ifPresent(qm -> {
             super.onClosed(event, channel);
-            logger.finer(() -> "QMP socket closed.");
+            logger.fine(() -> "QMP connection closed.");
             monitorReady = false;
         });
     }
@@ -158,7 +164,7 @@ public class QemuMonitor extends QemuConnector {
     public void onMonitorCommand(MonitorCommand event) throws IOException {
         // Check prerequisites
         if (!monitorReady && !(event.command() instanceof QmpCapabilities)) {
-            logger.severe(() -> "Premature monitor command (not ready): "
+            logger.severe(() -> "Premature QMP command (not ready): "
                 + event.command());
             rep().fire(new Stop());
             return;
@@ -166,10 +172,11 @@ public class QemuMonitor extends QemuConnector {
 
         // Send the command
         var command = event.command();
-        logger.fine(() -> "monitor(out): " + command.toString());
+        logger.fine(() -> "QMP handles: " + event.toString());
         String asText;
         try {
             asText = command.asText();
+            logger.finer(() -> "monitor(out): " + asText);
         } catch (JsonProcessingException e) {
             logger.log(Level.SEVERE, e,
                 () -> "Cannot serialize Json: " + e.getMessage());
@@ -192,8 +199,8 @@ public class QemuMonitor extends QemuConnector {
     @SuppressWarnings("PMD.AvoidSynchronizedStatement")
     public void onStop(Stop event) {
         if (!monitorReady) {
-            logger.fine(() -> "No QMP connection,"
-                + " cannot send powerdown command");
+            logger.fine(() -> "Not sending QMP powerdown command"
+                + " because QMP connection is closed");
             return;
         }
 

org.jdrupes.vmoperator.runner.qemu/src/org/jdrupes/vmoperator/runner/qemu/VmopAgentClient.java

@@ -59,10 +59,14 @@ public class VmopAgentClient extends AgentConnector {
      */
     @Handler
     public void onVmopAgentLogIn(VmopAgentLogIn event) throws IOException {
-        logger.fine(() -> "vmop agent(out): login " + event.user());
         if (writer().isPresent()) {
+            logger.fine(() -> "Vmop agent handles:" + event);
             executing.add(event);
+            logger.finer(() -> "vmop agent(out): login " + event.user());
             sendCommand("login " + event.user());
+        } else {
+            logger
+                .warning(() -> "No vmop agent connection for sending " + event);
         }
     }
 
@@ -74,9 +78,10 @@ public class VmopAgentClient extends AgentConnector {
      */
     @Handler
     public void onVmopAgentLogout(VmopAgentLogOut event) throws IOException {
-        logger.fine(() -> "vmop agent(out): logout");
         if (writer().isPresent()) {
+            logger.fine(() -> "Vmop agent handles:" + event);
             executing.add(event);
+            logger.finer(() -> "vmop agent(out): logout");
             sendCommand("logout");
         }
     }
@@ -85,23 +90,27 @@ public class VmopAgentClient extends AgentConnector {
     @SuppressWarnings({ "PMD.UnnecessaryReturn",
         "PMD.AvoidLiteralsInIfCondition" })
     protected void processInput(String line) throws IOException {
-        logger.fine(() -> "vmop agent(in): " + line);
+        logger.finer(() -> "vmop agent(in): " + line);
 
         // Check validity
         if (line.isEmpty() || !Character.isDigit(line.charAt(0))) {
-            logger.warning(() -> "Illegal response: " + line);
+            logger.warning(() -> "Illegal vmop agent response: " + line);
             return;
         }
 
         // Check positive responses
         if (line.startsWith("220 ")) {
-            rep().fire(new VmopAgentConnected());
+            var evt = new VmopAgentConnected();
+            logger.fine(() -> "Vmop agent triggers " + evt);
+            rep().fire(evt);
             return;
         }
         if (line.startsWith("201 ")) {
             Event<?> cmd = executing.pop();
             if (cmd instanceof VmopAgentLogIn login) {
-                rep().fire(new VmopAgentLoggedIn(login));
+                var evt = new VmopAgentLoggedIn(login);
+                logger.fine(() -> "Vmop agent triggers " + evt);
+                rep().fire(evt);
             } else {
                 logger.severe(() -> "Response " + line
                     + " does not match executing command " + cmd);
@@ -111,7 +120,9 @@ public class VmopAgentClient extends AgentConnector {
         if (line.startsWith("202 ")) {
             Event<?> cmd = executing.pop();
             if (cmd instanceof VmopAgentLogOut logout) {
-                rep().fire(new VmopAgentLoggedOut(logout));
+                var evt = new VmopAgentLoggedOut(logout);
+                logger.fine(() -> "Vmop agent triggers " + evt);
+                rep().fire(evt);
             } else {
                 logger.severe(() -> "Response " + line
                     + "does not match executing command " + cmd);
@@ -125,7 +136,7 @@ public class VmopAgentClient extends AgentConnector {
         }
 
         // Error
-        logger.warning(() -> "Error response: " + line);
+        logger.warning(() -> "Error response from vmop agent: " + line);
         executing.pop();
     }
 

org.jdrupes.vmoperator.runner.qemu/src/org/jdrupes/vmoperator/runner/qemu/events/MonitorEvent.java

@@ -20,6 +20,8 @@ package org.jdrupes.vmoperator.runner.qemu.events;
 
 import com.fasterxml.jackson.databind.JsonNode;
 import java.util.Optional;
+import org.jgrapes.core.Channel;
+import org.jgrapes.core.Components;
 import org.jgrapes.core.Event;
 
 /**
@@ -112,4 +114,20 @@ public class MonitorEvent extends Event<Void> {
     public JsonNode data() {
         return data;
     }
+
+    /*
+     * (non-Javadoc)
+     * 
+     * @see java.lang.Object#toString()
+     */
+    @Override
+    public String toString() {
+        StringBuilder builder = new StringBuilder();
+        builder.append(Components.objectName(this)).append(" [").append(data);
+        if (channels() != null) {
+            builder.append(", channels=").append(Channel.toString(channels()));
+        }
+        builder.append(']');
+        return builder.toString();
+    }
 }

org.jdrupes.vmoperator.runner.qemu/src/org/jdrupes/vmoperator/runner/qemu/events/OsinfoEvent.java

@@ -19,6 +19,8 @@
 package org.jdrupes.vmoperator.runner.qemu.events;
 
 import com.fasterxml.jackson.databind.JsonNode;
+import org.jgrapes.core.Channel;
+import org.jgrapes.core.Components;
 import org.jgrapes.core.Event;
 
 /**
@@ -40,4 +42,21 @@ public class OsinfoEvent extends Event<Void> {
     public JsonNode osinfo() {
         return osinfo;
     }
+
+    /*
+     * (non-Javadoc)
+     * 
+     * @see java.lang.Object#toString()
+     */
+    @Override
+    public String toString() {
+        StringBuilder builder = new StringBuilder();
+        builder.append(Components.objectName(this)).append(" [")
+            .append(osinfo);
+        if (channels() != null) {
+            builder.append(", channels=").append(Channel.toString(channels()));
+        }
+        builder.append(']');
+        return builder.toString();
+    }
 }