You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-commits@hadoop.apache.org by st...@apache.org on 2011/10/14 12:53:01 UTC
svn commit: r1183292 - in
/hadoop/common/trunk/hadoop-common-project/hadoop-common: CHANGES.txt
src/main/java/org/apache/hadoop/log/Log4Json.java
src/test/java/org/apache/hadoop/log/TestLog4Json.java
Author: stevel
Date: Fri Oct 14 10:53:01 2011
New Revision: 1183292
URL: http://svn.apache.org/viewvc?rev=1183292&view=rev
Log:
HADOOP-7705
Added:
hadoop/common/trunk/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java
hadoop/common/trunk/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java
Modified:
hadoop/common/trunk/hadoop-common-project/hadoop-common/CHANGES.txt
Modified: hadoop/common/trunk/hadoop-common-project/hadoop-common/CHANGES.txt
URL: http://svn.apache.org/viewvc/hadoop/common/trunk/hadoop-common-project/hadoop-common/CHANGES.txt?rev=1183292&r1=1183291&r2=1183292&view=diff
==============================================================================
--- hadoop/common/trunk/hadoop-common-project/hadoop-common/CHANGES.txt (original)
+++ hadoop/common/trunk/hadoop-common-project/hadoop-common/CHANGES.txt Fri Oct 14 10:53:01 2011
@@ -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
Added: hadoop/common/trunk/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java
URL: http://svn.apache.org/viewvc/hadoop/common/trunk/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java?rev=1183292&view=auto
==============================================================================
--- hadoop/common/trunk/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java (added)
+++ hadoop/common/trunk/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/log/Log4Json.java Fri Oct 14 10:53:01 2011
@@ -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.
+ *
+ * <ol>
+ * <li>Every event is a standalone JSON clause</li>
+ * <li>Time is published as a time_t event since 1/1/1970
+ * -this is the fastest to generate.</li>
+ * <li>An ISO date is generated, but this is cached and will only be accurate to within a second</li>
+ * <li>the stack trace is included as an array</li>
+ * </ol>
+ *
+ * A simple log event will resemble the following
+ * <pre>
+ * {"name":"test","time":1318429136789,"date":"2011-10-12 15:18:56,789","level":"INFO","thread":"main","message":"test message"}
+ * </pre>
+ *
+ * An event with an error will contain data similar to that below (which has been reformatted to be multi-line).
+ *
+ * <pre>
+ * {
+ * "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)"
+ * ]
+ * }
+ * </pre>
+ */
+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;
+ }
+}
Added: hadoop/common/trunk/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java
URL: http://svn.apache.org/viewvc/hadoop/common/trunk/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java?rev=1183292&view=auto
==============================================================================
--- hadoop/common/trunk/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java (added)
+++ hadoop/common/trunk/hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/log/TestLog4Json.java Fri Oct 14 10:53:01 2011
@@ -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() {
+ }
+ }
+}