Search API: Add how long the search took (in milliseconds), closes el…

…astic#536.
medcl · Nov 24, 2010 · d150ac2 · d150ac2
1 parent 5127358
commit d150ac2
Show file tree

Hide file tree

Showing 9 changed files with 123 additions and 8 deletions.
diff --git a/...s/benchmark/micro/src/main/java/org/elasticsearch/benchmark/time/SimpleTimeBenchmark.java b/...s/benchmark/micro/src/main/java/org/elasticsearch/benchmark/time/SimpleTimeBenchmark.java
@@ -0,0 +1,64 @@
+/*
+ * Licensed to Elastic Search and Shay Banon under one
+ * or more contributor license agreements.  See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. Elastic Search 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.elasticsearch.benchmark.time;
+
+import org.elasticsearch.common.StopWatch;
+
+import java.util.UUID;
+import java.util.concurrent.CountDownLatch;
+
+/**
+ * @author kimchy (Shay Banon)
+ */
+public class SimpleTimeBenchmark {
+
+    private static long NUMBER_OF_ITERATIONS = 1000000;
+    private static int NUMBER_OF_THREADS = 100;
+
+    public static void main(String[] args) throws Exception {
+        StopWatch stopWatch = new StopWatch().start();
+        System.out.println("Running " + NUMBER_OF_ITERATIONS);
+        for (long i = 0; i < NUMBER_OF_ITERATIONS; i++) {
+            System.currentTimeMillis();
+        }
+        System.out.println("Took " + stopWatch.stop().totalTime() + " TP Millis " + (stopWatch.totalTime().millisFrac() / NUMBER_OF_ITERATIONS));
+
+        System.out.println("Running using " + NUMBER_OF_THREADS + " threads with " + NUMBER_OF_ITERATIONS + " iterations");
+        final CountDownLatch latch = new CountDownLatch(NUMBER_OF_THREADS);
+        Thread[] threads = new Thread[NUMBER_OF_THREADS];
+        for (int i = 0; i < threads.length; i++) {
+            threads[i] = new Thread(new Runnable() {
+                @Override public void run() {
+                    for (long i = 0; i < NUMBER_OF_ITERATIONS; i++) {
+                        System.currentTimeMillis();
+                    }
+                    latch.countDown();
+                }
+            });
+        }
+        stopWatch = new StopWatch().start();
+        for (Thread thread : threads) {
+            thread.start();
+        }
+        latch.await();
+        stopWatch.stop();
+        System.out.println("Took " + stopWatch.totalTime() + " TP Millis " + (stopWatch.totalTime().millisFrac() / (NUMBER_OF_ITERATIONS * NUMBER_OF_THREADS)));
+    }
+}
diff --git a/modules/elasticsearch/src/main/java/org/elasticsearch/action/search/SearchResponse.java b/modules/elasticsearch/src/main/java/org/elasticsearch/action/search/SearchResponse.java
@@ -22,6 +22,7 @@
 import org.elasticsearch.action.ActionResponse;
 import org.elasticsearch.common.io.stream.StreamInput;
 import org.elasticsearch.common.io.stream.StreamOutput;
+import org.elasticsearch.common.unit.TimeValue;
 import org.elasticsearch.common.xcontent.ToXContent;
 import org.elasticsearch.common.xcontent.XContentBuilder;
 import org.elasticsearch.common.xcontent.XContentBuilderString;
@@ -51,14 +52,17 @@ public class SearchResponse implements ActionResponse, ToXContent {
 
     private ShardSearchFailure[] shardFailures;
 
+    private long tookInMillis;
+
     SearchResponse() {
     }
 
-    public SearchResponse(InternalSearchResponse internalResponse, String scrollId, int totalShards, int successfulShards, ShardSearchFailure[] shardFailures) {
+    public SearchResponse(InternalSearchResponse internalResponse, String scrollId, int totalShards, int successfulShards, long tookInMillis, ShardSearchFailure[] shardFailures) {
         this.internalResponse = internalResponse;
         this.scrollId = scrollId;
         this.totalShards = totalShards;
         this.successfulShards = successfulShards;
+        this.tookInMillis = tookInMillis;
         this.shardFailures = shardFailures;
     }
 
@@ -90,6 +94,34 @@ public Facets getFacets() {
         return facets();
     }
 
+    /**
+     * How long the search took.
+     */
+    public TimeValue took() {
+        return new TimeValue(tookInMillis);
+    }
+
+    /**
+     * How long the search took.
+     */
+    public TimeValue getTook() {
+        return took();
+    }
+
+    /**
+     * How long the search took in milliseconds.
+     */
+    public long tookInMillis() {
+        return tookInMillis;
+    }
+
+    /**
+     * How long the search took in milliseconds.
+     */
+    public long getTookInMillis() {
+        return tookInMillis();
+    }
+
     /**
      * The total number of shards the search was executed on.
      */
@@ -172,12 +204,14 @@ static final class Fields {
         static final XContentBuilderString INDEX = new XContentBuilderString("index");
         static final XContentBuilderString SHARD = new XContentBuilderString("shard");
         static final XContentBuilderString REASON = new XContentBuilderString("reason");
+        static final XContentBuilderString TOOK = new XContentBuilderString("took");
     }
 
     @Override public void toXContent(XContentBuilder builder, Params params) throws IOException {
         if (scrollId != null) {
             builder.field(Fields._SCROLL_ID, scrollId);
         }
+        builder.field(Fields.TOOK, tookInMillis);
         builder.startObject(Fields._SHARDS);
         builder.field(Fields.TOTAL, totalShards());
         builder.field(Fields.SUCCESSFUL, successfulShards());
@@ -223,6 +257,7 @@ public static SearchResponse readSearchResponse(StreamInput in) throws IOExcepti
         if (in.readBoolean()) {
             scrollId = in.readUTF();
         }
+        tookInMillis = in.readVLong();
     }
 
     @Override public void writeTo(StreamOutput out) throws IOException {
@@ -241,5 +276,6 @@ public static SearchResponse readSearchResponse(StreamInput in) throws IOExcepti
             out.writeBoolean(true);
             out.writeUTF(scrollId);
         }
+        out.writeVLong(tookInMillis);
     }
 }
diff --git a/...main/java/org/elasticsearch/action/search/type/TransportSearchDfsQueryAndFetchAction.java b/...main/java/org/elasticsearch/action/search/type/TransportSearchDfsQueryAndFetchAction.java
@@ -170,7 +170,7 @@ private void innerFinishHim() {
             if (request.scroll() != null) {
                 scrollId = buildScrollId(request.searchType(), dfsResults);
             }
-            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildShardFailures()));
+            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildTookInMillis(), buildShardFailures()));
         }
     }
 }
diff --git a/...ain/java/org/elasticsearch/action/search/type/TransportSearchDfsQueryThenFetchAction.java b/...ain/java/org/elasticsearch/action/search/type/TransportSearchDfsQueryThenFetchAction.java
@@ -264,7 +264,7 @@ private void innerFinishHim() {
             if (request.scroll() != null) {
                 scrollId = TransportSearchHelper.buildScrollId(request.searchType(), dfsResults);
             }
-            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildShardFailures()));
+            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildTookInMillis(), buildShardFailures()));
         }
     }
 }
diff --git a/...rc/main/java/org/elasticsearch/action/search/type/TransportSearchQueryAndFetchAction.java b/...rc/main/java/org/elasticsearch/action/search/type/TransportSearchQueryAndFetchAction.java
@@ -82,7 +82,7 @@ private AsyncAction(SearchRequest request, ActionListener<SearchResponse> listen
             if (request.scroll() != null) {
                 scrollId = buildScrollId(request.searchType(), queryFetchResults.values());
             }
-            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildShardFailures()));
+            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildTookInMillis(), buildShardFailures()));
             searchCache.releaseQueryFetchResults(queryFetchResults);
         }
     }

diff --git a/...c/main/java/org/elasticsearch/action/search/type/TransportSearchQueryThenFetchAction.java b/...c/main/java/org/elasticsearch/action/search/type/TransportSearchQueryThenFetchAction.java
@@ -177,7 +177,7 @@ private void innerFinishHim() {
             if (request.scroll() != null) {
                 scrollId = TransportSearchHelper.buildScrollId(request.searchType(), queryResults.values());
             }
-            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildShardFailures()));
+            invokeListener(new SearchResponse(internalResponse, scrollId, expectedSuccessfulOps, successulOps.get(), buildTookInMillis(), buildShardFailures()));
         }
     }
 }
diff --git a/...n/java/org/elasticsearch/action/search/type/TransportSearchScrollQueryAndFetchAction.java b/...n/java/org/elasticsearch/action/search/type/TransportSearchScrollQueryAndFetchAction.java
@@ -91,6 +91,8 @@ private class AsyncAction {
 
         private final AtomicInteger counter;
 
+        private final long startTime = System.currentTimeMillis();
+
         private AsyncAction(SearchScrollRequest request, ParsedScrollId scrollId, ActionListener<SearchResponse> listener) {
             this.request = request;
             this.listener = listener;
@@ -209,7 +211,8 @@ private void innerFinishHim() {
                 scrollId = request.scrollId();
             }
             searchCache.releaseQueryFetchResults(queryFetchResults);
-            invokeListener(new SearchResponse(internalResponse, scrollId, this.scrollId.values().length, successfulOps.get(), buildShardFailures(shardFailures, searchCache)));
+            invokeListener(new SearchResponse(internalResponse, scrollId, this.scrollId.values().length, successfulOps.get(),
+                    System.currentTimeMillis() - startTime, buildShardFailures(shardFailures, searchCache)));
         }
 
         protected void invokeListener(final SearchResponse response) {

diff --git a/.../java/org/elasticsearch/action/search/type/TransportSearchScrollQueryThenFetchAction.java b/.../java/org/elasticsearch/action/search/type/TransportSearchScrollQueryThenFetchAction.java
@@ -97,6 +97,8 @@ private class AsyncAction {
 
         private final AtomicInteger successfulOps;
 
+        private final long startTime = System.currentTimeMillis();
+
         private AsyncAction(SearchScrollRequest request, ParsedScrollId scrollId, ActionListener<SearchResponse> listener) {
             this.request = request;
             this.listener = listener;
@@ -236,7 +238,8 @@ private void innerFinishHim() {
             if (request.scroll() != null) {
                 scrollId = request.scrollId();
             }
-            invokeListener(new SearchResponse(internalResponse, scrollId, this.scrollId.values().length, successfulOps.get(), buildShardFailures(shardFailures, searchCache)));
+            invokeListener(new SearchResponse(internalResponse, scrollId, this.scrollId.values().length, successfulOps.get(),
+                    System.currentTimeMillis() - startTime, buildShardFailures(shardFailures, searchCache)));
             searchCache.releaseQueryResults(queryResults);
             searchCache.releaseFetchResults(fetchResults);
         }

diff --git a/...csearch/src/main/java/org/elasticsearch/action/search/type/TransportSearchTypeAction.java b/...csearch/src/main/java/org/elasticsearch/action/search/type/TransportSearchTypeAction.java
@@ -96,6 +96,8 @@ protected abstract class BaseAsyncAction<FirstResult extends SearchPhaseResult>
 
         protected volatile ShardDoc[] sortedShardList;
 
+        protected final long startTime = System.currentTimeMillis();
+
         protected BaseAsyncAction(SearchRequest request, ActionListener<SearchResponse> listener) {
             this.request = request;
             this.listener = listener;
@@ -291,10 +293,17 @@ private void onFirstPhaseResult(ShardRouting shard, final ShardIterator shardIt,
             }
         }
 
+        /**
+         * Builds how long it took to execute the search.
+         */
+        protected final long buildTookInMillis() {
+            return System.currentTimeMillis() - startTime;
+        }
+
         /**
          * Builds the shard failures, and releases the cache (meaning this should only be called once!).
          */
-        protected ShardSearchFailure[] buildShardFailures() {
+        protected final ShardSearchFailure[] buildShardFailures() {
             return TransportSearchHelper.buildShardFailures(shardFailures, searchCache);
         }