Adding objectTrace logger to output configurable fields to a new log file from PickUpPlace

src/main/config/logback.xml

@@ -49,6 +49,35 @@
     </then>
   </if>
 
+  <!-- Enable output metrics logging by creating an environment variable of "ObjectTrace=true" -->
+  <if condition='${ObjectTrace} == true'>
+    <then>
+      <appender name="OBJECT-TRACE" class="emissary.util.ObjectTracingLogbackAppender">
+        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
+          <customFields>{"node":"${emissary.node.name}"}</customFields>
+          <includeMdc>false</includeMdc>
+          <fieldNames>
+            <version>[ignore]</version>
+            <logValue>[ignore]</logValue>
+            <logger>[ignore]</logger>
+            <thread>[ignore]</thread>
+            <levelValue>[ignore]</levelValue>
+            <level>[ignore]</level>
+            <message>[ignore]</message>
+          </fieldNames>
+        </encoder>
+        <file>logs/${emissary.node.name}-${emissary.node.port}-object-trace.log</file>
+        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
+          <fileNamePattern>logs/${emissary.node.name}-${emissary.node.port}-object-trace.log.%d{yyyyMMdd-HHmm}</fileNamePattern>
+        </rollingPolicy>
+      </appender>
+
+      <logger name="objectTrace" level="INFO" additivity="false">
+        <appender-ref ref="OBJECT-TRACE" />
+      </logger>
+    </then>
+  </if>
+
   <root level="INFO">
     <!-- stop logging to a file in development man, redirect or tee to a file
     <appender-ref ref="TOFILE"/>

src/main/java/emissary/pickup/PickUpPlace.java

@@ -17,9 +17,12 @@
 import emissary.place.ServiceProviderPlace;
 import emissary.pool.AgentPool;
 import emissary.util.ClassComparator;
+import emissary.util.ObjectTracing;
 import emissary.util.TimeUtil;
 import emissary.util.shell.Executrix;
 
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
 
 import java.io.File;
@@ -34,6 +37,7 @@
 
 import static emissary.core.constants.Parameters.FILE_DATE;
 import static emissary.core.constants.Parameters.FILE_NAME;
+import static net.logstash.logback.marker.Markers.appendEntries;
 
 /**
  * This class is the base class of those places that inject data into the system. This place knows a lot about
@@ -77,6 +81,10 @@ public abstract class PickUpPlace extends ServiceProviderPlace implements IPickU
     // Metadata items that should always be copied to children
     protected Set<String> ALWAYS_COPY_METADATA_VALS = new HashSet<>();
 
+    private boolean useObjectTraceLogger = false;
+    protected Logger objectTraceLogger;
+    private ObjectTracing tracingUtil;
+
     public PickUpPlace() throws IOException {
         super();
         configurePickUpPlace();
@@ -180,6 +188,14 @@ protected void configurePickUpPlace() {
         }
 
         ALWAYS_COPY_METADATA_VALS = configG.findEntriesAsSet("ALWAYS_COPY_METADATA");
+
+        // Setup objectTraceLogger
+        useObjectTraceLogger = configG.findBooleanEntry("USE_OBJECT_TRACE_LOGGER", useObjectTraceLogger);
+        if (useObjectTraceLogger) {
+            logger.info("Setting up the object trace logger");
+            objectTraceLogger = LoggerFactory.getLogger("objectTrace");
+        }
+        tracingUtil = new ObjectTracing();
     }
 
     /**
@@ -552,10 +568,25 @@ protected boolean processDataObject(IBaseDataObject d, String fixedName, File th
         dataObjectCreated(d, theFile);
         logger.info("**Deploying an agent for {} and object {} forms={} simple={}", fixedName, d.getInternalId(), d.getAllCurrentForms(),
                 (simpleMode ? "simple" : ""));
+
+        // If object tracing log that agent is being deployed for fixedName (filename)
+        if (useObjectTraceLogger) {
+            objectTraceLog(d);
+        }
+
         assignToPooledAgent(d, -1L);
         return true;
     }
 
+    /**
+     * Creates an entry in the object trace log.
+     * 
+     * @param d The IBDO
+     */
+    public void objectTraceLog(IBaseDataObject d) {
+        objectTraceLogger.info(appendEntries(tracingUtil.createTraceMessageMap(d)), "");
+    }
+
     /**
      * Parse out sessions and process data from a file
      * 

src/main/java/emissary/util/ObjectTracing.java

@@ -0,0 +1,27 @@
+package emissary.util;
+
+import emissary.core.IBaseDataObject;
+
+import java.util.HashMap;
+import java.util.Map;
+
+public class ObjectTracing {
+
+    public ObjectTracing() {}
+
+    /**
+     * Given an IBDO, create a map with log entries we care about and return it
+     * 
+     * @param d the IBDO
+     * @return the map of log entries to add to the log
+     */
+    public Map<String, String> createTraceMessageMap(IBaseDataObject d) {
+
+        Map<String, String> jsonMap = new HashMap<>();
+
+        // add our fields
+        jsonMap.put("inputFileName", d.getFilename());
+        jsonMap.put("stage", "PickUpPlace");
+        return jsonMap;
+    }
+}

src/main/java/emissary/util/ObjectTracingLogbackAppender.java

@@ -0,0 +1,44 @@
+package emissary.util;
+
+import emissary.config.ConfigUtil;
+import emissary.config.Configurator;
+
+import ch.qos.logback.core.rolling.RollingFileAppender;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+import java.io.IOException;
+
+public class ObjectTracingLogbackAppender<E> extends RollingFileAppender<E> {
+    private long start = System.currentTimeMillis();
+    private int rolloverTime = 15;
+    private boolean isConfigured = false;
+
+    protected static final Logger logger = LoggerFactory.getLogger(ObjectTracingLogbackAppender.class);
+
+    public void configure() {
+        try {
+            Configurator configG = ConfigUtil.getConfigInfo(getClass());
+            rolloverTime = configG.findIntEntry("ROLLOVER_TIME_MINUTES", rolloverTime);
+        } catch (IOException e) {
+            logger.error("Could not read from the config for the ObjectTracingLogbackAppender ", e);
+        }
+    }
+
+    @Override
+    public void rollover() {
+
+        if (!isConfigured) {
+            configure();
+            isConfigured = true;
+        }
+
+        long currentTime = System.currentTimeMillis();
+        int maxIntervalSinceLastLoggingInMillis = rolloverTime * 60 * 1000;
+
+        if ((currentTime - start) >= maxIntervalSinceLastLoggingInMillis) {
+            super.rollover();
+            start = System.currentTimeMillis();
+        }
+    }
+}

src/main/resources/emissary/pickup/file/FilePickUpPlace.cfg

@@ -36,4 +36,4 @@ WIN_OUT_ROOT = "@{OUTPUT_DATA}"
 MINIMUM_DATA_SIZE = "-1"
 MAXIMUM_DATA_SIZE = "-1"
 
-
+USE_OBJECT_TRACE_LOGGER = true

src/main/resources/emissary/util/ObjectTracing.cfg

@@ -0,0 +1,2 @@
+FIELD_NAME = "stage"
+FIELD_NAME = "inputFileName"

src/main/resources/emissary/util/ObjectTracingLogbackAppender.cfg

@@ -0,0 +1 @@
+ROLLOVER_TIME_MINUTES = 15