You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@lucene.apache.org by "Chris M. Hostetter (Jira)" <ji...@apache.org> on 2020/05/01 00:16:00 UTC
[jira] [Commented] (SOLR-14451) debug=query does not reliably
ensure json.facet debug info returned in cloud clusters
[ https://issues.apache.org/jira/browse/SOLR-14451?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17097068#comment-17097068 ]
Chris M. Hostetter commented on SOLR-14451:
-------------------------------------------
NOTE: I'm not actively investigating this, just filed issue for tracking
----
Here's a quick and dirty example of how to reproduce -- notice when the output does or does not include {{"facet-trace"}}:
Single node...
{noformat}
hossman@slate:~/lucene/dev/solr [j11] [master] $ bin/solr -e schemaless -noprompt
...
hossman@slate:~/lucene/dev/solr [j11] [master] $ curl -sS -X POST 'http://localhost:8983/solr/gettingstarted/update?commit=true' -d '[{"id":"XXX","num":42}, {"id":"YYY", "num":99}]'
...
hossman@slate:~/lucene/dev/solr [j11] [master] $ curl -sS -X POST http://localhost:8983/solr/gettingstarted/query -d 'debug=query&rows=0&q=*:*&json.facet={ min:"min(num)" }'
{
"responseHeader":{
"status":0,
"QTime":5,
"params":{
"q":"*:*",
"json.facet":"{ min:\"min(num)\" }",
"debug":"query",
"rows":"0"}},
"response":{"numFound":2,"start":0,"docs":[]
},
"facets":{
"count":2,
"min":42},
"debug":{
"rawquerystring":"*:*",
"querystring":"*:*",
"parsedquery":"MatchAllDocsQuery(*:*)",
"parsedquery_toString":"*:*",
"facet-trace":{
"processor":"FacetQueryProcessor",
"elapse":0,
"query":null,
"domainSize":2},
"json":{"facet":{"min":"min(num)"}},
"QParser":"LuceneQParser"}}
hossman@slate:~/lucene/dev/solr [j11] [master] $ curl -sS -X POST http://localhost:8983/solr/gettingstarted/query -d 'debug=true&rows=0&q=*:*&json.facet={ min:"min(num)" }'
{
"responseHeader":{
"status":0,
"QTime":64,
"params":{
"q":"*:*",
"json.facet":"{ min:\"min(num)\" }",
"debug":"true",
"rows":"0"}},
"response":{"numFound":2,"start":0,"docs":[]
},
"facets":{
"count":2,
"min":42},
"debug":{
"rawquerystring":"*:*",
"querystring":"*:*",
"parsedquery":"MatchAllDocsQuery(*:*)",
"parsedquery_toString":"*:*",
"explain":{},
"facet-trace":{
"processor":"FacetQueryProcessor",
"elapse":6,
"query":null,
"domainSize":2},
"json":{"facet":{"min":"min(num)"}},
"QParser":"LuceneQParser",
"timing":{
"time":64.0,
"prepare":{
"time":34.0,
"query":{
"time":25.0},
"facet":{
"time":0.0},
"facet_module":{
"time":8.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":24.0,
"query":{
"time":13.0},
"facet":{
"time":0.0},
"facet_module":{
"time":9.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}}}}}
{noformat}
...compared to Cloud...
{noformat}
hossman@slate:~/lucene/dev/solr [j11] [master] $ bin/solr -e cloud -noprompt
...
hossman@slate:~/lucene/dev/solr [j11] [master] $ curl -sS -X POST 'http://localhost:8983/solr/gettingstarted/update?commit=true' -d '[{"id":"XXX","num":42}, {"id":"YYY", "num":99}]'
...
hossman@slate:~/lucene/dev/solr [j11] [master] $ curl -sS -X POST http://localhost:8983/solr/gettingstarted/query -d 'debug=query&rows=0&q=*:*&json.facet={ min:"min(num)" }'
{
"responseHeader":{
"zkConnected":true,
"status":0,
"QTime":26,
"params":{
"q":"*:*",
"json.facet":"{ min:\"min(num)\" }",
"debug":"query",
"rows":"0"}},
"response":{"numFound":2,"start":0,"maxScore":1.0,"docs":[]
},
"facets":{
"count":2,
"min":42},
"debug":{
"rawquerystring":"*:*",
"querystring":"*:*",
"parsedquery":"MatchAllDocsQuery(*:*)",
"parsedquery_toString":"*:*",
"QParser":"LuceneQParser"}}
hossman@slate:~/lucene/dev/solr [j11] [master] $ curl -sS -X POST http://localhost:8983/solr/gettingstarted/query -d 'debug=true&rows=0&q=*:*&json.facet={ min:"min(num)" }'
{
"responseHeader":{
"zkConnected":true,
"status":0,
"QTime":75,
"params":{
"q":"*:*",
"json.facet":"{ min:\"min(num)\" }",
"debug":"true",
"rows":"0"}},
"response":{"numFound":2,"start":0,"maxScore":1.0,"docs":[]
},
"facets":{
"count":2,
"min":42},
"debug":{
"track":{
"rid":"localhost-gettingstarted_shard1_replica_n1-1588284136131-0",
"EXECUTE_QUERY":{
"http://localhost:7574/solr/gettingstarted_shard2_replica_n4/|http://localhost:8983/solr/gettingstarted_shard2_replica_n6/":{
"QTime":"7",
"ElapsedTime":"13",
"RequestPurpose":"GET_TOP_IDS,SET_TERM_STATS",
"NumFound":"0",
"Response":"{responseHeader={zkConnected=true, status=0, QTime=7, params={df=_text_, distrib=false, debug=[false, timing, track], qt=/query, _facet_={}, fl=[id, score], shards.purpose=1064964, start=0, fsv=true, shard.url=http://localhost:7574/solr/gettingstarted_shard2_replica_n4/|http://localhost:8983/solr/gettingstarted_shard2_replica_n6/, rows=0, rid=localhost-gettingstarted_shard1_replica_n1-1588284136131-0, version=2, q=*:*, json.facet={ min:\"min(num)\" }, omitHeader=false, requestPurpose=GET_TOP_IDS,SET_TERM_STATS, NOW=1588284136130, isShard=true, wt=javabin, debugQuery=false}}, response={numFound=0,start=0,maxScore=0.0,docs=[]}, sort_values={}, facets={count=0}, debug={facet-trace={processor=FacetQueryProcessor, elapse=0, query=null, domainSize=0}, json={facet={min=min(num)}}, timing={time=6.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=5.0, query={time=3.0}, facet={time=0.0}, facet_module={time=1.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}}}}}"},
"http://localhost:8983/solr/gettingstarted_shard1_replica_n1/|http://localhost:7574/solr/gettingstarted_shard1_replica_n2/":{
"QTime":"38",
"ElapsedTime":"54",
"RequestPurpose":"GET_TOP_IDS,SET_TERM_STATS",
"NumFound":"2",
"Response":"{responseHeader={zkConnected=true, status=0, QTime=38, params={df=_text_, distrib=false, debug=[false, timing, track], qt=/query, _facet_={}, fl=[id, score], shards.purpose=1064964, start=0, fsv=true, shard.url=http://localhost:8983/solr/gettingstarted_shard1_replica_n1/|http://localhost:7574/solr/gettingstarted_shard1_replica_n2/, rows=0, rid=localhost-gettingstarted_shard1_replica_n1-1588284136131-0, version=2, q=*:*, json.facet={ min:\"min(num)\" }, omitHeader=false, requestPurpose=GET_TOP_IDS,SET_TERM_STATS, NOW=1588284136130, isShard=true, wt=javabin, debugQuery=false}}, response={numFound=2,start=0,maxScore=1.0,docs=[]}, sort_values={}, facets={count=2, min=42}, debug={facet-trace={processor=FacetQueryProcessor, elapse=7, query=null, domainSize=2}, json={facet={min=min(num)}}, timing={time=37.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=34.0, query={time=24.0}, facet={time=0.0}, facet_module={time=10.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}}}}}"}}},
"facet-trace":{
"processor":"FacetQueryProcessor",
"elapse":7,
"query":null,
"domainSize":2},
"json":{"facet":{"min":"min(num)"}},
"timing":{
"time":43.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":39.0,
"query":{
"time":27.0},
"facet":{
"time":0.0},
"facet_module":{
"time":11.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}}},
"rawquerystring":"*:*",
"querystring":"*:*",
"parsedquery":"MatchAllDocsQuery(*:*)",
"parsedquery_toString":"*:*",
"QParser":"LuceneQParser",
"explain":{}}}
{noformat}
> debug=query does not reliably ensure json.facet debug info returned in cloud clusters
> -------------------------------------------------------------------------------------
>
> Key: SOLR-14451
> URL: https://issues.apache.org/jira/browse/SOLR-14451
> Project: Solr
> Issue Type: Bug
> Security Level: Public(Default Security Level. Issues are Public)
> Components: Facet Module, SolrCloud
> Reporter: Chris M. Hostetter
> Priority: Major
>
> While working on a randomized cloud test in SOLR-13132 that needs to inspect the {{"facet-trace"}} debug output to inspect the processor used (among other details), i discovered that {{FacetModule}} would not reliably initialize the {{FactDebugInfo}} container when using {{debug=query}} in the request.
> AFAICT, it *does* appear to always track & return facet debugging info when using {{debug=true}} instead - but i haven't rigerously proved this.
> Under the covers, {{FacetModule}} is just checking {{ResponseBuilder.isDebug()}} - an old "back compat" API for components to check before we started breaking down multiple types of "debug" info - that should return true anytime {{debug=query}} is set, so there is really no logical reason why this shouldn't work... it's got to be a bug somewhere (it doesn't seem tied to the request, but does break on diff randomized indexes, so perhaps it's related to the document/bucket distribution? or maybe something more low level and unrelated to FacetModule at all?)
> ----
> It only seems to be a problem in cloud mode - i haven't observed FacetModule's debug output behave any differently between {{debug=query}} vs {{debug=true}} in single node mode.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org