From c1322b21952a0023e264372ef7c6eac95d4723be Mon Sep 17 00:00:00 2001 From: minherz Date: Sun, 16 Jan 2022 14:57:49 +0200 Subject: [PATCH 1/6] feat: add support for metadata auto-population and redirection to STDOUT (#649) Add configuration to opt-out metadata auto-population. Add configuration to redirect appender output to stdout. Add relevant unit tests. Refactor unit tests. Improve javadoc comments for methods. Remove warnings. Make methods with no modifier to be private. --- .../logging/logback/LoggingAppender.java | 185 +++++++--- .../enhancers/AnotherTestLoggingEnhancer.java | 28 -- .../enhancers/TestLoggingEnhancer.java | 28 -- .../logging/logback/LoggingAppenderTest.java | 347 +++++++++++------- 4 files changed, 335 insertions(+), 253 deletions(-) delete mode 100644 src/test/java/com/example/enhancers/AnotherTestLoggingEnhancer.java delete mode 100644 src/test/java/com/example/enhancers/TestLoggingEnhancer.java diff --git a/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java b/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java index e4d5128a6..976bd8231 100644 --- a/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java +++ b/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java @@ -38,6 +38,7 @@ import com.google.common.collect.ImmutableList; import java.io.FileInputStream; import java.io.IOException; +import java.time.Instant; import java.util.ArrayList; import java.util.Collections; import java.util.HashMap; @@ -58,15 +59,21 @@ * <level>INFO</level> * </filter> * - * <!-- Optional: defaults to "java.log" --> + * <!-- Optional: defaults to {@code "java.log"} --> * <log>application.log</log> * - * <!-- Optional: defaults to "ERROR" --> + * <!-- Optional: defaults to {@code "ERROR"} --> * <flushLevel>WARNING</flushLevel> * - * <!-- Optional: defaults to ASYNC --> + * <!-- Optional: defaults to {@code ASYNC} --> * <writeSynchronicity>SYNC</writeSynchronicity> * + * <!-- Optional: defaults to {@code true} --> + * <autoPopulateMetadata>false</autoPopulateMetadata> + * + * <!-- Optional: defaults to {@code false} --> + * <redirectToStdout>true</redirectToStdout> + * * <!-- Optional: auto detects on App Engine Flex, Standard, GCE and GKE, defaults to "global". See supported resource types --> @@ -96,6 +103,7 @@ public class LoggingAppender extends UnsynchronizedAppenderBase { private volatile Logging logging; private LoggingOptions loggingOptions; + private MonitoredResource monitoredResource; private List loggingEnhancers; private List loggingEventEnhancers; private WriteOption[] defaultWriteOptions; @@ -105,14 +113,16 @@ public class LoggingAppender extends UnsynchronizedAppenderBase { private String resourceType; private String credentialsFile; private String logDestinationProjectId; + private boolean autoPopulateMetadata = true; + private boolean redirectToStdout = false; private Synchronicity writeSyncFlag = Synchronicity.ASYNC; private final Set enhancerClassNames = new HashSet<>(); private final Set loggingEventEnhancerClassNames = new HashSet<>(); /** - * Batched logging requests get immediately flushed for logs at or above this level. + * Sets a threshold for log severity level to flush all log entries that were batched so far. * - *

Defaults to Error if not set. + *

Defaults to Error. * * @param flushLevel Logback log level */ @@ -121,35 +131,37 @@ public void setFlushLevel(Level flushLevel) { } /** - * Sets the log filename. + * Sets the LOG_ID part of the https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#FIELDS.log_name + * for which the logs are ingested. * - * @param log filename + * @param log LOG_ID part of the name */ public void setLog(String log) { this.log = log; } /** - * Sets the name of the monitored resource (Optional). - * - *

Must be a supported resource type. - * gae_app, gce_instance and container are auto-detected. + * Sets the name of the monitored resource (Optional). If not define the appender will try to + * identify the resource type automatically. Currently support resource types include "gae_app", + * "gce_instance", "k8s_container", "cloud_run_revision" and "cloud_function". If the appender + * fails to identify the resource type it will be set to "global". * - *

Defaults to "global" + *

Must be a one of the supported resource types. * - * @param resourceType name of the monitored resource + * @param resourceType the name of the monitored resource. */ public void setResourceType(String resourceType) { this.resourceType = resourceType; } /** - * Sets the credentials file to use to create the {@link LoggingOptions}. The credentials returned - * by {@link GoogleCredentials#getApplicationDefault()} will be used if no custom credentials file - * has been set. + * Sets the path to the https://cloud.google.com/iam/docs/creating-managing-service-account-keys. If not set + * the appender will use {@link GoogleCredentials#getApplicationDefault()} to authenticate. * - * @param credentialsFile The credentials file to use. + * @param credentialsFile the path to the credentials file. */ public void setCredentialsFile(String credentialsFile) { this.credentialsFile = credentialsFile; @@ -166,14 +178,39 @@ public void setLogDestinationProjectId(String projectId) { } /** - * Define synchronization mode for writing log entries. + * Sets the log ingestion mode. It can be one of the {@link Synchronicity} values. * - * @param flag to set {@code Synchronicity} value. + *

Default to {@code Synchronicity.ASYNC} + * + * @param flag the new ingestion mode. */ public void setWriteSynchronicity(Synchronicity flag) { this.writeSyncFlag = flag; } + /** + * Sets the automatic population of metadata fields for ingested logs. + * + *

Default to {@code true}. + * + * @param flag the metadata auto-population flag. + */ + public void setAutoPopulateMetadata(boolean flag) { + autoPopulateMetadata = flag; + } + + /** + * Sets the redirect of the appender's output to STDOUT instead of ingesting logs to Cloud Logging + * using Logging API. + * + *

Default to {@code false}. + * + * @param flag the redirect flag. + */ + public void setRedirectToStdout(boolean flag) { + redirectToStdout = flag; + } + /** Add extra labels using classes that implement {@link LoggingEnhancer}. */ public void addEnhancer(String enhancerClassName) { this.enhancerClassNames.add(enhancerClassName); @@ -183,57 +220,70 @@ public void addLoggingEventEnhancer(String enhancerClassName) { this.loggingEventEnhancerClassNames.add(enhancerClassName); } - Level getFlushLevel() { - return (flushLevel != null) ? flushLevel : Level.ERROR; + /** + * Returns the current value of the ingestion mode. + * + *

The method is deprecated. Use appender configuration to setup the ingestion + * + * @return a {@link Synchronicity} value of the ingestion module. + */ + @Deprecated + public Synchronicity getWriteSynchronicity() { + return (this.writeSyncFlag != null) ? this.writeSyncFlag : Synchronicity.ASYNC; } - String getLogName() { - return (log != null) ? log : "java.log"; + private void setupMonitoredResource() { + if (autoPopulateMetadata) { + monitoredResource = MonitoredResourceUtil.getResource(getProjectId(), resourceType); + } else { + monitoredResource = null; + } } - public Synchronicity getWriteSynchronicity() { - return (this.writeSyncFlag != null) ? this.writeSyncFlag : Synchronicity.ASYNC; + @InternalApi("Visible for testing") + void setupMonitoredResource(MonitoredResource monitoredResource) { + this.monitoredResource = monitoredResource; } - MonitoredResource getMonitoredResource(String projectId) { - return MonitoredResourceUtil.getResource(projectId, resourceType); + private Level getFlushLevel() { + return (flushLevel != null) ? flushLevel : Level.ERROR; } - List getLoggingEnhancers() { - return getEnhancers(enhancerClassNames); + private String getLogName() { + return (log != null) ? log : "java.log"; } - List getLoggingEventEnhancers() { + private List getLoggingEnhancers() { + return getEnhancers(enhancerClassNames, LoggingEnhancer.class); + } + + private List getLoggingEventEnhancers() { if (loggingEventEnhancerClassNames.isEmpty()) { return DEFAULT_LOGGING_EVENT_ENHANCERS; } else { - return getEnhancers(loggingEventEnhancerClassNames); + return getEnhancers(loggingEventEnhancerClassNames, LoggingEventEnhancer.class); } } - List getEnhancers(Set classNames) { - List loggingEnhancers = new ArrayList<>(); + private List getEnhancers(Set classNames, Class classOfT) { + List enhancers = new ArrayList<>(); if (classNames != null) { - for (String enhancerClassName : classNames) { - if (enhancerClassName != null) { - T enhancer = getEnhancer(enhancerClassName); - if (enhancer != null) { - loggingEnhancers.add(enhancer); + for (String className : classNames) { + if (className != null) { + try { + T enhancer = + Loader.loadClass(className.trim()) + .asSubclass(classOfT) + .getDeclaredConstructor() + .newInstance(); + enhancers.add(enhancer); + } catch (Exception ex) { + // invalid className: ignore } } } } - return loggingEnhancers; - } - - private T getEnhancer(String enhancerClassName) { - try { - Class clz = (Class) Loader.loadClass(enhancerClassName.trim()); - return clz.getDeclaredConstructor().newInstance(); - } catch (Exception ex) { - // If we cannot create the enhancer we fallback to null - } - return null; + return enhancers; } /** Initialize and configure the cloud logging service. */ @@ -242,9 +292,13 @@ public synchronized void start() { if (isStarted()) { return; } - MonitoredResource resource = getMonitoredResource(getProjectId()); + + setupMonitoredResource(); + defaultWriteOptions = - new WriteOption[] {WriteOption.logName(getLogName()), WriteOption.resource(resource)}; + new WriteOption[] { + WriteOption.logName(getLogName()), WriteOption.resource(monitoredResource) + }; Level flushLevel = getFlushLevel(); if (flushLevel != Level.OFF) { getLogging().setFlushSeverity(severityFor(flushLevel)); @@ -265,8 +319,26 @@ String getProjectId() { @Override protected void append(ILoggingEvent e) { - LogEntry logEntry = logEntryFor(e); - getLogging().write(Collections.singleton(logEntry), defaultWriteOptions); + Iterable entries = Collections.singleton(logEntryFor(e)); + if (autoPopulateMetadata) { + entries = + getLogging() + .populateMetadata( + entries, + monitoredResource, + "com.google.cloud.logging", + "jdk", + "sun", + "java", + "ch.qos.logback"); + } + if (redirectToStdout) { + for (LogEntry entry : entries) { + System.out.println(entry.toStructuredJsonString()); + } + } else { + getLogging().write(entries, defaultWriteOptions); + } } @Override @@ -295,6 +367,7 @@ Logging getLogging() { } /** Flushes any pending asynchronous logging writes. */ + @Deprecated public void flush() { if (!isStarted()) { return; @@ -321,6 +394,8 @@ protected LoggingOptions getLoggingOptions() { e); } } + // opt-out metadata auto-population to control it in the appender code + builder.setAutoPopulateMetadata(false); loggingOptions = builder.build(); } return loggingOptions; @@ -340,7 +415,7 @@ private LogEntry logEntryFor(ILoggingEvent e) { } LogEntry.Builder builder = LogEntry.newBuilder(Payload.JsonPayload.of(jsonContent)) - .setTimestamp(e.getTimeStamp()) + .setTimestamp(Instant.ofEpochMilli(e.getTimeStamp())) .setSeverity(severity); builder .addLabel(LEVEL_NAME_KEY, level.toString()) diff --git a/src/test/java/com/example/enhancers/AnotherTestLoggingEnhancer.java b/src/test/java/com/example/enhancers/AnotherTestLoggingEnhancer.java deleted file mode 100644 index d9da84471..000000000 --- a/src/test/java/com/example/enhancers/AnotherTestLoggingEnhancer.java +++ /dev/null @@ -1,28 +0,0 @@ -/* - * Copyright 2017 Google LLC - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -package com.example.enhancers; - -import com.google.cloud.logging.LogEntry; -import com.google.cloud.logging.LoggingEnhancer; - -public class AnotherTestLoggingEnhancer implements LoggingEnhancer { - - @Override - public void enhanceLogEntry(LogEntry.Builder logEntry) { - logEntry.addLabel("test-label-2", "test-value-2"); - } -} diff --git a/src/test/java/com/example/enhancers/TestLoggingEnhancer.java b/src/test/java/com/example/enhancers/TestLoggingEnhancer.java deleted file mode 100644 index f982b3f06..000000000 --- a/src/test/java/com/example/enhancers/TestLoggingEnhancer.java +++ /dev/null @@ -1,28 +0,0 @@ -/* - * Copyright 2017 Google LLC - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -package com.example.enhancers; - -import com.google.cloud.logging.LogEntry; -import com.google.cloud.logging.LoggingEnhancer; - -public class TestLoggingEnhancer implements LoggingEnhancer { - - @Override - public void enhanceLogEntry(LogEntry.Builder logEntry) { - logEntry.addLabel("test-label-1", "test-value-1"); - } -} diff --git a/src/test/java/com/google/cloud/logging/logback/LoggingAppenderTest.java b/src/test/java/com/google/cloud/logging/logback/LoggingAppenderTest.java index 2805abd35..b71747af3 100644 --- a/src/test/java/com/google/cloud/logging/logback/LoggingAppenderTest.java +++ b/src/test/java/com/google/cloud/logging/logback/LoggingAppenderTest.java @@ -22,7 +22,6 @@ import static org.easymock.EasyMock.expectLastCall; import static org.easymock.EasyMock.replay; import static org.easymock.EasyMock.verify; -import static org.junit.Assert.fail; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.filter.ThresholdFilter; @@ -33,11 +32,15 @@ import com.google.cloud.logging.LogEntry; import com.google.cloud.logging.Logging; import com.google.cloud.logging.Logging.WriteOption; -import com.google.cloud.logging.LoggingOptions; -import com.google.cloud.logging.Payload.JsonPayload; +import com.google.cloud.logging.LoggingEnhancer; +import com.google.cloud.logging.Payload; 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 java.util.HashMap; +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.time.Instant; import java.util.Map; import org.easymock.Capture; import org.easymock.EasyMock; @@ -49,18 +52,83 @@ @RunWith(EasyMockRunner.class) public class LoggingAppenderTest { - private final String projectId = "test-project"; - private final String credentialFileProjectId = "project-12345"; - private final String overridenProjectId = "some-project-id"; - private final String dummyCredentialsFile = + private static final String PROJECT_ID = "test-project"; + private static final String CRED_FILE_PROJECT_ID = "project-12345"; + private static final String OVERRIDED_PROJECT_ID = "some-project-id"; + private static final String DUMMY_CRED_FILE_PATH = "src/test/java/com/google/cloud/logging/logback/dummy-credentials.json"; + private static Payload.JsonPayload JSON_PAYLOAD = + Payload.JsonPayload.of(ImmutableMap.of("message", "this is a test")); + private static Payload.JsonPayload JSON_ERROR_PAYLOAD = + Payload.JsonPayload.of( + ImmutableMap.of( + "message", + "this is a test", + "@type", + "type.googleapis.com/google.devtools.clouderrorreporting.v1beta1.ReportedErrorEvent")); + private static final MonitoredResource DEFAULT_RESOURCE = + MonitoredResource.of("global", ImmutableMap.of("project_id", PROJECT_ID)); + private static final LogEntry WARN_ENTRY = + LogEntry.newBuilder(JSON_PAYLOAD) + .setTimestamp(Instant.ofEpochMilli(100000L)) + .setSeverity(Severity.WARNING) + .setLabels( + new ImmutableMap.Builder() + .put("levelName", "WARN") + .put("levelValue", String.valueOf(30000L)) + .put("loggerName", LoggingAppenderTest.class.getName()) + // .put("test-label-1", "test-value-1") + // .put("test-label-2", "test-value-2") + .build()) + .build(); + private static final LogEntry ERROR_ENTRY = + LogEntry.newBuilder(JSON_ERROR_PAYLOAD) + .setTimestamp(Instant.ofEpochMilli(100000L)) + .setSeverity(Severity.ERROR) + .setLabels( + new ImmutableMap.Builder() + .put("levelName", "ERROR") + .put("levelValue", String.valueOf(40000L)) + .put("loggerName", LoggingAppenderTest.class.getName()) + .build()) + .build(); + private static final LogEntry INFO_ENTRY = + LogEntry.newBuilder(JSON_PAYLOAD) + .setTimestamp(Instant.ofEpochMilli(100000L)) + .setSeverity(Severity.INFO) + .setLabels( + new ImmutableMap.Builder() + .put("levelName", "INFO") + .put("levelValue", String.valueOf(20000L)) + .put("loggerName", LoggingAppenderTest.class.getName()) + .put("mdc1", "value1") + .put("mdc2", "value2") + .build()) + .build(); + private Logging logging; private LoggingAppender loggingAppender; + static class CustomLoggingEventEnhancer implements LoggingEventEnhancer { + + @Override + public void enhanceLogEntry(LogEntry.Builder builder, ILoggingEvent e) { + builder.addLabel("foo", "bar"); + } + } + + static class CustomLoggingEnhancer implements LoggingEnhancer { + + @Override + public void enhanceLogEntry(LogEntry.Builder builder) { + builder.addLabel("foo", "bar"); + } + } + class TestLoggingAppender extends LoggingAppender { @Override String getProjectId() { - return projectId; + return PROJECT_ID; } @Override @@ -73,6 +141,7 @@ Logging getLogging() { public void setUp() { logging = EasyMock.createStrictMock(Logging.class); loggingAppender = new TestLoggingAppender(); + loggingAppender.setAutoPopulateMetadata(false); } private final WriteOption[] defaultWriteOptions = @@ -81,29 +150,18 @@ public void setUp() { WriteOption.resource( MonitoredResource.newBuilder("global") .setLabels( - new ImmutableMap.Builder().put("project_id", projectId).build()) + new ImmutableMap.Builder() + .put("project_id", PROJECT_ID) + .build()) .build()) }; @Test public void testFlushLevelConfigUpdatesLoggingFlushSeverity() { - Map jsonContent = new HashMap<>(); - jsonContent.put("message", "this is a test"); - JsonPayload payload = JsonPayload.of(jsonContent); - LogEntry logEntry = - LogEntry.newBuilder(payload) - .setTimestamp(100000L) - .setSeverity(Severity.WARNING) - .setLabels( - new ImmutableMap.Builder() - .put("levelName", "WARN") - .put("levelValue", String.valueOf(30000L)) - .put("loggerName", this.getClass().getName()) - .build()) - .build(); logging.setFlushSeverity(Severity.WARNING); Capture> capturedArgument = Capture.newInstance(); - logging.write(capture(capturedArgument), (WriteOption) anyObject(), (WriteOption) anyObject()); + logging.write( + capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class)); replay(logging); Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); LoggingEvent loggingEvent = createLoggingEvent(Level.WARN, timestamp.getSeconds()); @@ -113,7 +171,7 @@ public void testFlushLevelConfigUpdatesLoggingFlushSeverity() { loggingAppender.doAppend(loggingEvent); verify(logging); assertThat(capturedArgument.getValue().iterator().hasNext()).isTrue(); - assertThat(capturedArgument.getValue().iterator().next()).isEqualTo(logEntry); + assertThat(capturedArgument.getValue().iterator().next()).isEqualTo(WARN_ENTRY); } @Test @@ -126,26 +184,10 @@ public void testFlushLevelConfigSupportsFlushLevelOff() { @Test public void testFilterLogsOnlyLogsAtOrAboveLogLevel() { - Map jsonContent = new HashMap<>(); - jsonContent.put("message", "this is a test"); - jsonContent.put( - "@type", - "type.googleapis.com/google.devtools.clouderrorreporting.v1beta1.ReportedErrorEvent"); - JsonPayload payload = JsonPayload.of(jsonContent); - LogEntry logEntry = - LogEntry.newBuilder(payload) - .setTimestamp(100000L) - .setSeverity(Severity.ERROR) - .setLabels( - new ImmutableMap.Builder() - .put("levelName", "ERROR") - .put("levelValue", String.valueOf(40000L)) - .put("loggerName", this.getClass().getName()) - .build()) - .build(); logging.setFlushSeverity(Severity.ERROR); Capture> capturedArgument = Capture.newInstance(); - logging.write(capture(capturedArgument), (WriteOption) anyObject(), (WriteOption) anyObject()); + logging.write( + capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class)); expectLastCall().once(); replay(logging); Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); @@ -162,41 +204,7 @@ public void testFilterLogsOnlyLogsAtOrAboveLogLevel() { loggingAppender.doAppend(loggingEvent2); verify(logging); assertThat(capturedArgument.getValue().iterator().hasNext()).isTrue(); - assertThat(capturedArgument.getValue().iterator().next()).isEqualTo(logEntry); - } - - @Test - public void testEnhancersAddCorrectLabelsToLogEntries() { - Map jsonContent = new HashMap<>(); - jsonContent.put("message", "this is a test"); - JsonPayload payload = JsonPayload.of(jsonContent); - LogEntry logEntry = - LogEntry.newBuilder(payload) - .setTimestamp(100000L) - .setSeverity(Severity.WARNING) - .setLabels( - new ImmutableMap.Builder() - .put("levelName", "WARN") - .put("levelValue", String.valueOf(30000L)) - .put("loggerName", this.getClass().getName()) - .put("test-label-1", "test-value-1") - .put("test-label-2", "test-value-2") - .build()) - .build(); - logging.setFlushSeverity(Severity.ERROR); - Capture> capturedArgument = Capture.newInstance(); - logging.write(capture(capturedArgument), (WriteOption) anyObject(), (WriteOption) anyObject()); - expectLastCall().once(); - replay(logging); - loggingAppender.addEnhancer("com.example.enhancers.TestLoggingEnhancer"); - loggingAppender.addEnhancer("com.example.enhancers.AnotherTestLoggingEnhancer"); - loggingAppender.start(); - Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); - LoggingEvent loggingEvent = createLoggingEvent(Level.WARN, timestamp.getSeconds()); - loggingAppender.doAppend(loggingEvent); - verify(logging); - assertThat(capturedArgument.getValue().iterator().hasNext()).isTrue(); - assertThat(capturedArgument.getValue().iterator().next()).isEqualTo(logEntry); + assertThat(capturedArgument.getValue().iterator().next()).isEqualTo(ERROR_ENTRY); } @Test @@ -204,7 +212,8 @@ public void testDefaultWriteOptionsHasExpectedDefaults() { logging.setFlushSeverity(Severity.ERROR); Capture logNameArg = Capture.newInstance(); Capture resourceArg = Capture.newInstance(); - logging.write((Iterable) anyObject(), capture(logNameArg), capture(resourceArg)); + logging.write( + EasyMock.>anyObject(), capture(logNameArg), capture(resourceArg)); expectLastCall().once(); replay(logging); loggingAppender.start(); @@ -219,25 +228,10 @@ public void testDefaultWriteOptionsHasExpectedDefaults() { @Test public void testMdcValuesAreConvertedToLabels() { - Map jsonContent = new HashMap<>(); - jsonContent.put("message", "this is a test"); - JsonPayload payload = JsonPayload.of(jsonContent); - LogEntry logEntry = - LogEntry.newBuilder(payload) - .setTimestamp(100000L) - .setSeverity(Severity.INFO) - .setLabels( - new ImmutableMap.Builder() - .put("levelName", "INFO") - .put("levelValue", String.valueOf(20000L)) - .put("loggerName", this.getClass().getName()) - .put("mdc1", "value1") - .put("mdc2", "value2") - .build()) - .build(); logging.setFlushSeverity(Severity.ERROR); Capture> capturedArgument = Capture.newInstance(); - logging.write(capture(capturedArgument), (WriteOption) anyObject(), (WriteOption) anyObject()); + logging.write( + capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class)); expectLastCall().once(); replay(logging); Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); @@ -248,50 +242,32 @@ public void testMdcValuesAreConvertedToLabels() { loggingAppender.doAppend(loggingEvent); verify(logging); assertThat(capturedArgument.getValue().iterator().hasNext()).isTrue(); - assertThat(capturedArgument.getValue().iterator().next()).isEqualTo(logEntry); + assertThat(capturedArgument.getValue().iterator().next()).isEqualTo(INFO_ENTRY); } - @Test - public void testCreateLoggingOptions() { - // Try to build LoggingOptions with custom credentials. + @Test(expected = RuntimeException.class) + public void testCreateLoggingOptionsWithInvalidCredentials() { final String nonExistentFile = "/path/to/non/existent/file"; LoggingAppender appender = new LoggingAppender(); appender.setCredentialsFile(nonExistentFile); - try { - appender.getLoggingOptions(); - fail("Expected exception"); - } catch (Exception e) { - assertThat(e.getMessage().contains(nonExistentFile)); - } - // Try to build LoggingOptions with default credentials. - LoggingOptions defaultOptions = null; - try { - defaultOptions = LoggingOptions.getDefaultInstance(); - } catch (Exception e) { - // Could not build a default LoggingOptions instance. - } - if (defaultOptions != null) { - appender = new LoggingAppender(); - LoggingOptions options = appender.getLoggingOptions(); - assertThat(options).isEqualTo(defaultOptions); - } + appender.getLoggingOptions(); } @Test public void testCreateLoggingOptionsWithCredentials() { // Try to build LoggingOptions with file based credentials. LoggingAppender appender = new LoggingAppender(); - appender.setCredentialsFile(dummyCredentialsFile); - assertThat(appender.getLoggingOptions().getProjectId()).isEqualTo(credentialFileProjectId); + appender.setCredentialsFile(DUMMY_CRED_FILE_PATH); + assertThat(appender.getLoggingOptions().getProjectId()).isEqualTo(CRED_FILE_PROJECT_ID); } @Test public void testCreateLoggingOptionsWithDestination() { // Try to build LoggingOptions with file based credentials. LoggingAppender appender = new LoggingAppender(); - appender.setCredentialsFile(dummyCredentialsFile); - appender.setLogDestinationProjectId(overridenProjectId); - assertThat(appender.getLoggingOptions().getProjectId()).isEqualTo(overridenProjectId); + appender.setCredentialsFile(DUMMY_CRED_FILE_PATH); + appender.setLogDestinationProjectId(OVERRIDED_PROJECT_ID); + assertThat(appender.getLoggingOptions().getProjectId()).isEqualTo(OVERRIDED_PROJECT_ID); } private LoggingEvent createLoggingEvent(Level level, long timestamp) { @@ -310,7 +286,8 @@ public void testMdcValuesAreConvertedToLabelsWithPassingNullValues() { MDC.put("mdc3", "value3"); logging.setFlushSeverity(Severity.ERROR); Capture> capturedArgument = Capture.newInstance(); - logging.write(capture(capturedArgument), (WriteOption) anyObject(), (WriteOption) anyObject()); + logging.write( + capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class)); expectLastCall().once(); replay(logging); Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); @@ -332,13 +309,13 @@ public void testAddCustomLoggingEventEnhancers() { MDC.put("mdc1", "value1"); logging.setFlushSeverity(Severity.ERROR); Capture> capturedArgument = Capture.newInstance(); - logging.write(capture(capturedArgument), (WriteOption) anyObject(), (WriteOption) anyObject()); + logging.write( + capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class)); expectLastCall().once(); replay(logging); Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); LoggingEvent loggingEvent = createLoggingEvent(Level.INFO, timestamp.getSeconds()); - loggingAppender.addLoggingEventEnhancer(CustomLoggingEventEnhancer1.class.getName()); - loggingAppender.addLoggingEventEnhancer(CustomLoggingEventEnhancer2.class.getName()); + loggingAppender.addLoggingEventEnhancer(CustomLoggingEventEnhancer.class.getName()); loggingAppender.start(); loggingAppender.doAppend(loggingEvent); verify(logging); @@ -346,15 +323,36 @@ public void testAddCustomLoggingEventEnhancers() { Map capturedArgumentMap = capturedArgument.getValue().iterator().next().getLabels(); assertThat(capturedArgumentMap.get("mdc1")).isNull(); - assertThat(capturedArgumentMap.get("foo")).isEqualTo("foo"); - assertThat(capturedArgumentMap.get("bar")).isEqualTo("bar"); + assertThat(capturedArgumentMap.get("foo")).isEqualTo("bar"); } @Test - public void testFlush() { + public void testAddCustomLoggingEnhancer() { logging.setFlushSeverity(Severity.ERROR); Capture> capturedArgument = Capture.newInstance(); - logging.write(capture(capturedArgument), (WriteOption) anyObject(), (WriteOption) anyObject()); + logging.write( + capture(capturedArgument), anyObject(WriteOption.class), anyObject(WriteOption.class)); + expectLastCall().once(); + replay(logging); + loggingAppender.addEnhancer(CustomLoggingEnhancer.class.getName()); + loggingAppender.start(); + Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); + LoggingEvent loggingEvent = createLoggingEvent(Level.WARN, timestamp.getSeconds()); + loggingAppender.doAppend(loggingEvent); + verify(logging); + Map capturedArgumentMap = + capturedArgument.getValue().iterator().next().getLabels(); + assertThat(capturedArgumentMap.get("foo")).isEqualTo("bar"); + } + + @Test + @SuppressWarnings("deprecation") + public void testFlush() { + logging.setFlushSeverity(Severity.ERROR); + logging.write( + EasyMock.>anyObject(), + anyObject(WriteOption.class), + anyObject(WriteOption.class)); expectLastCall().times(2); logging.flush(); replay(logging); @@ -368,19 +366,84 @@ public void testFlush() { verify(logging); } - static class CustomLoggingEventEnhancer1 implements LoggingEventEnhancer { + @Test + public void testAutoPopulationEnabled() { + logging.setFlushSeverity(Severity.ERROR); + Capture> capturedLogEntries = Capture.newInstance(); + EasyMock.expect( + logging.populateMetadata( + capture(capturedLogEntries), + EasyMock.eq(DEFAULT_RESOURCE), + EasyMock.eq("com.google.cloud.logging"), + EasyMock.eq("jdk"), + EasyMock.eq("sun"), + EasyMock.eq("java"), + EasyMock.eq("ch.qos.logback"))) + .andReturn(ImmutableList.of(INFO_ENTRY)) + .once(); + // it is impossible to define expectation for varargs using a single anyObject() matcher + // see the EasyMock bug https://github.com/easymock/easymock/issues/130. + // the following mock uses the known fact that the method pass two WriteOption arguments + // the arguments should be replaced with a single anyObject() matchers when the bug is fixed + logging.write( + EasyMock.>anyObject(), + anyObject(WriteOption.class), + anyObject(WriteOption.class)); + expectLastCall().once(); + replay(logging); - @Override - public void enhanceLogEntry(LogEntry.Builder builder, ILoggingEvent e) { - builder.addLabel("foo", "foo"); - } + loggingAppender.setupMonitoredResource(DEFAULT_RESOURCE); + loggingAppender.setAutoPopulateMetadata(true); + loggingAppender.start(); + Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); + LoggingEvent loggingEvent = createLoggingEvent(Level.INFO, timestamp.getSeconds()); + loggingEvent.setMDCPropertyMap(ImmutableMap.of("mdc1", "value1", "mdc2", "value2")); + loggingAppender.doAppend(loggingEvent); + verify(logging); + LogEntry testLogEntry = capturedLogEntries.getValue().iterator().next(); + assertThat(testLogEntry).isEqualTo(INFO_ENTRY); } - static class CustomLoggingEventEnhancer2 implements LoggingEventEnhancer { + @Test + public void testRedirectToStdoutEnabled() { + logging.setFlushSeverity(Severity.ERROR); + EasyMock.expect( + logging.populateMetadata( + EasyMock.>anyObject(), + EasyMock.anyObject(MonitoredResource.class), + EasyMock.anyString(), + EasyMock.anyString(), + EasyMock.anyString(), + EasyMock.anyString(), + EasyMock.anyString())) + .andReturn(ImmutableList.of(INFO_ENTRY)) + .once(); + replay(logging); - @Override - public void enhanceLogEntry(LogEntry.Builder builder, ILoggingEvent e) { - builder.addLabel("bar", "bar"); - } + ByteArrayOutputStream bout = new ByteArrayOutputStream(); + PrintStream out = new PrintStream(bout); + System.setOut(out); + loggingAppender.setupMonitoredResource(DEFAULT_RESOURCE); + loggingAppender.setAutoPopulateMetadata(true); + loggingAppender.setRedirectToStdout(true); + loggingAppender.start(); + Timestamp timestamp = Timestamp.ofTimeSecondsAndNanos(100000, 0); + LoggingEvent loggingEvent = createLoggingEvent(Level.INFO, timestamp.getSeconds()); + loggingAppender.doAppend(loggingEvent); + verify(logging); + assertThat(Strings.isNullOrEmpty(bout.toString())).isFalse(); + System.setOut(null); + } + + @Test + public void testRedirectToStdoutDisabled() { + ByteArrayOutputStream bout = new ByteArrayOutputStream(); + PrintStream out = new PrintStream(bout); + System.setOut(out); + + testAutoPopulationEnabled(); + + assertThat(Strings.isNullOrEmpty(bout.toString())).isTrue(); + System.setOut(null); } } From cceb48d0636f9d27ffdfef0a729f0d45810c9aae Mon Sep 17 00:00:00 2001 From: Owl Bot Date: Sun, 16 Jan 2022 13:14:37 +0000 Subject: [PATCH 2/6] =?UTF-8?q?=F0=9F=A6=89=20Updates=20from=20OwlBot?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md --- README.md | 8 +------- 1 file changed, 1 insertion(+), 7 deletions(-) diff --git a/README.md b/README.md index 019518b9b..a7175c804 100644 --- a/README.md +++ b/README.md @@ -8,9 +8,6 @@ Java idiomatic client for [Cloud Logging Logback Appender][product-docs]. - [Product Documentation][product-docs] - [Client Library Documentation][javadocs] -> Note: This client is a work-in-progress, and may occasionally -> make backwards-incompatible changes. - ## Quickstart @@ -197,9 +194,6 @@ and on [google-cloud-java][g-c-j]. This library follows [Semantic Versioning](http://semver.org/). -It is currently in major version zero (``0.y.z``), which means that anything may change at any time -and the public API should not be considered stable. - ## Contributing @@ -240,7 +234,7 @@ Java is a registered trademark of Oracle and/or its affiliates. [kokoro-badge-link-4]: http://storage.googleapis.com/cloud-devrel-public/java/badges/java-logging-logback/java8-win.html [kokoro-badge-image-5]: http://storage.googleapis.com/cloud-devrel-public/java/badges/java-logging-logback/java11.svg [kokoro-badge-link-5]: http://storage.googleapis.com/cloud-devrel-public/java/badges/java-logging-logback/java11.html -[stability-image]: https://img.shields.io/badge/stability-alpha-orange +[stability-image]: https://img.shields.io/badge/stability-unknown-red [maven-version-image]: https://img.shields.io/maven-central/v/com.google.cloud/google-cloud-logging-logback.svg [maven-version-link]: https://search.maven.org/search?q=g:com.google.cloud%20AND%20a:google-cloud-logging-logback&core=gav [authentication]: https://github.com/googleapis/google-cloud-java#authentication From a23364701fe5e38f3c389976347ba5006a40ba21 Mon Sep 17 00:00:00 2001 From: minherz Date: Sun, 16 Jan 2022 17:38:28 +0200 Subject: [PATCH 3/6] chore: fix auto-population monitored resource (#657) to allow unit testing to customize the logic auto-population should be skipped if monotored resource is set. --- .../com/google/cloud/logging/logback/LoggingAppender.java | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java b/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java index 976bd8231..a8b751077 100644 --- a/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java +++ b/src/main/java/com/google/cloud/logging/logback/LoggingAppender.java @@ -233,10 +233,8 @@ public Synchronicity getWriteSynchronicity() { } private void setupMonitoredResource() { - if (autoPopulateMetadata) { + if (monitoredResource == null && autoPopulateMetadata) { monitoredResource = MonitoredResourceUtil.getResource(getProjectId(), resourceType); - } else { - monitoredResource = null; } } From a629b3ee303a6a3ff5e2a5bcc704bfb6a2c5f09a Mon Sep 17 00:00:00 2001 From: minherz Date: Tue, 18 Jan 2022 11:14:59 +0200 Subject: [PATCH 4/6] chore: update readme with auto-population and redirect to stdout info (#655) --- .readme-partials.yaml | 42 +++++++++++++++++++++++++++++++++++++++--- 1 file changed, 39 insertions(+), 3 deletions(-) diff --git a/.readme-partials.yaml b/.readme-partials.yaml index 8f99019a7..f25287604 100644 --- a/.readme-partials.yaml +++ b/.readme-partials.yaml @@ -19,7 +19,16 @@ custom_content: | WARNING - + + SYNC + + + false + + + true + + @@ -39,7 +48,7 @@ custom_content: | ``` - In your code : + In your code: ```java import org.slf4j.Logger; @@ -57,4 +66,31 @@ custom_content: | testLogger.log("test"); } } - ``` \ No newline at end of file + ``` + + ### Populate log entries with metadata + + The library provides multiple ways to enrich log entries with additional information. + You can select one or more ways to customize log entries that will be written into Cloud Logging. + + * Manually update a log entry using [`LoggingEnhancer`] + (https://github.com/googleapis/java-logging/blob/main/google-cloud-logging/src/main/java/com/google/cloud/logging/. + * Use [`ILoggingEvent`](https://logback.qos.ch/apidocs/ch/qos/logback/classic/spi/ILoggingEvent.html) to update a log entry with [`LoggingEventEnhancer`] + (https://github.com/googleapis/java-logging-logback/blob/main/src/main/java/com/google/cloud/logging/logback/LoggingEventEnhancer.java). + * Enable [auto-population](https://github.com/googleapis/java-logging#auto-population-of-log-entrys-metadata) of the `LogEntry` metadata using the `autoPopulateMetadata` configuration flag. + + #### Optimize log ingestion + + By default, the appender will ingest log entries asynchronously by calling Logging API. + Multiple calls may be aggregated before being sent to improve use of API quota and bandwidth. + You can set the `writeSynchronicity` configuration flag to `SYNC` if they want to ingest log entries synchronously. + Note that configuring synchronous ingestion will probably result in performance penalties to your applications. + If you plan to deploy your application in one of Google Cloud managed environments (e.g. Cloud Run, Cloud Function or App Engine), + you can leverage the support provided by the implicit logging agent and the [structured logging](https://cloud.google.com/logging/docs/structured-logging) feature. + To use it, set the `redirectToStdout` configuration flag to `true`. + This flag instructs the appender to print the log entries to `stdout` instead of ingesting them using Logging API. + The log entries are printed using the [structured logging Json format](https://cloud.google.com/logging/docs/structured-logging#special-payload-fields). + In result, the logging agent will be responsible for ingesting the logs to Logging API. + Note that using the structured logging Json format you cannot control the log name where the logs will be ingested. + The logs will be ingested into the project that hosts the environment where your application is running. + The configuration `logDestinationProjectId` will be ignored. From 2acfdf26099f5c03a4b9442b9a0b4c769a91d83b Mon Sep 17 00:00:00 2001 From: Owl Bot Date: Tue, 18 Jan 2022 09:16:58 +0000 Subject: [PATCH 5/6] =?UTF-8?q?=F0=9F=A6=89=20Updates=20from=20OwlBot?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md --- README.md | 41 +++++++++++++++++++++++++++++++++++++++-- 1 file changed, 39 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index a7175c804..3c52a3077 100644 --- a/README.md +++ b/README.md @@ -87,7 +87,16 @@ See [Logback filters](https://logback.qos.ch/manual/filters.html#thresholdFilter WARNING - + + SYNC + + + false + + + true + + @@ -107,7 +116,7 @@ See [Logback filters](https://logback.qos.ch/manual/filters.html#thresholdFilter ``` -In your code : +In your code: ```java import org.slf4j.Logger; @@ -127,6 +136,34 @@ public class TestLogger { } ``` +### Populate log entries with metadata + +The library provides multiple ways to enrich log entries with additional information. +You can select one or more ways to customize log entries that will be written into Cloud Logging. + +* Manually update a log entry using [`LoggingEnhancer`] +(https://github.com/googleapis/java-logging/blob/main/google-cloud-logging/src/main/java/com/google/cloud/logging/. +* Use [`ILoggingEvent`](https://logback.qos.ch/apidocs/ch/qos/logback/classic/spi/ILoggingEvent.html) to update a log entry with [`LoggingEventEnhancer`] +(https://github.com/googleapis/java-logging-logback/blob/main/src/main/java/com/google/cloud/logging/logback/LoggingEventEnhancer.java). +* Enable [auto-population](https://github.com/googleapis/java-logging#auto-population-of-log-entrys-metadata) of the `LogEntry` metadata using the `autoPopulateMetadata` configuration flag. + +#### Optimize log ingestion + +By default, the appender will ingest log entries asynchronously by calling Logging API. +Multiple calls may be aggregated before being sent to improve use of API quota and bandwidth. +You can set the `writeSynchronicity` configuration flag to `SYNC` if they want to ingest log entries synchronously. +Note that configuring synchronous ingestion will probably result in performance penalties to your applications. +If you plan to deploy your application in one of Google Cloud managed environments (e.g. Cloud Run, Cloud Function or App Engine), +you can leverage the support provided by the implicit logging agent and the [structured logging](https://cloud.google.com/logging/docs/structured-logging) feature. +To use it, set the `redirectToStdout` configuration flag to `true`. +This flag instructs the appender to print the log entries to `stdout` instead of ingesting them using Logging API. +The log entries are printed using the [structured logging Json format](https://cloud.google.com/logging/docs/structured-logging#special-payload-fields). +In result, the logging agent will be responsible for ingesting the logs to Logging API. +Note that using the structured logging Json format you cannot control the log name where the logs will be ingested. +The logs will be ingested into the project that hosts the environment where your application is running. +The configuration `logDestinationProjectId` will be ignored. + + ## Samples From 22ee67c9e92980037e2a241228ac544ab32c4359 Mon Sep 17 00:00:00 2001 From: Owl Bot Date: Tue, 18 Jan 2022 09:22:33 +0000 Subject: [PATCH 6/6] =?UTF-8?q?=F0=9F=A6=89=20Updates=20from=20OwlBot?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md --- README.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/README.md b/README.md index 083eb4951..893510da7 100644 --- a/README.md +++ b/README.md @@ -8,6 +8,9 @@ Java idiomatic client for [Cloud Logging Logback Appender][product-docs]. - [Product Documentation][product-docs] - [Client Library Documentation][javadocs] +> Note: This client is a work-in-progress, and may occasionally +> make backwards-incompatible changes. + ## Quickstart @@ -231,6 +234,9 @@ and on [google-cloud-java][g-c-j]. This library follows [Semantic Versioning](http://semver.org/). +It is currently in major version zero (``0.y.z``), which means that anything may change at any time +and the public API should not be considered stable. + ## Contributing