feat: Add support for library instrumentation (#789)

* feat: Add support for library instrumentation * 🦉 Updates from OwlBot post-processor See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md * Update pom.xml * Address PR comments Co-authored-by: Owl Bot <gcf-owl-bot[bot]@users.noreply.github.com>
googleapis · Jun 28, 2022 · 3a08dac · 3a08dac
1 parent fcca46b
commit 3a08dac
Show file tree

Hide file tree

Showing 4 changed files with 109 additions and 5 deletions.
diff --git a/README.md b/README.md
@@ -22,20 +22,20 @@ If you are using Maven, add this to your pom.xml file:
 <dependency>
   <groupId>com.google.cloud</groupId>
   <artifactId>google-cloud-logging-logback</artifactId>
-  <version>0.125.2-alpha</version>
+  <version>0.125.3-alpha</version>
 </dependency>
 ```
 
 If you are using Gradle without BOM, add this to your dependencies
 
 ```Groovy
-implementation 'com.google.cloud:google-cloud-logging-logback:0.125.2-alpha'
+implementation 'com.google.cloud:google-cloud-logging-logback:0.125.3-alpha'
 ```
 
 If you are using SBT, add this to your dependencies
 
 ```Scala
-libraryDependencies += "com.google.cloud" % "google-cloud-logging-logback" % "0.125.2-alpha"
+libraryDependencies += "com.google.cloud" % "google-cloud-logging-logback" % "0.125.3-alpha"
 ```
 
 ## Authentication

diff --git a/pom.xml b/pom.xml
@@ -134,6 +134,10 @@
           </exclusion>
         </exclusions>
     </dependency>
+    <dependency>
+      <groupId>com.google.protobuf</groupId>
+      <artifactId>protobuf-java</artifactId>
+    </dependency>    
   </dependencies>
 
   <reporting>

diff --git a/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java b/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java
@@ -25,6 +25,7 @@
 import com.google.api.core.InternalApi;
 import com.google.auth.oauth2.GoogleCredentials;
 import com.google.cloud.MonitoredResource;
+import com.google.cloud.logging.Instrumentation;
 import com.google.cloud.logging.LogEntry;
 import com.google.cloud.logging.Logging;
 import com.google.cloud.logging.Logging.WriteOption;
@@ -40,7 +41,6 @@
 import java.io.IOException;
 import java.time.Instant;
 import java.util.ArrayList;
-import java.util.Collections;
 import java.util.HashMap;
 import java.util.HashSet;
 import java.util.List;
@@ -100,6 +100,9 @@ public class LoggingAppender extends UnsynchronizedAppenderBase<ILoggingEvent> {
       "type.googleapis.com/google.devtools.clouderrorreporting.v1beta1.ReportedErrorEvent";
   private static final List<LoggingEventEnhancer> DEFAULT_LOGGING_EVENT_ENHANCERS =
       ImmutableList.<LoggingEventEnhancer>of(new MDCEventEnhancer());
+  public static final String JAVA_LOGBACK_LIBRARY_NAME = "java-logback";
+  private static boolean instrumentationAdded = false;
+  private static Object instrumentationLock = new Object();
 
   private volatile Logging logging;
   private LoggingOptions loggingOptions;
@@ -317,7 +320,16 @@ String getProjectId() {
 
   @Override
   protected void append(ILoggingEvent e) {
-    Iterable<LogEntry> entries = Collections.singleton(logEntryFor(e));
+    List<LogEntry> entriesList = new ArrayList<LogEntry>();
+    entriesList.add(logEntryFor(e));
+    // Check if instrumentation was already added - if not, create a log entry with instrumentation
+    // data
+    if (!setInstrumentationStatus(true)) {
+      entriesList.add(
+          Instrumentation.createDiagnosticEntry(
+              JAVA_LOGBACK_LIBRARY_NAME, Instrumentation.getLibraryVersion(LoggingAppender.class)));
+    }
+    Iterable<LogEntry> entries = entriesList;
     if (autoPopulateMetadata) {
       entries =
           getLogging()
@@ -490,4 +502,19 @@ private static Severity severityFor(Level level) {
         return Severity.DEFAULT;
     }
   }
+
+  /**
+   * The package-private helper method used to set the flag which indicates if instrumentation info
+   * already written or not.
+   *
+   * @returns The value of the flag before it was set.
+   */
+  static boolean setInstrumentationStatus(boolean value) {
+    if (instrumentationAdded == value) return instrumentationAdded;
+    synchronized (instrumentationLock) {
+      boolean current = instrumentationAdded;
+      instrumentationAdded = value;
+      return current;
+    }
+  }
 }
diff --git a/src/test/java/com/google/cloud/logging/logback/LoggingAppenderTest.java b/src/test/java/com/google/cloud/logging/logback/LoggingAppenderTest.java
@@ -22,22 +22,28 @@
 import static org.easymock.EasyMock.expectLastCall;
 import static org.easymock.EasyMock.replay;
 import static org.easymock.EasyMock.verify;
+import static org.junit.Assert.assertEquals;
 
 import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.filter.ThresholdFilter;
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.classic.spi.LoggingEvent;
 import com.google.cloud.MonitoredResource;
 import com.google.cloud.Timestamp;
+import com.google.cloud.logging.Instrumentation;
 import com.google.cloud.logging.LogEntry;
 import com.google.cloud.logging.Logging;
 import com.google.cloud.logging.Logging.WriteOption;
 import com.google.cloud.logging.LoggingEnhancer;
 import com.google.cloud.logging.Payload;
+import com.google.cloud.logging.Payload.JsonPayload;
+import com.google.cloud.logging.Payload.Type;
 import com.google.cloud.logging.Severity;
 import com.google.common.base.Strings;
 import com.google.common.collect.ImmutableList;
 import com.google.common.collect.ImmutableMap;
+import com.google.protobuf.ListValue;
+import com.google.protobuf.Value;
 import java.io.ByteArrayOutputStream;
 import java.io.PrintStream;
 import java.time.Instant;
@@ -139,6 +145,7 @@ Logging getLogging() {
 
   @Before
   public void setUp() {
+    LoggingAppender.setInstrumentationStatus(true);
     logging = EasyMock.createStrictMock(Logging.class);
     loggingAppender = new TestLoggingAppender();
     loggingAppender.setAutoPopulateMetadata(false);
@@ -446,4 +453,70 @@ public void testRedirectToStdoutDisabled() {
     assertThat(Strings.isNullOrEmpty(bout.toString())).isTrue();
     System.setOut(null);
   }
+
+  @Test
+  public void testFDiagnosticInfoAdded() {
+    LoggingAppender.setInstrumentationStatus(false);
+    Capture<Iterable<LogEntry>> capturedArgument = Capture.newInstance();
+    logging.setFlushSeverity(Severity.ERROR);
+    logging.write(
+        capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class));
+    replay(logging);
+    LoggingEvent loggingEvent =
+        createLoggingEvent(Level.ERROR, Timestamp.ofTimeSecondsAndNanos(100000, 0).getSeconds());
+    loggingAppender.start();
+    loggingAppender.doAppend(loggingEvent);
+    verify(logging);
+    int count = 0;
+    int diagnosticRecordCount = 0;
+    for (LogEntry entry : capturedArgument.getValue()) {
+      count++;
+      if (entry.getPayload().getType() == Type.JSON) {
+        JsonPayload payload = entry.<Payload.JsonPayload>getPayload();
+        if (!payload.getData().containsFields(Instrumentation.DIAGNOSTIC_INFO_KEY)) continue;
+        ListValue infoList =
+            payload
+                .getData()
+                .getFieldsOrThrow(Instrumentation.DIAGNOSTIC_INFO_KEY)
+                .getStructValue()
+                .getFieldsOrThrow(Instrumentation.INSTRUMENTATION_SOURCE_KEY)
+                .getListValue();
+        for (Value val : infoList.getValuesList()) {
+          String name =
+              val.getStructValue()
+                  .getFieldsOrThrow(Instrumentation.INSTRUMENTATION_NAME_KEY)
+                  .getStringValue();
+          assertThat(name.startsWith(Instrumentation.JAVA_LIBRARY_NAME_PREFIX)).isTrue();
+          if (name.equals(LoggingAppender.JAVA_LOGBACK_LIBRARY_NAME)) {
+            diagnosticRecordCount++;
+          }
+        }
+      }
+    }
+    assertEquals(count, 2);
+    assertEquals(diagnosticRecordCount, 1);
+  }
+
+  @Test
+  public void testFDiagnosticInfoNotAdded() {
+    logging.setFlushSeverity(Severity.ERROR);
+    Capture<Iterable<LogEntry>> capturedArgument = Capture.newInstance();
+    logging.write(
+        capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class));
+    replay(logging);
+    LoggingEvent loggingEvent =
+        createLoggingEvent(Level.WARN, Timestamp.ofTimeSecondsAndNanos(100000, 0).getSeconds());
+    loggingAppender.start();
+    loggingAppender.doAppend(loggingEvent);
+    verify(logging);
+    int count = 0;
+    for (LogEntry entry : capturedArgument.getValue()) {
+      count++;
+      if (entry.getPayload().getType() == Type.JSON) {
+        JsonPayload payload = entry.<Payload.JsonPayload>getPayload();
+        assertThat(payload.getData().containsFields(Instrumentation.DIAGNOSTIC_INFO_KEY)).isFalse();
+      }
+    }
+    assertEquals(count, 1);
+  }
 }