Add trace logging for responses coming from server (#50530) (#51221)

(cherry picked from commit 38eb485deffa175c7eb0b55a42a3e309f8a9802d)

x-pack/plugin/sql/src/main/java/org/elasticsearch/xpack/sql/execution/search/CompositeAggCursor.java

@@ -46,7 +46,7 @@ import java.util.function.Supplier;
  */
 public class CompositeAggCursor implements Cursor {
 
-    private final Logger log = LogManager.getLogger(getClass());
+    private static final Logger log = LogManager.getLogger(CompositeAggCursor.class);
 
     public static final String NAME = "c";
 
@@ -167,6 +167,9 @@ public class CompositeAggCursor implements Cursor {
             ActionListener<Page> listener,
             Schema schema) {
         
+        if (log.isTraceEnabled()) {
+            Querier.logSearchResponse(response, log);
+        }
         // there are some results
         if (response.getAggregations().asList().isEmpty() == false) {
             // retry

x-pack/plugin/sql/src/main/java/org/elasticsearch/xpack/sql/execution/search/Querier.java

@@ -69,6 +69,7 @@ import org.elasticsearch.xpack.sql.util.StringUtils;
 import java.io.IOException;
 import java.util.ArrayList;
 import java.util.BitSet;
+import java.util.Collections;
 import java.util.Comparator;
 import java.util.LinkedHashSet;
 import java.util.List;
@@ -84,7 +85,7 @@ import static org.elasticsearch.action.ActionListener.wrap;
 // TODO: add retry/back-off
 public class Querier {
 
-    private final Logger log = LogManager.getLogger(getClass());
+    private static final Logger log = LogManager.getLogger(Querier.class);
 
     private final PlanExecutor planExecutor;
     private final Configuration cfg;
@@ -150,6 +151,30 @@ public class Querier {
                         includeFrozen ? IndexResolver.FIELD_CAPS_FROZEN_INDICES_OPTIONS : IndexResolver.FIELD_CAPS_INDICES_OPTIONS)
                 .request();
     }
+    
+    protected static void logSearchResponse(SearchResponse response, Logger logger) {
+        List<Aggregation> aggs = Collections.emptyList();
+        if (response.getAggregations() != null) {
+            aggs = response.getAggregations().asList();
+        }
+        StringBuilder aggsNames = new StringBuilder();
+        for (int i = 0; i < aggs.size(); i++) {
+            aggsNames.append(aggs.get(i).getName() + (i + 1 == aggs.size() ? "" : ", "));
+        }
+        
+        logger.trace("Got search response [hits {} {}, {} aggregations: [{}], {} failed shards, {} skipped shards, "
+                + "{} successful shards, {} total shards, took {}, timed out [{}]]",
+                response.getHits().getTotalHits().relation.toString(),
+                response.getHits().getTotalHits().value,
+                aggs.size(),
+                aggsNames,
+                response.getFailedShards(),
+                response.getSkippedShards(),
+                response.getSuccessfulShards(),
+                response.getTotalShards(),
+                response.getTook(),
+                response.isTimedOut());
+    }
 
     /**
      * Listener used for local sorting (typically due to aggregations used inside `ORDER BY`).
@@ -280,6 +305,10 @@ public class Querier {
 
         @Override
         protected void handleResponse(SearchResponse response, ActionListener<Page> listener) {
+            if (log.isTraceEnabled()) {
+                logSearchResponse(response, log);
+            }
+            
             Aggregations aggs = response.getAggregations();
             if (aggs != null) {
                 Aggregation agg = aggs.get(Aggs.ROOT_GROUP_NAME);

x-pack/plugin/sql/src/main/java/org/elasticsearch/xpack/sql/execution/search/ScrollCursor.java

@@ -36,7 +36,7 @@ import static org.elasticsearch.action.ActionListener.wrap;
 
 public class ScrollCursor implements Cursor {
 
-    private final Logger log = LogManager.getLogger(getClass());
+    private static final Logger log = LogManager.getLogger(ScrollCursor.class);
 
     public static final String NAME = "s";
 
@@ -113,6 +113,9 @@ public class ScrollCursor implements Cursor {
     
     static void handle(SearchResponse response, Supplier<SearchHitRowSet> makeRowHit, Consumer<Page> onPage, Consumer<Page> clearScroll,
             Schema schema) {
+        if (log.isTraceEnabled()) {
+            Querier.logSearchResponse(response, log);
+        }
         SearchHit[] hits = response.getHits().getHits();
         // clean-up
         if (hits.length > 0) {