This is an automated email from the ASF dual-hosted git repository. rombert pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/sling-org-apache-sling-tracer.git
commit 76a34ef54c3dd31bb35b4053a32e03c5f23b0b31 Author: Chetan Mehrotra <[email protected]> AuthorDate: Wed Feb 10 05:52:44 2016 +0000 SLING-5459 - Recording of tracer logs Handle logs separately in recorded json git-svn-id: https://svn.apache.org/repos/asf/sling/trunk@1729531 13f79535-47bb-0310-9956-ffa450edef68 --- .../sling/tracer/internal/JSONRecording.java | 70 ++++++++++++++++++++++ .../sling/tracer/internal/TracerContext.java | 14 +++-- .../sling/tracer/internal/JSONRecordingTest.java | 30 ++++++++++ .../sling/tracer/internal/LogTracerTest.java | 40 +++++++++++++ 4 files changed, 148 insertions(+), 6 deletions(-) diff --git a/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java b/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java index 8980ff9..cf1cea3 100644 --- a/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java +++ b/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java @@ -20,6 +20,7 @@ package org.apache.sling.tracer.internal; import java.io.IOException; +import java.io.PrintWriter; import java.io.StringWriter; import java.io.Writer; import java.util.ArrayList; @@ -35,12 +36,14 @@ import org.apache.sling.commons.json.io.JSONWriter; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.slf4j.helpers.FormattingTuple; +import org.slf4j.helpers.MessageFormatter; class JSONRecording implements Recording { private static final Logger log = LoggerFactory.getLogger(JSONRecording.class); private final String method; private final String requestId; private final List<String> queries = new ArrayList<String>(); + private final List<LogEntry> logs = new ArrayList<LogEntry>(); private RequestProgressTracker tracker; private String json; @@ -66,6 +69,7 @@ class JSONRecording implements Recording { && params != null && params.length == 2) { queries.add((String) params[1]); } + logs.add(new LogEntry(level, logger, tuple)); } @Override @@ -83,6 +87,7 @@ class JSONRecording implements Recording { //not occupy memory tracker = null; queries.clear(); + logs.clear(); } } catch (JSONException e) { log.warn("Error occurred while converting the log data for request {} to JSON", requestId, e); @@ -113,7 +118,72 @@ class JSONRecording implements Recording { jw.value(q); } jw.endArray(); + + addJson(jw, "logs", logs); jw.endObject(); return sw.toString(); } + + private void addJson(JSONWriter jw, String name, List<? extends JsonEntry> entries) throws JSONException { + jw.key(name); + jw.array(); + for (JsonEntry je : entries) { + jw.object(); + je.toJson(jw); + jw.endObject(); + } + jw.endArray(); + } + + private interface JsonEntry { + void toJson(JSONWriter jw) throws JSONException; + } + + private static class LogEntry implements JsonEntry { + final Level level; + final String logger; + final FormattingTuple tuple; + + private LogEntry(Level level, String logger, FormattingTuple tuple) { + this.level = level != null ? level : Level.INFO; + this.logger = logger; + this.tuple = tuple; + } + + private static String toString(Object o) { + //Make use of Slf4j null safe toString support! + return MessageFormatter.format("{}", o).getMessage(); + } + + private static String getStackTraceAsString(Throwable throwable) { + StringWriter stringWriter = new StringWriter(); + throwable.printStackTrace(new PrintWriter(stringWriter)); + return stringWriter.toString(); + } + + @Override + public void toJson(JSONWriter jw) throws JSONException { + jw.key("level").value(level.levelStr); + jw.key("logger").value(logger); + jw.key("message").value(tuple.getMessage()); + + Object[] params = tuple.getArgArray(); + if (params != null) { + jw.key("params"); + jw.array(); + for (Object o : params) { + jw.value(toString(o)); + } + jw.endArray(); + } + + Throwable t = tuple.getThrowable(); + if (t != null) { + //Later we can look into using Logback Throwable handling + jw.key("exception").value(getStackTraceAsString(t)); + + } + } + } + } diff --git a/src/main/java/org/apache/sling/tracer/internal/TracerContext.java b/src/main/java/org/apache/sling/tracer/internal/TracerContext.java index 47615e9..bd12def 100644 --- a/src/main/java/org/apache/sling/tracer/internal/TracerContext.java +++ b/src/main/java/org/apache/sling/tracer/internal/TracerContext.java @@ -82,11 +82,13 @@ class TracerContext { } public boolean log(Level level, String logger, String format, Object[] params) { - FormattingTuple tuple; - + FormattingTuple tuple = null; if (QUERY_LOGGER.equals(logger) && params != null && params.length == 2) { - tuple = logQuery((String) params[1]); + if (logQuery((String) params[1])){ + //Get original log message + tuple = logWithLoggerName(logger, format, params); + } } else { tuple = logWithLoggerName(logger, format, params); } @@ -132,12 +134,12 @@ class TracerContext { return tuple; } - private FormattingTuple logQuery(String query) { + private boolean logQuery(String query) { if (ignorableQuery(query)) { - return null; + return false; } queryCount++; - return logWithLoggerName("JCR", " Query {}", query); + return true; } private boolean ignorableQuery(String msg) { diff --git a/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java b/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java index 159555e..82116fc 100644 --- a/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java +++ b/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java @@ -26,9 +26,12 @@ import javax.servlet.http.HttpServletRequest; import ch.qos.logback.classic.Level; import org.apache.sling.commons.json.JSONObject; import org.junit.Test; +import org.slf4j.helpers.FormattingTuple; import org.slf4j.helpers.MessageFormatter; import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNotNull; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.when; @@ -67,4 +70,31 @@ public class JSONRecordingTest { assertEquals(2, json.getJSONArray("requestProgressLogs").length()); } + @Test + public void logs() throws Exception{ + StringWriter sw = new StringWriter(); + JSONRecording r = new JSONRecording("abc", request); + + FormattingTuple tp1 = MessageFormatter.arrayFormat("{} is going", new Object[]{"Jack"}); + r.log(Level.INFO, "foo", tp1); + r.log(Level.WARN, "foo.bar", MessageFormatter.arrayFormat("Jill is going", null)); + r.log(Level.ERROR, "foo.bar", + MessageFormatter.arrayFormat("Jack and {} is going", new Object[]{"Jill" , new Exception()})); + + r.done(); + r.render(sw); + + JSONObject json = new JSONObject(sw.toString()); + assertEquals(3, json.getJSONArray("logs").length()); + + JSONObject l1 = json.getJSONArray("logs").getJSONObject(0); + assertEquals("INFO", l1.getString("level")); + assertEquals("foo", l1.getString("logger")); + assertEquals(tp1.getMessage(), l1.getString("message")); + assertEquals(1, l1.getJSONArray("params").length()); + assertFalse(l1.has("exception")); + + JSONObject l3 = json.getJSONArray("logs").getJSONObject(2); + assertNotNull(l3.get("exception")); + } } diff --git a/src/test/java/org/apache/sling/tracer/internal/LogTracerTest.java b/src/test/java/org/apache/sling/tracer/internal/LogTracerTest.java index 1409f95..c6b9e42 100644 --- a/src/test/java/org/apache/sling/tracer/internal/LogTracerTest.java +++ b/src/test/java/org/apache/sling/tracer/internal/LogTracerTest.java @@ -264,6 +264,46 @@ public class LogTracerTest { assertEquals(2, json.getJSONArray("requestProgressLogs").length()); } + @Test + public void recordingWithTracing() throws Exception{ + activateTracerAndServlet(); + MockSlingHttpServletRequest request = new MockSlingHttpServletRequest(){ + @Override + public RequestProgressTracker getRequestProgressTracker() { + return createTracker("x", "y"); + } + }; + request.setHeader(TracerLogServlet.HEADER_TRACER_RECORDING, "true"); + request.setHeader(LogTracer.HEADER_TRACER_CONFIG, "a.b.c;level=trace,a.b;level=debug"); + + HttpServletResponse response = mock(HttpServletResponse.class); + + FilterChain chain = new FilterChain() { + @Override + public void doFilter(ServletRequest request, ServletResponse response) + throws IOException, ServletException { + assertNotNull(context.getService(TurboFilter.class)); + getLogContext().addTurboFilter(context.getService(TurboFilter.class)); + getLogger("a.b").info("a.b-info"); + } + }; + + prepareChain(chain).doFilter(request, response); + + String requestId = getRequestId(response); + assertNotNull(requestId); + Recording r = ((TracerLogServlet)context.getService(Servlet.class)).getRecording(requestId); + assertTrue(r instanceof JSONRecording); + JSONRecording jr = (JSONRecording) r; + + StringWriter sw = new StringWriter(); + jr.render(sw); + JSONObject json = new JSONObject(sw.toString()); + + assertEquals(2, json.getJSONArray("requestProgressLogs").length()); + assertEquals(1, json.getJSONArray("logs").length()); + } + private void activateTracer() { context.registerInjectActivateService(new LogTracer(), -- To stop receiving notification emails like this one, please contact "[email protected]" <[email protected]>.
