Improve logging (#790)

Author: SamCarlberg

core/src/main/java/edu/wpi/grip/core/Connection.java

@@ -8,6 +8,7 @@
 import edu.wpi.grip.core.sockets.InputSocket;
 import edu.wpi.grip.core.sockets.OutputSocket;
 
+import com.google.common.base.MoreObjects;
 import com.google.common.eventbus.EventBus;
 import com.google.common.eventbus.Subscribe;
 import com.google.inject.Inject;
@@ -112,6 +113,14 @@ public void remove() {
     eventBus.post(new ConnectionRemovedEvent(this));
   }
 
+  @Override
+  public String toString() {
+    return MoreObjects.toStringHelper(this)
+        .add("src", outputSocket.simpleString())
+        .add("dst", inputSocket.simpleString())
+        .toString();
+  }
+
   public interface Factory<T> {
     Connection<T> create(OutputSocket<? extends T> outputSocket, InputSocket<T> inputSocket);
   }

core/src/main/java/edu/wpi/grip/core/GripCoreModule.java

@@ -1,5 +1,6 @@
 package edu.wpi.grip.core;
 
+import edu.wpi.grip.core.events.EventLogger;
 import edu.wpi.grip.core.events.UnexpectedThrowableEvent;
 import edu.wpi.grip.core.metrics.BenchmarkRunner;
 import edu.wpi.grip.core.metrics.Timer;
@@ -68,8 +69,8 @@ public class GripCoreModule extends AbstractModule {
           = new FileHandler(GripFileManager.GRIP_DIRECTORY.getPath() + "/GRIP.log");
 
       //Set level to handler and logger
-      fileHandler.setLevel(Level.FINE);
-      globalLogger.setLevel(Level.FINE);
+      fileHandler.setLevel(Level.INFO);
+      globalLogger.setLevel(Level.INFO);
 
       // We need to stream to System.out instead of System.err
       final StreamHandler sh = new StreamHandler(System.out, new SimpleFormatter()) {
@@ -124,6 +125,7 @@ public <I> void hear(TypeLiteral<I> type, TypeEncounter<I> encounter) {
     });
 
     bind(EventBus.class).toInstance(eventBus);
+    bind(EventLogger.class).asEagerSingleton();
 
     // Allow for just injecting the settings provider, instead of the whole pipeline
     bind(SettingsProvider.class).to(Pipeline.class);
@@ -172,7 +174,7 @@ protected void onSubscriberException(Throwable exception, @Nullable SubscriberEx
     } else {
       logger.log(Level.SEVERE, "An event subscriber threw an exception", exception);
       eventBus.post(new UnexpectedThrowableEvent(exception, "An event subscriber threw an "
-          + "exception"));
+          + "exception on thread '" + Thread.currentThread().getName() + "'"));
     }
   }
 

core/src/main/java/edu/wpi/grip/core/Source.java

@@ -9,6 +9,7 @@
 import edu.wpi.grip.core.sources.NetworkTableEntrySource;
 import edu.wpi.grip.core.util.ExceptionWitness;
 
+import com.google.common.base.MoreObjects;
 import com.google.common.collect.ImmutableList;
 import com.google.inject.Inject;
 
@@ -100,6 +101,13 @@ public final void initializeSafely() {
     }
   }
 
+  @Override
+  public String toString() {
+    return MoreObjects.toStringHelper(this)
+        .add("name", getName())
+        .toString();
+  }
+
   public interface SourceFactory {
     Source create(Class<?> type, Properties properties) throws IOException;
   }

core/src/main/java/edu/wpi/grip/core/Step.java

@@ -6,6 +6,7 @@
 import edu.wpi.grip.core.sockets.Socket;
 import edu.wpi.grip.core.util.ExceptionWitness;
 
+import com.google.common.base.MoreObjects;
 import com.google.common.collect.ImmutableList;
 import com.google.inject.Inject;
 import com.google.inject.Singleton;
@@ -174,6 +175,13 @@ protected boolean removed() {
     return removed;
   }
 
+  @Override
+  public String toString() {
+    return MoreObjects.toStringHelper(this)
+        .add("operation", description.name())
+        .toString();
+  }
+
   @Singleton
   public static class Factory {
     private final ExceptionWitness.Factory exceptionWitnessFactory;

core/src/main/java/edu/wpi/grip/core/events/AppSettingsChangedEvent.java

@@ -7,7 +7,7 @@
 /**
  * An event fired when the app settings are changed.
  */
-public class AppSettingsChangedEvent {
+public class AppSettingsChangedEvent implements LoggableEvent {
 
   private final AppSettings appSettings;
 

core/src/main/java/edu/wpi/grip/core/events/BenchmarkEvent.java

@@ -3,7 +3,7 @@
 /**
  * An event posted before and after a pipeline is benchmarked.
  */
-public final class BenchmarkEvent {
+public final class BenchmarkEvent implements LoggableEvent {
 
   private final boolean isStart;
 

core/src/main/java/edu/wpi/grip/core/events/CodeGenerationSettingsChangedEvent.java

@@ -7,7 +7,7 @@
 /**
  * An event fired when code generation settings are changed.
  */
-public class CodeGenerationSettingsChangedEvent implements DirtiesSaveEvent {
+public class CodeGenerationSettingsChangedEvent implements DirtiesSaveEvent, LoggableEvent {
 
   private final CodeGenerationSettings settings;
 

core/src/main/java/edu/wpi/grip/core/events/ConnectionAddedEvent.java

@@ -10,7 +10,7 @@
  * An event that occurs when a new connection is added to the pipeline.  This is triggered by the
  * user adding a connection with the GUI.
  */
-public class ConnectionAddedEvent implements RunPipelineEvent, DirtiesSaveEvent {
+public class ConnectionAddedEvent implements RunPipelineEvent, DirtiesSaveEvent, LoggableEvent {
   private final Connection connection;
 
   /**

core/src/main/java/edu/wpi/grip/core/events/ConnectionRemovedEvent.java

@@ -10,7 +10,7 @@
  * An event that occurs when a connection is removed from the pipeline.  This is triggered by the
  * user deleting a connection with the GUI.
  */
-public class ConnectionRemovedEvent implements DirtiesSaveEvent {
+public class ConnectionRemovedEvent implements DirtiesSaveEvent, LoggableEvent {
   private final Connection<?> connection;
 
   /**

core/src/main/java/edu/wpi/grip/core/events/EventLogger.java

@@ -0,0 +1,25 @@
+package edu.wpi.grip.core.events;
+
+import com.google.common.eventbus.AllowConcurrentEvents;
+import com.google.common.eventbus.Subscribe;
+import com.google.inject.Singleton;
+
+import java.util.logging.Logger;
+
+/**
+ * Class for logging events as they're posted to the event bus.
+ */
+@Singleton
+public class EventLogger {
+
+  private static final Logger logger = Logger.getLogger(EventLogger.class.getName());
+
+  @Subscribe
+  @AllowConcurrentEvents
+  public void eventPosted(LoggableEvent event) {
+    final String threadName = Thread.currentThread().getName();
+    logger.log(event.logLevel(),
+        "Event on thread '" + threadName + "': " + event.asLoggableString());
+  }
+
+}