add slow query log

Summary:
add slow query log

add slow query log

add slow query log

add slow query log

shard int[]

add slow log

remove useless code

Reviewers: zhaoyonghui

Reviewed By: zhaoyonghui

Differential Revision: https://phabricator.d.xiaomi.net/D110039

demo/cars/conf/log4j2.xml

@@ -34,6 +34,16 @@
             </Policies>
             <DefaultRolloverStrategy max="7"/>
         </RollingFile>
+        <RollingFile name="slow" fileName="${sys:log.path}/linden-slow.log"
+            filePattern="${sys:log.path}/linden-slow-%d{yyyy-MM-dd}-%i.log" >
+            <PatternLayout>
+                <Pattern>%d [%t] %-5p %M(%F:%L) - %m%n</Pattern>
+            </PatternLayout>
+            <Policies>
+                <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
+            </Policies>
+            <DefaultRolloverStrategy max="7"/>
+        </RollingFile>
     </appenders>
     <loggers>
         <root level="info">
@@ -44,5 +54,9 @@
             <AppenderRef ref="index" level="info" />
             <AppenderRef ref="common" level="error" />
         </Logger>
+        <Logger name="com.xiaomi.linden.service.CoreLindenServiceImpl.SlowRequest" level="info" additivity="false">
+            <AppenderRef ref="slow"/>
+        </Logger>
+
     </loggers>
 </configuration>

linden-core/src/main/java/com/xiaomi/linden/core/LindenConfig.java

@@ -93,6 +93,7 @@ public enum CommandType {
   private boolean enableSourceFieldCache;
   private int indexSearcherParallelThreadNum;
   private String lindenWarmerFactory;
+  private int slowQueryThresholdMillis;
 
   private Map<String, LindenFieldSchema> fieldSchemaMap = new HashMap<>();
 
@@ -115,6 +116,7 @@ public LindenConfig() {
     this.indexManagerThreadNum = 11;
     this.enableSourceFieldCache = false;
     this.indexSearcherParallelThreadNum = 2 * Runtime.getRuntime().availableProcessors();
+    this.slowQueryThresholdMillis = 300;
   }
 
   public void putToProperties(String key, String val) {
@@ -433,6 +435,14 @@ public LindenConfig setLindenWarmerFactory(String lindenWarmerFactory) {
     return this;
   }
 
+  public int getSlowQueryThresholdMillis() {
+    return slowQueryThresholdMillis;
+  }
+
+  public void setSlowQueryThresholdMillis(int slowQueryThresholdMillis) {
+    this.slowQueryThresholdMillis = slowQueryThresholdMillis;
+  }
+
   public LindenFieldSchema getFieldSchema(String field) {
     LindenFieldSchema fieldSchema = fieldSchemaMap.get(field);
     if (fieldSchema != null) {

linden-core/src/main/java/com/xiaomi/linden/core/LindenConfigBuilder.java

@@ -58,6 +58,7 @@ public class LindenConfigBuilder {
   public static final String SEARCH_THREAD_POOL_JSON_CONFIG = "search.thread.pool.json.config";
   public static final String ENABLE_SOURCE_FIELD_CACHE = "enable.source.field.cache";
   public static final String INDEX_SEARCHER_PARALLEL_THREAD_NUM = "index.searcher.parallel.thread.num";
+  public static final String SLOW_QUERY_THRESHOLD_MILLIS = "slow.query.threshold.millis";
 
 
   protected static class FieldInfo {
@@ -119,6 +120,7 @@ public Class<?> getType() {
     fieldMap.put(SEARCH_THREAD_POOL_JSON_CONFIG, new FieldInfo("SearchThreadPoolConfig", String.class));
     fieldMap.put(ENABLE_SOURCE_FIELD_CACHE, new FieldInfo("EnableSourceFieldCache", boolean.class));
     fieldMap.put(INDEX_SEARCHER_PARALLEL_THREAD_NUM, new FieldInfo("IndexSearcherParallelThreadNum", int.class));
+    fieldMap.put(SLOW_QUERY_THRESHOLD_MILLIS,new FieldInfo("SlowQueryThresholdMillis",int.class));
 
   }
 

linden-core/src/main/java/com/xiaomi/linden/lucene/query/flexiblequery/FlexibleScoreModelStrategy.java

@@ -16,7 +16,6 @@
 
 import java.io.IOException;
 import java.util.Arrays;
-import java.util.List;
 
 import org.apache.lucene.search.Explanation;
 import org.apache.lucene.search.Query;
@@ -104,7 +103,7 @@ public int position(int field, int term) {
     return termMatchedInfo(field, term).position(doc());
   }
 
-  public List<Integer> positions(int field, int term) {
+  public int[] positions(int field, int term) {
     return termMatchedInfo(field, term).positions(doc());
   }
 

linden-core/src/main/java/com/xiaomi/linden/lucene/query/flexiblequery/TermDocsEnum.java

@@ -14,17 +14,15 @@
 
 package com.xiaomi.linden.lucene.query.flexiblequery;
 
+import java.io.IOException;
+
 import org.apache.lucene.index.DocsAndPositionsEnum;
 import org.apache.lucene.search.ComplexExplanation;
 import org.apache.lucene.search.DocIdSetIterator;
 import org.apache.lucene.search.Explanation;
 import org.apache.lucene.search.Query;
 import org.apache.lucene.search.similarities.Similarity;
 
-import java.io.IOException;
-import java.util.ArrayList;
-import java.util.List;
-
 public class TermDocsEnum {
 
   protected DocsAndPositionsEnum postings;
@@ -33,16 +31,18 @@ public class TermDocsEnum {
 
   protected int doc;
   private int position;
-  private List<Integer> positions;
+  private int[] positions;
   private int freq;
   protected int termPos = -1;
   protected int docFreq = -1;
 
   private int matchedDoc = -1;
   private int matchedPosition = -1;
-  private List<Integer> matchedPositions;
+  private int[] matchedPositions;
   private int matchedFreq = -1;
   private int field;
+  private int initPositionSize = 5;
+
 
   public TermDocsEnum(FlexibleQuery.FlexibleTerm term, int docFreq, DocsAndPositionsEnum postings,
                       Similarity.SimScorer docScorer, int field, int termPos) throws IOException {
@@ -53,12 +53,15 @@ public TermDocsEnum(FlexibleQuery.FlexibleTerm term, int docFreq, DocsAndPositio
     this.docScorer = docScorer;
     this.field = field;
     this.termPos = termPos;
+    this.positions = new int[initPositionSize];
+    this.matchedPositions = new int[initPositionSize];
   }
 
   public FlexibleQuery.FlexibleTerm term() {
     return term;
   }
 
+
   public float score(int doc) throws IOException {
     if (isMatched(doc)) {
       return docScorer.score(matchedDoc, matchedFreq);
@@ -77,11 +80,16 @@ public boolean next() throws IOException {
       return false;
     }
     freq = postings.freq();
-    positions = new ArrayList<>(freq);
+    if (freq > initPositionSize) {
+      int newSize = 2 * freq;
+      positions = new int[newSize];
+      matchedPositions = new int[newSize];
+      initPositionSize = newSize;
+    }
     for (int i = 0; i < freq; i++) {
-      positions.add(postings.nextPosition());
+      positions[i] = postings.nextPosition();
     }
-    position = positions.get(0);
+    position = positions[0];
     return true;
   }
 
@@ -98,8 +106,13 @@ public int position(int doc) {
     return doc == matchedDoc ? matchedPosition : -1;
   }
 
-  public List<Integer> positions(int doc) {
-    return doc == matchedDoc ? matchedPositions : null;
+  public int[] positions(int doc) {
+    if (doc == matchedDoc) {
+      int[] matchedPositionsData = new int[matchedFreq];
+      System.arraycopy(matchedPositions, 0, matchedPositionsData, 0, matchedFreq);
+      return matchedPositionsData;
+    }
+    return new int[0];
   }
 
   public String toString() {
@@ -134,10 +147,13 @@ public void saveMatchedInfo() {
     this.matchedDoc = doc;
     this.matchedPosition = position;
     this.matchedFreq = freq;
-    this.matchedPositions = positions;
+    for (int i = 0; i < matchedFreq; i++) {
+      matchedPositions[i] = positions[i];
+    }
   }
 
   public int getField() {
     return field;
   }
+
 }

linden-core/src/main/java/com/xiaomi/linden/service/CoreLindenServiceImpl.java

@@ -62,6 +62,8 @@
 public class CoreLindenServiceImpl implements LindenService.ServiceIface {
 
   private static final Logger LOGGER = LoggerFactory.getLogger(CoreLindenServiceImpl.class);
+  private static final Logger SLOW_LOGGER = LoggerFactory.getLogger("CoreLindenServiceImpl.SlowRequest");
+
 
   private final LindenCluster lindenCluster;
   private final BQLCompiler bqlCompiler;
@@ -79,6 +81,7 @@ public class CoreLindenServiceImpl implements LindenService.ServiceIface {
   private LindenWarmer lindenWarmer;
   private int instanceFuturePoolWaitTimeout;
   private int clusterFuturePoolWaitTimeout;
+  private int slowQueryThresholdMillis;
 
   public CoreLindenServiceImpl(final LindenConfig config) throws Exception {
     Preconditions.checkArgument(config != null, "LindenConfig can not be null.");
@@ -143,6 +146,8 @@ public CoreLindenServiceImpl(final LindenConfig config) throws Exception {
 
     bqlCompiler = new BQLCompiler(config.getSchema());
 
+    this.slowQueryThresholdMillis = config.getSlowQueryThresholdMillis();
+
     try {
       lindenCluster = new CoreLindenCluster(config, shardingStrategy, this);
     } catch (Exception e) {
@@ -222,8 +227,9 @@ public Future<LindenResult> search(final LindenSearchRequest request) {
       public LindenResult apply() {
         LindenResult result = null;
         String logTag = null;
+        long eps = 0;
         try {
-          long eps = sw.elapsed(TimeUnit.MILLISECONDS);
+          eps = sw.elapsed(TimeUnit.MILLISECONDS);
           if (eps > 10) {
             LOGGER.warn("Warning: instanceExecutorPool took " + eps + "ms to start search.");
             if (eps > instanceFuturePoolWaitTimeout) {
@@ -244,12 +250,19 @@ public LindenResult apply() {
           logTag = "instanceExceptionalSearch";
         } finally {
           metricsManager.time(sw.elapsed(TimeUnit.NANOSECONDS), logTag);
-          result.setCost((int) sw.elapsed(TimeUnit.MILLISECONDS));
+          long cost = sw.elapsed(TimeUnit.MILLISECONDS);
+          result.setCost((int)cost);
           if (result.isSuccess()) {
-            LOGGER.info("Instance search request succeeded, request: {}, hits: {}, cost: {} ms.", request,
-                        result.getHitsSize(), result.getCost());
+            if (cost >= slowQueryThresholdMillis) {
+              SLOW_LOGGER.warn("Slow request: {}, totalHits: {}, waits: {} ms , cost: {} ms.", request.getOriginQuery(),
+                               result.getTotalHits(), eps, result.getCost());
+            } else {
+              LOGGER.info("Instance search request succeeded, request: {}, hits: {}, cost: {} ms.",
+                          request.getOriginQuery(),
+                          result.getHitsSize(), result.getCost());
+            }
           } else {
-            LOGGER.error("Instance search request failed, request: {}, error: {}, cost: {} ms.", request,
+            LOGGER.error("Instance search request failed, request: {}, error: {}, cost: {} ms.", request.getOriginQuery(),
                          result.getError(), result.getCost());
           }
           return result;
@@ -350,7 +363,9 @@ public LindenResult apply() {
           }
           LindenRequest lindenRequest = bqlCompiler.compile(bql);
           if (lindenRequest.isSetSearchRequest()) {
-            result = lindenCore.search(lindenRequest.getSearchRequest());
+            LindenSearchRequest searchRequest = lindenRequest.getSearchRequest();
+            searchRequest.setOriginQuery(bql);
+            result = lindenCore.search(searchRequest);
             if (result.isSuccess()) {
               logTag = "singleInstanceSearch";
             } else {
@@ -445,7 +460,9 @@ public LindenResult apply() {
           }
           LindenRequest request = bqlCompiler.compile(bql);
           if (request.isSetSearchRequest()) {
-            result = lindenCluster.search(request.getSearchRequest());
+            LindenSearchRequest searchRequest = request.getSearchRequest();
+            searchRequest.setOriginQuery(bql);
+            result = lindenCluster.search(searchRequest);
             if (result.isSuccess()) {
               logTag = "search";
             } else {
@@ -542,7 +559,9 @@ public LindenResult apply() {
           }
           LindenRequest request = bqlCompiler.compile(bql);
           if (request.isSetSearchRequest()) {
-            result = lindenCluster.search(request.getSearchRequest());
+            LindenSearchRequest searchRequest = request.getSearchRequest();
+            searchRequest.setOriginQuery(bql);
+            result = lindenCluster.search(searchRequest);
             if (result.isSuccess()) {
               logTag = "search";
             } else {

linden-core/src/test/java/com/xiaomi/linden/lucene/query/flexiblequery/TestFlexibleQuery.java

@@ -185,15 +185,15 @@ public void testBasic() throws IOException {
           + "   int continuousMatches = 0;\n"
           + "     for (int i = 0; i < getFieldLength(); ++i) {\n"
           + "      int lastMatechedTermIdx = Integer.MIN_VALUE;\n"
-          + "      List<Integer> lastPositions = null;\n"
-          + "      List<Integer> curPositions;\n"
+          + "      int[] lastPositions = null;\n"
+          + "      int[] curPositions;\n"
           + "      for (int j = 0; j < getTermLength(); ++j) {\n"
           + "        if (isMatched(i, j)) {\n"
           + "          curPositions = positions(i, j);\n"
           + "          if (lastMatechedTermIdx + 1 == j) {\n"
-          + "            for (int ii = 0; ii < lastPositions.size(); ++ii)\n"
-          + "              for (int jj = 0; jj < curPositions.size(); ++jj) {\n"
-          + "                if (lastPositions.get(ii) + 1 == curPositions.get(jj)) {\n"
+          + "            for (int ii = 0; ii < lastPositions.length; ++ii)\n"
+          + "              for (int jj = 0; jj < curPositions.length; ++jj) {\n"
+          + "                if (lastPositions[ii] + 1 == curPositions[jj]) {\n"
           + "                  ++continuousMatches;\n"
           + "                }\n"
           + "              }\n"
@@ -229,15 +229,15 @@ public void testBasic() throws IOException {
           + "      int continuousMatches = 0;\n"
           + "      float fieldScore = 0f;\n"
           + "      int lastMatechedTermIdx = Integer.MIN_VALUE;\n"
-          + "      List<Integer> lastPositions = null;\n"
-          + "      List<Integer> curPositions;\n"
+          + "      int[] lastPositions = null;\n"
+          + "      int[] curPositions;\n"
           + "      for (int j = 0; j < getTermLength(); ++j) {\n"
           + "        if (isMatched(i, j)) {\n"
           + "          curPositions = positions(i, j);\n"
           + "          if (lastMatechedTermIdx + 1 == j) {\n"
-          + "            for (int ii = 0; ii < lastPositions.size(); ++ii)\n"
-          + "              for (int jj = 0; jj < curPositions.size(); ++jj) {\n"
-          + "                if (lastPositions.get(ii) + 1 == curPositions.get(jj)) {\n"
+          + "            for (int ii = 0; ii < lastPositions.length; ++ii)\n"
+          + "              for (int jj = 0; jj < curPositions.length; ++jj) {\n"
+          + "                if (lastPositions[ii] + 1 == curPositions[jj]) {\n"
           + "                  ++continuousMatches;\n"
           + "                }\n"
           + "              }\n"

linden-thrift/src/main/thrift/LindenRequest.thrift

@@ -305,6 +305,7 @@ struct LindenSearchRequest {
     14: optional list<string> sourceFields,
     15: optional list<string> indexNames,
     16: optional GroupParam groupParam,
+    17: optional string originQuery,
 }
 
 struct LindenDeleteRequest {