001    /**
002     * Licensed to the Apache Software Foundation (ASF) under one
003     * or more contributor license agreements.  See the NOTICE file
004     * distributed with this work for additional information
005     * regarding copyright ownership.  The ASF licenses this file
006     * to you under the Apache License, Version 2.0 (the
007     * "License"); you may not use this file except in compliance
008     * with the License.  You may obtain a copy of the License at
009     *
010     *     http://www.apache.org/licenses/LICENSE-2.0
011     *
012     * Unless required by applicable law or agreed to in writing, software
013     * distributed under the License is distributed on an "AS IS" BASIS,
014     * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
015     * See the License for the specific language governing permissions and
016     * limitations under the License.
017     */
018    
019    
020    package org.apache.hadoop.log;
021    
022    import org.apache.log4j.Layout;
023    import org.apache.log4j.helpers.ISO8601DateFormat;
024    import org.apache.log4j.spi.LoggingEvent;
025    import org.apache.log4j.spi.ThrowableInformation;
026    import org.codehaus.jackson.JsonFactory;
027    import org.codehaus.jackson.JsonGenerator;
028    import org.codehaus.jackson.JsonNode;
029    import org.codehaus.jackson.map.MappingJsonFactory;
030    import org.codehaus.jackson.map.ObjectMapper;
031    import org.codehaus.jackson.node.ContainerNode;
032    
033    import java.io.IOException;
034    import java.io.StringWriter;
035    import java.io.Writer;
036    import java.text.DateFormat;
037    import java.util.Date;
038    
039    /**
040     * This offers a log layout for JSON, with some test entry points. It's purpose is
041     * to allow Log4J to generate events that are easy for other programs to parse, but which are somewhat
042     * human-readable.
043     *
044     * Some features.
045     *
046     * <ol>
047     *     <li>Every event is a standalone JSON clause</li>
048     *     <li>Time is published as a time_t event since 1/1/1970
049     *      -this is the fastest to generate.</li>
050     *     <li>An ISO date is generated, but this is cached and will only be accurate to within a second</li>
051     *     <li>the stack trace is included as an array</li>
052     * </ol>
053     *
054     * A simple log event will resemble the following
055     * <pre>
056     *     {"name":"test","time":1318429136789,"date":"2011-10-12 15:18:56,789","level":"INFO","thread":"main","message":"test message"}
057     * </pre>
058     *
059     * An event with an error will contain data similar to that below (which has been reformatted to be multi-line).
060     *
061     * <pre>
062     *     {
063     *     "name":"testException",
064     *     "time":1318429136789,
065     *     "date":"2011-10-12 15:18:56,789",
066     *     "level":"INFO",
067     *     "thread":"quoted\"",
068     *     "message":"new line\n and {}",
069     *     "exceptionclass":"java.net.NoRouteToHostException",
070     *     "stack":[
071     *         "java.net.NoRouteToHostException: that box caught fire 3 years ago",
072     *         "\tat org.apache.hadoop.log.TestLog4Json.testException(TestLog4Json.java:49)",
073     *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)",
074     *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)",
075     *         "\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)",
076     *         "\tat java.lang.reflect.Method.invoke(Method.java:597)",
077     *         "\tat junit.framework.TestCase.runTest(TestCase.java:168)",
078     *         "\tat junit.framework.TestCase.runBare(TestCase.java:134)",
079     *         "\tat junit.framework.TestResult$1.protect(TestResult.java:110)",
080     *         "\tat junit.framework.TestResult.runProtected(TestResult.java:128)",
081     *         "\tat junit.framework.TestResult.run(TestResult.java:113)",
082     *         "\tat junit.framework.TestCase.run(TestCase.java:124)",
083     *         "\tat junit.framework.TestSuite.runTest(TestSuite.java:232)",
084     *         "\tat junit.framework.TestSuite.run(TestSuite.java:227)",
085     *         "\tat org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)",
086     *         "\tat org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:59)",
087     *         "\tat org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:120)",
088     *         "\tat org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:145)",
089     *         "\tat org.apache.maven.surefire.Surefire.run(Surefire.java:104)",
090     *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)",
091     *         "\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)",
092     *         "\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)",
093     *         "\tat java.lang.reflect.Method.invoke(Method.java:597)",
094     *         "\tat org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:290)",
095     *         "\tat org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:1017)"
096     *         ]
097     *     }
098     * </pre>
099     */
100    public class Log4Json extends Layout {
101    
102      /**
103       * Jackson factories are thread safe when constructing parsers and generators.
104       * They are not thread safe in configure methods; if there is to be any
105       * configuration it must be done in a static intializer block.
106       */
107      private static final JsonFactory factory = new MappingJsonFactory();
108      public static final String DATE = "date";
109      public static final String EXCEPTION_CLASS = "exceptionclass";
110      public static final String LEVEL = "level";
111      public static final String MESSAGE = "message";
112      public static final String NAME = "name";
113      public static final String STACK = "stack";
114      public static final String THREAD = "thread";
115      public static final String TIME = "time";
116      public static final String JSON_TYPE = "application/json";
117    
118      private final DateFormat dateFormat;
119    
120      public Log4Json() {
121        dateFormat = new ISO8601DateFormat();
122      }
123    
124    
125      /**
126       * @return the mime type of JSON
127       */
128      @Override
129      public String getContentType() {
130        return JSON_TYPE;
131      }
132    
133      @Override
134      public String format(LoggingEvent event) {
135        try {
136          return toJson(event);
137        } catch (IOException e) {
138          //this really should not happen, and rather than throw an exception
139          //which may hide the real problem, the log class is printed
140          //in JSON format. The classname is used to ensure valid JSON is 
141          //returned without playing escaping games
142          return "{ \"logfailure\":\"" + e.getClass().toString() + "\"}";
143        }
144      }
145    
146      /**
147       * Convert an event to JSON
148       *
149       * @param event the event -must not be null
150       * @return a string value
151       * @throws IOException on problems generating the JSON
152       */
153      public String toJson(LoggingEvent event) throws IOException {
154        StringWriter writer = new StringWriter();
155        toJson(writer, event);
156        return writer.toString();
157      }
158    
159      /**
160       * Convert an event to JSON
161       *
162       * @param writer the destination writer
163       * @param event the event -must not be null
164       * @return the writer
165       * @throws IOException on problems generating the JSON
166       */
167      public Writer toJson(final Writer writer, final LoggingEvent event)
168          throws IOException {
169        ThrowableInformation ti = event.getThrowableInformation();
170        toJson(writer,
171               event.getLoggerName(),
172               event.getTimeStamp(),
173               event.getLevel().toString(),
174               event.getThreadName(),
175               event.getRenderedMessage(),
176               ti);
177        return writer;
178      }
179    
180      /**
181       * Build a JSON entry from the parameters. This is public for testing.
182       *
183       * @param writer destination
184       * @param loggerName logger name
185       * @param timeStamp time_t value
186       * @param level level string
187       * @param threadName name of the thread
188       * @param message rendered message
189       * @param ti nullable thrown information
190       * @return the writer
191       * @throws IOException on any problem
192       */
193      public Writer toJson(final Writer writer,
194                           final String loggerName,
195                           final long timeStamp,
196                           final String level,
197                           final String threadName,
198                           final String message,
199                           final ThrowableInformation ti) throws IOException {
200        JsonGenerator json = factory.createJsonGenerator(writer);
201        json.writeStartObject();
202        json.writeStringField(NAME, loggerName);
203        json.writeNumberField(TIME, timeStamp);
204        Date date = new Date(timeStamp);
205        json.writeStringField(DATE, dateFormat.format(date));
206        json.writeStringField(LEVEL, level);
207        json.writeStringField(THREAD, threadName);
208        json.writeStringField(MESSAGE, message);
209        if (ti != null) {
210          //there is some throwable info, but if the log event has been sent over the wire,
211          //there may not be a throwable inside it, just a summary.
212          Throwable thrown = ti.getThrowable();
213          String eclass = (thrown != null) ?
214              thrown.getClass().getName()
215              : "";
216          json.writeStringField(EXCEPTION_CLASS, eclass);
217          String[] stackTrace = ti.getThrowableStrRep();
218          json.writeArrayFieldStart(STACK);
219          for (String row : stackTrace) {
220            json.writeString(row);
221          }
222          json.writeEndArray();
223        }
224        json.writeEndObject();
225        json.flush();
226        json.close();
227        return writer;
228      }
229    
230      /**
231       * This appender does not ignore throwables
232       *
233       * @return false, always
234       */
235      @Override
236      public boolean ignoresThrowable() {
237        return false;
238      }
239    
240      /**
241       * Do nothing
242       */
243      @Override
244      public void activateOptions() {
245      }
246    
247      /**
248       * For use in tests
249       *
250       * @param json incoming JSON to parse
251       * @return a node tree
252       * @throws IOException on any parsing problems
253       */
254      public static ContainerNode parse(String json) throws IOException {
255        ObjectMapper mapper = new ObjectMapper(factory);
256        JsonNode jsonNode = mapper.readTree(json);
257        if (!(jsonNode instanceof ContainerNode)) {
258          throw new IOException("Wrong JSON data: " + json);
259        }
260        return (ContainerNode) jsonNode;
261      }
262    }