diff --git a/appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java b/appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java similarity index 70% rename from appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java rename to appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java index 5c1a728..4ab3fc9 100644 --- a/appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java +++ b/appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java @@ -14,42 +14,45 @@ * limitations under the License. */ -package com.google.apphosting.vmruntime; - -import com.google.apphosting.logging.JsonFormatter; -import com.google.apphosting.logging.SystemLogger; +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.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 implements SystemLogger { +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.%u.%g.log.json"; private static final String APP_ENGINE_LOG_CONFIG_PATTERN_ENV = "APP_ENGINE_LOG_CONFIG_PATTERN"; - private static final int LOG_PER_FILE_SIZE = 100 * 1024 * 1024; - private static final int LOG_MAX_FILES = 3; + private static final int LOG_PER_FILE_SIZE = getConfigInt("limit", 100 * 1024 * 1024); + private static final int LOG_MAX_FILES = getConfigInt("count", 3); - public VmRuntimeFileLogHandler() throws IOException { + 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. @@ -76,12 +79,12 @@ public void configure() throws IOException { // Look for the expected Handlers for (Handler handler : rootLogger.getHandlers()) { - if (handler instanceof VmRuntimeFileLogHandler) { + if (handler instanceof CloudLoggingFileHandler) { // Nothing else to do, return return; } } - rootLogger.addHandler(new VmRuntimeFileLogHandler()); + rootLogger.addHandler(new CloudLoggingFileHandler()); } } diff --git a/appengine-java-logging/src/main/java/com/google/apphosting/logging/LogContext.java b/appengine-java-logging/src/main/java/com/google/apphosting/logging/LogContext.java index 7640f47..59b55db 100644 --- a/appengine-java-logging/src/main/java/com/google/apphosting/logging/LogContext.java +++ b/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. *

- *

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. + *

*/ public class LogContext extends ConcurrentHashMap { diff --git a/appengine-java-logging/src/test/java/com/google/apphosting/logging/CommonsLoggingExample.java b/appengine-java-logging/src/test/java/com/google/apphosting/logging/CommonsLoggingExample.java index d505a78..304280e 100644 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/CommonsLoggingExample.java +++ b/appengine-java-logging/src/test/java/com/google/apphosting/logging/CommonsLoggingExample.java @@ -22,16 +22,16 @@ import java.util.concurrent.ThreadLocalRandom; class CommonsLoggingExample implements Runnable { - private static final Log LOG = LogFactory.getLog(CommonsLoggingExample.class); + private static final Log logger = LogFactory.getLog(CommonsLoggingExample.class); @Override public void run() { ThreadLocalRandom rand = ThreadLocalRandom.current(); - LOG.trace(String.format("A CommonsLogging Trace Event: %d", rand.nextInt())); - LOG.debug(String.format("A CommonsLogging Debug Event: %d", rand.nextInt())); - LOG.info(String.format("A CommonsLogging Info Event: %d", rand.nextInt())); - LOG.warn(String.format("A CommonsLogging Warn Event: %d", rand.nextInt())); - LOG.error(String.format("A CommonsLogging Error Event: %d", rand.nextInt()), + 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")); } } diff --git a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonCaptureHandler.java b/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonCaptureHandler.java index 36dba2c..013f1df 100644 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonCaptureHandler.java +++ b/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonCaptureHandler.java @@ -21,14 +21,9 @@ import java.util.logging.Handler; import java.util.logging.LogRecord; -public class JsonCaptureHandler extends Handler { - private final JsonFormatter formatter; - private List events; - - public JsonCaptureHandler() { - formatter = new JsonFormatter(); - events = new ArrayList<>(); - } +public final class JsonCaptureHandler extends Handler { + private final JsonFormatter formatter = new JsonFormatter(); + private List events = new ArrayList<>(); @Override public void publish(LogRecord record) { @@ -40,7 +35,7 @@ public void flush() { } @Override - public void close() throws SecurityException { + public void close() { } public List getEvents() { diff --git a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonFormatterTest.java b/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonFormatterTest.java index bf49331..10bc694 100644 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonFormatterTest.java +++ b/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonFormatterTest.java @@ -110,8 +110,8 @@ public void messageIncludesStackTrace() throws Exception { @Test public void testCommonsLogging() { - final Instant now = Instant.now(); - final String expectedThreadName = Thread.currentThread().getName(); + Instant now = Instant.now(); + String expectedThreadName = Thread.currentThread().getName(); // Generate Events from Commons Logging new CommonsLoggingExample().run(); @@ -143,8 +143,8 @@ public void testCommonsLogging() { @Test public void testJavaUtilLogging() { - final Instant now = Instant.now(); - final String expectedThreadName = Thread.currentThread().getName(); + Instant now = Instant.now(); + String expectedThreadName = Thread.currentThread().getName(); // Generate Events from java.util.logging new JulExample().run(); @@ -178,8 +178,8 @@ public void testJavaUtilLogging() { @Test public void testLog4jLogging() { - final Instant now = Instant.now(); - final String expectedThreadName = Thread.currentThread().getName(); + Instant now = Instant.now(); + String expectedThreadName = Thread.currentThread().getName(); // Generate Events from Apache Log4j Logging new Log4jExample().run(); @@ -212,8 +212,8 @@ public void testLog4jLogging() { @Test public void testSlf4jLogging() { - final Instant now = Instant.now(); - final String expectedThreadName = Thread.currentThread().getName(); + Instant now = Instant.now(); + String expectedThreadName = Thread.currentThread().getName(); // Generate Events from Slf4j Logging new Slf4jExample().run(); @@ -252,7 +252,6 @@ public static class LogTimestamp { public int nanos; } - public LogTimestamp timestamp; public String severity; public String thread; diff --git a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JulExample.java b/appengine-java-logging/src/test/java/com/google/apphosting/logging/JulExample.java index 705c772..35c7998 100644 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JulExample.java +++ b/appengine-java-logging/src/test/java/com/google/apphosting/logging/JulExample.java @@ -21,18 +21,18 @@ import java.util.logging.Logger; class JulExample implements Runnable { - public static final Logger LOG = Logger.getLogger(JulExample.class.getName()); + public static final Logger logger = Logger.getLogger(JulExample.class.getName()); @Override public void run() { ThreadLocalRandom rand = ThreadLocalRandom.current(); - LOG.log(Level.FINEST, "A JUL Finest Event: {0}", rand.nextInt()); - LOG.log(Level.FINER, "A JUL Finer Event: {0}", rand.nextInt()); - LOG.log(Level.FINE, "A JUL Fine Event: {0}", rand.nextInt()); - LOG.log(Level.CONFIG, "A JUL Config Event: {0}", rand.nextInt()); - LOG.log(Level.INFO, "A JUL Info Event: {0}", rand.nextInt()); - LOG.log(Level.WARNING, "A JUL Warning Event: {0}", rand.nextInt()); - LOG.log(Level.SEVERE, String.format("A JUL Severe Event: %d", rand.nextInt()), + logger.log(Level.FINEST, "A JUL Finest Event: {0}", rand.nextInt()); + logger.log(Level.FINER, "A JUL Finer Event: {0}", rand.nextInt()); + logger.log(Level.FINE, "A JUL Fine Event: {0}", rand.nextInt()); + logger.log(Level.CONFIG, "A JUL Config Event: {0}", rand.nextInt()); + logger.log(Level.INFO, "A JUL Info Event: {0}", rand.nextInt()); + logger.log(Level.WARNING, "A JUL Warning Event: {0}", rand.nextInt()); + logger.log(Level.SEVERE, String.format("A JUL Severe Event: %d", rand.nextInt()), new RuntimeException("Generic Error")); } } diff --git a/appengine-java-logging/src/test/java/com/google/apphosting/logging/Log4jExample.java b/appengine-java-logging/src/test/java/com/google/apphosting/logging/Log4jExample.java index a7bbdc6..df43747 100644 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/Log4jExample.java +++ b/appengine-java-logging/src/test/java/com/google/apphosting/logging/Log4jExample.java @@ -21,16 +21,16 @@ import java.util.concurrent.ThreadLocalRandom; class Log4jExample implements Runnable { - private static final Logger LOG = Logger.getLogger(Log4jExample.class); + private static final Logger logger = Logger.getLogger(Log4jExample.class); @Override public void run() { ThreadLocalRandom rand = ThreadLocalRandom.current(); - LOG.trace(String.format("A Log4j Trace Event: %d", rand.nextInt())); - LOG.debug(String.format("A Log4j Debug Event: %d", rand.nextInt())); - LOG.info(String.format("A Log4j Info Event: %d", rand.nextInt())); - LOG.warn(String.format("A Log4j Warn Event: %d", rand.nextInt())); - LOG.error(String.format("A Log4j Error Event: %d", rand.nextInt()), + logger.trace(String.format("A Log4j Trace Event: %d", rand.nextInt())); + logger.debug(String.format("A Log4j Debug Event: %d", rand.nextInt())); + logger.info(String.format("A Log4j Info Event: %d", rand.nextInt())); + logger.warn(String.format("A Log4j Warn Event: %d", rand.nextInt())); + logger.error(String.format("A Log4j Error Event: %d", rand.nextInt()), new RuntimeException("Generic Error")); } } diff --git a/appengine-java-logging/src/test/java/com/google/apphosting/logging/Slf4jExample.java b/appengine-java-logging/src/test/java/com/google/apphosting/logging/Slf4jExample.java index 2efe145..1af3563 100644 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/Slf4jExample.java +++ b/appengine-java-logging/src/test/java/com/google/apphosting/logging/Slf4jExample.java @@ -22,16 +22,16 @@ import java.util.concurrent.ThreadLocalRandom; class Slf4jExample implements Runnable { - private static final Logger LOG = LoggerFactory.getLogger(Slf4jExample.class); + private static final Logger logger = LoggerFactory.getLogger(Slf4jExample.class); @Override public void run() { ThreadLocalRandom rand = ThreadLocalRandom.current(); - LOG.trace("A Slf4j Trace Event: {}", rand.nextInt()); - LOG.debug("A Slf4j Debug Event: {}", rand.nextInt()); - LOG.info("A Slf4j Info Event: {}", rand.nextInt()); - LOG.warn("A Slf4j Warn Event: {}", rand.nextInt()); - LOG.error(String.format("A Slf4j Error Event: %d", rand.nextInt()), + logger.trace("A Slf4j Trace Event: {}", rand.nextInt()); + logger.debug("A Slf4j Debug Event: {}", rand.nextInt()); + logger.info("A Slf4j Info Event: {}", rand.nextInt()); + logger.warn("A Slf4j Warn Event: {}", rand.nextInt()); + logger.error(String.format("A Slf4j Error Event: %d", rand.nextInt()), new RuntimeException("Generic Error")); } } diff --git a/appengine-managed-runtime/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger b/appengine-managed-runtime/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger index 9d08267..9187909 100644 --- a/appengine-managed-runtime/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger +++ b/appengine-managed-runtime/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger @@ -1 +1 @@ -com.google.apphosting.vmruntime.VmRuntimeFileLogHandler \ No newline at end of file +com.google.apphosting.logging.CloudLoggingFileHandler diff --git a/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/RequestLoggerHandler.java b/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/RequestLoggerHandler.java index 6e3d900..37dbc42 100644 --- a/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/RequestLoggerHandler.java +++ b/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/RequestLoggerHandler.java @@ -10,6 +10,12 @@ import java.util.logging.LogRecord; import java.util.logging.Logger; +/** + * The {@link java.util.logging.Handler} responsible for capturing the + * access logging events from {@link org.eclipse.jetty.server.handler.RequestLogHandler} + * and {@link org.eclipse.jetty.server.Slf4jRequestLog} to a rolling file + * on disk. + */ public class RequestLoggerHandler extends FileHandler implements SystemLogger { public static class RequestLogFormatter extends Formatter { @Override @@ -19,22 +25,37 @@ public String format(LogRecord record) { } } - public static final String LOG_DIRECTORY_PROPERTY = "com.google.apphosting.logs"; public static final String LOG_PATTERN_CONFIG_PROPERTY = RequestLoggerHandler.class.getName() + ".pattern"; private static final String DEFAULT_LOG_DIRECTORY = "/var/log/app_engine"; private static final String DEFAULT_LOG_PATTERN = "access.%g.log"; - private static final int LOG_PER_FILE_SIZE = 10 * 1024 * 1024; - private static final int LOG_MAX_FILES = 3; - private static final boolean LOG_APPEND = true; + private static final int LOG_PER_FILE_SIZE = getConfigInt("limit", 10 * 1024 * 1024); + private static final int LOG_MAX_FILES = getConfigInt("count", 3); + private static final boolean LOG_APPEND = getConfigBool("append", true); public RequestLoggerHandler() throws IOException, SecurityException { super(getFilePattern(), LOG_PER_FILE_SIZE, LOG_MAX_FILES, LOG_APPEND); setFormatter(new RequestLogFormatter()); } + private static boolean getConfigBool(String suffix, boolean defValue) { + String val = System.getProperty(RequestLoggerHandler.class.getName() + '.' + suffix); + if (val == null) { + return defValue; + } + return Boolean.parseBoolean(val); + } + + private static int getConfigInt(String suffix, int defValue) { + String val = System.getProperty(RequestLoggerHandler.class.getName() + '.' + suffix); + if (val == null) { + return defValue; + } + return Integer.parseInt(val); + } + private static String getFilePattern() { String directory = System.getProperty(LOG_DIRECTORY_PROPERTY, DEFAULT_LOG_DIRECTORY); diff --git a/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/JettyRunner.java b/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/JettyRunner.java index a4a5ce3..82b932f 100644 --- a/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/JettyRunner.java +++ b/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/JettyRunner.java @@ -20,7 +20,7 @@ import static com.google.apphosting.vmruntime.jetty9.VmRuntimeTestBase.JETTY_HOME_PATTERN; import com.google.apphosting.jetty9.GoogleRequestCustomizer; -import com.google.apphosting.vmruntime.VmRuntimeFileLogHandler; +import com.google.apphosting.logging.CloudLoggingFileHandler; import org.eclipse.jetty.apache.jsp.JettyJasperInitializer; import org.eclipse.jetty.io.MappedByteBufferPool; @@ -40,20 +40,13 @@ import org.eclipse.jetty.util.thread.QueuedThreadPool; import org.junit.Assert; -import java.io.BufferedReader; import java.io.File; -import java.io.FileInputStream; -import java.io.FileNotFoundException; import java.io.IOException; -import java.io.InputStreamReader; import java.net.ServerSocket; -import java.nio.charset.StandardCharsets; import java.util.Arrays; import java.util.Collections; import java.util.concurrent.CountDownLatch; import java.util.concurrent.TimeUnit; -import java.util.regex.Matcher; -import java.util.regex.Pattern; import java.util.stream.Collectors; class JettyRunner extends AbstractLifeCycle implements Runnable { @@ -267,59 +260,11 @@ public void run() { } } - /** - * Find the log file that contains the specific content pattern. - *

- * This exists to get around the fact that the java.util.logging - * layer will generate a new log file each time its reset/initialized - * because it sees the lock from the previous instance before the - * previous instance has a chance to close and remove the lock. - *

- *

- * This function will iterate through all of the log files and - * attempt to find the specific pattern you are interested in. - *

- * - * @param regex the text (regex) pattern to look for in the log file. - * @return the File for the discovered log file - * @throws java.io.FileNotFoundException if unable to find a log - * file with the specific text pattern - * @throws IOException if unable to read a log file and/or pattern - */ - public File findLogFileThatContains(String regex) throws IOException { - Pattern logPattern = Pattern.compile("log[0-9]+\\.[0-9]+\\.json"); - Pattern textPattern = Pattern.compile(regex); - Matcher logMatcher; - String line; - - for (File file : getLogDir().listFiles()) { - logMatcher = logPattern.matcher(file.getName()); - boolean validFile = logMatcher.matches(); - if (validFile) { - // search file - try (FileInputStream in = new FileInputStream(file); - InputStreamReader reader = new InputStreamReader(in, StandardCharsets.UTF_8); - BufferedReader buf = new BufferedReader(reader)) { - Matcher textMatcher; - while ((line = buf.readLine()) != null) { - textMatcher = textPattern.matcher(line); - if (textMatcher.find()) { - return file; - } - } - } - } - } - - throw new FileNotFoundException( - "Unable to find pattern [" + textPattern.pattern() + "] in logs at " + getLogDir()); - } - /** * Sets the system properties expected by jetty.xml. */ protected void setSystemProperties(File logs) throws IOException { - System.setProperty(VmRuntimeFileLogHandler.LOG_PATTERN_CONFIG_PROPERTY, + System.setProperty(CloudLoggingFileHandler.LOG_PATTERN_CONFIG_PROPERTY, logs.getAbsolutePath() + "/log%u.%g.json"); System.setProperty(RequestLoggerHandler.LOG_PATTERN_CONFIG_PROPERTY, logs.getAbsolutePath() + "/request-%u.%g.log"); diff --git a/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/LoggingIT.java b/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/LoggingIT.java index 3a8e584..f1cd342 100644 --- a/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/LoggingIT.java +++ b/jetty9-compat-base/src/test/java/com/google/apphosting/vmruntime/jetty9/LoggingIT.java @@ -28,11 +28,63 @@ import java.io.BufferedReader; import java.io.File; import java.io.FileInputStream; +import java.io.FileNotFoundException; +import java.io.IOException; import java.io.InputStreamReader; import java.nio.charset.StandardCharsets; +import java.util.regex.Matcher; +import java.util.regex.Pattern; public class LoggingIT extends VmRuntimeTestBase { + /** + * Find the log file that contains the specific content pattern. + *

+ * This exists to get around the fact that the java.util.logging + * layer will generate a new log file each time its reset/initialized + * because it sees the lock from the previous instance before the + * previous instance has a chance to close and remove the lock. + *

+ *

+ * This function will iterate through all of the log files and + * attempt to find the specific pattern you are interested in. + *

+ * + * @param regex the text (regex) pattern to look for in the log file. + * @return the File for the discovered log file + * @throws java.io.FileNotFoundException if unable to find a log + * file with the specific text pattern + * @throws IOException if unable to read a log file and/or pattern + */ + public File findLogFileThatContains(File logDir, String regex) throws IOException { + Pattern logPattern = Pattern.compile("log[0-9]+\\.[0-9]+\\.json"); + Pattern textPattern = Pattern.compile(regex); + Matcher logMatcher; + String line; + + for (File file : logDir.listFiles()) { + logMatcher = logPattern.matcher(file.getName()); + boolean validFile = logMatcher.matches(); + if (validFile) { + // search file + try (FileInputStream in = new FileInputStream(file); + InputStreamReader reader = new InputStreamReader(in, StandardCharsets.UTF_8); + BufferedReader buf = new BufferedReader(reader)) { + Matcher textMatcher; + while ((line = buf.readLine()) != null) { + textMatcher = textPattern.matcher(line); + if (textMatcher.find()) { + return file; + } + } + } + } + } + + throw new FileNotFoundException( + "Unable to find pattern [" + textPattern.pattern() + "] in logs at " + logDir); + } + public void testGet() throws Exception { //runner.dump(); @@ -48,7 +100,7 @@ public void testGet() throws Exception { String body = get.getResponseBodyAsString(); assertThat(body, equalTo("FINE\nSEVERE\nfalse\n\n")); - File log = runner.findLogFileThatContains(query); + File log = findLogFileThatContains(runner.getLogDir(),query); assertTrue(log.exists());