Term Vectors: requests are now timed

When asking for term statistics, generating term vectors on the fly or with
`dfs` set to `true`, some requests may take a while, so it is useful to know
exactly how long.

Closes #9583

src/main/java/org/elasticsearch/action/termvectors/TermVectorsRequest.java

@@ -77,6 +77,8 @@ public class TermVectorsRequest extends SingleShardOperationRequest<TermVectorsR
     private EnumSet<Flag> flagsEnum = EnumSet.of(Flag.Positions, Flag.Offsets, Flag.Payloads,
             Flag.FieldStatistics);
 
+    long startTime;
+
     public TermVectorsRequest() {
     }
 
@@ -100,13 +102,22 @@ public class TermVectorsRequest extends SingleShardOperationRequest<TermVectorsR
         super(other.index());
         this.id = other.id();
         this.type = other.type();
+        if (this.doc != null) {
+            this.doc = other.doc().copyBytesArray();
+        }
         this.flagsEnum = other.getFlags().clone();
         this.preference = other.preference();
         this.routing = other.routing();
         if (other.selectedFields != null) {
             this.selectedFields = new HashSet<>(other.selectedFields);
         }
+        if (other.perFieldAnalyzer != null) {
+            this.perFieldAnalyzer = new HashMap<>(other.perFieldAnalyzer);
+        }
         this.realtime = other.realtime();
+        this.version = other.version();
+        this.versionType = VersionType.fromValue(other.versionType().getValue());
+        this.startTime = other.startTime();
     }
 
     public TermVectorsRequest(MultiGetRequest.Item item) {
@@ -387,6 +398,10 @@ public class TermVectorsRequest extends SingleShardOperationRequest<TermVectorsR
         }
     }
 
+    public long startTime() {
+        return this.startTime;
+    }
+
     @Override
     public ActionRequestValidationException validate() {
         ActionRequestValidationException validationException = super.validate();

src/main/java/org/elasticsearch/action/termvectors/TermVectorsResponse.java

@@ -36,6 +36,7 @@ import org.elasticsearch.common.bytes.BytesReference;
 import org.elasticsearch.common.io.stream.BytesStreamOutput;
 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;
@@ -70,9 +71,9 @@ public class TermVectorsResponse extends ActionResponse implements ToXContent {
         public static final XContentBuilderString _ID = new XContentBuilderString("_id");
         public static final XContentBuilderString _VERSION = new XContentBuilderString("_version");
         public static final XContentBuilderString FOUND = new XContentBuilderString("found");
+        public static final XContentBuilderString TOOK = new XContentBuilderString("took");
         public static final XContentBuilderString TERMS = new XContentBuilderString("terms");
         public static final XContentBuilderString TERM_VECTORS = new XContentBuilderString("term_vectors");
-
     }
 
     private BytesReference termVectors;
@@ -83,6 +84,7 @@ public class TermVectorsResponse extends ActionResponse implements ToXContent {
     private long docVersion;
     private boolean exists = false;
     private boolean artificial = false;
+    private long tookInMillis;
 
     private boolean sourceCopied = false;
 
@@ -108,6 +110,8 @@ public class TermVectorsResponse extends ActionResponse implements ToXContent {
         out.writeVLong(docVersion);
         final boolean docExists = isExists();
         out.writeBoolean(docExists);
+        out.writeBoolean(artificial);
+        out.writeVLong(tookInMillis);
         out.writeBoolean(hasTermVectors());
         if (hasTermVectors()) {
             out.writeBytesReference(headerRef);
@@ -127,6 +131,8 @@ public class TermVectorsResponse extends ActionResponse implements ToXContent {
         id = in.readString();
         docVersion = in.readVLong();
         exists = in.readBoolean();
+        artificial = in.readBoolean();
+        tookInMillis = in.readVLong();
         if (in.readBoolean()) {
             headerRef = in.readBytesReference();
             termVectors = in.readBytesReference();
@@ -172,6 +178,7 @@ public class TermVectorsResponse extends ActionResponse implements ToXContent {
         }
         builder.field(FieldStrings._VERSION, docVersion);
         builder.field(FieldStrings.FOUND, isExists());
+        builder.field(FieldStrings.TOOK, tookInMillis);
         if (!isExists()) {
             return builder;
         }
@@ -313,6 +320,18 @@ public class TermVectorsResponse extends ActionResponse implements ToXContent {
         }
     }
 
+    public void updateTookInMillis(long startTime) {
+        this.tookInMillis = Math.max(1, System.currentTimeMillis() - startTime);
+    }
+
+    public TimeValue getTook() {
+        return new TimeValue(tookInMillis);
+    }
+
+    public long getTookInMillis() {
+        return tookInMillis;
+    }
+
     public boolean isExists() {
         return exists;
     }
@@ -331,7 +350,6 @@ public class TermVectorsResponse extends ActionResponse implements ToXContent {
         if (termVectorsByField != null) {
             tvw.setFields(termVectorsByField, selectedFields, flags, topLevelFields, dfs);
         }
-
     }
 
     public void setTermVectorsField(BytesStreamOutput output) {

src/main/java/org/elasticsearch/action/termvectors/TransportMultiTermVectorsAction.java

@@ -62,6 +62,7 @@ public class TransportMultiTermVectorsAction extends HandledTransportAction<Mult
         Map<ShardId, MultiTermVectorsShardRequest> shardRequests = new HashMap<>();
         for (int i = 0; i < request.requests.size(); i++) {
             TermVectorsRequest termVectorsRequest = request.requests.get(i);
+            termVectorsRequest.startTime = System.currentTimeMillis();
             termVectorsRequest.routing(clusterState.metaData().resolveIndexRouting(termVectorsRequest.routing(), termVectorsRequest.index()));
             if (!clusterState.metaData().hasConcreteIndex(termVectorsRequest.index())) {
                 responses.set(i, new MultiTermVectorsItemResponse(null, new MultiTermVectorsResponse.Failure(termVectorsRequest.index(),
@@ -80,7 +81,6 @@ public class TransportMultiTermVectorsAction extends HandledTransportAction<Mult
             if (shardRequest == null) {
                 shardRequest = new MultiTermVectorsShardRequest(request, shardId.index().name(), shardId.id());
                 shardRequest.preference(request.preference);
-
                 shardRequests.put(shardId, shardRequest);
             }
             shardRequest.add(i, termVectorsRequest);

src/main/java/org/elasticsearch/action/termvectors/TransportShardMultiTermsVectorAction.java

@@ -30,8 +30,8 @@ import org.elasticsearch.cluster.routing.ShardIterator;
 import org.elasticsearch.common.inject.Inject;
 import org.elasticsearch.common.settings.Settings;
 import org.elasticsearch.index.IndexService;
-import org.elasticsearch.index.shard.ShardId;
 import org.elasticsearch.index.shard.IndexShard;
+import org.elasticsearch.index.shard.ShardId;
 import org.elasticsearch.indices.IndicesService;
 import org.elasticsearch.threadpool.ThreadPool;
 import org.elasticsearch.transport.TransportService;
@@ -89,6 +89,7 @@ public class TransportShardMultiTermsVectorAction extends TransportShardSingleOp
                 IndexService indexService = indicesService.indexServiceSafe(request.index());
                 IndexShard indexShard = indexService.shardSafe(shardId.id());
                 TermVectorsResponse termVectorsResponse = indexShard.termVectorsService().getTermVectors(termVectorsRequest, shardId.getIndex());
+                termVectorsResponse.updateTookInMillis(termVectorsRequest.startTime());
                 response.add(request.locations.get(i), termVectorsResponse);
             } catch (Throwable t) {
                 if (TransportActions.isShardNotAvailableException(t)) {

src/main/java/org/elasticsearch/action/termvectors/TransportTermVectorsAction.java

@@ -20,6 +20,7 @@
 package org.elasticsearch.action.termvectors;
 
 import org.elasticsearch.ElasticsearchException;
+import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.RoutingMissingException;
 import org.elasticsearch.action.support.ActionFilters;
 import org.elasticsearch.action.support.single.shard.TransportShardSingleOperationAction;
@@ -42,6 +43,12 @@ public class TransportTermVectorsAction extends TransportShardSingleOperationAct
 
     private final IndicesService indicesService;
 
+    @Override
+    protected void doExecute(TermVectorsRequest request, ActionListener<TermVectorsResponse> listener) {
+        request.startTime = System.currentTimeMillis();
+        super.doExecute(request, listener);
+    }
+
     @Inject
     public TransportTermVectorsAction(Settings settings, ClusterService clusterService, TransportService transportService,
                                       IndicesService indicesService, ThreadPool threadPool, ActionFilters actionFilters) {
@@ -80,7 +87,9 @@ public class TransportTermVectorsAction extends TransportShardSingleOperationAct
     protected TermVectorsResponse shardOperation(TermVectorsRequest request, ShardId shardId) throws ElasticsearchException {
         IndexService indexService = indicesService.indexServiceSafe(shardId.getIndex());
         IndexShard indexShard = indexService.shardSafe(shardId.id());
-        return indexShard.termVectorsService().getTermVectors(request, shardId.getIndex());
+        TermVectorsResponse response = indexShard.termVectorsService().getTermVectors(request, shardId.getIndex());
+        response.updateTookInMillis(request.startTime());
+        return response;
     }
 
     @Override

src/test/java/org/elasticsearch/action/termvectors/GetTermVectorsCheckDocFreqTests.java

@@ -146,7 +146,7 @@ public class GetTermVectorsCheckDocFreqTests extends ElasticsearchIntegrationTes
         response.toXContent(xBuilder, null);
         xBuilder.endObject();
         BytesStream bytesStream = xBuilder.bytesStream();
-        String utf8 = bytesStream.bytes().toUtf8();
+        String utf8 = bytesStream.bytes().toUtf8().replaceFirst("\"took\":\\d+,", "");;
         String expectedString = "{\"_index\":\"test\",\"_type\":\"type1\",\"_id\":\""
                 + i
                 + "\",\"_version\":1,\"found\":true,\"term_vectors\":{\"field\":{\"terms\":{\"brown\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":2,\"start_offset\":10,\"end_offset\":15,\"payload\":\"d29yZA==\"}]},\"dog\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":8,\"start_offset\":40,\"end_offset\":43,\"payload\":\"d29yZA==\"}]},\"fox\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":3,\"start_offset\":16,\"end_offset\":19,\"payload\":\"d29yZA==\"}]},\"jumps\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":4,\"start_offset\":20,\"end_offset\":25,\"payload\":\"d29yZA==\"}]},\"lazy\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":7,\"start_offset\":35,\"end_offset\":39,\"payload\":\"d29yZA==\"}]},\"over\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":5,\"start_offset\":26,\"end_offset\":30,\"payload\":\"d29yZA==\"}]},\"quick\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":1,\"start_offset\":4,\"end_offset\":9,\"payload\":\"d29yZA==\"}]},\"the\":{\"doc_freq\":15,\"ttf\":30,\"term_freq\":2,\"tokens\":[{\"position\":0,\"start_offset\":0,\"end_offset\":3,\"payload\":\"d29yZA==\"},{\"position\":6,\"start_offset\":31,\"end_offset\":34,\"payload\":\"d29yZA==\"}]}}}}}";
@@ -203,7 +203,7 @@ public class GetTermVectorsCheckDocFreqTests extends ElasticsearchIntegrationTes
         response.toXContent(xBuilder, null);
         xBuilder.endObject();
         BytesStream bytesStream = xBuilder.bytesStream();
-        String utf8 = bytesStream.bytes().toUtf8();
+        String utf8 = bytesStream.bytes().toUtf8().replaceFirst("\"took\":\\d+,", "");;
         String expectedString = "{\"_index\":\"test\",\"_type\":\"type1\",\"_id\":\""
                 + i
                 + "\",\"_version\":1,\"found\":true,\"term_vectors\":{\"field\":{\"field_statistics\":{\"sum_doc_freq\":120,\"doc_count\":15,\"sum_ttf\":135},\"terms\":{\"brown\":{\"term_freq\":1,\"tokens\":[{\"position\":2,\"start_offset\":10,\"end_offset\":15,\"payload\":\"d29yZA==\"}]},\"dog\":{\"term_freq\":1,\"tokens\":[{\"position\":8,\"start_offset\":40,\"end_offset\":43,\"payload\":\"d29yZA==\"}]},\"fox\":{\"term_freq\":1,\"tokens\":[{\"position\":3,\"start_offset\":16,\"end_offset\":19,\"payload\":\"d29yZA==\"}]},\"jumps\":{\"term_freq\":1,\"tokens\":[{\"position\":4,\"start_offset\":20,\"end_offset\":25,\"payload\":\"d29yZA==\"}]},\"lazy\":{\"term_freq\":1,\"tokens\":[{\"position\":7,\"start_offset\":35,\"end_offset\":39,\"payload\":\"d29yZA==\"}]},\"over\":{\"term_freq\":1,\"tokens\":[{\"position\":5,\"start_offset\":26,\"end_offset\":30,\"payload\":\"d29yZA==\"}]},\"quick\":{\"term_freq\":1,\"tokens\":[{\"position\":1,\"start_offset\":4,\"end_offset\":9,\"payload\":\"d29yZA==\"}]},\"the\":{\"term_freq\":2,\"tokens\":[{\"position\":0,\"start_offset\":0,\"end_offset\":3,\"payload\":\"d29yZA==\"},{\"position\":6,\"start_offset\":31,\"end_offset\":34,\"payload\":\"d29yZA==\"}]}}}}}";
@@ -263,7 +263,7 @@ public class GetTermVectorsCheckDocFreqTests extends ElasticsearchIntegrationTes
         response.toXContent(xBuilder, ToXContent.EMPTY_PARAMS);
         xBuilder.endObject();
         BytesStream bytesStream = xBuilder.bytesStream();
-        String utf8 = bytesStream.bytes().toUtf8();
+        String utf8 = bytesStream.bytes().toUtf8().replaceFirst("\"took\":\\d+,", "");;
         String expectedString = "{\"_index\":\"test\",\"_type\":\"type1\",\"_id\":\""
                 + i
                 + "\",\"_version\":1,\"found\":true,\"term_vectors\":{\"field\":{\"field_statistics\":{\"sum_doc_freq\":120,\"doc_count\":15,\"sum_ttf\":135},\"terms\":{\"brown\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":2,\"start_offset\":10,\"end_offset\":15,\"payload\":\"d29yZA==\"}]},\"dog\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":8,\"start_offset\":40,\"end_offset\":43,\"payload\":\"d29yZA==\"}]},\"fox\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":3,\"start_offset\":16,\"end_offset\":19,\"payload\":\"d29yZA==\"}]},\"jumps\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":4,\"start_offset\":20,\"end_offset\":25,\"payload\":\"d29yZA==\"}]},\"lazy\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":7,\"start_offset\":35,\"end_offset\":39,\"payload\":\"d29yZA==\"}]},\"over\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":5,\"start_offset\":26,\"end_offset\":30,\"payload\":\"d29yZA==\"}]},\"quick\":{\"doc_freq\":15,\"ttf\":15,\"term_freq\":1,\"tokens\":[{\"position\":1,\"start_offset\":4,\"end_offset\":9,\"payload\":\"d29yZA==\"}]},\"the\":{\"doc_freq\":15,\"ttf\":30,\"term_freq\":2,\"tokens\":[{\"position\":0,\"start_offset\":0,\"end_offset\":3,\"payload\":\"d29yZA==\"},{\"position\":6,\"start_offset\":31,\"end_offset\":34,\"payload\":\"d29yZA==\"}]}}}}}";