diff --git a/hadoop-common-project/hadoop-common/CHANGES.txt b/hadoop-common-project/hadoop-common/CHANGES.txt index 66e6d53933..bbc7f771d9 100644 --- a/hadoop-common-project/hadoop-common/CHANGES.txt +++ b/hadoop-common-project/hadoop-common/CHANGES.txt @@ -475,6 +475,9 @@ Release 0.23.0 - Unreleased HADOOP-7709. Running a set of methods in a Single Test Class. (Jonathan Eagles via mahadev) + HADOOP-7705. Add a log4j back end that can push out JSON data, + one per line. (stevel) + OPTIMIZATIONS HADOOP-7333. Performance improvement in PureJavaCrc32. (Eric Caspole diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java new file mode 100644 index 0000000000..d998fbc327 --- /dev/null +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java @@ -0,0 +1,262 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you 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 org.apache.hadoop.log; + +import org.apache.log4j.Layout; +import org.apache.log4j.helpers.ISO8601DateFormat; +import org.apache.log4j.spi.LoggingEvent; +import org.apache.log4j.spi.ThrowableInformation; +import org.codehaus.jackson.JsonFactory; +import org.codehaus.jackson.JsonGenerator; +import org.codehaus.jackson.JsonNode; +import org.codehaus.jackson.map.MappingJsonFactory; +import org.codehaus.jackson.map.ObjectMapper; +import org.codehaus.jackson.node.ContainerNode; + +import java.io.IOException; +import java.io.StringWriter; +import java.io.Writer; +import java.text.DateFormat; +import java.util.Date; + +/** + * This offers a log layout for JSON, with some test entry points. It's purpose is + * to allow Log4J to generate events that are easy for other programs to parse, but which are somewhat + * human-readable. + * + * Some features. + * + *
    + *
  1. Every event is a standalone JSON clause
  2. + *
  3. Time is published as a time_t event since 1/1/1970 + * -this is the fastest to generate.
  4. + *
  5. An ISO date is generated, but this is cached and will only be accurate to within a second
  6. + *
  7. the stack trace is included as an array
  8. + *
+ * + * A simple log event will resemble the following + *
+ *     {"name":"test","time":1318429136789,"date":"2011-10-12 15:18:56,789","level":"INFO","thread":"main","message":"test message"}
+ * 
+ * + * An event with an error will contain data similar to that below (which has been reformatted to be multi-line). + * + *
+ *     {
+ *     "name":"testException",
+ *     "time":1318429136789,
+ *     "date":"2011-10-12 15:18:56,789",
+ *     "level":"INFO",
+ *     "thread":"quoted\"",
+ *     "message":"new line\n and {}",
+ *     "exceptionclass":"java.net.NoRouteToHostException",
+ *     "stack":[
+ *         "java.net.NoRouteToHostException: that box caught fire 3 years ago",
+ *         "\tat org.apache.hadoop.log.TestLog4Json.testException(TestLog4Json.java:49)",
+ *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)",
+ *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)",
+ *         "\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)",
+ *         "\tat java.lang.reflect.Method.invoke(Method.java:597)",
+ *         "\tat junit.framework.TestCase.runTest(TestCase.java:168)",
+ *         "\tat junit.framework.TestCase.runBare(TestCase.java:134)",
+ *         "\tat junit.framework.TestResult$1.protect(TestResult.java:110)",
+ *         "\tat junit.framework.TestResult.runProtected(TestResult.java:128)",
+ *         "\tat junit.framework.TestResult.run(TestResult.java:113)",
+ *         "\tat junit.framework.TestCase.run(TestCase.java:124)",
+ *         "\tat junit.framework.TestSuite.runTest(TestSuite.java:232)",
+ *         "\tat junit.framework.TestSuite.run(TestSuite.java:227)",
+ *         "\tat org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)",
+ *         "\tat org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:59)",
+ *         "\tat org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:120)",
+ *         "\tat org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:145)",
+ *         "\tat org.apache.maven.surefire.Surefire.run(Surefire.java:104)",
+ *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)",
+ *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)",
+ *         "\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)",
+ *         "\tat java.lang.reflect.Method.invoke(Method.java:597)",
+ *         "\tat org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:290)",
+ *         "\tat org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:1017)"
+ *         ]
+ *     }
+ * 
+ */ +public class Log4Json extends Layout { + + /** + * Jackson factories are thread safe when constructing parsers and generators. + * They are not thread safe in configure methods; if there is to be any + * configuration it must be done in a static intializer block. + */ + private static final JsonFactory factory = new MappingJsonFactory(); + public static final String DATE = "date"; + public static final String EXCEPTION_CLASS = "exceptionclass"; + public static final String LEVEL = "level"; + public static final String MESSAGE = "message"; + public static final String NAME = "name"; + public static final String STACK = "stack"; + public static final String THREAD = "thread"; + public static final String TIME = "time"; + public static final String JSON_TYPE = "application/json"; + + private final DateFormat dateFormat; + + public Log4Json() { + dateFormat = new ISO8601DateFormat(); + } + + + /** + * @return the mime type of JSON + */ + @Override + public String getContentType() { + return JSON_TYPE; + } + + @Override + public String format(LoggingEvent event) { + try { + return toJson(event); + } catch (IOException e) { + //this really should not happen, and rather than throw an exception + //which may hide the real problem, the log class is printed + //in JSON format. The classname is used to ensure valid JSON is + //returned without playing escaping games + return "{ \"logfailure\":\"" + e.getClass().toString() + "\"}"; + } + } + + /** + * Convert an event to JSON + * + * @param event the event -must not be null + * @return a string value + * @throws IOException on problems generating the JSON + */ + public String toJson(LoggingEvent event) throws IOException { + StringWriter writer = new StringWriter(); + toJson(writer, event); + return writer.toString(); + } + + /** + * Convert an event to JSON + * + * @param writer the destination writer + * @param event the event -must not be null + * @return the writer + * @throws IOException on problems generating the JSON + */ + public Writer toJson(final Writer writer, final LoggingEvent event) + throws IOException { + ThrowableInformation ti = event.getThrowableInformation(); + toJson(writer, + event.getLoggerName(), + event.getTimeStamp(), + event.getLevel().toString(), + event.getThreadName(), + event.getRenderedMessage(), + ti); + return writer; + } + + /** + * Build a JSON entry from the parameters. This is public for testing. + * + * @param writer destination + * @param loggerName logger name + * @param timeStamp time_t value + * @param level level string + * @param threadName name of the thread + * @param message rendered message + * @param ti nullable thrown information + * @return the writer + * @throws IOException on any problem + */ + public Writer toJson(final Writer writer, + final String loggerName, + final long timeStamp, + final String level, + final String threadName, + final String message, + final ThrowableInformation ti) throws IOException { + JsonGenerator json = factory.createJsonGenerator(writer); + json.writeStartObject(); + json.writeStringField(NAME, loggerName); + json.writeNumberField(TIME, timeStamp); + Date date = new Date(timeStamp); + json.writeStringField(DATE, dateFormat.format(date)); + json.writeStringField(LEVEL, level); + json.writeStringField(THREAD, threadName); + json.writeStringField(MESSAGE, message); + if (ti != null) { + //there is some throwable info, but if the log event has been sent over the wire, + //there may not be a throwable inside it, just a summary. + Throwable thrown = ti.getThrowable(); + String eclass = (thrown != null) ? + thrown.getClass().getName() + : ""; + json.writeStringField(EXCEPTION_CLASS, eclass); + String[] stackTrace = ti.getThrowableStrRep(); + json.writeArrayFieldStart(STACK); + for (String row : stackTrace) { + json.writeString(row); + } + json.writeEndArray(); + } + json.writeEndObject(); + json.flush(); + json.close(); + return writer; + } + + /** + * This appender does not ignore throwables + * + * @return false, always + */ + @Override + public boolean ignoresThrowable() { + return false; + } + + /** + * Do nothing + */ + @Override + public void activateOptions() { + } + + /** + * For use in tests + * + * @param json incoming JSON to parse + * @return a node tree + * @throws IOException on any parsing problems + */ + public static ContainerNode parse(String json) throws IOException { + ObjectMapper mapper = new ObjectMapper(factory); + JsonNode jsonNode = mapper.readTree(json); + if (!(jsonNode instanceof ContainerNode)) { + throw new IOException("Wrong JSON data: " + json); + } + return (ContainerNode) jsonNode; + } +} diff --git a/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java b/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java new file mode 100644 index 0000000000..8c3ddd51ac --- /dev/null +++ b/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java @@ -0,0 +1,270 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you 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 org.apache.hadoop.log; + +import junit.framework.TestCase; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; +import org.apache.log4j.Appender; +import org.apache.log4j.Category; +import org.apache.log4j.Level; +import org.apache.log4j.Logger; +import org.apache.log4j.WriterAppender; +import org.apache.log4j.spi.HierarchyEventListener; +import org.apache.log4j.spi.LoggerFactory; +import org.apache.log4j.spi.LoggerRepository; +import org.apache.log4j.spi.ThrowableInformation; +import org.codehaus.jackson.JsonFactory; +import org.codehaus.jackson.JsonNode; +import org.codehaus.jackson.map.MappingJsonFactory; +import org.codehaus.jackson.node.ContainerNode; +import org.junit.Test; + +import java.io.IOException; +import java.io.StringWriter; +import java.io.Writer; +import java.net.NoRouteToHostException; +import java.util.Enumeration; +import java.util.Vector; + +public class TestLog4Json extends TestCase { + + private static final Log LOG = LogFactory.getLog(TestLog4Json.class); + private static final JsonFactory factory = new MappingJsonFactory(); + + @Test + public void testConstruction() throws Throwable { + Log4Json l4j = new Log4Json(); + String outcome = l4j.toJson(new StringWriter(), + "name", 0, "DEBUG", "thread1", + "hello, world", null).toString(); + println("testConstruction", outcome); + } + + @Test + public void testException() throws Throwable { + Exception e = + new NoRouteToHostException("that box caught fire 3 years ago"); + ThrowableInformation ti = new ThrowableInformation(e); + Log4Json l4j = new Log4Json(); + long timeStamp = System.currentTimeMillis(); + String outcome = l4j.toJson(new StringWriter(), + "testException", + timeStamp, + "INFO", + "quoted\"", + "new line\n and {}", + ti) + .toString(); + println("testException", outcome); + } + + @Test + public void testNestedException() throws Throwable { + Exception e = + new NoRouteToHostException("that box caught fire 3 years ago"); + Exception ioe = new IOException("Datacenter problems", e); + ThrowableInformation ti = new ThrowableInformation(ioe); + Log4Json l4j = new Log4Json(); + long timeStamp = System.currentTimeMillis(); + String outcome = l4j.toJson(new StringWriter(), + "testNestedException", + timeStamp, + "INFO", + "quoted\"", + "new line\n and {}", + ti) + .toString(); + println("testNestedException", outcome); + ContainerNode rootNode = Log4Json.parse(outcome); + assertEntryEquals(rootNode, Log4Json.LEVEL, "INFO"); + assertEntryEquals(rootNode, Log4Json.NAME, "testNestedException"); + assertEntryEquals(rootNode, Log4Json.TIME, timeStamp); + assertEntryEquals(rootNode, Log4Json.EXCEPTION_CLASS, + ioe.getClass().getName()); + JsonNode node = assertNodeContains(rootNode, Log4Json.STACK); + assertTrue("Not an array: " + node, node.isArray()); + node = assertNodeContains(rootNode, Log4Json.DATE); + assertTrue("Not a string: " + node, node.isTextual()); + //rather than try and make assertions about the format of the text + //message equalling another ISO date, this test asserts that the hypen + //and colon characters are in the string. + String dateText = node.getTextValue(); + assertTrue("No '-' in " + dateText, dateText.contains("-")); + assertTrue("No '-' in " + dateText, dateText.contains(":")); + + } + + + /** + * Create a log instance and and log to it + * @throws Throwable if it all goes wrong + */ + @Test + public void testLog() throws Throwable { + String message = "test message"; + Throwable throwable = null; + String json = logOut(message, throwable); + println("testLog", json); + } + + /** + * Create a log instance and and log to it + * @throws Throwable if it all goes wrong + */ + @Test + public void testLogExceptions() throws Throwable { + String message = "test message"; + Throwable inner = new IOException("Directory / not found"); + Throwable throwable = new IOException("startup failure", inner); + String json = logOut(message, throwable); + println("testLogExceptions", json); + } + + + void assertEntryEquals(ContainerNode rootNode, String key, String value) { + JsonNode node = assertNodeContains(rootNode, key); + assertEquals(value, node.getTextValue()); + } + + private JsonNode assertNodeContains(ContainerNode rootNode, String key) { + JsonNode node = rootNode.get(key); + if (node == null) { + fail("No entry of name \"" + key + "\" found in " + rootNode.toString()); + } + return node; + } + + void assertEntryEquals(ContainerNode rootNode, String key, long value) { + JsonNode node = assertNodeContains(rootNode, key); + assertEquals(value, node.getNumberValue()); + } + + /** + * Print out what's going on. The logging APIs aren't used and the text + * delimited for more details + * + * @param name name of operation + * @param text text to print + */ + private void println(String name, String text) { + System.out.println(name + ": #" + text + "#"); + } + + private String logOut(String message, Throwable throwable) { + StringWriter writer = new StringWriter(); + Logger logger = createLogger(writer); + logger.info(message, throwable); + //remove and close the appender + logger.removeAllAppenders(); + return writer.toString(); + } + + public Logger createLogger(Writer writer) { + TestLoggerRepository repo = new TestLoggerRepository(); + Logger logger = repo.getLogger("test"); + Log4Json layout = new Log4Json(); + WriterAppender appender = new WriterAppender(layout, writer); + logger.addAppender(appender); + return logger; + } + + /** + * This test logger avoids integrating with the main runtimes Logger hierarchy + * in ways the reader does not want to know. + */ + private static class TestLogger extends Logger { + private TestLogger(String name, LoggerRepository repo) { + super(name); + repository = repo; + setLevel(Level.INFO); + } + + } + + public static class TestLoggerRepository implements LoggerRepository { + @Override + public void addHierarchyEventListener(HierarchyEventListener listener) { + } + + @Override + public boolean isDisabled(int level) { + return false; + } + + @Override + public void setThreshold(Level level) { + } + + @Override + public void setThreshold(String val) { + } + + @Override + public void emitNoAppenderWarning(Category cat) { + } + + @Override + public Level getThreshold() { + return Level.ALL; + } + + @Override + public Logger getLogger(String name) { + return new TestLogger(name, this); + } + + @Override + public Logger getLogger(String name, LoggerFactory factory) { + return new TestLogger(name, this); + } + + @Override + public Logger getRootLogger() { + return new TestLogger("root", this); + } + + @Override + public Logger exists(String name) { + return null; + } + + @Override + public void shutdown() { + } + + @Override + public Enumeration getCurrentLoggers() { + return new Vector().elements(); + } + + @Override + public Enumeration getCurrentCategories() { + return new Vector().elements(); + } + + @Override + public void fireAddAppenderEvent(Category logger, Appender appender) { + } + + @Override + public void resetConfiguration() { + } + } +}