Preventing logging re-entrance at FINE level

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,13 +90,13 @@ 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<String> EXCLUDED_LOGGERS = ImmutableSet.of("io.grpc", "io.netty",
-      "com.google.api.client.http", "sun.net.www.protocol.http");
+
+  private static final ThreadLocal<Boolean> inPublishCall = new ThreadLocal<>();
 
   private final LoggingOptions options;
-  private final List<LogEntry> buffer = new LinkedList<>();
   private final WriteOption[] writeOptions;
-  private Logging logging;
+  private List<LogEntry> buffer = new LinkedList<>();
+  private volatile 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<LoggingHandler> 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<LoggingHandler> 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<LogEntry> 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<LogEntry> entries, WriteOption... options) {
-    getLogging().write(entries, options);
+    getLogging().writeAsync(entries, options);
   }
 
   @Override
-  public synchronized void flush() {
+  public void flush() {
+    List<LogEntry> flushBuffer;
+    WriteOption[] flushWriteOptions;
+
+    synchronized (this) {
+      if (buffer.isEmpty()) {
+        return;
+      }
+      flushBuffer = buffer;
+      flushWriteOptions = writeOptions;
+      buffer = new LinkedList<>();
+    }
+
+    flush(flushBuffer, flushWriteOptions);
+  }
+
+  private void flush(List<LogEntry> 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();
     }
   }
 
@@ -407,6 +428,5 @@ public synchronized long setFlushSize(long flushSize) {
    */
   public static void addHandler(Logger logger, LoggingHandler handler) {
     logger.addHandler(handler);
-    maskLoggers();
   }
 }

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 =

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<DeleteLogRequest, Empty> deleteLogSettings;
-  private final SimpleCallSettings<WriteLogEntriesRequest, WriteLogEntriesResponse>
+  private final BundlingCallSettings<WriteLogEntriesRequest, WriteLogEntriesResponse>
       writeLogEntriesSettings;
   private final PagedCallSettings<
           ListLogEntriesRequest, ListLogEntriesResponse, ListLogEntriesPagedResponse>
@@ -121,7 +128,7 @@ public SimpleCallSettings<DeleteLogRequest, Empty> deleteLogSettings() {
   }
 
   /** Returns the object with the settings used for calls to writeLogEntries. */
-  public SimpleCallSettings<WriteLogEntriesRequest, WriteLogEntriesResponse>
+  public BundlingCallSettings<WriteLogEntriesRequest, WriteLogEntriesResponse>
       writeLogEntriesSettings() {
     return writeLogEntriesSettings;
   }
@@ -368,12 +375,80 @@ public ListLogsPagedResponse createPagedListResponse(
             }
           };
 
+  private static final BundlingDescriptor<WriteLogEntriesRequest, WriteLogEntriesResponse>
+      WRITE_LOG_ENTRIES_BUNDLING_DESC =
+          new BundlingDescriptor<WriteLogEntriesRequest, WriteLogEntriesResponse>() {
+            @Override
+            public String getBundlePartitionKey(WriteLogEntriesRequest request) {
+              return request.getLogName()
+                  + "|"
+                  + request.getResource()
+                  + "|"
+                  + request.getLabels()
+                  + "|";
+            }
+
+            @Override
+            public WriteLogEntriesRequest mergeRequests(
+                Collection<WriteLogEntriesRequest> requests) {
+              WriteLogEntriesRequest firstRequest = requests.iterator().next();
+
+              List<LogEntry> 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<? extends RequestIssuer<WriteLogEntriesRequest, WriteLogEntriesResponse>>
+                    bundle) {
+              int bundleMessageIndex = 0;
+              for (RequestIssuer<WriteLogEntriesRequest, WriteLogEntriesResponse> responder :
+                  bundle) {
+                WriteLogEntriesResponse response = WriteLogEntriesResponse.newBuilder().build();
+                responder.setResponse(response);
+              }
+            }
+
+            @Override
+            public void splitException(
+                Throwable throwable,
+                Collection<? extends RequestIssuer<WriteLogEntriesRequest, WriteLogEntriesResponse>>
+                    bundle) {
+              for (RequestIssuer<WriteLogEntriesRequest, WriteLogEntriesResponse> 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<UnaryCallSettings.Builder> unaryMethodSettingsBuilders;
 
     private final SimpleCallSettings.Builder<DeleteLogRequest, Empty> deleteLogSettings;
-    private final SimpleCallSettings.Builder<WriteLogEntriesRequest, WriteLogEntriesResponse>
+    private final BundlingCallSettings.Builder<WriteLogEntriesRequest, WriteLogEntriesResponse>
         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<DeleteLogRequest, Empty> deleteLogSettings() {
     }
 
     /** Returns the builder for the settings used for calls to writeLogEntries. */
-    public SimpleCallSettings.Builder<WriteLogEntriesRequest, WriteLogEntriesResponse>
+    public BundlingCallSettings.Builder<WriteLogEntriesRequest, WriteLogEntriesResponse>
         writeLogEntriesSettings() {
       return writeLogEntriesSettings;
     }