diff options
Diffstat (limited to 'container-core/src')
4 files changed, 65 insertions, 165 deletions
diff --git a/container-core/src/main/java/com/yahoo/container/jdisc/LoggingRequestHandler.java b/container-core/src/main/java/com/yahoo/container/jdisc/LoggingRequestHandler.java index 064b6cf6279..9bb9819cd1f 100644 --- a/container-core/src/main/java/com/yahoo/container/jdisc/LoggingRequestHandler.java +++ b/container-core/src/main/java/com/yahoo/container/jdisc/LoggingRequestHandler.java @@ -3,7 +3,6 @@ package com.yahoo.container.jdisc; import com.google.inject.Inject; import com.yahoo.container.handler.Timing; -import com.yahoo.container.http.AccessLogUtil; import com.yahoo.container.logging.AccessLog; import com.yahoo.container.logging.AccessLogEntry; import com.yahoo.jdisc.Metric; @@ -11,16 +10,15 @@ import com.yahoo.jdisc.Response; import com.yahoo.jdisc.handler.CompletionHandler; import com.yahoo.jdisc.handler.ContentChannel; import com.yahoo.jdisc.http.server.jetty.AccessLoggingRequestHandler; -import java.util.logging.Level; import com.yahoo.yolean.Exceptions; import java.io.IOException; import java.io.OutputStream; -import java.net.InetSocketAddress; import java.net.SocketAddress; import java.net.URI; import java.util.Optional; import java.util.concurrent.Executor; +import java.util.logging.Level; /** * A request handler base class extending the features of @@ -28,35 +26,43 @@ import java.util.concurrent.Executor; * * @author Steinar Knutsen */ +// TODO Vespa 8: Deprecate all constructors taking AccessLog as parameter public abstract class LoggingRequestHandler extends ThreadedHttpRequestHandler { - private final AccessLog accessLog; + public LoggingRequestHandler(Executor executor, AccessLog ignored) { + this(executor, ignored, null); + } - public LoggingRequestHandler(Executor executor, AccessLog accessLog) { - this(executor, accessLog, null); + public LoggingRequestHandler(Executor executor) { + this(executor, null, null); } public static class Context { final Executor executor; - final AccessLog accessLog; + final AccessLog ignored; final Metric metric; @Inject - public Context(Executor executor, AccessLog accessLog, Metric metric) { + public Context(Executor executor, AccessLog ignored, Metric metric) { this.executor = executor; - this.accessLog = accessLog; + this.ignored = ignored; this.metric = metric; } + + public Context(Executor executor, Metric metric) { + this(executor, null, metric); + } + public Context(Context other) { this.executor = other.executor; - this.accessLog = other.accessLog; + this.ignored = other.ignored; this.metric = other.metric; } public Executor getExecutor() { return executor; } - public AccessLog getAccessLog() { return accessLog; } + public AccessLog getAccessLog() { return ignored; } public Metric getMetric() { return metric; } } @@ -74,20 +80,19 @@ public abstract class LoggingRequestHandler extends ThreadedHttpRequestHandler { @Inject public LoggingRequestHandler(Context ctx) { - this(ctx.executor, ctx.accessLog, ctx.metric); + this(ctx.executor, ctx.ignored, ctx.metric); } public LoggingRequestHandler(Context ctx, boolean allowAsyncResponse) { - this(ctx.executor, ctx.accessLog, ctx.metric, allowAsyncResponse); + this(ctx.executor, ctx.ignored, ctx.metric, allowAsyncResponse); } - public LoggingRequestHandler(Executor executor, AccessLog accessLog, Metric metric) { - this(executor, accessLog, metric, false); + public LoggingRequestHandler(Executor executor, AccessLog ignored, Metric metric) { + this(executor, ignored, metric, false); } - public LoggingRequestHandler(Executor executor, AccessLog accessLog, Metric metric, boolean allowAsyncResponse) { + public LoggingRequestHandler(Executor executor, AccessLog ignored, Metric metric, boolean allowAsyncResponse) { super(executor, metric, allowAsyncResponse); - this.accessLog = accessLog; } @Override @@ -106,26 +111,6 @@ public abstract class LoggingRequestHandler extends ThreadedHttpRequestHandler { return clientAddress.toString(); } - private static long getEvalStart(Timing timing, long startTime) { - if (timing == null || timing.getQueryStartTime() == 0L) { - return startTime; - } else { - return timing.getQueryStartTime(); - } - } - - private static String remoteHostAddress(com.yahoo.jdisc.http.HttpRequest httpRequest) { - SocketAddress remoteAddress = httpRequest.getRemoteAddress(); - if (remoteAddress == null) return "0.0.0.0"; - - if (remoteAddress instanceof InetSocketAddress) { - return ((InetSocketAddress) remoteAddress).getAddress().getHostAddress(); - } else { - throw new RuntimeException("Expected remote address of type InetSocketAddress, got " + - remoteAddress.getClass().getName()); - } - } - private void logTimes(long startTime, String sourceIP, long renderStartTime, long commitStartTime, long endTime, String req, String normalizedQuery, Timing t) { @@ -257,21 +242,8 @@ public abstract class LoggingRequestHandler extends ThreadedHttpRequestHandler { // The request is created by JDisc http layer (Jetty) // Actual logging will be done by the Jetty integration; here, we just need to populate. entry = jdiscRequestAccessLogEntry.get(); - } else { - // Not running on JDisc http layer (Jetty), e.g unit tests - AccessLogEntry accessLogEntry = new AccessLogEntry(); - populateAccessLogEntryNotCreatedByHttpServer(accessLogEntry, - jdiscRequest, - extendedResponse.getTiming(), - httpRequest.getUri().toString(), - commitStartTime, - startTime, - rendererWiring.written(), - httpResponse.getStatus()); - accessLog.log(accessLogEntry); - entry = accessLogEntry; + httpResponse.populateAccessLogEntry(entry); } - httpResponse.populateAccessLogEntry(entry); } private String getUri(com.yahoo.jdisc.http.HttpRequest jdiscRequest) { @@ -285,36 +257,4 @@ public abstract class LoggingRequestHandler extends ThreadedHttpRequestHandler { } } - private void populateAccessLogEntryNotCreatedByHttpServer(AccessLogEntry logEntry, - com.yahoo.jdisc.http.HttpRequest httpRequest, - Timing timing, - String fullRequest, - long commitStartTime, - long startTime, - long written, - int status) { - try { - InetSocketAddress remoteAddress = AccessLogUtil.getRemoteAddress(httpRequest); - long evalStartTime = getEvalStart(timing, startTime); - logEntry.setIpV4Address(remoteHostAddress(httpRequest)); - logEntry.setTimeStamp(evalStartTime); - logEntry.setDurationBetweenRequestResponse(commitStartTime - evalStartTime); - logEntry.setReturnedContentSize(written); - logEntry.setStatusCode(status); - if (remoteAddress != null) { - logEntry.setRemoteAddress(remoteAddress); - logEntry.setRemotePort(remoteAddress.getPort()); - } - URI uri = AccessLogUtil.getUri(httpRequest); - logEntry.setRawPath(uri.getRawPath()); - logEntry.setRawQuery(uri.getRawQuery()); - logEntry.setUserAgent(AccessLogUtil.getUserAgentHeader(httpRequest)); - logEntry.setReferer(AccessLogUtil.getReferrerHeader(httpRequest)); - logEntry.setHttpMethod(AccessLogUtil.getHttpMethod(httpRequest)); - logEntry.setHttpVersion(AccessLogUtil.getHttpVersion(httpRequest)); - } catch (Exception e) { - log.log(Level.WARNING, "Could not populate the access log [" + fullRequest + "]", e); - } - } - } diff --git a/container-core/src/main/java/com/yahoo/processing/handler/ProcessingTestDriver.java b/container-core/src/main/java/com/yahoo/processing/handler/ProcessingTestDriver.java index d4e55dbc556..7170f63234e 100644 --- a/container-core/src/main/java/com/yahoo/processing/handler/ProcessingTestDriver.java +++ b/container-core/src/main/java/com/yahoo/processing/handler/ProcessingTestDriver.java @@ -7,7 +7,7 @@ import com.yahoo.component.chain.Chain; import com.yahoo.component.provider.ComponentRegistry; import com.yahoo.container.jdisc.RequestHandlerTestDriver; import com.yahoo.container.logging.AccessLog; -import com.yahoo.container.logging.AccessLogInterface; +import com.yahoo.container.logging.RequestLogHandler; import com.yahoo.processing.Processor; import com.yahoo.processing.execution.chain.ChainRegistry; import com.yahoo.processing.rendering.Renderer; @@ -60,15 +60,15 @@ public class ProcessingTestDriver extends RequestHandlerTestDriver { this.processingHandler = processingHandler; } - public ProcessingTestDriver(Chain<Processor> chain, AccessLogInterface accessLogInterface) { + public ProcessingTestDriver(Chain<Processor> chain, RequestLogHandler accessLogInterface) { this(createProcessingHandler( Collections.singleton(chain), new ComponentRegistry<>(), createAccessLog(accessLogInterface))); } - private static AccessLog createAccessLog(AccessLogInterface accessLogInterface) { - ComponentRegistry<AccessLogInterface> componentRegistry = new ComponentRegistry<>(); + private static AccessLog createAccessLog(RequestLogHandler accessLogInterface) { + ComponentRegistry<RequestLogHandler> componentRegistry = new ComponentRegistry<>(); componentRegistry.register(ComponentId.createAnonymousComponentId("access-log"), accessLogInterface); componentRegistry.freeze(); diff --git a/container-core/src/test/java/com/yahoo/container/jdisc/LoggingRequestHandlerTestCase.java b/container-core/src/test/java/com/yahoo/container/jdisc/LoggingRequestHandlerTestCase.java index 92fe347f7d1..734b3fa11af 100644 --- a/container-core/src/test/java/com/yahoo/container/jdisc/LoggingRequestHandlerTestCase.java +++ b/container-core/src/test/java/com/yahoo/container/jdisc/LoggingRequestHandlerTestCase.java @@ -1,51 +1,43 @@ // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. package com.yahoo.container.jdisc; -import static org.junit.Assert.*; - -import java.io.IOException; -import java.io.OutputStream; -import java.net.InetSocketAddress; -import java.net.URISyntaxException; -import java.nio.ByteBuffer; -import java.util.concurrent.ArrayBlockingQueue; -import java.util.concurrent.Executor; -import java.util.concurrent.ExecutorService; -import java.util.concurrent.Executors; -import java.util.concurrent.TimeUnit; - import com.google.inject.Key; +import com.yahoo.component.provider.ComponentRegistry; +import com.yahoo.container.handler.Coverage; +import com.yahoo.container.handler.Timing; +import com.yahoo.container.logging.AccessLog; import com.yahoo.container.logging.HitCounts; +import com.yahoo.container.logging.RequestLogHandler; import com.yahoo.jdisc.Container; import com.yahoo.jdisc.References; import com.yahoo.jdisc.ResourceReference; +import com.yahoo.jdisc.handler.CompletionHandler; +import com.yahoo.jdisc.handler.ContentChannel; import com.yahoo.jdisc.handler.RequestHandler; +import com.yahoo.jdisc.handler.ResponseHandler; import com.yahoo.jdisc.service.CurrentContainer; -import java.net.URI; import org.junit.After; import org.junit.Before; -import org.junit.Test; -import com.yahoo.component.ComponentId; -import com.yahoo.component.provider.ComponentRegistry; -import com.yahoo.container.handler.Coverage; -import com.yahoo.container.handler.Timing; -import com.yahoo.container.logging.AccessLog; -import com.yahoo.container.logging.AccessLogEntry; -import com.yahoo.container.logging.AccessLogInterface; -import com.yahoo.jdisc.handler.BufferedContentChannel; -import com.yahoo.jdisc.handler.CompletionHandler; -import com.yahoo.jdisc.handler.ContentChannel; -import com.yahoo.jdisc.handler.ResponseHandler; +import java.io.IOException; +import java.io.OutputStream; +import java.net.InetSocketAddress; +import java.net.URI; +import java.net.URISyntaxException; +import java.nio.ByteBuffer; +import java.util.concurrent.Executor; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; + +import static org.junit.Assert.fail; /** * Test contracts in LoggingRequestHandler. * - * @author <a href="mailto:steinar@yahoo-inc.com">Steinar Knutsen</a> + * @author Steinar Knutsen */ public class LoggingRequestHandlerTestCase { - StartTimePusher accessLogging; AccessLogTestHandler handler; ExecutorService executor; @@ -121,21 +113,9 @@ public class LoggingRequestHandlerTestCase { } - static final class StartTimePusher implements AccessLogInterface { - - public final ArrayBlockingQueue<Long> starts = new ArrayBlockingQueue<>(1); - - @Override - public void log(final AccessLogEntry accessLogEntry) { - starts.offer(Long.valueOf(accessLogEntry.getTimeStampMillis())); - } - } - @Before public void setUp() throws Exception { - accessLogging = new StartTimePusher(); - ComponentRegistry<AccessLogInterface> implementers = new ComponentRegistry<>(); - implementers.register(new ComponentId("nalle"), accessLogging); + ComponentRegistry<RequestLogHandler> implementers = new ComponentRegistry<>(); implementers.freeze(); executor = Executors.newCachedThreadPool(); handler = new AccessLogTestHandler(executor, new AccessLog(implementers)); @@ -143,31 +123,11 @@ public class LoggingRequestHandlerTestCase { @After public void tearDown() throws Exception { - accessLogging = null; handler = null; executor.shutdown(); executor = null; } - @Test - public final void checkStartIsNotZeroWithoutTimingInstance() throws InterruptedException { - Long startTime; - - MockResponseHandler responseHandler = new MockResponseHandler(); - com.yahoo.jdisc.http.HttpRequest request = createRequest(); - BufferedContentChannel requestContent = new BufferedContentChannel(); - requestContent.close(null); - handler.handleRequest(request, requestContent, responseHandler); - startTime = accessLogging.starts.poll(5, TimeUnit.MINUTES); - if (startTime == null) { - // test timed out, ignoring - } else { - assertFalse( - "Start time was 0, that should never happen after the first millisecond of 1970.", - startTime.longValue() == 0L); - } - } - public static com.yahoo.jdisc.http.HttpRequest createRequest() { return createRequest("http://localhost/search/?query=geewhiz"); } diff --git a/container-core/src/test/java/com/yahoo/processing/handler/ProcessingHandlerTestCase.java b/container-core/src/test/java/com/yahoo/processing/handler/ProcessingHandlerTestCase.java index 6498514c075..ae1076a4773 100644 --- a/container-core/src/test/java/com/yahoo/processing/handler/ProcessingHandlerTestCase.java +++ b/container-core/src/test/java/com/yahoo/processing/handler/ProcessingHandlerTestCase.java @@ -8,9 +8,10 @@ import com.yahoo.component.chain.Chain; import com.yahoo.component.provider.ComponentRegistry; import com.yahoo.container.jdisc.RequestHandlerTestDriver; import com.yahoo.container.logging.AccessLogEntry; -import com.yahoo.container.logging.AccessLogInterface; import com.yahoo.container.protect.Error; +import com.yahoo.jdisc.Request; import com.yahoo.jdisc.Response; +import com.yahoo.jdisc.handler.ContentChannel; import com.yahoo.jdisc.http.HttpRequest; import com.yahoo.processing.Processor; import com.yahoo.processing.execution.Execution; @@ -23,11 +24,11 @@ import com.yahoo.processing.test.ProcessorLibrary; import org.junit.After; import org.junit.Ignore; import org.junit.Test; -import org.mockito.ArgumentCaptor; -import org.mockito.Mockito; import java.io.IOException; import java.io.InputStream; +import java.net.URI; +import java.nio.ByteBuffer; import java.util.ArrayList; import java.util.Arrays; import java.util.Collections; @@ -37,17 +38,16 @@ import java.util.List; import java.util.Map; import java.util.concurrent.ExecutionException; +import static com.yahoo.jdisc.http.server.jetty.AccessLoggingRequestHandler.CONTEXT_KEY_ACCESS_LOG_ENTRY; import static com.yahoo.processing.test.ProcessorLibrary.MapData; import static org.hamcrest.CoreMatchers.is; import static org.hamcrest.CoreMatchers.notNullValue; import static org.hamcrest.CoreMatchers.sameInstance; import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertFalse; -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.times; /** * Tests processing handler scenarios end to end. @@ -83,18 +83,18 @@ public class ProcessingHandlerTestCase { } @Test - public void processing_handler_stores_trace_log_values_in_the_access_log_entry() throws InterruptedException { - ArgumentCaptor<AccessLogEntry> accessLogEntryCaptor = ArgumentCaptor.forClass(AccessLogEntry.class); - AccessLogInterface accessLog = Mockito.mock(AccessLogInterface.class); - - driver = new ProcessingTestDriver(logValueChain, accessLog); - driver.sendRequest("http://localhost/?chain=log-value").readAll(); - - Mockito.verify(accessLog, times(1)).log(accessLogEntryCaptor.capture()); - - AccessLogEntry entry = accessLogEntryCaptor.getValue(); - assertNotNull(entry); - assertThat(entry.getKeyValues().get(LOG_KEY), is(Collections.singletonList(LOG_VALUE))); + public void processing_handler_stores_trace_log_values_in_the_access_log_entry() { + driver = new ProcessingTestDriver(logValueChain); + Request request = HttpRequest.newServerRequest(driver.jDiscDriver(), URI.create("http://localhost/?chain=log-value"), HttpRequest.Method.GET); + AccessLogEntry entry = new AccessLogEntry(); + request.context().put(CONTEXT_KEY_ACCESS_LOG_ENTRY, entry); + RequestHandlerTestDriver.MockResponseHandler responseHandler = new RequestHandlerTestDriver.MockResponseHandler(); + ContentChannel requestContent = request.connect(responseHandler); + requestContent.write(ByteBuffer.allocate(0), null); + requestContent.close(null); + request.release(); + responseHandler.readAll(); + assertThat(entry.getKeyValues().get(LOG_KEY), is(List.of(LOG_VALUE))); } @Test |