Merge pull request #295 from jetty-project/bugs/231-julroot

Issue #231 - Logging Rotation and Levels

appengine-java-logging/pom.xml

@@ -29,12 +29,46 @@
   <packaging>jar</packaging>
   <description>Support code for writing log files compatible with Google App Engine</description>
 
+  <properties>
+    <slf4j.version>1.7.16</slf4j.version>
+  </properties>
+
   <dependencies>
+    <!-- Logging: API -->
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>slf4j-api</artifactId>
+      <version>${slf4j.version}</version>
+    </dependency>
+    <!-- Logging: Capturing Layers -->
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>jcl-over-slf4j</artifactId>
+      <version>${slf4j.version}</version>
+    </dependency>
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>log4j-over-slf4j</artifactId>
+      <version>${slf4j.version}</version>
+    </dependency>
+    <!-- Logging: Output / Appender Layer -->
+    <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>slf4j-jdk14</artifactId>
+      <version>${slf4j.version}</version>
+    </dependency>
+
     <dependency>
       <groupId>com.google.code.gson</groupId>
       <artifactId>gson</artifactId>
     </dependency>
 
+    <dependency>
+      <groupId>org.hamcrest</groupId>
+      <artifactId>hamcrest-library</artifactId>
+      <scope>test</scope>
+    </dependency>
+
     <dependency>
       <groupId>junit</groupId>
       <artifactId>junit</artifactId>

appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java → appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java

@@ -14,44 +14,45 @@
  * limitations under the License.
  */
 
-package com.google.apphosting.vmruntime;
-
-import com.google.apphosting.logging.JsonFormatter;
+package com.google.apphosting.logging;
 
 import java.io.IOException;
-import java.util.logging.ConsoleHandler;
 import java.util.logging.FileHandler;
 import java.util.logging.Handler;
 import java.util.logging.Level;
-import java.util.logging.LogManager;
 import java.util.logging.Logger;
 
 /**
- * {@code VmRuntimeFileLogHandler} is installed on the root logger. It converts all messages
- * to the json format understood by the cloud logging agent and logs to a file in a volume shared
- * with the cloud logging agent.
- *
+ * A root level {@link java.util.logging.FileHandler} for interfacing with the GCloud logging
+ * console. It converts all logging events to the json format understood by the cloud logging
+ * agent and logs to a file in a volume shared with the cloud logging agent.
  */
-public class VmRuntimeFileLogHandler extends FileHandler {
-
+public class CloudLoggingFileHandler extends FileHandler implements SystemLogger {
   // This exists for testing purposes only.  If set, the cloud logger may lose logs.
   public static final String LOG_DIRECTORY_PROPERTY = "com.google.apphosting.logs";
   public static final String LOG_PATTERN_CONFIG_PROPERTY =
-      "com.google.apphosting.vmruntime.VmRuntimeFileLogHandler.pattern";
+      CloudLoggingFileHandler.class.getName() + ".pattern";
   // Log files to /var/log/app_engine/app.[0-2].log.json
   private static final String DEFAULT_LOG_DIRECTORY = "/var/log/app_engine";
-  private static final String DEFAULT_LOG_PATTERN = "app.%g.log.json";
+  private static final String DEFAULT_LOG_PATTERN = "app.%u.%g.log.json";
   private static final String APP_ENGINE_LOG_CONFIG_PATTERN_ENV = "APP_ENGINE_LOG_CONFIG_PATTERN";
-  private static final int LOG_MAX_SIZE = 100 * 1024 * 1024;
-  private static final int LOG_MAX_FILES = 3;
-  public static final String JAVA_UTIL_LOGGING_CONFIG_PROPERTY = "java.util.logging.config.file";
+  private static final int LOG_PER_FILE_SIZE = getConfigInt("limit", 100 * 1024 * 1024);
+  private static final int LOG_MAX_FILES = getConfigInt("count", 3);
 
-  private VmRuntimeFileLogHandler() throws IOException {
-    super(fileLogPattern(), LOG_MAX_SIZE, LOG_MAX_FILES, true);
+  public CloudLoggingFileHandler() throws IOException {
+    super(fileLogPattern(), LOG_PER_FILE_SIZE, LOG_MAX_FILES, true);
     setLevel(Level.FINEST);
     setFormatter(new JsonFormatter());
   }
 
+  private static int getConfigInt(String suffix, int defValue) {
+    String val = System.getProperty(CloudLoggingFileHandler.class.getName() + '.' + suffix);
+    if (val == null) {
+      return defValue;
+    }
+    return Integer.parseInt(val);
+  }
+
   private static String fileLogPattern() {
     String pattern = System.getenv(APP_ENGINE_LOG_CONFIG_PATTERN_ENV);
     // For Cloud SDK usage only for local Jetty processes.
@@ -72,34 +73,18 @@ private static String fileLogPattern() {
     return directory + "/" + DEFAULT_LOG_PATTERN;
   }
 
-  /**
-   * Initialize the {@code VmRuntimeFileLogHandler} by installing it on the root logger.
-   */
-  public static void init() throws IOException {
-    reloadLoggingProperties(LogManager.getLogManager());
+  @Override
+  public void configure() throws IOException {
     Logger rootLogger = Logger.getLogger("");
+
+    // Look for the expected Handlers
     for (Handler handler : rootLogger.getHandlers()) {
-      if (handler instanceof VmRuntimeFileLogHandler) {
-        return; // Already installed.
+      if (handler instanceof CloudLoggingFileHandler) {
+        // Nothing else to do, return
+        return;
       }
     }
-    rootLogger.addHandler(new VmRuntimeFileLogHandler());
-  }
 
-  /**
-   * Reloads logging to pick up changes to the java.util.logging.config.file system property.
-   */
-  private static void reloadLoggingProperties(LogManager logManager) {
-    String logging = System.getProperty(VmRuntimeFileLogHandler.JAVA_UTIL_LOGGING_CONFIG_PROPERTY);
-    if (logging == null) {
-      return;
-    }
-    try {
-      logManager.readConfiguration();
-    } catch (SecurityException | IOException e) {
-      e.printStackTrace();
-      System.err.println("Warning: caught exception when reading logging properties.");
-      System.err.println(e.getClass().getName() + ": " + e.getMessage());
-    }
+    rootLogger.addHandler(new CloudLoggingFileHandler());
   }
 }

appengine-java-logging/src/main/java/com/google/apphosting/logging/CoreLogging.java

@@ -0,0 +1,149 @@
+/*
+ * Copyright 2016 Google Inc. All Rights Reserved.
+ *
+ * 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.google.apphosting.logging;
+
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.IOException;
+import java.util.ServiceLoader;
+import java.util.logging.LogManager;
+
+/**
+ * Logging Core behavior.
+ */
+public class CoreLogging {
+  public static final String JAVA_UTIL_LOGGING_CONFIG_PROPERTY = "java.util.logging.config.file";
+  private static final boolean DEBUG = Boolean.getBoolean("com.google.apphosting.logging.DEBUG");
+
+  /**
+   * Initialize the java.util.logging Environment.
+   * <p>
+   * Order is:
+   * <ol>
+   * <li>Apply App (User) Configuration</li>
+   * <li>Apply System Mandated Configuration</li>
+   * </ol>
+   * </p>
+   *
+   * @param appConfigFile the filename for the (optional) app specific java.util.logging
+   *                      properties file configuration.
+   */
+  public static void init(File appConfigFile) throws IOException {
+    // Use App (User) Configuration specified as a file parameter
+    if (appConfigFile != null && appConfigFile.exists()) {
+      debug("Loading App Config (from file): %s", appConfigFile);
+      appConfig(appConfigFile);
+    } else {
+      // Use App (User) Configuration specified as a System property
+      String julConfigFile = System.getProperty(JAVA_UTIL_LOGGING_CONFIG_PROPERTY);
+      if (julConfigFile != null) {
+        File configFile = new File(julConfigFile);
+        if (configFile.exists()) {
+          debug("Loading App Config (from property): %s", appConfigFile);
+          appConfig(configFile);
+        } else {
+          warning("Config System Property (%s) points to invalid file: %s",
+              JAVA_UTIL_LOGGING_CONFIG_PROPERTY, appConfigFile.getAbsolutePath());
+        }
+      } else {
+        debug("No App Config");
+      }
+    }
+
+    // Manually Adjust Configuration to support System Logging Requirements
+    systemConfig();
+  }
+
+  /**
+   * Convenience method for {@link #init(File)}.
+   *
+   * @param appConfigFilename the filename of the config file (or null)
+   * @throws IOException if unable to configure the logging
+   */
+  public static void init(String appConfigFilename) throws IOException {
+    File appConfigFile = null;
+    if (appConfigFilename != null) {
+      appConfigFile = new File(appConfigFilename);
+    }
+    init(appConfigFile);
+  }
+
+  private static void appConfig(File configFile) {
+    try (FileInputStream is = new FileInputStream(configFile)) {
+      LogManager logManager = LogManager.getLogManager();
+      logManager.reset(); // close & remove existing handlers, reset existing logger levels
+      logManager.readConfiguration(is);
+    } catch (SecurityException | IOException e) {
+      warning("Caught exception when reading logging properties: %s", configFile
+          .getAbsolutePath());
+      e.printStackTrace(System.err);
+    }
+  }
+
+  /**
+   * Manually Configure the System Level requirements for java.util.logging.
+   */
+  private static void systemConfig() throws IOException {
+    // Since System Loggers can arrive from deep within the various compat layers, it
+    // makes sense to use the ServiceLoader to obtain references to specific System loggers
+    // that need to be initialized during this step in the logging initialization.
+
+    int count = 0;
+    ServiceLoader<SystemLogger> serviceLoader = ServiceLoader.load(SystemLogger.class);
+    for (SystemLogger systemLogger : serviceLoader) {
+      debug("Executing SystemLogger: %s", systemLogger.getClass().getName());
+      systemLogger.configure();
+      count++;
+    }
+    debug("Initialized %d SystemLogger(s)", count);
+  }
+
+  /**
+   * Non JUL debug logging.
+   * <p>
+   *   As this class sets up the java.util.logging,
+   *   we can't reliable start using logging yet.
+   * </p>
+   * <p>
+   *   Note: by default this does not produce any output.
+   *   Set the System.property {@code com.google.apphosting.logging.DEBUG} to
+   *   true to see this output.
+   * </p>
+   *
+   * @param format the format of the debug line
+   * @param args the arguments of the debug line
+   */
+  private static void debug(String format, Object... args) {
+    if (DEBUG) {
+      System.err.printf("[CoreLogging:DEBUG] " + format + "%n", args);
+    }
+  }
+
+  /**
+   * Non JUL warnings logging.
+   * <p>
+   *   As this class sets up the java.util.logging,
+   *   we can't reliable start using logging yet.
+   * </p>
+   *
+   * @param format the format of the debug line
+   * @param args the arguments of the debug line
+   */
+  private static void warning(String format, Object... args) {
+    System.err.printf("[CoreLogging:WARNING] " + format + "%n", args);
+  }
+}

appengine-java-logging/src/main/java/com/google/apphosting/logging/LogContext.java

@@ -23,8 +23,9 @@
 /**
  * The context for logging information associated with the current Thread.
  * <p>
- * <p>This is an implementation of a Mapped Diagnostic Context for use with the java.util.logging
+ * This is an implementation of a Mapped Diagnostic Context for use with the java.util.logging
  * framework.
+ * </p>
  */
 public class LogContext extends ConcurrentHashMap<String, Object> {
 

appengine-java-logging/src/main/java/com/google/apphosting/logging/SystemLogger.java

@@ -0,0 +1,32 @@
+/*
+ * Copyright 2016 Google Inc. All Rights Reserved.
+ *
+ * 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.google.apphosting.logging;
+
+import java.io.IOException;
+
+/**
+ * Interface for any component wanting to participate in the System Logging level
+ * configuration.
+ */
+public interface SystemLogger {
+  /**
+   * Configure your System Level Logger on this event.
+   *
+   * @throws IOException if unable to configure the System Level Logger
+   */
+  void configure() throws IOException;
+}

appengine-java-logging/src/test/java/com/google/apphosting/logging/CommonsLoggingExample.java

@@ -0,0 +1,37 @@
+/*
+ * Copyright 2016 Google Inc. All Rights Reserved.
+ *
+ * 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.google.apphosting.logging;
+
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
+
+import java.util.concurrent.ThreadLocalRandom;
+
+class CommonsLoggingExample implements Runnable {
+  private static final Log logger = LogFactory.getLog(CommonsLoggingExample.class);
+
+  @Override
+  public void run() {
+    ThreadLocalRandom rand = ThreadLocalRandom.current();
+    logger.trace(String.format("A CommonsLogging Trace Event: %d", rand.nextInt()));
+    logger.debug(String.format("A CommonsLogging Debug Event: %d", rand.nextInt()));
+    logger.info(String.format("A CommonsLogging Info Event: %d", rand.nextInt()));
+    logger.warn(String.format("A CommonsLogging Warn Event: %d", rand.nextInt()));
+    logger.error(String.format("A CommonsLogging Error Event: %d", rand.nextInt()),
+        new RuntimeException("Generic Error"));
+  }
+}