HAWKULAR-309 Improve debug output in Pinger and Availability Creator

hawkular · Jun 8, 2015 · a79ab70 · a79ab70
1 parent 1d8fd2b
commit a79ab70
Show file tree

Hide file tree

Showing 9 changed files with 81 additions and 24 deletions.
diff --git a/dist/src/main/resources/wildfly/patches/standalone.xsl b/dist/src/main/resources/wildfly/patches/standalone.xsl
@@ -69,6 +69,12 @@
         <logger category="org.hawkular.bus">
           <level name="INFO"/>
         </logger>
+        <logger category="org.hawkular.component.availcreator">
+          <level name="INFO"/>
+        </logger>
+        <logger category="org.hawkular.component.pinger">
+          <level name="INFO"/>
+        </logger>
         <logger category="org.hawkular.inventory">
           <level name="INFO"/>
         </logger>
@@ -95,6 +101,12 @@
         <logger category="org.hawkular.bus">
           <level name="INFO"/>
         </logger>
+        <logger category="org.hawkular.component.availcreator">
+          <level name="INFO"/>
+        </logger>
+        <logger category="org.hawkular.component.pinger">
+          <level name="INFO"/>
+        </logger>
         <logger category="org.hawkular.inventory">
           <level name="INFO"/>
         </logger>

diff --git a/modules/avail-creator/src/main/java/org/hawkular/component/availcreator/AvailPublisher.java b/modules/avail-creator/src/main/java/org/hawkular/component/availcreator/AvailPublisher.java
@@ -83,10 +83,10 @@ public void sendToMetricsViaRest(List<SingleAvail> availabilities) {
             try {
                 HttpResponse response = client.execute(request);
                 if (response.getStatusLine().getStatusCode() > 399) {
-                    Log.LOG.availPostStatus(response.getStatusLine().toString());
+                    Log.LOG.wAvailPostStatus(response.getStatusLine().toString());
                 }
             } catch (IOException e) {
-                e.printStackTrace();  // TODO: Customize this generated block
+                Log.LOG.wAvailPostStatus(e.getMessage());
             }
         }
     }
@@ -105,7 +105,7 @@ public void publishToTopic(List<SingleAvail> availRecordList, MetricReceiver met
                 MessageProcessor processor = new MessageProcessor();
                 processor.send(pc, msg);
             } catch (Exception e) {
-                e.printStackTrace();
+                Log.LOG.eCouldNotSendMessage(e);
             }
         }
         else {

diff --git a/modules/avail-creator/src/main/java/org/hawkular/component/availcreator/Log.java b/modules/avail-creator/src/main/java/org/hawkular/component/availcreator/Log.java
@@ -16,18 +16,20 @@
  */
 package org.hawkular.component.availcreator;
 
+import org.jboss.logging.BasicLogger;
 import org.jboss.logging.LogMessage;
 import org.jboss.logging.Logger;
 import org.jboss.logging.Message;
 import org.jboss.logging.MessageLogger;
+import org.jboss.logging.annotations.Cause;
 
 /**
  * Log messages of the creator
  *
  * @author Heiko W. Rupp
  */
 @MessageLogger(projectCode = "HAWKULAR")
-public interface Log {
+public interface Log extends BasicLogger {
 
     Log LOG = Logger.getMessageLogger(Log.class, "org.hawkular.component.availcreator");
 
@@ -36,6 +38,15 @@ public interface Log {
     void wNoTopicConnection(String topicName);
 
     @LogMessage(level = Logger.Level.WARN)
-    @Message(id = 5101, value = "Problem sending availabiliy to Hawkular-Metrics: %s")
-    void availPostStatus(String s);
+    @Message(id = 5101, value = "Problem sending availabiliy to Hawkular Metrics: %s")
+    void wAvailPostStatus(String s);
+
+    @LogMessage(level = Logger.Level.ERROR)
+    @Message(id = 5102, value = "Could not send a message to Hawkular Bus")
+    void eCouldNotSendMessage(@Cause Throwable e);
+
+    @LogMessage(level = Logger.Level.ERROR)
+    @Message(id = 5103, value = "Could not handle a message from Hawkular Bus")
+    void eCouldNotHandleBusMessage(@Cause Exception e);
+
 }
diff --git a/modules/avail-creator/src/main/java/org/hawkular/component/availcreator/MetricReceiver.java b/modules/avail-creator/src/main/java/org/hawkular/component/availcreator/MetricReceiver.java
@@ -99,7 +99,7 @@ public void onMessage(Message message) {
             availPublisher.publishToTopic(outer, this);
 
         } catch (Exception e) {
-            e.printStackTrace();  // TODO: Customise this generated block
+            Log.LOG.eCouldNotHandleBusMessage(e);
         }
 
     }

diff --git a/modules/pinger/src/main/java/org/hawkular/component/pinger/Log.java b/modules/pinger/src/main/java/org/hawkular/component/pinger/Log.java
@@ -16,11 +16,14 @@
  */
 package org.hawkular.component.pinger;
 
+import java.io.IOException;
+
 import org.jboss.logging.BasicLogger;
 import org.jboss.logging.LogMessage;
 import org.jboss.logging.Logger;
 import org.jboss.logging.Message;
 import org.jboss.logging.MessageLogger;
+import org.jboss.logging.annotations.Cause;
 
 /**
  * Log messages of the pinger
@@ -37,24 +40,37 @@ public interface Log extends BasicLogger {
     @Message(id = 5000, value = "No action in message headers found")
     void wNoAction();
 
-    @LogMessage
-    @Message(id = 5001, value = "Pinging the remote threw an exception: %s")
-    void wPingExeption(String message);
+    @LogMessage(level = Logger.Level.DEBUG)
+    @Message(id = 5001, value = "Could not ping URL '%s': %s")
+    void dCouldNotPingUrl(String url, String message);
 
     @LogMessage(level = Logger.Level.WARN)
-    @Message(id = 5002, value = "Post to metrics failed with post status : %s")
-    void metricPostStatus(String s);
+    @Message(id = 5002, value = "Post to Hawkular Metrics failed with post status : %s")
+    void wMetricPostStatus(String s);
 
     @LogMessage(level = Logger.Level.WARN)
     @Message(id = 5003, value = "No connection to topic %s possible")
     void wNoTopicConnection(String topicName);
 
     @LogMessage(level = Logger.Level.WARN)
-    @Message(id = 5004, value = "Could not contact inventory - there will be no resources to start pinging. " +
+    @Message(id = 5004, value = "Could not contact Hawkular Inventory - there will be no resources to start pinging. " +
             "Code %d, message= %s")
     void wNoInventoryFound(int status, String reasonPhrase);
 
     @LogMessage(level = Logger.Level.INFO)
     @Message(id = 5005, value = "Resource '%s' of tenant '%s' is no longer present in inventory.")
     void iResourceNotFound(String resourceId, String tenantId);
+
+    @LogMessage(level = Logger.Level.INFO)
+    @Message(id = 5006, value = "About to initialize Hawkular Pinger with %d URLs")
+    void iInitializedWithUrls(int urlsCount);
+
+    @LogMessage(level = Logger.Level.ERROR)
+    @Message(id = 5007, value = "Could not send a message to Hawkular Bus")
+    void eCouldNotSendMessage(@Cause Throwable e);
+
+    @LogMessage(level = Logger.Level.ERROR)
+    @Message(id = 5008, value = "IOException accessing Hawkular Metrics")
+    void eMetricsIoException(@Cause IOException e);
+
 }
diff --git a/modules/pinger/src/main/java/org/hawkular/component/pinger/MetricPublisher.java b/modules/pinger/src/main/java/org/hawkular/component/pinger/MetricPublisher.java
@@ -104,10 +104,10 @@ public void sendToMetricsViaRest(PingStatus status) {
         try {
             HttpResponse response = client.execute(request);
             if (response.getStatusLine().getStatusCode() > 399) {
-                Log.LOG.metricPostStatus(response.getStatusLine().toString());
+                Log.LOG.wMetricPostStatus(response.getStatusLine().toString());
             }
         } catch (IOException e) {
-            e.printStackTrace(); // TODO: Customise this generated block
+            Log.LOG.eMetricsIoException(e);
         }
     }
 
@@ -149,7 +149,7 @@ public void publishToTopic(PingStatus status) {
                 MessageProcessor processor = new MessageProcessor();
                 processor.send(pc, msg);
             } catch (Exception e) {
-                e.printStackTrace();
+                Log.LOG.eCouldNotSendMessage(e);
             }
         } else {
             Log.LOG.wNoTopicConnection("HawkularMetricData");

diff --git a/modules/pinger/src/main/java/org/hawkular/component/pinger/PingManager.java b/modules/pinger/src/main/java/org/hawkular/component/pinger/PingManager.java
@@ -93,10 +93,12 @@ public void startUp() {
         // We need that though because pinger doesn't have storage of its own and is considered "trusted", so it's ok.
         Set<Resource> urls = inventory.tenants().getAll().resourceTypes().getAll(With.id(PingDestination.URL_TYPE))
                 .resources().getAll().entities();
-        Log.LOG.infof("About to initialize Hawkular Pinger with %d URLs", urls.size());
+        Log.LOG.iInitializedWithUrls(urls.size());
 
         for (Resource r : urls) {
-            destinations.add(PingDestination.from(r));
+            PingDestination dest = PingDestination.from(r);
+            destinations.add(dest);
+            Log.LOG.debugf("Added initial URL to ping: %s", dest.getUrl());
         }
     }
 
@@ -115,10 +117,13 @@ public void startUp() {
     @Schedule(minute = "*", hour = "*", second = "0,20,40", persistent = false)
     public void scheduleWork() {
 
+        Log.LOG.debugf("Pinger awake to ping");
+
         /* Apply URL additions and removals collected in between. */
         urlChangesCollector.apply(this.destinations);
 
         if (destinations.size() == 0) {
+            Log.LOG.debugf("Nothing to ping");
             return;
         }
 
@@ -132,6 +137,8 @@ public void scheduleWork() {
      * @param destinations Set of destinations to ping
      */
     private void doThePing(Set<PingDestination> destinations) {
+        Log.LOG.debugf("About to ping %d URLs", destinations.size());
+
         List<PingStatus> results = new ArrayList<>(destinations.size());
         // In case of timeouts we will not be able to get the PingStatus from the Future, so use a Map
         // to keep track of what destination's ping actually hung.
@@ -171,6 +178,7 @@ private void doThePing(Set<PingDestination> destinations) {
             final long now = System.currentTimeMillis();
             PingStatus ps = PingStatus.timeout(destination, now, TIMEOUT_MILLIS);
             results.add(ps);
+            Log.LOG.debugf("Timed out: %s", destination.getUrl());
         }
 
         reportResults(results);

diff --git a/modules/pinger/src/main/java/org/hawkular/component/pinger/Pinger.java b/modules/pinger/src/main/java/org/hawkular/component/pinger/Pinger.java
@@ -107,13 +107,14 @@ public Future<PingStatus> ping(final PingDestination destination) {
             final int duration = (int) (now - start);
             Traits traits = Traits.collect(httpResponse, now);
             PingStatus result = new PingStatus(destination, code, now, duration, traits);
-            Log.LOG.debugf("Pinged %d %s", code, destination.getUrl());
+            Log.LOG.debugf("Got status code %d from %s", code, destination.getUrl());
             return new AsyncResult<>(result);
         } catch (UnknownHostException e) {
             PingStatus result = PingStatus.error(destination, 404, System.currentTimeMillis());
+            Log.LOG.debugf("Got UnknownHostException for %s", destination.getUrl());
             return new AsyncResult<>(result);
         } catch (IOException e) {
-            Log.LOG.wPingExeption(e.getMessage());
+            Log.LOG.dCouldNotPingUrl(destination.getUrl(), e.getMessage());
             PingStatus result = PingStatus.error(destination, 500, System.currentTimeMillis());
             return new AsyncResult<>(result);
         }

diff --git a/modules/pinger/src/main/java/org/hawkular/component/pinger/UrlChangesCollector.java b/modules/pinger/src/main/java/org/hawkular/component/pinger/UrlChangesCollector.java
@@ -74,7 +74,9 @@ public UrlChange(Action<?, ?> action, PingDestination destination) {
         public void call(Resource r) {
             if (PingDestination.isUrl(r)) {
                 synchronized (lock) {
-                    changes.add(new UrlChange(Action.created(), PingDestination.from(r)));
+                    PingDestination dest = PingDestination.from(r);
+                    changes.add(new UrlChange(Action.created(), dest));
+                    Log.LOG.debugf("Observed an URL creation: %s", dest.getUrl());
                 }
             }
         }
@@ -93,7 +95,9 @@ public void call(Resource r) {
         public void call(Resource r) {
             if (PingDestination.isUrl(r)) {
                 synchronized (lock) {
-                    changes.add(new UrlChange(Action.deleted(), PingDestination.from(r)));
+                    PingDestination dest = PingDestination.from(r);
+                    changes.add(new UrlChange(Action.deleted(), dest));
+                    Log.LOG.debugf("Observed an URL deletion: %s", dest.getUrl());
                 }
             }
         }
@@ -111,11 +115,16 @@ public void call(Resource r) {
     public void apply(Set<PingDestination> destinations) {
         List<UrlChange> changesCopy = getChanges();
 
+        Log.LOG.debugf("About to apply %d changes to ping list", changesCopy.size());
+
         for (UrlChange change : changesCopy) {
+            final PingDestination dest = change.destination;
             if (Action.created().equals(change.action)) {
-                destinations.add(change.destination);
+                destinations.add(dest);
+                Log.LOG.debugf("Added to ping list: %s", dest.getUrl());
             } else if (Action.deleted().equals(change.action)) {
-                destinations.remove(change.destination);
+                destinations.remove(dest);
+                Log.LOG.debugf("Removed from ping list: %s", dest.getUrl());
             } else {
                 throw new IllegalStateException("Unexpected action '" + change.action
                         + "'; expected Action.created() or Action.deleted()");