From 44327ecd1e244f473d0d55539b8fb0b99eefbf4b Mon Sep 17 00:00:00 2001 From: minherz Date: Thu, 23 Dec 2021 10:42:11 +0000 Subject: [PATCH 1/3] feat: add opt-out configuration for metadata population to JUL handler adds metadata auto-population flag to JUL handler. adds metadata auto-population flag to logging config file. forwards metadata auto-population flag via WriteOption to write() calls. refactors JUL handler tests to remove duplication, unused calls and warnings --- .../google/cloud/logging/LoggingConfig.java | 9 ++ .../google/cloud/logging/LoggingHandler.java | 49 +++++++++- .../cloud/logging/LoggingHandlerTest.java | 90 ++++--------------- 3 files changed, 74 insertions(+), 74 deletions(-) diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingConfig.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingConfig.java index 9d0fd94b2..561edb228 100644 --- a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingConfig.java +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingConfig.java @@ -41,6 +41,7 @@ class LoggingConfig { private static final String RESOURCE_TYPE_TAG = "resourceType"; private static final String ENHANCERS_TAG = "enhancers"; private static final String USE_INHERITED_CONTEXT = "useInheritedContext"; + private static final String AUTO_POPULATE_METADATA = "autoPopulateMetadata"; public LoggingConfig(String className) { this.className = className; @@ -76,6 +77,14 @@ Formatter getFormatter() { return getFormatterProperty(FORMATTER_TAG, new SimpleFormatter()); } + Boolean getAutoPopulateMetadata() { + String flag = getProperty(AUTO_POPULATE_METADATA); + if (flag != null) { + return Boolean.parseBoolean(flag); + } + return null; + } + MonitoredResource getMonitoredResource(String projectId) { String resourceType = getProperty(RESOURCE_TYPE_TAG, ""); return MonitoredResourceUtil.getResource(projectId, resourceType); diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java index db18fe1a1..ac9553a39 100644 --- a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java @@ -17,6 +17,7 @@ package com.google.cloud.logging; import static com.google.common.base.MoreObjects.firstNonNull; +import static com.google.common.base.Preconditions.checkNotNull; import com.google.cloud.MonitoredResource; import com.google.cloud.logging.Logging.WriteOption; @@ -25,6 +26,7 @@ import com.google.common.collect.Iterables; import java.time.Instant; import java.util.ArrayList; +import java.util.Arrays; import java.util.Collections; import java.util.LinkedList; import java.util.List; @@ -109,6 +111,9 @@ * else "global"). *
  • {@code com.google.cloud.logging.Synchronicity} the synchronicity of the write method to use * to write logs to the Cloud Logging service (defaults to {@link Synchronicity#ASYNC}). + *
  • {@code com.google.cloud.logging.LoggingHandler.autoPopulateMetadata} is a boolean flag that + * opts-out the population of the log entries metadata before the logs are sent to Cloud + * Logging (defaults to {@code true}). * * *

    To add a {@code LoggingHandler} to an existing {@link Logger} and be sure to avoid infinite @@ -139,6 +144,8 @@ public class LoggingHandler extends Handler { private volatile Level flushLevel; + private volatile Boolean autoPopulateMetadata; + private WriteOption[] defaultWriteOptions; /** Creates an handler that publishes messages to Cloud Logging. */ @@ -196,7 +203,10 @@ public LoggingHandler( } /** - * Creates a handler that publishes messages to Cloud Logging. + * Creates a handler that publishes messages to Cloud Logging. Auto-population of the logs + * metadata can be opted-out in {@code options} argument or in the configuration file. At least + * one flag {@link LoggingOptions} or {@link LoggingConfig} has to be explicitly set to {@code + * false} in order to opt-out the metadata auto-population. * * @param log the name of the log to which log entries are written * @param options options for the Cloud Logging service @@ -222,14 +232,18 @@ public LoggingHandler( setLevel(level); baseLevel = level.equals(Level.ALL) ? Level.FINEST : level; flushLevel = config.getFlushLevel(); + Boolean f1 = options.getAutoPopulateMetadata(); + Boolean f2 = config.getAutoPopulateMetadata(); + autoPopulateMetadata = isTrueOrNull(f1) && isTrueOrNull(f2); String logName = log != null ? log : config.getLogName(); - MonitoredResource resource = firstNonNull( monitoredResource, config.getMonitoredResource(loggingOptions.getProjectId())); List writeOptions = new ArrayList(); writeOptions.add(WriteOption.logName(logName)); - writeOptions.add(WriteOption.resource(resource)); + if (resource != null) { + writeOptions.add(WriteOption.resource(resource)); + } writeOptions.add( WriteOption.labels( ImmutableMap.of( @@ -240,6 +254,7 @@ public LoggingHandler( if (destination != null) { writeOptions.add(WriteOption.destination(destination)); } + writeOptions.add(WriteOption.autoPopulateMetadata(autoPopulateMetadata)); defaultWriteOptions = Iterables.toArray(writeOptions, WriteOption.class); getLogging().setFlushSeverity(severityFor(flushLevel)); @@ -365,6 +380,30 @@ public Synchronicity getSynchronicity() { return getLogging().getWriteSynchronicity(); } + /** + * Sets the metadata auto population flag. + * + * @param synchronicity {@link Synchronicity} + */ + public void setAutoPopulateMetadata(Boolean value) { + checkNotNull(value); + this.autoPopulateMetadata = value; + List writeOptions = Arrays.asList(defaultWriteOptions); + for (int i = 0; i < writeOptions.size(); i++) { + if (writeOptions.get(i).getOptionType() == WriteOption.OptionType.AUTO_POPULATE_METADATA) { + writeOptions.remove(i); + break; + } + } + writeOptions.add(WriteOption.autoPopulateMetadata(value)); + defaultWriteOptions = Iterables.toArray(writeOptions, WriteOption.class); + } + + /** Gets the metadata auto population flag. */ + public Boolean getAutoPopulateMetadata() { + return this.autoPopulateMetadata; + } + /** * Adds the provided {@code LoggingHandler} to {@code logger}. Use this method to register Cloud * Logging handlers instead of {@link Logger#addHandler(Handler)} to avoid infinite recursion when @@ -417,4 +456,8 @@ private Logging getLogging() { } return logging; } + + private static boolean isTrueOrNull(Boolean b) { + return b == null || b == Boolean.TRUE; + } } diff --git a/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java b/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java index af4be4cce..79be8d823 100644 --- a/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java +++ b/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java @@ -28,7 +28,6 @@ import com.google.common.collect.ImmutableList; import com.google.common.collect.ImmutableMap; import java.util.Collections; -import java.util.Map; import java.util.logging.ErrorManager; import java.util.logging.Filter; import java.util.logging.Formatter; @@ -41,6 +40,7 @@ import org.junit.Before; import org.junit.Test; +@SuppressWarnings("deprecation") public class LoggingHandlerTest { private static final String LOG_NAME = "java.log"; @@ -156,18 +156,6 @@ public class LoggingHandlerTest { .setTimestamp(123456789L) .build(); - private static final String CONFIG_NAMESPACE = "com.google.cloud.logging.LoggingHandler"; - private static final ImmutableMap CONFIG_MAP = - ImmutableMap.builder() - .put("log", "testLogName") - .put("level", "ALL") - .put("filter", "com.google.cloud.logging.LoggingHandlerTest$TestFilter") - .put("formatter", "com.google.cloud.logging.LoggingHandlerTest$TestFormatter") - .put("flushLevel", "CRITICAL") - .put("enhancers", "com.google.cloud.logging.LoggingHandlerTest$TestLoggingEnhancer") - .put("resourceType", "testResourceType") - .put("synchronicity", "SYNC") - .build(); private static final ImmutableMap BASE_SEVERITY_MAP = ImmutableMap.of( "levelName", Level.INFO.getName(), "levelValue", String.valueOf(Level.INFO.intValue())); @@ -175,22 +163,10 @@ public class LoggingHandlerTest { new WriteOption[] { WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE), - WriteOption.labels(BASE_SEVERITY_MAP) + WriteOption.labels(BASE_SEVERITY_MAP), + WriteOption.autoPopulateMetadata(false), }; - private static byte[] renderConfig(Map config) { - StringBuilder str = new StringBuilder(); - for (Map.Entry entry : config.entrySet()) { - str.append(CONFIG_NAMESPACE) - .append('.') - .append(entry.getKey()) - .append('=') - .append(entry.getValue()) - .append(System.lineSeparator()); - } - return str.toString().getBytes(); - } - private Logging logging; private LoggingOptions options; @@ -219,7 +195,10 @@ public void enhanceLogEntry(LogEntry.Builder builder) { @Before public void setUp() { logging = EasyMock.createMock(Logging.class); - options = EasyMock.createStrictMock(LoggingOptions.class); + options = EasyMock.createMock(LoggingOptions.class); + expect(options.getProjectId()).andStubReturn(PROJECT); + expect(options.getService()).andStubReturn(logging); + expect(options.getAutoPopulateMetadata()).andStubReturn(Boolean.FALSE); } @After @@ -235,8 +214,6 @@ private static LogRecord newLogRecord(Level level, String message) { @Test public void testPublishLevels() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -290,8 +267,6 @@ public void testPublishLevels() { @Test public void testPublishCustomResource() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -301,7 +276,8 @@ public void testPublishCustomResource() { ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(resource), - WriteOption.labels(BASE_SEVERITY_MAP)); + WriteOption.labels(BASE_SEVERITY_MAP), + WriteOption.autoPopulateMetadata(false)); expectLastCall().once(); replay(options, logging); Handler handler = new LoggingHandler(LOG_NAME, options, resource); @@ -334,8 +310,6 @@ public void testPublishCustomResourceWithProject() { @Test public void testPublishKubernetesContainerResource() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -358,7 +332,8 @@ public void testPublishKubernetesContainerResource() { ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(resource), - WriteOption.labels(BASE_SEVERITY_MAP)); + WriteOption.labels(BASE_SEVERITY_MAP), + WriteOption.autoPopulateMetadata(false)); expectLastCall().once(); replay(options, logging); Handler handler = new LoggingHandler(LOG_NAME, options, resource); @@ -369,18 +344,11 @@ public void testPublishKubernetesContainerResource() { @Test public void testEnhancedLogEntry() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); - MonitoredResource resource = MonitoredResource.of("custom", ImmutableMap.of()); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); expectLastCall().once(); - logging.write( - ImmutableList.of(FINEST_ENHANCED_ENTRY), - WriteOption.logName(LOG_NAME), - WriteOption.resource(resource), - WriteOption.labels(BASE_SEVERITY_MAP)); + logging.write(ImmutableList.of(FINEST_ENHANCED_ENTRY), DEFAULT_OPTIONS); expectLastCall().once(); replay(options, logging); LoggingEnhancer enhancer = @@ -391,7 +359,8 @@ public void enhanceLogEntry(Builder builder) { } }; Handler handler = - new LoggingHandler(LOG_NAME, options, resource, Collections.singletonList(enhancer)); + new LoggingHandler( + LOG_NAME, options, DEFAULT_RESOURCE, Collections.singletonList(enhancer)); handler.setLevel(Level.ALL); handler.setFormatter(new TestFormatter()); handler.publish(newLogRecord(Level.FINEST, MESSAGE)); @@ -399,24 +368,18 @@ public void enhanceLogEntry(Builder builder) { @Test public void testTraceEnhancedLogEntry() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); - MonitoredResource resource = MonitoredResource.of("custom", ImmutableMap.of()); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); expectLastCall().once(); - logging.write( - ImmutableList.of(TRACE_ENTRY), - WriteOption.logName(LOG_NAME), - WriteOption.resource(resource), - WriteOption.labels(BASE_SEVERITY_MAP)); + logging.write(ImmutableList.of(TRACE_ENTRY), DEFAULT_OPTIONS); expectLastCall().once(); replay(options, logging); LoggingEnhancer enhancer = new TraceLoggingEnhancer(); TraceLoggingEnhancer.setCurrentTraceId("projects/projectId/traces/traceId"); Handler handler = - new LoggingHandler(LOG_NAME, options, resource, Collections.singletonList(enhancer)); + new LoggingHandler( + LOG_NAME, options, DEFAULT_RESOURCE, Collections.singletonList(enhancer)); handler.setLevel(Level.ALL); handler.setFormatter(new TestFormatter()); handler.publish(newLogRecord(Level.FINEST, MESSAGE)); @@ -424,8 +387,6 @@ public void testTraceEnhancedLogEntry() { @Test public void testReportWriteError() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); RuntimeException ex = new RuntimeException(); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); @@ -448,8 +409,6 @@ public void testReportWriteError() { @Test public void testReportFlushError() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); RuntimeException ex = new RuntimeException(); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); @@ -475,8 +434,6 @@ public void testReportFlushError() { @Test public void testReportFormatError() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -501,8 +458,6 @@ public void testReportFormatError() { // BUG(1795): rewrite this test when flush actually works. // @Test public void testFlushLevel() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -529,8 +484,6 @@ public void testFlushLevel() { @Test public void testSyncWrite() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); LogEntry entry = LogEntry.newBuilder(Payload.StringPayload.of(MESSAGE)) .setSeverity(Severity.DEBUG) @@ -560,8 +513,6 @@ public void testSyncWrite() { @Test public void testAddHandler() { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -586,8 +537,6 @@ public void close() { @Test public void testClose() throws Exception { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -607,8 +556,6 @@ public void testClose() throws Exception { private void testPublishCustomResourceWithDestination( LogEntry entry, LogDestinationName destination) { - expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); - expect(options.getService()).andReturn(logging); logging.setFlushSeverity(Severity.ERROR); expectLastCall().once(); logging.setWriteSynchronicity(Synchronicity.ASYNC); @@ -619,7 +566,8 @@ private void testPublishCustomResourceWithDestination( WriteOption.logName(LOG_NAME), WriteOption.resource(resource), WriteOption.labels(BASE_SEVERITY_MAP), - WriteOption.destination(destination)); + WriteOption.destination(destination), + WriteOption.autoPopulateMetadata(false)); expectLastCall().once(); replay(options, logging); Handler handler = new LoggingHandler(LOG_NAME, options, resource, null, destination); From 632936a00a6134ee2713e5f39c758f179b2acaef Mon Sep 17 00:00:00 2001 From: minherz Date: Thu, 23 Dec 2021 11:36:06 +0000 Subject: [PATCH 2/3] chore: test JUL handler with enabled auto-population --- .../cloud/logging/LoggingHandlerTest.java | 27 ++++++++++++++++++- 1 file changed, 26 insertions(+), 1 deletion(-) diff --git a/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java b/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java index 79be8d823..6fc2f2fb5 100644 --- a/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java +++ b/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingHandlerTest.java @@ -19,6 +19,7 @@ import static org.easymock.EasyMock.expect; import static org.easymock.EasyMock.expectLastCall; import static org.easymock.EasyMock.replay; +import static org.easymock.EasyMock.reset; import static org.easymock.EasyMock.verify; import com.google.cloud.MonitoredResource; @@ -551,7 +552,31 @@ public void testClose() throws Exception { handler.setFormatter(new TestFormatter()); handler.publish(newLogRecord(Level.FINEST, MESSAGE)); handler.close(); - handler.close(); + } + + @Test + public void testAutoPopulationEnabled() { + reset(options); + options = EasyMock.createMock(LoggingOptions.class); + expect(options.getProjectId()).andStubReturn(PROJECT); + expect(options.getService()).andStubReturn(logging); + expect(options.getAutoPopulateMetadata()).andStubReturn(true); + logging.setFlushSeverity(Severity.ERROR); + expectLastCall().andVoid(); + logging.setWriteSynchronicity(Synchronicity.ASYNC); + expectLastCall().andVoid(); + logging.write( + ImmutableList.of(INFO_ENTRY), + WriteOption.logName(LOG_NAME), + WriteOption.resource(DEFAULT_RESOURCE), + WriteOption.labels(BASE_SEVERITY_MAP), + WriteOption.autoPopulateMetadata(true)); + expectLastCall().once(); + replay(options, logging); + Handler handler = new LoggingHandler(LOG_NAME, options, DEFAULT_RESOURCE); + handler.setLevel(Level.ALL); + handler.setFormatter(new TestFormatter()); + handler.publish(newLogRecord(Level.INFO, MESSAGE)); } private void testPublishCustomResourceWithDestination( From 6bc345c6e9ad0d4b3ea5dc51daf8274d8ee09c3e Mon Sep 17 00:00:00 2001 From: minherz Date: Thu, 23 Dec 2021 18:29:12 +0000 Subject: [PATCH 3/3] chore: remove not needed param comment --- .../src/main/java/com/google/cloud/logging/LoggingHandler.java | 2 -- 1 file changed, 2 deletions(-) diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java index ac9553a39..b644421da 100644 --- a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingHandler.java @@ -382,8 +382,6 @@ public Synchronicity getSynchronicity() { /** * Sets the metadata auto population flag. - * - * @param synchronicity {@link Synchronicity} */ public void setAutoPopulateMetadata(Boolean value) { checkNotNull(value);