From 13ef68736d4c11f7f145112a86cbab1aa79f408a Mon Sep 17 00:00:00 2001 From: Garrett Jones Date: Wed, 11 Jan 2017 15:13:29 -0800 Subject: [PATCH 1/3] Preventing logging re-entrance at FINE level Also: * Reducing the scope of synchronized blocks * Removing logger exclusions except for Http2FrameLogger --- .../google/cloud/logging/LoggingHandler.java | 122 +++++++++++------- .../spi/v2/LoggingServiceV2Client.java | 3 + .../spi/v2/LoggingServiceV2Settings.java | 96 +++++++++++++- .../cloud/logging/LoggingHandlerTest.java | 98 ++++++-------- 4 files changed, 211 insertions(+), 108 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 e7168d6da678..5653842b5650 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 @@ -22,11 +22,8 @@ import com.google.cloud.logging.Logging.WriteOption; import com.google.common.collect.ImmutableList; import com.google.common.collect.ImmutableMap; -import com.google.common.collect.ImmutableSet; - import java.util.LinkedList; import java.util.List; -import java.util.Set; import java.util.logging.ErrorManager; import java.util.logging.Filter; import java.util.logging.Formatter; @@ -93,12 +90,12 @@ public class LoggingHandler extends Handler { private static final String HANDLERS_PROPERTY = "handlers"; private static final String ROOT_LOGGER_NAME = ""; private static final String[] NO_HANDLERS = new String[0]; - private static final Set EXCLUDED_LOGGERS = ImmutableSet.of("io.grpc", "io.netty", - "com.google.api.client.http", "sun.net.www.protocol.http"); + + private static final ThreadLocal inPublishCall = new ThreadLocal<>(); private final LoggingOptions options; - private final List buffer = new LinkedList<>(); private final WriteOption[] writeOptions; + private List buffer = new LinkedList<>(); private Logging logging; private Level flushLevel; private long flushSize; @@ -148,31 +145,6 @@ public LoggingHandler(String log, LoggingOptions options, MonitoredResource moni String logName = firstNonNull(log, helper.getProperty(className + ".log", "java.log")); MonitoredResource resource = firstNonNull(monitoredResource, getDefaultResource()); writeOptions = new WriteOption[]{WriteOption.logName(logName), WriteOption.resource(resource)}; - maskLoggers(); - } - - private static void maskLoggers() { - for (String loggerName : EXCLUDED_LOGGERS) { - Logger logger = Logger.getLogger(loggerName); - // We remove the Clould Logging handler if it has been registered for a logger that should be - // masked - List loggingHandlers = getLoggingHandlers(logger); - for (LoggingHandler loggingHandler : loggingHandlers) { - logger.removeHandler(loggingHandler); - } - // We mask ancestors if they have a Stackdriver Logging Handler registered - Logger currentLogger = logger; - Logger ancestor = currentLogger.getParent(); - boolean masked = false; - while (ancestor != null && !masked) { - if (hasLoggingHandler(ancestor)) { - currentLogger.setUseParentHandlers(false); - masked = true; - } - currentLogger = ancestor; - ancestor = ancestor.getParent(); - } - } } private static List getLoggingHandlers(Logger logger) { @@ -272,23 +244,55 @@ Formatter getFormatterProperty(String name, Formatter defaultValue) { */ Logging getLogging() { if (logging == null) { - logging = options.getService(); + synchronized (this) { + if (logging == null) { + logging = options.getService(); + } + } } return logging; } @Override - public synchronized void publish(LogRecord record) { + public void publish(LogRecord record) { // check that the log record should be logged if (!isLoggable(record)) { return; } - LogEntry entry = entryFor(record); - if (entry != null) { - buffer.add(entry); + + // HACK warning: this logger doesn't work like normal loggers; the log calls are issued + // from another class instead of by itself, so it can't be configured off like normal + // loggers. We have to check the source class name instead. + if ("io.netty.handler.codec.http2.Http2FrameLogger".equals(record.getSourceClassName())) { + return; } - if (buffer.size() >= flushSize || record.getLevel().intValue() >= flushLevel.intValue()) { - flush(); + + if (inPublishCall.get() != null) { + // ignore all logs generated in the course of logging through this handler + return; + } + inPublishCall.set(true); + + try { + LogEntry entry = entryFor(record); + + List flushBuffer = null; + WriteOption[] flushWriteOptions = null; + + synchronized (this) { + if (entry != null) { + buffer.add(entry); + } + if (buffer.size() >= flushSize || record.getLevel().intValue() >= flushLevel.intValue()) { + flushBuffer = buffer; + flushWriteOptions = writeOptions; + buffer = new LinkedList<>(); + } + } + + flush(flushBuffer, flushWriteOptions); + } finally { + inPublishCall.remove(); } } @@ -350,18 +354,35 @@ private static Severity severityFor(Level level) { * how entries should be written. */ void write(List entries, WriteOption... options) { - getLogging().write(entries, options); + getLogging().writeAsync(entries, options); } @Override - public synchronized void flush() { + public void flush() { + List flushBuffer; + WriteOption[] flushWriteOptions; + + synchronized (this) { + if (buffer.isEmpty()) { + return; + } + flushBuffer = buffer; + flushWriteOptions = writeOptions; + buffer = new LinkedList<>(); + } + + flush(flushBuffer, flushWriteOptions); + } + + private void flush(List flushBuffer, WriteOption[] flushWriteOptions) { + if (flushBuffer == null) { + return; + } try { - write(buffer, writeOptions); + write(flushBuffer, flushWriteOptions); } catch (Exception ex) { // writing can fail but we should not throw an exception, we report the error instead reportError(null, ex, ErrorManager.FLUSH_FAILURE); - } finally { - buffer.clear(); } } @@ -369,15 +390,23 @@ public synchronized void flush() { * Closes the handler and the associated {@link Logging} object. */ @Override - public synchronized void close() throws SecurityException { + public void close() throws SecurityException { + Logging loggingToClose = null; if (logging != null) { + synchronized (this) { + if (logging != null) { + loggingToClose = logging; + logging = null; + } + } + } + if (loggingToClose != null) { try { - logging.close(); + loggingToClose.close(); } catch (Exception ex) { // ignore } } - logging = null; } /** @@ -407,6 +436,5 @@ public synchronized long setFlushSize(long flushSize) { */ public static void addHandler(Logger logger, LoggingHandler handler) { logger.addHandler(handler); - maskLoggers(); } } diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Client.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Client.java index fd83a4e2471e..502d6b1d950e 100644 --- a/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Client.java +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Client.java @@ -151,6 +151,9 @@ protected LoggingServiceV2Client(LoggingServiceV2Settings settings) throws IOExc UnaryCallable.create(settings.deleteLogSettings(), this.channel, this.executor); this.writeLogEntriesCallable = UnaryCallable.create(settings.writeLogEntriesSettings(), this.channel, this.executor); + if (settings.writeLogEntriesSettings().getBundlerFactory() != null) { + closeables.add(settings.writeLogEntriesSettings().getBundlerFactory()); + } this.listLogEntriesCallable = UnaryCallable.create(settings.listLogEntriesSettings(), this.channel, this.executor); this.listLogEntriesPagedCallable = diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Settings.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Settings.java index e854c3fcf872..9ea30ed25120 100644 --- a/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Settings.java +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/spi/v2/LoggingServiceV2Settings.java @@ -22,6 +22,9 @@ import com.google.api.MonitoredResourceDescriptor; import com.google.api.gax.core.GoogleCredentialsProvider; import com.google.api.gax.core.RetrySettings; +import com.google.api.gax.grpc.BundlingCallSettings; +import com.google.api.gax.grpc.BundlingDescriptor; +import com.google.api.gax.grpc.BundlingSettings; import com.google.api.gax.grpc.CallContext; import com.google.api.gax.grpc.ChannelProvider; import com.google.api.gax.grpc.ClientSettings; @@ -31,6 +34,7 @@ import com.google.api.gax.grpc.PagedCallSettings; import com.google.api.gax.grpc.PagedListDescriptor; import com.google.api.gax.grpc.PagedListResponseFactory; +import com.google.api.gax.grpc.RequestIssuer; import com.google.api.gax.grpc.SimpleCallSettings; import com.google.api.gax.grpc.UnaryCallSettings; import com.google.api.gax.grpc.UnaryCallable; @@ -54,6 +58,9 @@ import com.google.protobuf.ExperimentalApi; import io.grpc.Status; import java.io.IOException; +import java.util.ArrayList; +import java.util.Collection; +import java.util.List; import javax.annotation.Generated; import org.joda.time.Duration; @@ -103,7 +110,7 @@ public class LoggingServiceV2Settings extends ClientSettings { .build(); private final SimpleCallSettings deleteLogSettings; - private final SimpleCallSettings + private final BundlingCallSettings writeLogEntriesSettings; private final PagedCallSettings< ListLogEntriesRequest, ListLogEntriesResponse, ListLogEntriesPagedResponse> @@ -121,7 +128,7 @@ public SimpleCallSettings deleteLogSettings() { } /** Returns the object with the settings used for calls to writeLogEntries. */ - public SimpleCallSettings + public BundlingCallSettings writeLogEntriesSettings() { return writeLogEntriesSettings; } @@ -368,12 +375,80 @@ public ListLogsPagedResponse createPagedListResponse( } }; + private static final BundlingDescriptor + WRITE_LOG_ENTRIES_BUNDLING_DESC = + new BundlingDescriptor() { + @Override + public String getBundlePartitionKey(WriteLogEntriesRequest request) { + return request.getLogName() + + "|" + + request.getResource() + + "|" + + request.getLabels() + + "|"; + } + + @Override + public WriteLogEntriesRequest mergeRequests( + Collection requests) { + WriteLogEntriesRequest firstRequest = requests.iterator().next(); + + List elements = new ArrayList<>(); + for (WriteLogEntriesRequest request : requests) { + elements.addAll(request.getEntriesList()); + } + + WriteLogEntriesRequest bundleRequest = + WriteLogEntriesRequest.newBuilder() + .setLogName(firstRequest.getLogName()) + .setResource(firstRequest.getResource()) + .putAllLabels(firstRequest.getLabels()) + .addAllEntries(elements) + .build(); + return bundleRequest; + } + + @Override + public void splitResponse( + WriteLogEntriesResponse bundleResponse, + Collection> + bundle) { + int bundleMessageIndex = 0; + for (RequestIssuer responder : + bundle) { + WriteLogEntriesResponse response = WriteLogEntriesResponse.newBuilder().build(); + responder.setResponse(response); + } + } + + @Override + public void splitException( + Throwable throwable, + Collection> + bundle) { + for (RequestIssuer responder : + bundle) { + responder.setException(throwable); + } + } + + @Override + public long countElements(WriteLogEntriesRequest request) { + return request.getEntriesCount(); + } + + @Override + public long countBytes(WriteLogEntriesRequest request) { + return request.getSerializedSize(); + } + }; + /** Builder for LoggingServiceV2Settings. */ public static class Builder extends ClientSettings.Builder { private final ImmutableList unaryMethodSettingsBuilders; private final SimpleCallSettings.Builder deleteLogSettings; - private final SimpleCallSettings.Builder + private final BundlingCallSettings.Builder writeLogEntriesSettings; private final PagedCallSettings.Builder< ListLogEntriesRequest, ListLogEntriesResponse, ListLogEntriesPagedResponse> @@ -433,7 +508,9 @@ private Builder() { deleteLogSettings = SimpleCallSettings.newBuilder(LoggingServiceV2Grpc.METHOD_DELETE_LOG); writeLogEntriesSettings = - SimpleCallSettings.newBuilder(LoggingServiceV2Grpc.METHOD_WRITE_LOG_ENTRIES); + BundlingCallSettings.newBuilder( + LoggingServiceV2Grpc.METHOD_WRITE_LOG_ENTRIES, WRITE_LOG_ENTRIES_BUNDLING_DESC) + .setBundlingSettingsBuilder(BundlingSettings.newBuilder()); listLogEntriesSettings = PagedCallSettings.newBuilder( @@ -465,6 +542,15 @@ private static Builder createDefault() { .setRetryableCodes(RETRYABLE_CODE_DEFINITIONS.get("idempotent")) .setRetrySettingsBuilder(RETRY_PARAM_DEFINITIONS.get("default")); + builder + .writeLogEntriesSettings() + .getBundlingSettingsBuilder() + .setElementCountThreshold(1) + .setElementCountLimit(1000) + .setRequestByteThreshold(1024) + .setRequestByteLimit(10485760) + .setDelayThreshold(Duration.millis(10)) + .setBlockingCallCountThreshold(1); builder .writeLogEntriesSettings() .setRetryableCodes(RETRYABLE_CODE_DEFINITIONS.get("non_idempotent")) @@ -537,7 +623,7 @@ public SimpleCallSettings.Builder deleteLogSettings() { } /** Returns the builder for the settings used for calls to writeLogEntries. */ - public SimpleCallSettings.Builder + public BundlingCallSettings.Builder writeLogEntriesSettings() { return writeLogEntriesSettings; } 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 e75c981376f9..bf5d008f3e60 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 @@ -27,6 +27,8 @@ import com.google.common.collect.ImmutableList; import com.google.common.collect.ImmutableMap; +import com.google.common.util.concurrent.Futures; +import com.google.common.util.concurrent.SettableFuture; import org.easymock.EasyMock; import org.junit.After; import org.junit.Before; @@ -138,45 +140,45 @@ public void afterClass() { public void testPublishLevels() { EasyMock.expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); EasyMock.expect(options.getService()).andReturn(logging); - logging.write(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), + logging.writeAsync(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(FINER_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(FINER_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(FINE_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(FINE_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(CONFIG_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(CONFIG_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(INFO_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(INFO_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(WARNING_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(WARNING_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(SEVERE_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(SEVERE_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(DEBUG_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(DEBUG_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(NOTICE_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(NOTICE_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(ERROR_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(ERROR_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(CRITICAL_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(CRITICAL_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(ALERT_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(ALERT_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); - logging.write(ImmutableList.of(EMERGENCY_ENTRY), WriteOption.logName(LOG_NAME), + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); + logging.writeAsync(ImmutableList.of(EMERGENCY_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); EasyMock.replay(options, logging); Handler handler = new LoggingHandler(LOG_NAME, options); handler.setLevel(Level.ALL); @@ -203,9 +205,9 @@ public void testPublishCustomResource() { EasyMock.expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); EasyMock.expect(options.getService()).andReturn(logging); MonitoredResource resource = MonitoredResource.of("custom", ImmutableMap.of()); - logging.write(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), + logging.writeAsync(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(resource)); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); EasyMock.replay(options, logging); Handler handler = new LoggingHandler(LOG_NAME, options, resource); handler.setLevel(Level.ALL); @@ -218,13 +220,13 @@ public void testReportFlushError() { EasyMock.expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); EasyMock.expect(options.getService()).andReturn(logging); RuntimeException ex = new RuntimeException(); - logging.write(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), + logging.writeAsync(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); EasyMock.expectLastCall().andThrow(ex); EasyMock.replay(options, logging); ErrorManager errorManager = EasyMock.createStrictMock(ErrorManager.class); errorManager.error(null, ex, ErrorManager.FLUSH_FAILURE); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().once(); EasyMock.replay(errorManager); Handler handler = new LoggingHandler(LOG_NAME, options); handler.setLevel(Level.ALL); @@ -242,7 +244,7 @@ public void testReportFormatError() { RuntimeException ex = new RuntimeException(); ErrorManager errorManager = EasyMock.createStrictMock(ErrorManager.class); errorManager.error(null, ex, ErrorManager.FORMAT_FAILURE); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().once(); LogRecord record = new LogRecord(Level.FINEST, MESSAGE); EasyMock.expect(formatter.format(record)).andThrow(ex); EasyMock.replay(errorManager, formatter); @@ -258,9 +260,9 @@ public void testReportFormatError() { public void testFlushSize() { EasyMock.expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); EasyMock.expect(options.getService()).andReturn(logging); - logging.write(ImmutableList.of(FINEST_ENTRY, FINER_ENTRY, FINE_ENTRY, CONFIG_ENTRY, INFO_ENTRY, + logging.writeAsync(ImmutableList.of(FINEST_ENTRY, FINER_ENTRY, FINE_ENTRY, CONFIG_ENTRY, INFO_ENTRY, WARNING_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); EasyMock.replay(options, logging); LoggingHandler handler = new LoggingHandler(LOG_NAME, options); handler.setLevel(Level.ALL); @@ -278,10 +280,10 @@ public void testFlushSize() { public void testFlushLevel() { EasyMock.expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); EasyMock.expect(options.getService()).andReturn(logging); - logging.write(ImmutableList.of(FINEST_ENTRY, FINER_ENTRY, FINE_ENTRY, CONFIG_ENTRY, INFO_ENTRY, + logging.writeAsync(ImmutableList.of(FINEST_ENTRY, FINER_ENTRY, FINE_ENTRY, CONFIG_ENTRY, INFO_ENTRY, WARNING_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); EasyMock.replay(options, logging); LoggingHandler handler = new LoggingHandler(LOG_NAME, options); handler.setLevel(Level.ALL); @@ -300,9 +302,9 @@ public void testFlushLevel() { public void testAddHandler() { EasyMock.expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); EasyMock.expect(options.getService()).andReturn(logging); - logging.write(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), + logging.writeAsync(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); EasyMock.replay(options, logging); LoggingHandler handler = new LoggingHandler(LOG_NAME, options); handler.setLevel(Level.ALL); @@ -313,31 +315,15 @@ public void testAddHandler() { logger.finest(MESSAGE); } - @Test - public void testMaskLoggers() { - EasyMock.expect(options.getProjectId()).andReturn(PROJECT); - EasyMock.replay(options, logging); - LoggingHandler handler = new LoggingHandler(LOG_NAME, options); - Logger logger = Logger.getLogger("com.google"); - Logger maskedLogger = Logger.getLogger("com.google.api.client.http"); - maskedLogger.addHandler(handler); - assertTrue(maskedLogger.getUseParentHandlers()); - assertSame(logger, maskedLogger.getParent()); - LoggingHandler.addHandler(logger, handler); - assertFalse(maskedLogger.getUseParentHandlers()); - assertEquals(0, maskedLogger.getHandlers().length); - logger.removeHandler(handler); - } - @Test public void testClose() throws Exception { EasyMock.expect(options.getProjectId()).andReturn(PROJECT).anyTimes(); EasyMock.expect(options.getService()).andReturn(logging); - logging.write(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), + logging.writeAsync(ImmutableList.of(FINEST_ENTRY), WriteOption.logName(LOG_NAME), WriteOption.resource(DEFAULT_RESOURCE)); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().andReturn(Futures.immediateFuture(null)); logging.close(); - EasyMock.expectLastCall(); + EasyMock.expectLastCall().once(); EasyMock.replay(options, logging); Handler handler = new LoggingHandler(LOG_NAME, options); handler.setLevel(Level.ALL); From a4409836a89b0d9e7ff6ddfa70cc67cb9f092c9a Mon Sep 17 00:00:00 2001 From: Garrett Jones Date: Thu, 12 Jan 2017 11:32:29 -0800 Subject: [PATCH 2/3] Removing unused imports --- .../google/cloud/logging/LoggingHandlerTest.java | 16 ++++------------ 1 file changed, 4 insertions(+), 12 deletions(-) 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 bf5d008f3e60..e48b2051cd5d 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 @@ -16,30 +16,22 @@ package com.google.cloud.logging; -import static org.junit.Assert.assertEquals; -import static org.junit.Assert.assertFalse; -import static org.junit.Assert.assertSame; -import static org.junit.Assert.assertTrue; - import com.google.cloud.MonitoredResource; import com.google.cloud.logging.Logging.WriteOption; import com.google.cloud.logging.Payload.StringPayload; import com.google.common.collect.ImmutableList; import com.google.common.collect.ImmutableMap; - import com.google.common.util.concurrent.Futures; -import com.google.common.util.concurrent.SettableFuture; -import org.easymock.EasyMock; -import org.junit.After; -import org.junit.Before; -import org.junit.Test; - import java.util.logging.ErrorManager; import java.util.logging.Formatter; import java.util.logging.Handler; import java.util.logging.Level; import java.util.logging.LogRecord; import java.util.logging.Logger; +import org.easymock.EasyMock; +import org.junit.After; +import org.junit.Before; +import org.junit.Test; public class LoggingHandlerTest { From 41ec1788e4c4730b2511c8b8038481696d83cb4b Mon Sep 17 00:00:00 2001 From: Garrett Jones Date: Thu, 12 Jan 2017 17:35:53 -0800 Subject: [PATCH 3/3] Concurrency fix + simplification --- .../com/google/cloud/logging/LoggingHandler.java | 16 ++++------------ 1 file changed, 4 insertions(+), 12 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 5653842b5650..3bdc301c624a 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 @@ -96,7 +96,7 @@ public class LoggingHandler extends Handler { private final LoggingOptions options; private final WriteOption[] writeOptions; private List buffer = new LinkedList<>(); - private Logging logging; + private volatile Logging logging; private Level flushLevel; private long flushSize; @@ -390,23 +390,15 @@ private void flush(List flushBuffer, WriteOption[] flushWriteOptions) * Closes the handler and the associated {@link Logging} object. */ @Override - public void close() throws SecurityException { - Logging loggingToClose = null; + public synchronized void close() throws SecurityException { if (logging != null) { - synchronized (this) { - if (logging != null) { - loggingToClose = logging; - logging = null; - } - } - } - if (loggingToClose != null) { try { - loggingToClose.close(); + logging.close(); } catch (Exception ex) { // ignore } } + logging = null; } /**