Debug BardQueryInfo to show query split counting

CHANGELOG.md

@@ -203,6 +203,11 @@ Current
 
 ### Fixed:
 
+- [Debug BardQueryInfo to show query split counting](https://github.com/yahoo/fili/pull/596/files)
+    * Query counter in `BardQueryInfo` does not show up in logging because the counter used to be static and JSON
+      serializer does not serialize static fields.
+    * This externalizes the state via a getter for serialization.
+
 - [Fix intermittent class scanner error on DataSourceConstraint equal](https://github.com/yahoo/fili/pull/573)
    * Class Scanner Spec was injecting an improper dependant field due to type erasure.  Made field type explicit.
 

fili-core/src/main/java/com/yahoo/bard/webservice/logging/blocks/BardQueryInfo.java

@@ -4,7 +4,6 @@
 
 import com.yahoo.bard.webservice.logging.LogInfo;
 import com.yahoo.bard.webservice.logging.RequestLog;
-import com.yahoo.bard.webservice.web.ErrorMessageFormat;
 
 import com.fasterxml.jackson.annotation.JsonAutoDetect;
 
@@ -20,23 +19,17 @@
 /**
  * Main log of a request served by the TablesServlet.
  */
-@JsonAutoDetect(fieldVisibility = JsonAutoDetect.Visibility.ANY)
+@JsonAutoDetect(getterVisibility = JsonAutoDetect.Visibility.PUBLIC_ONLY)
 public class BardQueryInfo implements LogInfo {
     private static final Logger LOG = LoggerFactory.getLogger(BardQueryInfo.class);
-    private static final String WEIGHT_CHECK = "weight check queries count";
-    private static final String FACT_QUERIES = "fact queries count";
-    private static final String FACT_QUERY_CACHE_HIT  = "fact query cache hit count";
+    public static final String WEIGHT_CHECK = "weightCheckQueries";
+    public static final String FACT_QUERIES = "factQueryCount";
+    public static final String FACT_QUERY_CACHE_HIT = "factCacheHits";
 
-    protected static final Map<String, AtomicInteger> QUERY_COUNTER = Stream.of(
-            new AbstractMap.SimpleImmutableEntry<>(WEIGHT_CHECK, new AtomicInteger()),
-            new AbstractMap.SimpleImmutableEntry<>(FACT_QUERIES, new AtomicInteger()),
-            new AbstractMap.SimpleImmutableEntry<>(FACT_QUERY_CACHE_HIT, new AtomicInteger())
-    ).collect(Collectors.toMap(
-            AbstractMap.SimpleImmutableEntry::getKey,
-            AbstractMap.SimpleImmutableEntry::getValue
-    ));
-
-    protected final String type;
+    private final String type;
+    private final AtomicInteger weightCheckCount = new AtomicInteger();
+    private final AtomicInteger factQueryCount = new AtomicInteger();
+    private final AtomicInteger factCacheHitCount = new AtomicInteger();
 
     /**
      * Constructor.
@@ -47,25 +40,19 @@ public BardQueryInfo(String queryType) {
         this.type = queryType;
     }
 
-    /**
-     * Increments the number of fact queries.
-     */
-    public static void incrementCountFactHits() {
-        getBardQueryInfo().incrementCountFor(BardQueryInfo.FACT_QUERIES);
+    public String getType() {
+        return type;
     }
 
-    /**
-     * Increments the number of cache-hit queries.
-     */
-    public static void incrementCountCacheHits() {
-        getBardQueryInfo().incrementCountFor(BardQueryInfo.FACT_QUERY_CACHE_HIT);
-    }
-
-    /**
-     * Increments the number of weight check queries.
-     */
-    public static void incrementCountWeightCheck() {
-        getBardQueryInfo().incrementCountFor(BardQueryInfo.WEIGHT_CHECK);
+    public Map<String, AtomicInteger> getQueryCounter() {
+        return Stream.of(
+                new AbstractMap.SimpleImmutableEntry<>(WEIGHT_CHECK, weightCheckCount),
+                new AbstractMap.SimpleImmutableEntry<>(FACT_QUERIES, factQueryCount),
+                new AbstractMap.SimpleImmutableEntry<>(FACT_QUERY_CACHE_HIT, factCacheHitCount)
+        ).collect(Collectors.toMap(
+                AbstractMap.SimpleImmutableEntry::getKey,
+                AbstractMap.SimpleImmutableEntry::getValue
+        ));
     }
 
     /**
@@ -75,23 +62,28 @@ public static void incrementCountWeightCheck() {
      * @return {@link com.yahoo.bard.webservice.logging.blocks.BardQueryInfo} from
      * {@link com.yahoo.bard.webservice.logging.RequestLog}
      */
-    protected static BardQueryInfo getBardQueryInfo() {
+    public static BardQueryInfo getBardQueryInfo() {
         return ((BardQueryInfo) RequestLog.retrieve(BardQueryInfo.class));
     }
 
     /**
-     * Increments the number of a type of query, whose possible type are all specified in
-     * {@link com.yahoo.bard.webservice.logging.blocks.BardQueryInfo}.
-     *
-     * @param queryType  The type of the query
+     * Increments the number of fact queries.
+     */
+    public static void incrementCountFactHits() {
+        getBardQueryInfo().factQueryCount.incrementAndGet();
+    }
+
+    /**
+     * Increments the number of cache-hit queries.
      */
-    protected static void incrementCountFor(String queryType) {
-        AtomicInteger count = QUERY_COUNTER.get(queryType);
-        if (count == null) {
-            String message = ErrorMessageFormat.RESOURCE_RETRIEVAL_FAILURE.format(queryType);
-            LOG.error(message);
-            throw new IllegalArgumentException(message);
-        }
-        count.incrementAndGet();
+    public static void incrementCountCacheHits() {
+        getBardQueryInfo().factCacheHitCount.incrementAndGet();
+    }
+
+    /**
+     * Increments the number of weight check queries.
+     */
+    public static void incrementCountWeightCheck() {
+        getBardQueryInfo().weightCheckCount.incrementAndGet();
     }
 }

fili-core/src/main/java/com/yahoo/bard/webservice/web/handlers/AsyncWebServiceRequestHandler.java

@@ -52,7 +52,7 @@ public void invoke(JsonNode rootNode) {
         HttpErrorCallback error = response.getErrorCallback(druidQuery);
         FailureCallback failure = response.getFailureCallback(druidQuery);
 
-        BardQueryInfo.incrementCountFactHits();
+        BardQueryInfo.getBardQueryInfo().incrementCountFactHits();
         druidWebService.postDruidQuery(context, success, error, failure, druidQuery);
         return true;
     }

fili-core/src/main/java/com/yahoo/bard/webservice/web/handlers/CacheRequestHandler.java

@@ -84,7 +84,7 @@ public boolean handleRequest(
                 if (jsonResult != null) {
                     try {
                         if (context.getNumberOfOutgoing().decrementAndGet() == 0) {
-                            BardQueryInfo.incrementCountCacheHits();
+                            BardQueryInfo.getBardQueryInfo().incrementCountCacheHits();
                             RequestLog.stopTiming(REQUEST_WORKFLOW_TIMER);
                         }
 

fili-core/src/main/java/com/yahoo/bard/webservice/web/handlers/CacheV2RequestHandler.java

@@ -100,7 +100,7 @@ public boolean handleRequest(
                     ) {
                         try {
                             if (context.getNumberOfOutgoing().decrementAndGet() == 0) {
-                                BardQueryInfo.incrementCountCacheHits();
+                                BardQueryInfo.getBardQueryInfo().incrementCountCacheHits();
                                 RequestLog.stopTiming(REQUEST_WORKFLOW_TIMER);
                             }
 

fili-core/src/main/java/com/yahoo/bard/webservice/web/handlers/EtagCacheRequestHandler.java

@@ -90,7 +90,7 @@ public boolean handleRequest(
                             );
 
                     if (context.getNumberOfOutgoing().decrementAndGet() == 0) {
-                        BardQueryInfo.incrementCountCacheHits();
+                        BardQueryInfo.getBardQueryInfo().incrementCountCacheHits();
                         RequestLog.stopTiming(REQUEST_WORKFLOW_TIMER);
                     }
 

fili-core/src/main/java/com/yahoo/bard/webservice/web/handlers/WeightCheckRequestHandler.java

@@ -72,7 +72,7 @@ public boolean handleRequest(
             return next.handleRequest(context, request, druidQuery, response);
         }
 
-        BardQueryInfo.incrementCountWeightCheck();
+        BardQueryInfo.getBardQueryInfo().incrementCountWeightCheck();
         final WeightCheckResponseProcessor weightCheckResponse = new WeightCheckResponseProcessor(response);
         final DruidAggregationQuery<?> weightEvaluationQuery = queryWeightUtil.makeWeightEvaluationQuery(druidQuery);
         Granularity granularity = druidQuery.getInnermostQuery().getGranularity();

fili-core/src/test/groovy/com/yahoo/bard/webservice/logging/blocks/BardQueryInfoSpec.groovy

@@ -2,10 +2,13 @@
 // Licensed under the terms of the Apache license. Please see LICENSE.md file distributed with this work for terms.
 package com.yahoo.bard.webservice.logging.blocks
 
-import com.yahoo.bard.webservice.web.ErrorMessageFormat
+import com.yahoo.bard.webservice.application.ObjectMappersSuite
+
 import spock.lang.Specification
 import spock.lang.Unroll
 
+import java.util.concurrent.atomic.AtomicInteger
+
 class BardQueryInfoSpec extends Specification {
     BardQueryInfo bardQueryInfo
 
@@ -23,46 +26,30 @@ class BardQueryInfoSpec extends Specification {
     }
 
     @Unroll
-    def "incrementCountFor(#queryType) increments count of #queryType by 1"() {
+    def "increment Count For #queryType increments counter by 1"() {
+        setup:
+        AtomicInteger counter = BardQueryInfo.bardQueryInfo.queryCounter.get(queryType);
+
         expect: "count for #queryType is 0"
-        BardQueryInfo.QUERY_COUNTER.get(queryType).get() == 0
+        counter.get() == 0
 
         when: "calling incrementCountFor(#queryType)"
-        BardQueryInfo.incrementCountFor(queryType)
+        incrementor()
 
         then: "count of #queryType is incremented by 1"
-        BardQueryInfo.QUERY_COUNTER.get(queryType).get() == 1
+        counter.get() == 1
 
         where:
-        queryType                          | _
-        BardQueryInfo.WEIGHT_CHECK         | _
-        BardQueryInfo.FACT_QUERIES         | _
-        BardQueryInfo.FACT_QUERY_CACHE_HIT | _
+        queryType                          | incrementor
+        BardQueryInfo.WEIGHT_CHECK         | BardQueryInfo.&incrementCountWeightCheck
+        BardQueryInfo.FACT_QUERIES         | BardQueryInfo.&incrementCountFactHits
+        BardQueryInfo.FACT_QUERY_CACHE_HIT | BardQueryInfo.&incrementCountCacheHits
     }
 
-    def "incrementCountFor(String) throws IllegalArgumentException on non-existing query type"() {
-        when: "BardQueryInfo is given an unknown query type"
-        BardQueryInfo.incrementCountFor("nonExistingQueryType")
-
-        then: "IllegalArgumentException is thrown with exception message"
-        IllegalArgumentException illegalArgumentException = thrown()
-        illegalArgumentException.message == ErrorMessageFormat.RESOURCE_RETRIEVAL_FAILURE.format("nonExistingQueryType")
-    }
-
-    def "incrementCount*() methods increment their corresponding query type counts by 1"() {
-        expect: "all query counts are 0"
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.WEIGHT_CHECK).get() == 0
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.FACT_QUERIES).get() == 0
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.FACT_QUERY_CACHE_HIT).get() == 0
-
-        when: "calling incrementCount*() methods for all query types"
-        BardQueryInfo.incrementCountWeightCheck()
-        BardQueryInfo.incrementCountFactHits()
-        BardQueryInfo.incrementCountCacheHits()
-
-        then: "counts of all query types are incremented by 1"
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.WEIGHT_CHECK).get() == 1
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.FACT_QUERIES).get() == 1
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.FACT_QUERY_CACHE_HIT).get() == 1
+    def "Object serializes with type and map"() {
+        expect:
+        new ObjectMappersSuite().jsonMapper.writeValueAsString(
+                bardQueryInfo
+        ) == """{"type":"test","queryCounter":{"factQueryCount":0,"weightCheckQueries":0,"factCacheHits":0}}""";
     }
 }

fili-core/src/test/groovy/com/yahoo/bard/webservice/logging/blocks/BardQueryInfoUtils.groovy

@@ -4,8 +4,6 @@ package com.yahoo.bard.webservice.logging.blocks
 
 import com.yahoo.bard.webservice.logging.RequestLog
 
-import java.util.concurrent.atomic.AtomicInteger
-
 class BardQueryInfoUtils {
     /**
      * Constructs and returns a testing BardQueryInfo instance without a query type.
@@ -14,7 +12,7 @@ class BardQueryInfoUtils {
      */
     static BardQueryInfo initializeBardQueryInfo() {
         resetBardQueryInfo()
-        BardQueryInfo bardQueryInfo = new BardQueryInfo(null)
+        BardQueryInfo bardQueryInfo = new BardQueryInfo("test")
         RequestLog.getId() // initialize RequestLog
         RequestLog.record(bardQueryInfo)
         return bardQueryInfo
@@ -25,10 +23,5 @@ class BardQueryInfoUtils {
      */
     static void resetBardQueryInfo() {
         RequestLog.dump()
-
-        // reset counts of all query types after each individual test
-        for (Map.Entry<String, AtomicInteger> entry : BardQueryInfo.QUERY_COUNTER.entrySet()) {
-            entry.value = new AtomicInteger()
-        }
     }
 }

fili-core/src/test/groovy/com/yahoo/bard/webservice/web/handlers/AsyncWebServiceRequestHandlerSpec.groovy

@@ -21,8 +21,10 @@ import java.util.concurrent.Future
 
 class AsyncWebServiceRequestHandlerSpec extends Specification {
 
+    BardQueryInfo bardQueryInfo
+
     def setup() {
-        BardQueryInfoUtils.initializeBardQueryInfo()
+        bardQueryInfo = BardQueryInfoUtils.initializeBardQueryInfo()
     }
 
     def cleanup() {
@@ -47,7 +49,7 @@ class AsyncWebServiceRequestHandlerSpec extends Specification {
         boolean success
 
         expect:
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.FACT_QUERIES).get() == 0
+        bardQueryInfo.queryCounter.get(BardQueryInfo.FACT_QUERIES).get() == 0
 
         when:
         success = handler.handleRequest(rc, request, groupByQuery, response)
@@ -61,7 +63,7 @@ class AsyncWebServiceRequestHandlerSpec extends Specification {
             sc = a1
             return Mock(Future)
         }
-        BardQueryInfo.QUERY_COUNTER.get(BardQueryInfo.FACT_QUERIES).get() == 1
+        bardQueryInfo.queryCounter.get(BardQueryInfo.FACT_QUERIES).get() == 1
 
         when:
         sc.invoke(rootNode)