| /* |
| * 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.sling.tracer.internal; |
| |
| import java.io.IOException; |
| import java.io.StringReader; |
| import java.io.StringWriter; |
| import java.util.Collection; |
| import java.util.List; |
| |
| import javax.json.Json; |
| import javax.json.JsonObject; |
| import javax.servlet.Filter; |
| import javax.servlet.FilterChain; |
| import javax.servlet.Servlet; |
| import javax.servlet.ServletException; |
| import javax.servlet.ServletRequest; |
| import javax.servlet.ServletResponse; |
| import javax.servlet.http.HttpServletRequest; |
| import javax.servlet.http.HttpServletResponse; |
| |
| import ch.qos.logback.classic.Level; |
| import ch.qos.logback.classic.LoggerContext; |
| import ch.qos.logback.classic.spi.ILoggingEvent; |
| import ch.qos.logback.classic.turbo.TurboFilter; |
| import ch.qos.logback.core.read.ListAppender; |
| import com.google.common.collect.ImmutableMap; |
| import com.google.common.collect.Lists; |
| import org.apache.sling.api.SlingHttpServletRequest; |
| import org.apache.sling.api.request.RequestProgressTracker; |
| import org.apache.sling.testing.mock.osgi.MockOsgi; |
| import org.apache.sling.testing.mock.osgi.junit.OsgiContext; |
| import org.apache.sling.testing.mock.osgi.junit.OsgiContextCallback; |
| import org.apache.sling.testing.mock.sling.servlet.MockSlingHttpServletRequest; |
| import org.junit.Rule; |
| import org.junit.Test; |
| import org.junit.rules.TestWatcher; |
| import org.junit.runner.Description; |
| import org.osgi.framework.InvalidSyntaxException; |
| import org.osgi.framework.ServiceReference; |
| import org.slf4j.LoggerFactory; |
| |
| import static org.apache.sling.tracer.internal.TestUtil.createTracker; |
| import static org.apache.sling.tracer.internal.TestUtil.getRequestId; |
| import static org.hamcrest.CoreMatchers.hasItem; |
| import static org.hamcrest.CoreMatchers.not; |
| import static org.junit.Assert.assertEquals; |
| import static org.junit.Assert.assertNotNull; |
| import static org.junit.Assert.assertNull; |
| import static org.junit.Assert.assertThat; |
| import static org.junit.Assert.assertTrue; |
| import static org.mockito.Mockito.mock; |
| import static org.mockito.Mockito.when; |
| import static org.slf4j.LoggerFactory.getLogger; |
| |
| public class LogTracerTest { |
| |
| @Rule |
| public final LogCollector logCollector = new LogCollector(); |
| |
| @Rule |
| public final OsgiContext context = new OsgiContext(null, new OsgiContextCallback() { |
| @Override |
| public void execute(OsgiContext context) throws IOException { |
| if (context.getService(TurboFilter.class) != null) { |
| TurboFilter[] tfs = context.getServices(TurboFilter.class, null); |
| for (TurboFilter tf : tfs) { |
| getLogContext().getTurboFilterList().remove(tf); |
| } |
| } |
| } |
| }); |
| |
| @Test |
| public void defaultSetup() throws Exception { |
| context.registerInjectActivateService(new LogTracer()); |
| assertNull("Filters should not be registered unless enabled", context.getService(Filter.class)); |
| } |
| |
| @Test |
| public void enableTracer() throws Exception { |
| LogTracer tracer = context.registerInjectActivateService(new LogTracer(), |
| ImmutableMap.<String, Object>of("enabled", "true")); |
| assertEquals(2, context.getServices(Filter.class, null).length); |
| assertNull(context.getService(Servlet.class)); |
| |
| MockOsgi.deactivate(tracer); |
| assertNull(context.getService(Filter.class)); |
| } |
| |
| @Test |
| public void enableTracerLogServlet() throws Exception { |
| LogTracer tracer = context.registerInjectActivateService(new LogTracer(), |
| ImmutableMap.<String, Object>of("enabled", "true", "servletEnabled", "true")); |
| assertEquals(2, context.getServices(Filter.class, null).length); |
| assertNotNull(context.getService(Servlet.class)); |
| |
| TracerLogServlet logServlet = (TracerLogServlet) context.getService(Servlet.class); |
| assertEquals(true, logServlet.isCompressRecording()); |
| assertEquals(LogTracer.PROP_TRACER_SERVLET_CACHE_SIZE_DEFAULT, logServlet.getCacheSizeInMB()); |
| assertEquals(LogTracer.PROP_TRACER_SERVLET_CACHE_DURATION_DEFAULT, logServlet.getCacheDurationInSecs()); |
| |
| MockOsgi.deactivate(tracer); |
| assertNull(context.getService(Filter.class)); |
| assertNull(context.getService(Servlet.class)); |
| } |
| |
| @Test |
| public void enableTracerLogServletWithConfig() throws Exception { |
| LogTracer tracer = context.registerInjectActivateService(new LogTracer(), |
| ImmutableMap.<String, Object>builder() |
| .put("enabled", "true") |
| .put("servletEnabled", "true") |
| .put("recordingCacheSizeInMB", "17") |
| .put("recordingCacheDurationInSecs", "100") |
| .put("recordingCompressionEnabled", "false") |
| .put("gzipResponse", "true") |
| .build() |
| ); |
| assertEquals(2, context.getServices(Filter.class, null).length); |
| assertNotNull(context.getService(Servlet.class)); |
| |
| TracerLogServlet logServlet = (TracerLogServlet) context.getService(Servlet.class); |
| assertEquals(false, logServlet.isCompressRecording()); |
| assertEquals(false, logServlet.isGzipResponse()); |
| assertEquals(17, logServlet.getCacheSizeInMB()); |
| assertEquals(100, logServlet.getCacheDurationInSecs()); |
| } |
| |
| @Test |
| public void enableTracerLogServletWithConfigGzip() throws Exception { |
| LogTracer tracer = context.registerInjectActivateService(new LogTracer(), |
| ImmutableMap.<String, Object>builder() |
| .put("enabled", "true") |
| .put("servletEnabled", "true") |
| .put("recordingCompressionEnabled", "true") |
| .put("gzipResponse", "true") |
| .build() |
| ); |
| assertEquals(2, context.getServices(Filter.class, null).length); |
| assertNotNull(context.getService(Servlet.class)); |
| |
| TracerLogServlet logServlet = (TracerLogServlet) context.getService(Servlet.class); |
| assertEquals(true, logServlet.isCompressRecording()); |
| assertEquals(true, logServlet.isGzipResponse()); |
| } |
| |
| |
| @Test |
| public void noTurboFilterRegisteredUnlessTracingRequested() throws Exception { |
| HttpServletRequest request = mock(HttpServletRequest.class); |
| HttpServletResponse response = mock(HttpServletResponse.class); |
| |
| activateTracer(); |
| FilterChain chain = new FilterChain() { |
| @Override |
| public void doFilter(ServletRequest request, ServletResponse response) |
| throws IOException, ServletException { |
| assertNull(context.getService(TurboFilter.class)); |
| } |
| }; |
| |
| Filter filter = getFilter(false); |
| filter.doFilter(request, response, chain); |
| } |
| |
| @Test |
| public void turboFilterRegisteredWhenTracingRequested() throws Exception { |
| HttpServletRequest request = mock(HttpServletRequest.class); |
| HttpServletResponse response = mock(HttpServletResponse.class); |
| |
| when(request.getHeader(LogTracer.HEADER_TRACER_CONFIG)).thenReturn("foo.bar"); |
| activateTracer(); |
| FilterChain chain = new FilterChain() { |
| @Override |
| public void doFilter(ServletRequest request, ServletResponse response) |
| throws IOException, ServletException { |
| assertNotNull(context.getService(TurboFilter.class)); |
| } |
| }; |
| |
| Filter filter = getFilter(false); |
| filter.doFilter(request, response, chain); |
| assertNull("TurboFilter should get removed once request is done", |
| context.getService(TurboFilter.class)); |
| } |
| |
| @Test |
| public void turboFilterRegisteredWhenTracingRequested_Sling() throws Exception { |
| HttpServletRequest request = mock(SlingHttpServletRequest.class); |
| HttpServletResponse response = mock(HttpServletResponse.class); |
| |
| when(request.getParameter(LogTracer.PARAM_TRACER_CONFIG)).thenReturn("foo.bar"); |
| activateTracer(); |
| FilterChain chain = new FilterChain() { |
| @Override |
| public void doFilter(ServletRequest request, ServletResponse response) |
| throws IOException, ServletException { |
| assertNotNull(context.getService(TurboFilter.class)); |
| } |
| }; |
| |
| Filter filter = getFilter(true); |
| filter.doFilter(request, response, chain); |
| assertNull("TurboFilter should get removed once request is done", |
| context.getService(TurboFilter.class)); |
| } |
| |
| @Test |
| public void checkTracing() throws Exception { |
| HttpServletRequest request = mock(SlingHttpServletRequest.class); |
| HttpServletResponse response = mock(HttpServletResponse.class); |
| |
| when(request.getParameter(LogTracer.PARAM_TRACER_CONFIG)).thenReturn("a.b.c;level=trace,a.b;level=debug"); |
| activateTracer(); |
| Level oldLevel = rootLogger().getLevel(); |
| rootLogger().setLevel(Level.INFO); |
| |
| FilterChain chain = new FilterChain() { |
| @Override |
| public void doFilter(ServletRequest request, ServletResponse response) |
| throws IOException, ServletException { |
| TurboFilter turboFilter = context.getService(TurboFilter.class); |
| assertNotNull(turboFilter); |
| getLogContext().addTurboFilter(turboFilter); |
| getLogger("a").info("a-info"); |
| getLogger("a").debug("a-debug"); |
| getLogger("a.b").info("a.b-info"); |
| getLogger("a.b").debug("a.b-debug"); |
| getLogger("a.b").trace("a.b-trace"); |
| getLogger("a.b.c").debug("a.b.c-debug"); |
| getLogger("a.b.c").trace("a.b.c-trace"); |
| getLogger("a.b.c.d").trace("a.b.c.d-trace"); |
| |
| if (getLogger("a.b.c").isTraceEnabled()){ |
| getLogger("a.b.c").trace("a.b.c-trace2"); |
| } |
| } |
| }; |
| |
| Filter filter = getFilter(true); |
| filter.doFilter(request, response, chain); |
| assertNull(context.getService(TurboFilter.class)); |
| |
| List<String> logs = logCollector.getLogs(); |
| assertThat(logs, hasItem("a-info")); |
| assertThat(logs, not(hasItem("a-debug"))); |
| |
| assertThat(logs, hasItem("a.b-info")); |
| assertThat(logs, hasItem("a.b-debug")); |
| assertThat(logs, not(hasItem("a.b-trace"))); |
| |
| assertThat(logs, hasItem("a.b.c-debug")); |
| assertThat(logs, hasItem("a.b.c-trace")); |
| assertThat(logs, hasItem("a.b.c-trace2")); |
| assertThat(logs, hasItem("a.b.c.d-trace")); |
| |
| rootLogger().setLevel(oldLevel); |
| } |
| |
| @Test |
| public void recordingWithoutTracing() throws Exception{ |
| activateTracerAndServlet(); |
| MockSlingHttpServletRequest request = new MockSlingHttpServletRequest(context.bundleContext()){ |
| @Override |
| public RequestProgressTracker getRequestProgressTracker() { |
| return createTracker("x", "y"); |
| } |
| |
| @Override |
| public String getRequestURI() { |
| return "foo"; |
| } |
| }; |
| request.setHeader(TracerLogServlet.HEADER_TRACER_RECORDING, "true"); |
| |
| HttpServletResponse response = mock(HttpServletResponse.class); |
| |
| FilterChain chain = new FilterChain() { |
| @Override |
| public void doFilter(ServletRequest request, ServletResponse response) |
| throws IOException, ServletException { |
| //No TurboFilter should be registered if tracing is not requested |
| assertNull(context.getService(TurboFilter.class)); |
| } |
| }; |
| |
| 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 = Json.createReader(new StringReader(sw.toString())).readObject(); |
| |
| assertEquals(2, json.getJsonArray("requestProgressLogs").size()); |
| } |
| |
| @Test |
| public void recordingWithTracing() throws Exception{ |
| activateTracerAndServlet(); |
| MockSlingHttpServletRequest request = new MockSlingHttpServletRequest(context.bundleContext()){ |
| @Override |
| public RequestProgressTracker getRequestProgressTracker() { |
| return createTracker("x", "y"); |
| } |
| |
| @Override |
| public String getRequestURI() { |
| return "foo"; |
| } |
| }; |
| 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 = Json.createReader(new StringReader(sw.toString())).readObject(); |
| |
| assertEquals(2, json.getJsonArray("requestProgressLogs").size()); |
| assertEquals(1, json.getJsonArray("logs").size()); |
| } |
| |
| |
| private void activateTracer() { |
| context.registerInjectActivateService(new LogTracer(), |
| ImmutableMap.<String, Object>of("enabled", "true")); |
| } |
| |
| private void activateTracerAndServlet() { |
| context.registerInjectActivateService(new LogTracer(), |
| ImmutableMap.<String, Object>of("enabled", "true", "servletEnabled", "true")); |
| } |
| |
| private FilterChain prepareChain(FilterChain end) throws InvalidSyntaxException { |
| Filter servletFilter = getFilter(false); |
| Filter slingFilter = getFilter(true); |
| return new FilterChainImpl(end, servletFilter, slingFilter); |
| } |
| |
| private Filter getFilter(boolean slingFilter) throws InvalidSyntaxException { |
| Collection<ServiceReference<Filter>> refs = |
| context.bundleContext().getServiceReferences(Filter.class, null); |
| ServiceReference<Filter> result = null; |
| for (ServiceReference<Filter> ref : refs) { |
| if (slingFilter && ref.getProperty("sling.filter.scope") != null) { |
| result = ref; |
| break; |
| } else if (!slingFilter && ref.getProperty("pattern") != null) { |
| result = ref; |
| break; |
| } |
| } |
| |
| if (result != null) { |
| return context.bundleContext().getService(result); |
| } |
| throw new AssertionError("No filter found"); |
| } |
| |
| private static LoggerContext getLogContext(){ |
| return (LoggerContext)LoggerFactory.getILoggerFactory(); |
| } |
| |
| private static ch.qos.logback.classic.Logger rootLogger() { |
| return getLogContext().getLogger(ch.qos.logback.classic.Logger.ROOT_LOGGER_NAME); |
| } |
| |
| private static class LogCollector extends TestWatcher { |
| private List<String> msgs = Lists.newArrayList(); |
| private TestAppender appender = new TestAppender(); |
| |
| public List<String> getLogs(){ |
| return msgs; |
| } |
| |
| @Override |
| protected void starting(Description description) { |
| appender.setContext(getLogContext()); |
| appender.setName("TestLogCollector"); |
| appender.start(); |
| rootLogger().addAppender(appender); |
| } |
| |
| @Override |
| protected void finished(Description description) { |
| rootLogger().detachAppender(appender); |
| } |
| |
| private class TestAppender extends ListAppender<ILoggingEvent>{ |
| @Override |
| protected void append(ILoggingEvent iLoggingEvent) { |
| msgs.add(iLoggingEvent.getFormattedMessage()); |
| } |
| } |
| } |
| |
| private static class FilterChainImpl implements FilterChain { |
| private final Filter[] filters; |
| private final FilterChain delegate; |
| private int pos; |
| |
| public FilterChainImpl(FilterChain delegate, Filter ... filter){ |
| this.delegate = delegate; |
| this.filters = filter; |
| } |
| |
| @Override |
| public void doFilter(ServletRequest request, ServletResponse response) throws IOException, ServletException { |
| if (pos == filters.length){ |
| delegate.doFilter(request, response); |
| } else { |
| filters[pos++].doFilter(request, response, this); |
| } |
| } |
| } |
| |
| } |