Add filter query tracing

[risdenk]

trafficstars

https://issues.apache.org/jira/browse/SOLR-XXXXX

Description

Adds a filter-query-trace to the debug output to be able to see how long each query took and how it contributed to the overall query time

    "filter-query-trace":{
      "elapsed":189,
      "fqMergeElapsed":0,
      "sub-filter-query":[{
        "query":"bu:`\b\u0000\u0000$u bu:`\b\u0000\u0000\u0005A",
        "elapsed":189
      }]
    },

Full output:

{
  "responseHeader":{
    "status":0,
    "QTime":191,
    "params":{
      "cache":"false",
      "df":"uid",
      "debug":"true",
      "indent":"true",
      "echoParams":"all",
      "fl":"uid",
      "q.op":"OR",
      "fq":"bu:4725 OR bu:705",
      "rows":"1",
      "title":"StandardRequestHandler",
      "q":"*:*",
      "defType":"lucene",
      "sow":"true",
      "multiThreaded":"false",
      "rid":"null-13"
    }
  },
  "response":{
    "numFound":19547791,
    "start":0,
    "numFoundExact":true,
    "docs":[{
      "uid":"1193331315"
    }]
  },
  "debug":{
    "rawquerystring":"*:*",
    "querystring":"*:*",
    "parsedquery":"MatchAllDocsQuery(*:*)",
    "parsedquery_toString":"*:*",
    "explain":{
      "1193331315":"\n1.0 = *:*\n"
    },
    "filter-query-trace":{
      "elapsed":189,
      "fqMergeElapsed":0,
      "sub-filter-query":[{
        "query":"bu:`\b\u0000\u0000$u bu:`\b\u0000\u0000\u0005A",
        "elapsed":189
      }]
    },
    "QParser":"LuceneQParser",
    "filter_queries":["bu:4725 OR bu:705"],
    "parsed_filter_queries":["bu:4725 bu:705"],
    "timing":{
      "time":191.0,
      "prepare":{
        "time":0.0,
        "query":{
          "time":0.0
        },
        "facet":{
          "time":0.0
        },
        "facet_module":{
          "time":0.0
        },
        "mlt":{
          "time":0.0
        },
        "highlight":{
          "time":0.0
        },
        "stats":{
          "time":0.0
        },
        "expand":{
          "time":0.0
        },
        "terms":{
          "time":0.0
        },
        "debug":{
          "time":0.0
        }
      },
      "process":{
        "time":190.0,
        "query":{
          "time":190.0
        },
        "facet":{
          "time":0.0
        },
        "facet_module":{
          "time":0.0
        },
        "mlt":{
          "time":0.0
        },
        "highlight":{
          "time":0.0
        },
        "stats":{
          "time":0.0
        },
        "expand":{
          "time":0.0
        },
        "terms":{
          "time":0.0
        },
        "debug":{
          "time":0.0
        }
      }
    }
  }
}

Solution

Please provide a short description of the approach taken to implement your solution.

Tests

Please describe the tests you've developed or run to confirm this patch implements the feature or solves the problem.

Checklist

Please review the following and check all that apply:

• [ ] I have reviewed the guidelines for How to Contribute and my code conforms to the standards described there to the best of my ability.
• [ ] I have created a Jira issue and added the issue ID to my pull request title.
• [ ] I have given Solr maintainers access to contribute to my PR branch. (optional but recommended, not available for branches on forks living under an organisation)
• [ ] I have developed this patch against the main branch.
• [ ] I have run ./gradlew check.
• [ ] I have added tests for my changes.
• [ ] I have added documentation for the Reference Guide

[dsmiley]

If you didn't know, the word "tracing" is an industry word nowadays, and Solr has it but this PR isn't using it :-)

[risdenk]

If you didn't know, the word "tracing" is an industry word nowadays, and Solr has it but this PR isn't using it :-)

This just uses the same logic that was already there for facet debugging - https://github.com/apache/solr/blob/main/solr/core/src/java/org/apache/solr/handler/component/DebugComponent.java#L111