From b184756970d770159bd8997c2d74b73008564671 Mon Sep 17 00:00:00 2001 From: Ludovic Champenois Date: Fri, 2 Sep 2016 06:31:31 -0700 Subject: [PATCH] Revert "Issue #231 - Logging Rotation and Levels" --- appengine-java-logging/pom.xml | 34 -- .../apphosting/logging/CoreLogging.java | 149 -------- .../google/apphosting/logging/LogContext.java | 3 +- .../apphosting/logging/SystemLogger.java | 32 -- .../logging/CommonsLoggingExample.java | 37 -- .../logging/JsonCaptureHandler.java | 44 --- .../apphosting/logging/JsonFormatterTest.java | 164 +------- .../google/apphosting/logging/JulExample.java | 38 -- .../apphosting/logging/Log4jExample.java | 36 -- .../apphosting/logging/Slf4jExample.java | 37 -- appengine-managed-runtime/pom.xml | 11 +- .../apphosting/vmruntime/VmAppLogsWriter.java | 352 ++++++++++++++++++ .../vmruntime/VmRuntimeFileLogHandler.java | 69 ++-- ...com.google.apphosting.logging.SystemLogger | 1 - jetty9-base/pom.xml | 3 - jetty9-base/src/main/jetty-base/etc/gae.xml | 5 +- jetty9-compat-base/pom.xml | 3 - .../src/main/assembly/assembly.xml | 1 - .../jetty9/RequestLoggerHandler.java | 90 ----- .../jetty9/VmRuntimeWebAppContext.java | 9 +- .../src/main/jetty-base/etc/gae.xml | 19 +- ...com.google.apphosting.logging.SystemLogger | 1 - .../vmruntime/jetty9/JettyRunner.java | 21 +- .../vmruntime/jetty9/LoggingIT.java | 84 +---- pom.xml | 7 - 25 files changed, 444 insertions(+), 806 deletions(-) delete mode 100644 appengine-java-logging/src/main/java/com/google/apphosting/logging/CoreLogging.java delete mode 100644 appengine-java-logging/src/main/java/com/google/apphosting/logging/SystemLogger.java delete mode 100644 appengine-java-logging/src/test/java/com/google/apphosting/logging/CommonsLoggingExample.java delete mode 100644 appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonCaptureHandler.java delete mode 100644 appengine-java-logging/src/test/java/com/google/apphosting/logging/JulExample.java delete mode 100644 appengine-java-logging/src/test/java/com/google/apphosting/logging/Log4jExample.java delete mode 100644 appengine-java-logging/src/test/java/com/google/apphosting/logging/Slf4jExample.java create mode 100644 appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmAppLogsWriter.java rename appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java => appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java (51%) delete mode 100644 appengine-managed-runtime/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger delete mode 100644 jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/RequestLoggerHandler.java delete mode 100644 jetty9-compat-base/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger diff --git a/appengine-java-logging/pom.xml b/appengine-java-logging/pom.xml index 80c4b17..2a4db97 100644 --- a/appengine-java-logging/pom.xml +++ b/appengine-java-logging/pom.xml @@ -29,46 +29,12 @@ jar Support code for writing log files compatible with Google App Engine - - 1.7.16 - - - - - org.slf4j - slf4j-api - ${slf4j.version} - - - - org.slf4j - jcl-over-slf4j - ${slf4j.version} - - - org.slf4j - log4j-over-slf4j - ${slf4j.version} - - - - org.slf4j - slf4j-jdk14 - ${slf4j.version} - - com.google.code.gson gson - - org.hamcrest - hamcrest-library - test - - junit junit diff --git a/appengine-java-logging/src/main/java/com/google/apphosting/logging/CoreLogging.java b/appengine-java-logging/src/main/java/com/google/apphosting/logging/CoreLogging.java deleted file mode 100644 index 5cbe1e1..0000000 --- a/appengine-java-logging/src/main/java/com/google/apphosting/logging/CoreLogging.java +++ /dev/null @@ -1,149 +0,0 @@ -/* - * 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. - *

- * Order is: - *

    - *
  1. Apply App (User) Configuration
    2. - *
  2. Apply System Mandated Configuration
    3. - *
- *

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

- * As this class sets up the java.util.logging, - * we can't reliable start using logging yet. - *

- *

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

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

- * As this class sets up the java.util.logging, - * we can't reliable start using logging yet. - *

- * - * @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); - } -} 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 59b55db..7640f47 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,9 +23,8 @@ /** * 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/main/java/com/google/apphosting/logging/SystemLogger.java b/appengine-java-logging/src/main/java/com/google/apphosting/logging/SystemLogger.java deleted file mode 100644 index 0060e36..0000000 --- a/appengine-java-logging/src/main/java/com/google/apphosting/logging/SystemLogger.java +++ /dev/null @@ -1,32 +0,0 @@ -/* - * 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; -} 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 deleted file mode 100644 index 304280e..0000000 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/CommonsLoggingExample.java +++ /dev/null @@ -1,37 +0,0 @@ -/* - * 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")); - } -} 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 deleted file mode 100644 index 013f1df..0000000 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JsonCaptureHandler.java +++ /dev/null @@ -1,44 +0,0 @@ -/* - * 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.util.ArrayList; -import java.util.List; -import java.util.logging.Handler; -import java.util.logging.LogRecord; - -public final class JsonCaptureHandler extends Handler { - private final JsonFormatter formatter = new JsonFormatter(); - private List events = new ArrayList<>(); - - @Override - public void publish(LogRecord record) { - events.add(formatter.format(record)); - } - - @Override - public void flush() { - } - - @Override - public void close() { - } - - public List getEvents() { - return events; - } -} 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 10bc694..45cdc55 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 @@ -16,10 +16,6 @@ package com.google.apphosting.logging; -import static org.hamcrest.Matchers.containsString; -import static org.hamcrest.Matchers.greaterThanOrEqualTo; -import static org.hamcrest.Matchers.is; -import static org.hamcrest.Matchers.startsWith; import static org.hamcrest.core.StringEndsWith.endsWith; import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertThat; @@ -27,32 +23,17 @@ import com.google.gson.Gson; -import org.junit.Before; import org.junit.Test; import java.io.BufferedReader; import java.io.StringReader; -import java.time.Instant; -import java.util.List; import java.util.logging.Level; import java.util.logging.LogRecord; -import java.util.logging.Logger; public class JsonFormatterTest { private JsonFormatter formatter = new JsonFormatter(); - private JsonCaptureHandler capturingHandler; - - @Before - public void initLoggingCapture() { - Logger root = Logger.getLogger(""); - root.setLevel(Level.FINE); - - capturingHandler = new JsonCaptureHandler(); - root.addHandler(capturingHandler); - } - @Test public void formatProducesExpectedJsonData() throws Exception { LogRecord record = new LogRecord(Level.INFO, "message"); @@ -104,152 +85,17 @@ public void messageIncludesStackTrace() throws Exception { BufferedReader reader = new BufferedReader(new StringReader(message)); assertEquals("logger: message", reader.readLine()); assertEquals("java.lang.Throwable: thrown", reader.readLine()); - assertTrue(reader.readLine() - .startsWith("\tat " + getClass().getName() + ".messageIncludesStackTrace")); + assertTrue( + reader + .readLine() + .startsWith("\tat " + getClass().getName() + ".messageIncludesStackTrace")); } - @Test - public void testCommonsLogging() { - Instant now = Instant.now(); - String expectedThreadName = Thread.currentThread().getName(); - - // Generate Events from Commons Logging - new CommonsLoggingExample().run(); - - // Verify that event was captured by slf4j -> java.util.logging - String[][] expected = new String[][] {{"DEBUG", "A CommonsLogging Debug Event: "}, - {"INFO", "A CommonsLogging Info Event: "}, {"WARNING", "A CommonsLogging Warn Event: "}, - {"ERROR", "A CommonsLogging Error Event: "}}; - - List events = capturingHandler.getEvents(); - assertThat("Events", events.size(), is(expected.length)); - - for (int i = 0; i < events.size(); i++) { - String logLine = events.get(i); - JsonData data = new Gson().fromJson(logLine, JsonData.class); - assertThat("severity", data.severity, is(expected[i][0])); - assertThat("timestamp.seconds", data.timestamp.seconds, - greaterThanOrEqualTo(now.getEpochSecond())); - assertThat("timestamp.nanos", data.timestamp.nanos, greaterThanOrEqualTo(now.getNano())); - assertThat("thread name", data.thread, is(expectedThreadName)); - assertThat("logger message", data.message, - startsWith(CommonsLoggingExample.class.getName() + " run: " + expected[i][1])); - if (data.severity.equals("ERROR")) { - assertThat("throwable", data.message, - containsString("java.lang.RuntimeException: Generic Error")); - } - } - } - - @Test - public void testJavaUtilLogging() { - Instant now = Instant.now(); - String expectedThreadName = Thread.currentThread().getName(); - - // Generate Events from java.util.logging - new JulExample().run(); - - // Verify that event was captured by slf4j -> java.util.logging - String[][] expected = - new String[][] {{"DEBUG", "A JUL Fine Event: "}, {"DEBUG", "A JUL Config Event: "}, - {"INFO", "A JUL Info Event: "}, {"WARNING", "A JUL Warning Event: "}, - {"ERROR", "A JUL Severe Event: "}}; - - List events = capturingHandler.getEvents(); - assertThat("Events", events.size(), is(expected.length)); - - for (int i = 0; i < events.size(); i++) { - String logLine = events.get(i); - System.out.printf("logLine[%d] = %s", i, logLine); - JsonData data = new Gson().fromJson(logLine, JsonData.class); - assertThat("severity", data.severity, is(expected[i][0])); - assertThat("timestamp.seconds", data.timestamp.seconds, - greaterThanOrEqualTo(now.getEpochSecond())); - assertThat("timestamp.nanos", data.timestamp.nanos, greaterThanOrEqualTo(now.getNano())); - assertThat("thread name", data.thread, is(expectedThreadName)); - assertThat("logger message", data.message, - startsWith(JulExample.class.getName() + " run: " + expected[i][1])); - if (data.severity.equals("ERROR")) { - assertThat("throwable", data.message, - containsString("java.lang.RuntimeException: Generic Error")); - } - } - } - - @Test - public void testLog4jLogging() { - Instant now = Instant.now(); - String expectedThreadName = Thread.currentThread().getName(); - - // Generate Events from Apache Log4j Logging - new Log4jExample().run(); - - // Verify that event was captured by slf4j -> java.util.logging - String[][] expected = - new String[][] {{"DEBUG", "A Log4j Debug Event: "}, {"INFO", "A Log4j Info Event: "}, - {"WARNING", "A Log4j Warn Event: "}, {"ERROR", "A Log4j Error Event: "}}; - - List events = capturingHandler.getEvents(); - assertThat("Events", events.size(), is(expected.length)); - - for (int i = 0; i < events.size(); i++) { - String logLine = events.get(i); - System.out.printf("logLine[%d] = %s", i, logLine); - JsonData data = new Gson().fromJson(logLine, JsonData.class); - assertThat("severity", data.severity, is(expected[i][0])); - assertThat("timestamp.seconds", data.timestamp.seconds, - greaterThanOrEqualTo(now.getEpochSecond())); - assertThat("timestamp.nanos", data.timestamp.nanos, greaterThanOrEqualTo(now.getNano())); - assertThat("thread name", data.thread, is(expectedThreadName)); - assertThat("logger message", data.message, - startsWith(Log4jExample.class.getName() + " run: " + expected[i][1])); - if (data.severity.equals("ERROR")) { - assertThat("throwable", data.message, - containsString("java.lang.RuntimeException: Generic Error")); - } - } - } - - @Test - public void testSlf4jLogging() { - Instant now = Instant.now(); - String expectedThreadName = Thread.currentThread().getName(); - - // Generate Events from Slf4j Logging - new Slf4jExample().run(); - - // Verify that event was captured by slf4j -> java.util.logging - String[][] expected = - new String[][] {{"DEBUG", "A Slf4j Debug Event: "}, {"INFO", "A Slf4j Info Event: "}, - {"WARNING", "A Slf4j Warn Event: "}, {"ERROR", "A Slf4j Error Event: "}}; - - List events = capturingHandler.getEvents(); - assertThat("Events", events.size(), is(expected.length)); - - for (int i = 0; i < events.size(); i++) { - String logLine = events.get(i); - System.out.printf("logLine[%d] = %s", i, logLine); - JsonData data = new Gson().fromJson(logLine, JsonData.class); - assertThat("severity", data.severity, is(expected[i][0])); - assertThat("timestamp.seconds", data.timestamp.seconds, - greaterThanOrEqualTo(now.getEpochSecond())); - assertThat("timestamp.nanos", data.timestamp.nanos, greaterThanOrEqualTo(now.getNano())); - assertThat("thread name", data.thread, is(expectedThreadName)); - assertThat("logger message", data.message, - startsWith(Slf4jExample.class.getName() + " run: " + expected[i][1])); - if (data.severity.equals("ERROR")) { - assertThat("throwable", data.message, - containsString("java.lang.RuntimeException: Generic Error")); - } - } - } - - // Something that JSON can parser the JSON into public static class JsonData { public static class LogTimestamp { public long seconds; - public int nanos; + public long nanos; } public LogTimestamp timestamp; 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 deleted file mode 100644 index 35c7998..0000000 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/JulExample.java +++ /dev/null @@ -1,38 +0,0 @@ -/* - * 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.util.concurrent.ThreadLocalRandom; -import java.util.logging.Level; -import java.util.logging.Logger; - -class JulExample implements Runnable { - public static final Logger logger = Logger.getLogger(JulExample.class.getName()); - - @Override - public void run() { - ThreadLocalRandom rand = ThreadLocalRandom.current(); - 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 deleted file mode 100644 index df43747..0000000 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/Log4jExample.java +++ /dev/null @@ -1,36 +0,0 @@ -/* - * 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.log4j.Logger; - -import java.util.concurrent.ThreadLocalRandom; - -class Log4jExample implements Runnable { - private static final Logger logger = Logger.getLogger(Log4jExample.class); - - @Override - public void run() { - ThreadLocalRandom rand = ThreadLocalRandom.current(); - 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 deleted file mode 100644 index 1af3563..0000000 --- a/appengine-java-logging/src/test/java/com/google/apphosting/logging/Slf4jExample.java +++ /dev/null @@ -1,37 +0,0 @@ -/* - * 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.slf4j.Logger; -import org.slf4j.LoggerFactory; - -import java.util.concurrent.ThreadLocalRandom; - -class Slf4jExample implements Runnable { - private static final Logger logger = LoggerFactory.getLogger(Slf4jExample.class); - - @Override - public void run() { - ThreadLocalRandom rand = ThreadLocalRandom.current(); - 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/pom.xml b/appengine-managed-runtime/pom.xml index 2959b33..aa857c9 100644 --- a/appengine-managed-runtime/pom.xml +++ b/appengine-managed-runtime/pom.xml @@ -53,12 +53,11 @@ org.apache.httpcomponents httpclient 4.4.1 - - - commons-logging - commons-logging - - + + + commons-logging + commons-logging + 1.2 commons-codec diff --git a/appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmAppLogsWriter.java b/appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmAppLogsWriter.java new file mode 100644 index 0000000..1600c7c --- /dev/null +++ b/appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmAppLogsWriter.java @@ -0,0 +1,352 @@ +/* + * 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.vmruntime; + +import com.google.appengine.repackaged.com.google.common.base.Stopwatch; +import com.google.apphosting.api.ApiProxy; +import com.google.apphosting.api.ApiProxy.ApiConfig; +import com.google.apphosting.api.ApiProxy.LogRecord; +import com.google.apphosting.api.logservice.LogServicePb.FlushRequest; +import com.google.apphosting.api.logservice.LogServicePb.UserAppLogGroup; +import com.google.apphosting.api.logservice.LogServicePb.UserAppLogLine; + +import java.util.LinkedList; +import java.util.List; +import java.util.concurrent.ExecutionException; +import java.util.concurrent.Future; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.TimeoutException; +import java.util.logging.Level; +import java.util.logging.Logger; + +/** + * {@code AppsLogWriter} is responsible for batching application logs + * for a single request and sending them back to the AppServer via the + * LogService.Flush API call. + * + *

The current algorithm used to send logs is as follows: + *

    + *
  • The code never allows more than {@code byteCountBeforeFlush} bytes of + * log data to accumulate in the buffer. If adding a new log line + * would exceed that limit, the current set of logs are removed from it and an + * asynchronous API call is started to flush the logs before buffering the + * new line.
    • + * + *
  • If another flush occurs while a previous flush is still + * pending, the caller will block synchronously until the previous + * call completed.
    • + * + *
  • When the overall request completes is should call @code{waitForCurrentFlushAndStartNewFlush} + * and report the flush count as a HTTP response header. The vm_runtime on the appserver + * will wait for the reported number of log flushes before forwarding the HTTP response + * to the user.
    • + *
+ * + *

This class is also responsible for splitting large log entries + * into smaller fragments, which is unrelated to the batching + * mechanism described above but is necessary to prevent the AppServer + * from truncating individual log entries. + * + *

This class is thread safe and all methods accessing local state are + * synchronized. Since each request have their own instance of this class the + * only contention possible is between the original request thread and and any + * child RequestThreads created by the request through the threading API. + * + */ +@Deprecated +class VmAppLogsWriter { + private static final Logger logger = Logger.getLogger(VmAppLogsWriter.class.getName()); + + // (Some constants below package scope for testability) + static final String LOG_CONTINUATION_SUFFIX = "\n"; + static final int LOG_CONTINUATION_SUFFIX_LENGTH = LOG_CONTINUATION_SUFFIX.length(); + static final String LOG_CONTINUATION_PREFIX = "\n"; + static final int LOG_CONTINUATION_PREFIX_LENGTH = LOG_CONTINUATION_PREFIX.length(); + static final int MIN_MAX_LOG_MESSAGE_LENGTH = 1024; + // Log flushes generally complete fast (6 ms at the median, 46ms at the 99th percentile). + static final int LOG_FLUSH_TIMEOUT_MS = 2000; + + private final int maxLogMessageLength; + private final int logCutLength; + private final int logCutLengthDiv10; + private final List buffer; + private final long maxBytesToFlush; + private long currentByteCount; + private final int maxSecondsBetweenFlush; + private int flushCount = 0; + private Future currentFlush; + private Stopwatch stopwatch; + + /** + * Construct an AppLogsWriter instance. + * + * @param buffer Buffer holding messages between flushes. + * @param maxBytesToFlush The maximum number of bytes of log message to + * allow in a single flush. The code flushes any cached logs before + * reaching this limit. If this is 0, AppLogsWriter will not start + * an intermediate flush based on size. + * @param maxLogMessageLength The maximum length of an individual log line. + * A single log line longer than this will be written as multiple log + * entries (with the continuation prefix/suffixes added to indicate this). + * @param maxFlushSeconds The amount of time to allow a log line to sit + * cached before flushing. Once a log line has been sitting for more + * than the specified time, all currently cached logs are flushed. If + * this is 0, no time based flushing occurs. + * N.B. because we only check the time on a log call, it is possible for + * a log to stay cached long after the specified time has been reached. + * Consider this example (assume maxFlushSeconds=60): the app logs a message + * when the handler starts but then does not log another message for 10 + * minutes. The initial log will stay cached until the second message + * is logged. + */ + public VmAppLogsWriter( + List buffer, + long maxBytesToFlush, + int maxLogMessageLength, + int maxFlushSeconds) { + this.buffer = buffer; + this.maxSecondsBetweenFlush = maxFlushSeconds; + + if (maxLogMessageLength < MIN_MAX_LOG_MESSAGE_LENGTH) { + String message = + String.format( + "maxLogMessageLength silly small (%s); setting maxLogMessageLength to %s", + maxLogMessageLength, + MIN_MAX_LOG_MESSAGE_LENGTH); + logger.warning(message); + this.maxLogMessageLength = MIN_MAX_LOG_MESSAGE_LENGTH; + } else { + this.maxLogMessageLength = maxLogMessageLength; + } + logCutLength = maxLogMessageLength - LOG_CONTINUATION_SUFFIX_LENGTH; + logCutLengthDiv10 = logCutLength / 10; + + // This should never happen, but putting here just in case. + if (maxBytesToFlush < this.maxLogMessageLength) { + String message = + String.format( + "maxBytesToFlush (%s) smaller than maxLogMessageLength (%s)", + maxBytesToFlush, + this.maxLogMessageLength); + logger.warning(message); + this.maxBytesToFlush = this.maxLogMessageLength; + } else { + this.maxBytesToFlush = maxBytesToFlush; + } + + // Always have a stopwatch even if we're not doing time based flushing + // to keep code a bit simpler + stopwatch = Stopwatch.createUnstarted(); + } + + /** + * Add the specified {@link LogRecord} for the current request. If + * enough space (or in the future, time) has accumulated, an + * asynchronous flush may be started. If flushes are backed up, + * this method may block. + */ + synchronized void addLogRecordAndMaybeFlush(LogRecord fullRecord) { + for (LogRecord record : split(fullRecord)) { + UserAppLogLine logLine = new UserAppLogLine(); + logLine.setLevel(record.getLevel().ordinal()); + logLine.setTimestampUsec(record.getTimestamp()); + logLine.setMessage(record.getMessage()); + // Use maxEncodingSize() here because it's faster and accurate + // enough for us. It uses the maximum possible size for varint + // values, but the real size of strings. + int maxEncodingSize = logLine.maxEncodingSize(); + if (maxBytesToFlush > 0 && (currentByteCount + maxEncodingSize) > maxBytesToFlush) { + logger.info(currentByteCount + " bytes of app logs pending, starting flush..."); + waitForCurrentFlushAndStartNewFlush(); + } + if (buffer.size() == 0) { + // We only want to flush once a log message has been around for + // longer than maxSecondsBetweenFlush. So, we only start the timer + // when we add the first message so we don't include time when + // the queue is empty. + stopwatch.start(); + } + buffer.add(logLine); + currentByteCount += maxEncodingSize; + } + + if (maxSecondsBetweenFlush > 0 + && stopwatch.elapsed(TimeUnit.SECONDS) >= maxSecondsBetweenFlush) { + waitForCurrentFlushAndStartNewFlush(); + } + } + + /** + * Starts an asynchronous flush. This method may block if flushes + * are backed up. + * + * @return The number of times this AppLogsWriter has initiated a flush. + */ + synchronized int waitForCurrentFlushAndStartNewFlush() { + waitForCurrentFlush(); + if (buffer.size() > 0) { + currentFlush = doFlush(); + } + return flushCount; + } + + /** + * Initiates a synchronous flush. This method will always block + * until any pending flushes and its own flush completes. + */ + synchronized int flushAndWait() { + waitForCurrentFlush(); + if (buffer.size() > 0) { + currentFlush = doFlush(); + waitForCurrentFlush(); + } + return flushCount; + } + + /** + * This method blocks until any outstanding flush is completed. This method + * should be called prior to {@link #doFlush()} so that it is impossible for + * the appserver to process logs out of order. + */ + private void waitForCurrentFlush() { + if (currentFlush != null) { + logger.info("End of request or previous flush has not yet completed, blocking."); + try { + // VMApiProxyDelegate adds 1000 ms extra to the http connection deadline. + currentFlush.get( + VmApiProxyDelegate.ADDITIONAL_HTTP_TIMEOUT_BUFFER_MS + LOG_FLUSH_TIMEOUT_MS, + TimeUnit.MILLISECONDS); + } catch (InterruptedException ex) { + logger.warning( + "Interruped while blocking on a log flush, setting interrupt bit and " + + "continuing. Some logs may be lost or occur out of order!"); + Thread.currentThread().interrupt(); + } catch (TimeoutException e) { + logger.log( + Level.WARNING, + "Timeout waiting for log flush to complete. " + + "Log messages may have been lost/reordered!", + e); + } catch (ExecutionException ex) { + logger.log( + Level.WARNING, "A log flush request failed. Log messages may have been lost!", ex); + } + currentFlush = null; + } + } + + private Future doFlush() { + UserAppLogGroup group = new UserAppLogGroup(); + for (UserAppLogLine logLine : buffer) { + group.addLogLine(logLine); + } + buffer.clear(); + currentByteCount = 0; + flushCount++; + stopwatch.reset(); + FlushRequest request = new FlushRequest(); + request.setLogsAsBytes(group.toByteArray()); + // This assumes that we are always doing a flush from the request + // thread. See the TODO above. + ApiConfig apiConfig = new ApiConfig(); + apiConfig.setDeadlineInSeconds(LOG_FLUSH_TIMEOUT_MS / 1000.0); + return ApiProxy.makeAsyncCall("logservice", "Flush", request.toByteArray(), apiConfig); + } + + /** + * Because the App Server will truncate log messages that are too + * long, we want to split long log messages into mutliple messages. + * This method returns a {@link List} of {@code LogRecord}s, each of + * which have the same {@link LogRecord#getLevel()} and + * {@link LogRecord#getTimestamp()} as + * this one, and whose {@link LogRecord#getMessage()} is short enough + * that it will not be truncated by the App Server. If the + * {@code message} of this {@code LogRecord} is short enough, the list + * will contain only this {@code LogRecord}. Otherwise the list will + * contain multiple {@code LogRecord}s each of which contain a portion + * of the {@code message}. Additionally, strings will be + * prepended and appended to each of the {@code message}s indicating + * that the message is continued in the following log message or is a + * continuation of the previous log mesage. + */ + List split(LogRecord aRecord) { + // This method is public so it is testable. + LinkedList theList = new LinkedList(); + String message = aRecord.getMessage(); + if (null == message || message.length() <= maxLogMessageLength) { + theList.add(aRecord); + return theList; + } + String remaining = message; + while (remaining.length() > 0) { + String nextMessage; + if (remaining.length() <= maxLogMessageLength) { + nextMessage = remaining; + remaining = ""; + } else { + int cutLength = logCutLength; + boolean cutAtNewline = false; + // Try to cut the string at a friendly point + int friendlyCutLength = remaining.lastIndexOf('\n', logCutLength); + // But only if that yields a message of reasonable length + if (friendlyCutLength > logCutLengthDiv10) { + cutLength = friendlyCutLength; + cutAtNewline = true; + } + nextMessage = remaining.substring(0, cutLength) + LOG_CONTINUATION_SUFFIX; + remaining = remaining.substring(cutLength + (cutAtNewline ? 1 : 0)); + // Only prepend the continuation prefix if doing so would not push + // the length of the next message over the limit. + if (remaining.length() > maxLogMessageLength + || remaining.length() + LOG_CONTINUATION_PREFIX_LENGTH <= maxLogMessageLength) { + remaining = LOG_CONTINUATION_PREFIX + remaining; + } + } + theList.add(new LogRecord(aRecord, nextMessage)); + } + return theList; + } + + /** + * Sets the stopwatch used for time based flushing. + * + * This method is not simply visible for testing, it only exists for testing. + * + * @param stopwatch The {@link Stopwatch} instance to use. + */ + void setStopwatch(Stopwatch stopwatch) { + this.stopwatch = stopwatch; + } + + /** + * Get the max length of an individual log message. + * + * This method is not simply visible for testing, it only exists for testing. + */ + int getMaxLogMessageLength() { + return maxLogMessageLength; + } + + /** + * Get the maximum number of log bytes that can be sent at a single time. + * + * This code is not simply visible for testing, it only exists for testing. + */ + long getByteCountBeforeFlushing() { + return maxBytesToFlush; + } +} diff --git a/appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java b/appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java similarity index 51% rename from appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java rename to appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java index 4ab3fc9..0fd07a7 100644 --- a/appengine-java-logging/src/main/java/com/google/apphosting/logging/CloudLoggingFileHandler.java +++ b/appengine-managed-runtime/src/main/java/com/google/apphosting/vmruntime/VmRuntimeFileLogHandler.java @@ -14,45 +14,44 @@ * limitations under the License. */ -package com.google.apphosting.logging; +package com.google.apphosting.vmruntime; + +import com.google.apphosting.logging.JsonFormatter; 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; /** - * 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. + * {@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. + * */ -public class CloudLoggingFileHandler extends FileHandler implements SystemLogger { +public class VmRuntimeFileLogHandler extends FileHandler { + // 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 = - CloudLoggingFileHandler.class.getName() + ".pattern"; + "com.google.apphosting.vmruntime.VmRuntimeFileLogHandler.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 DEFAULT_LOG_PATTERN = "app.%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 = getConfigInt("limit", 100 * 1024 * 1024); - private static final int LOG_MAX_FILES = getConfigInt("count", 3); + 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"; - public CloudLoggingFileHandler() throws IOException { - super(fileLogPattern(), LOG_PER_FILE_SIZE, LOG_MAX_FILES, true); + private VmRuntimeFileLogHandler() throws IOException { + super(fileLogPattern(), LOG_MAX_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. @@ -73,18 +72,34 @@ private static String fileLogPattern() { return directory + "/" + DEFAULT_LOG_PATTERN; } - @Override - public void configure() throws IOException { + /** + * Initialize the {@code VmRuntimeFileLogHandler} by installing it on the root logger. + */ + public static void init() throws IOException { + reloadLoggingProperties(LogManager.getLogManager()); Logger rootLogger = Logger.getLogger(""); - - // Look for the expected Handlers for (Handler handler : rootLogger.getHandlers()) { - if (handler instanceof CloudLoggingFileHandler) { - // Nothing else to do, return - return; + if (handler instanceof VmRuntimeFileLogHandler) { + return; // Already installed. } } + rootLogger.addHandler(new VmRuntimeFileLogHandler()); + } - rootLogger.addHandler(new CloudLoggingFileHandler()); + /** + * 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()); + } } } 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 deleted file mode 100644 index 9187909..0000000 --- a/appengine-managed-runtime/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger +++ /dev/null @@ -1 +0,0 @@ -com.google.apphosting.logging.CloudLoggingFileHandler diff --git a/jetty9-base/pom.xml b/jetty9-base/pom.xml index b76027e..5cdd3c3 100644 --- a/jetty9-base/pom.xml +++ b/jetty9-base/pom.xml @@ -52,9 +52,6 @@ - - ${project.basedir}/src/main/resources - ${project.build.directory}/jetty-base false diff --git a/jetty9-base/src/main/jetty-base/etc/gae.xml b/jetty9-base/src/main/jetty-base/etc/gae.xml index ccca81b..8f88e3f 100644 --- a/jetty9-base/src/main/jetty-base/etc/gae.xml +++ b/jetty9-base/src/main/jetty-base/etc/gae.xml @@ -57,7 +57,10 @@ - + + /request.yyyy_mm_dd.log + 2 + true true GMT true diff --git a/jetty9-compat-base/pom.xml b/jetty9-compat-base/pom.xml index 19706a0..cf85a9a 100644 --- a/jetty9-compat-base/pom.xml +++ b/jetty9-compat-base/pom.xml @@ -140,9 +140,6 @@ - - ${project.basedir}/src/main/resources - ${project.build.directory}/jetty-base false diff --git a/jetty9-compat-base/src/main/assembly/assembly.xml b/jetty9-compat-base/src/main/assembly/assembly.xml index 88a4d82..e2578fe 100644 --- a/jetty9-compat-base/src/main/assembly/assembly.xml +++ b/jetty9-compat-base/src/main/assembly/assembly.xml @@ -31,7 +31,6 @@ **/META-INF/** - logs/** 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 deleted file mode 100644 index 678e0dd..0000000 --- a/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/RequestLoggerHandler.java +++ /dev/null @@ -1,90 +0,0 @@ -package com.google.apphosting.vmruntime.jetty9; - -import com.google.apphosting.logging.SystemLogger; - -import java.io.IOException; -import java.util.logging.FileHandler; -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; - -/** - * The {@link java.util.logging.Handler} is 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 - public String format(LogRecord record) { - // We don't expand the message, or use the ResourceBundle stuff for this formatter. - return record.getMessage(); - } - } - - 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 = 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); - - String pattern = System.getProperty(LOG_PATTERN_CONFIG_PROPERTY); - if (pattern != null) { - if (pattern.startsWith("/")) { - return pattern; - } - return directory + "/" + pattern; - } - - return directory + "/" + DEFAULT_LOG_PATTERN; - } - - @Override - public void configure() throws IOException { - // This name is logger name that the Sfl4jRequestLog emits events to - Logger logger = Logger.getLogger("org.eclipse.jetty.server.RequestLog"); - logger.setLevel(Level.INFO); - - // Ensure handler is present - // Look for the expected Handlers - for (Handler handler : logger.getHandlers()) { - if (handler instanceof RequestLoggerHandler) { - // Nothing else to do, return - return; - } - } - - logger.addHandler(new RequestLoggerHandler()); - } -} diff --git a/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/VmRuntimeWebAppContext.java b/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/VmRuntimeWebAppContext.java index 8ca3c5c..a4bac17 100644 --- a/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/VmRuntimeWebAppContext.java +++ b/jetty9-compat-base/src/main/java/com/google/apphosting/vmruntime/jetty9/VmRuntimeWebAppContext.java @@ -21,7 +21,6 @@ import com.google.appengine.api.memcache.MemcacheSerialization; import com.google.appengine.spi.ServiceFactoryFactory; import com.google.apphosting.api.ApiProxy; -import com.google.apphosting.logging.CoreLogging; import com.google.apphosting.logging.LogContext; import com.google.apphosting.runtime.DatastoreSessionStore; import com.google.apphosting.runtime.DeferredDatastoreSessionStore; @@ -40,6 +39,7 @@ import com.google.apphosting.vmruntime.VmEnvironmentFactory; import com.google.apphosting.vmruntime.VmMetadataCache; import com.google.apphosting.vmruntime.VmRequestUtils; +import com.google.apphosting.vmruntime.VmRuntimeFileLogHandler; import com.google.apphosting.vmruntime.VmRuntimeUtils; import com.google.apphosting.vmruntime.VmTimer; @@ -324,12 +324,11 @@ public void init(String appengineWebXmlFile) throws AppEngineConfigException, IO appEngineWebXml = appEngineWebXmlReader.readAppEngineWebXml(); } VmRuntimeUtils.installSystemProperties(defaultEnvironment, appEngineWebXml); - - String logConfig = System.getProperty(CoreLogging.JAVA_UTIL_LOGGING_CONFIG_PROPERTY); + String logConfig = System.getProperty("java.util.logging.config.file"); if (logConfig != null && logConfig.startsWith("WEB-INF/")) { - logConfig = URIUtil.addPaths(appDir, logConfig); + System.setProperty("java.util.logging.config.file", URIUtil.addPaths(appDir, logConfig)); } - CoreLogging.init(logConfig); + VmRuntimeFileLogHandler.init(); if (appEngineWebXml == null) { // No need to configure the session manager. diff --git a/jetty9-compat-base/src/main/jetty-base/etc/gae.xml b/jetty9-compat-base/src/main/jetty-base/etc/gae.xml index cacb1ae..c2265e0 100644 --- a/jetty9-compat-base/src/main/jetty-base/etc/gae.xml +++ b/jetty9-compat-base/src/main/jetty-base/etc/gae.xml @@ -88,14 +88,17 @@ - - - true - GMT - true - true - - + + + /request.yyyy_mm_dd.log + 2 + true + true + GMT + true + true + + diff --git a/jetty9-compat-base/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger b/jetty9-compat-base/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger deleted file mode 100644 index 07df7b2..0000000 --- a/jetty9-compat-base/src/main/resources/META-INF/services/com.google.apphosting.logging.SystemLogger +++ /dev/null @@ -1 +0,0 @@ -com.google.apphosting.vmruntime.jetty9.RequestLoggerHandler \ No newline at end of file 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 82b932f..88fae47 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 @@ -16,11 +16,11 @@ package com.google.apphosting.vmruntime.jetty9; -import static com.google.apphosting.logging.CoreLogging.JAVA_UTIL_LOGGING_CONFIG_PROPERTY; +import static com.google.apphosting.vmruntime.VmRuntimeFileLogHandler.JAVA_UTIL_LOGGING_CONFIG_PROPERTY; import static com.google.apphosting.vmruntime.jetty9.VmRuntimeTestBase.JETTY_HOME_PATTERN; import com.google.apphosting.jetty9.GoogleRequestCustomizer; -import com.google.apphosting.logging.CloudLoggingFileHandler; +import com.google.apphosting.vmruntime.VmRuntimeFileLogHandler; import org.eclipse.jetty.apache.jsp.JettyJasperInitializer; import org.eclipse.jetty.io.MappedByteBufferPool; @@ -120,14 +120,9 @@ public void doStart() throws Exception { Assert.assertTrue(target.isDirectory()); Assert.assertTrue(jettyBaseFile.isDirectory()); logs = new File(target, "logs"); - if (!logs.exists()) { - logs.mkdirs(); - /* Note: due to java.util.logging file locks, you cannot: - * - delete the log directory or - * - delete all of its contents or - * - or perform a deleteOnExit() successfully - */ - } + logs.delete(); + logs.mkdirs(); + logs.deleteOnExit(); // Set GAE SystemProperties setSystemProperties(logs); @@ -264,10 +259,8 @@ public void run() { * Sets the system properties expected by jetty.xml. */ protected void setSystemProperties(File logs) throws IOException { - 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"); + String logFilePattern = logs.getAbsolutePath() + "/log.%g"; + System.setProperty(VmRuntimeFileLogHandler.LOG_PATTERN_CONFIG_PROPERTY, logFilePattern); System.setProperty("jetty.appengineport", String.valueOf(findAvailablePort())); System.setProperty("jetty.appenginehost", "localhost"); System.setProperty("jetty.appengine.forwarded", "true"); 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 5819ead..be97a82 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 @@ -17,7 +17,6 @@ package com.google.apphosting.vmruntime.jetty9; import static org.hamcrest.Matchers.equalTo; -import static org.hamcrest.Matchers.notNullValue; import static org.junit.Assert.assertThat; import com.google.gson.Gson; @@ -28,73 +27,19 @@ 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 logDir the directory where log files are kept, tracked by - * the {@link JettyRunner} - * @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(); HttpClient httpClient = new HttpClient(); httpClient.getHttpConnectionManager().getParams().setConnectionTimeout(30000); - String query = "nano=" + Long.toHexString(System.nanoTime()); - GetMethod get = new GetMethod(createUrl("/testLogging?" + query).toString()); + String query = Long.toHexString(System.nanoTime()); + GetMethod get = new GetMethod(createUrl("/testLogging?nano=" + query).toString()); int httpCode = httpClient.executeMethod(get); assertThat(httpCode, equalTo(200)); @@ -102,36 +47,34 @@ public void testGet() throws Exception { String body = get.getResponseBodyAsString(); assertThat(body, equalTo("FINE\nSEVERE\nfalse\n\n")); - File log = findLogFileThatContains(runner.getLogDir(),query); + File logs = runner.getLogDir(); + File log = new File(logs, "log.0"); assertTrue(log.exists()); // Look for the log entry with our query string - try (FileInputStream in = new FileInputStream(log); - InputStreamReader reader = new InputStreamReader(in, StandardCharsets.UTF_8); - BufferedReader buf = new BufferedReader(reader)) { + try (BufferedReader in = + new BufferedReader( + new InputStreamReader(new FileInputStream(log), StandardCharsets.ISO_8859_1))) { String line; - while ((line = buf.readLine()) != null) { + while ((line = in.readLine()) != null) { if (line.contains(query)) { break; } } JsonData data = new Gson().fromJson(line, JsonData.class); - assertThat("Parsed Data", data, notNullValue()); assertThat(data.severity, equalTo("INFO")); - assertThat(data.message, org.hamcrest.Matchers.containsString("LogTest Hello " + query)); + assertThat(data.message, org.hamcrest.Matchers.containsString("LogTest Hello nano=" + query)); - line = buf.readLine(); + line = in.readLine(); data = new Gson().fromJson(line, JsonData.class); - assertThat("Parsed Data", data, notNullValue()); assertThat(data.severity, equalTo("ERROR")); - assertThat(data.message, - org.hamcrest.Matchers.containsString("LoggingServlet doGet: not null")); + assertThat( + data.message, org.hamcrest.Matchers.containsString("LoggingServlet doGet: not null")); - line = buf.readLine(); + line = in.readLine(); data = new Gson().fromJson(line, JsonData.class); - assertThat("Parsed Data", data, notNullValue()); assertThat(data.severity, equalTo("ERROR")); assertThat(data.message, org.hamcrest.Matchers.containsString("LoggingServlet doGet: null")); } @@ -144,7 +87,6 @@ public static class LogTimestamp { public long nanos; } - public LogTimestamp timestamp; public String severity; public String thread; diff --git a/pom.xml b/pom.xml index df41792..b43e8c7 100644 --- a/pom.xml +++ b/pom.xml @@ -95,13 +95,6 @@ 2.3.1 - - org.hamcrest - hamcrest-library - 1.3 - test - - junit junit