From f2a9d18477e9ed79dff64bfc141d5ad9f176601d Mon Sep 17 00:00:00 2001 From: Henning Baldersheim Date: Tue, 11 Feb 2020 12:00:59 +0000 Subject: If debugging of SearchHandler is turned on, the 1k first request will have trace and timing information. The 1k number is configurable in the container-http config. --- .../jdisc/ThreadedHttpRequestHandler.java | 4 +-- .../resources/configdefinitions/container-http.def | 3 ++ .../yahoo/search/handler/HttpSearchResponse.java | 4 +-- .../com/yahoo/search/handler/SearchHandler.java | 33 ++++++++++++++++++---- .../com/yahoo/search/searchchain/Execution.java | 2 -- .../com/yahoo/processing/execution/Execution.java | 4 +-- searchlib/src/tests/fef/fef_test.cpp | 1 + 7 files changed, 37 insertions(+), 14 deletions(-) diff --git a/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java b/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java index dddde1205ca..a9ea737c96c 100644 --- a/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java +++ b/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java @@ -93,7 +93,7 @@ public abstract class ThreadedHttpRequestHandler extends ThreadedRequestHandler /** Render and return whether the channel was closed */ private void render(HttpRequest request, HttpResponse httpResponse, - LazyContentChannel channel, long startTime) throws IOException { + LazyContentChannel channel, long startTime) { LoggingCompletionHandler logOnCompletion = null; ContentChannelOutputStream output = null; try { @@ -168,7 +168,7 @@ public abstract class ThreadedHttpRequestHandler extends ThreadedRequestHandler @Override public void close(CompletionHandler completionHandler) { if ( closed ) return; - try { httpRequest.getData().close(); } catch (IOException e) {}; + try { httpRequest.getData().close(); } catch (IOException e) {} if (channel == null) channel = handleResponse(); try { diff --git a/container-core/src/main/resources/configdefinitions/container-http.def b/container-core/src/main/resources/configdefinitions/container-http.def index ccf559b862a..23edd402893 100644 --- a/container-core/src/main/resources/configdefinitions/container-http.def +++ b/container-core/src/main/resources/configdefinitions/container-http.def @@ -3,3 +3,6 @@ namespace=container.core ## If non-empty, handlers should emit a header containing this string as key and the local host name as value hostResponseHeaderKey string default="" + +## For debugging, number of requests to add trace and timing information too if debugging is enabled. +numQueriesToTraceOnDebugAfterConstruction int default=1000 diff --git a/container-search/src/main/java/com/yahoo/search/handler/HttpSearchResponse.java b/container-search/src/main/java/com/yahoo/search/handler/HttpSearchResponse.java index 3602d21f7d8..23eb8387427 100644 --- a/container-search/src/main/java/com/yahoo/search/handler/HttpSearchResponse.java +++ b/container-search/src/main/java/com/yahoo/search/handler/HttpSearchResponse.java @@ -69,14 +69,14 @@ public class HttpSearchResponse extends ExtendedResponse { } } - public ListenableFuture waitableRender(OutputStream stream) throws IOException { + public ListenableFuture waitableRender(OutputStream stream) { return waitableRender(result, query, rendererCopy, stream); } public static ListenableFuture waitableRender(Result result, Query query, Renderer renderer, - OutputStream stream) throws IOException { + OutputStream stream) { SearchResponse.trimHits(result); SearchResponse.removeEmptySummaryFeatureFields(result); return renderer.render(stream, result, query.getModel().getExecution(), query); diff --git a/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java b/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java index 316b2376060..b9ffb9b0cd0 100644 --- a/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java +++ b/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java @@ -58,6 +58,7 @@ import java.util.Optional; import java.util.concurrent.Executor; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicLong; import java.util.logging.Level; import java.util.logging.Logger; @@ -98,6 +99,8 @@ public class SearchHandler extends LoggingRequestHandler { private final ExecutionFactory executionFactory; + private final AtomicLong numRequestsLeftToTrace; + private final class MeanConnections implements Callback { @Override @@ -125,6 +128,7 @@ public class SearchHandler extends LoggingRequestHandler { accessLog, QueryProfileConfigurer.createFromConfig(queryProfileConfig).compile(), executionFactory, + containerHttpConfig.numQueriesToTraceOnDebugAfterConstruction(), containerHttpConfig.hostResponseHeaderKey().equals("") ? Optional.empty() : Optional.of( containerHttpConfig.hostResponseHeaderKey())); } @@ -136,6 +140,17 @@ public class SearchHandler extends LoggingRequestHandler { CompiledQueryProfileRegistry queryProfileRegistry, ExecutionFactory executionFactory, Optional hostResponseHeaderKey) { + this(statistics, metric, executor, accessLog, queryProfileRegistry, executionFactory, 0, hostResponseHeaderKey); + } + + private SearchHandler(Statistics statistics, + Metric metric, + Executor executor, + AccessLog accessLog, + CompiledQueryProfileRegistry queryProfileRegistry, + ExecutionFactory executionFactory, + long numQueriesToTraceOnDebugAfterStartup, + Optional hostResponseHeaderKey) { super(executor, accessLog, metric, true); log.log(LogLevel.DEBUG, "SearchHandler.init " + System.identityHashCode(this)); this.queryProfileRegistry = queryProfileRegistry; @@ -144,12 +159,13 @@ public class SearchHandler extends LoggingRequestHandler { this.maxThreads = examineExecutor(executor); searchConnections = new Value(SEARCH_CONNECTIONS, statistics, - new Value.Parameters().setLogRaw(true).setLogMax(true) - .setLogMean(true).setLogMin(true) - .setNameExtension(true) - .setCallback(new MeanConnections())); + new Value.Parameters().setLogRaw(true).setLogMax(true) + .setLogMean(true).setLogMin(true) + .setNameExtension(true) + .setCallback(new MeanConnections())); this.hostResponseHeaderKey = hostResponseHeaderKey; + this.numRequestsLeftToTrace = new AtomicLong(numQueriesToTraceOnDebugAfterStartup); } /** @deprecated use the other constructor */ @@ -215,7 +231,6 @@ public class SearchHandler extends LoggingRequestHandler { } - @SuppressWarnings("unchecked") private HttpResponse errorResponse(HttpRequest request, ErrorMessage errorMessage) { Query query = new Query(); Result result = new Result(query, errorMessage); @@ -330,7 +345,13 @@ public class SearchHandler extends LoggingRequestHandler { Execution execution = executionFactory.newExecution(searchChain); query.getModel().setExecution(execution); - execution.trace().setForceTimestamps(query.properties().getBoolean(FORCE_TIMESTAMPS, false)); + if (log.isLoggable(Level.FINE) && (numRequestsLeftToTrace.getAndDecrement() > 0)) { + query.setTraceLevel(Math.max(1, query.getTraceLevel())); + execution.trace().setForceTimestamps(true); + + } else { + execution.trace().setForceTimestamps(query.properties().getBoolean(FORCE_TIMESTAMPS, false)); + } if (query.properties().getBoolean(DETAILED_TIMING_LOGGING, false)) { // check and set (instead of set directly) to avoid overwriting stuff from prepareForBreakdownAnalysis() execution.context().setDetailedDiagnostics(true); diff --git a/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java b/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java index 5cc34ff5b28..84fe88d0292 100644 --- a/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java +++ b/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java @@ -3,7 +3,6 @@ package com.yahoo.search.searchchain; import com.yahoo.component.chain.Chain; import com.yahoo.language.Linguistics; -import com.yahoo.log.LogLevel; import com.yahoo.prelude.IndexFacts; import com.yahoo.prelude.Ping; import com.yahoo.prelude.Pong; @@ -11,7 +10,6 @@ import com.yahoo.prelude.query.parser.SpecialTokenRegistry; import com.yahoo.processing.Processor; import com.yahoo.processing.Request; import com.yahoo.processing.Response; -import com.yahoo.protect.Validator; import com.yahoo.search.Query; import com.yahoo.search.Result; import com.yahoo.search.Searcher; diff --git a/processing/src/main/java/com/yahoo/processing/execution/Execution.java b/processing/src/main/java/com/yahoo/processing/execution/Execution.java index ee1e9eb39e4..aeeae58543e 100644 --- a/processing/src/main/java/com/yahoo/processing/execution/Execution.java +++ b/processing/src/main/java/com/yahoo/processing/execution/Execution.java @@ -206,7 +206,7 @@ public class Execution { * Creates an empty environment. Only useful for some limited testing */ public static Environment createEmpty() { - return new Environment(new ChainRegistry()); + return new Environment<>(new ChainRegistry<>()); } /** @@ -254,7 +254,7 @@ public class Execution { /** * If true, do timing logic, even though trace level is low. */ - private boolean forceTimestamps = false; + private boolean forceTimestamps; /** * Creates an empty root trace with a given level of tracing diff --git a/searchlib/src/tests/fef/fef_test.cpp b/searchlib/src/tests/fef/fef_test.cpp index 896a917d6e3..4d1163de6ee 100644 --- a/searchlib/src/tests/fef/fef_test.cpp +++ b/searchlib/src/tests/fef/fef_test.cpp @@ -94,6 +94,7 @@ TEST("verify size of essential fef classes") { EXPECT_EQUAL(24u,sizeof(TermFieldMatchDataPosition)); EXPECT_EQUAL(24u,sizeof(TermFieldMatchData::Features)); EXPECT_EQUAL(40u,sizeof(TermFieldMatchData)); + EXPECT_EQUAL(48u, sizeof(search::fef::FeatureExecutor)); } TEST_MAIN() { TEST_RUN_ALL(); } -- cgit v1.2.3 From 341038d7acd65046cf3224e64a2d666ac377137f Mon Sep 17 00:00:00 2001 From: Henning Baldersheim Date: Tue, 11 Feb 2020 12:04:44 +0000 Subject: Undo autoformat. --- .../src/main/java/com/yahoo/search/handler/SearchHandler.java | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java b/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java index b9ffb9b0cd0..0f0df3aa93e 100644 --- a/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java +++ b/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java @@ -159,10 +159,10 @@ public class SearchHandler extends LoggingRequestHandler { this.maxThreads = examineExecutor(executor); searchConnections = new Value(SEARCH_CONNECTIONS, statistics, - new Value.Parameters().setLogRaw(true).setLogMax(true) - .setLogMean(true).setLogMin(true) - .setNameExtension(true) - .setCallback(new MeanConnections())); + new Value.Parameters().setLogRaw(true).setLogMax(true) + .setLogMean(true).setLogMin(true) + .setNameExtension(true) + .setCallback(new MeanConnections())); this.hostResponseHeaderKey = hostResponseHeaderKey; this.numRequestsLeftToTrace = new AtomicLong(numQueriesToTraceOnDebugAfterStartup); -- cgit v1.2.3