Solr Performance Issues in Catalog-Next

[thejuliekramer]

Load testing #449 in catalog-next has shown us that solr is not performing as it should.

How to reproduce

1. Run load tests using the load testing tool and observe solr performance in NewRelic

Expected behavior

Solr should have less than a 500 ms response time

Actual behavior

Solr has a 500 ms response time

[thejuliekramer]

Logs from solr -> https://drive.google.com/file/d/1j1HoAd25PTymTmngxkD42xxJff9LDjvu/view?usp=drive_open

[avdata99]

Using this SOLR log tool I get this summary:

* Instance Report: solr.log
      QPS: 7.305192E-5  Errors: 0 OOMS: 0  

Searcher Report
-----------------
SolrIndexSearcher main open events: 0
SolrIndexSearcher realtime open events: 0
SolrIndexSearcher register events: 0


Commit Report
-----------------
Commits Found: 0
Contained Optimize: 0
Hard Commits: 0
Soft Commits: 0
With openSearcher: 0
Without openSearcher: 0

Query Report
-----------------

Approx QPS:7.305192E-5

Errors Report
-----------------
Errors found:0 OOMS:0

10 slowest queries:

Query: *:*
Info: [timestamp=2021-02-01 20:19:50.409, qtime=175, results=192195]
Log:  INFO  (qtp1761061602-458) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=187953&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=175

Query: *:*
Info: [timestamp=2021-02-01 20:05:50.753, qtime=172, results=192195]
Log:  INFO  (qtp1761061602-398) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=179510&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=172

Query: *:*
Info: [timestamp=2021-02-01 20:23:40.838, qtime=171, results=192195]
Log:  INFO  (qtp1761061602-490) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=174901&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=171

Query: *:*
Info: [timestamp=2021-02-01 20:08:05.710, qtime=167, results=192195]
Log:  INFO  (qtp1761061602-397) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=159489&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=167

Query: *:*
Info: [timestamp=2021-02-01 20:10:01.954, qtime=161, results=192195]
Log:  INFO  (qtp1761061602-400) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=175082&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=161

Query: *:*
Info: [timestamp=2021-02-01 20:09:49.075, qtime=159, results=192195]
Log:  INFO  (qtp1761061602-397) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=177738&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=159

Query: *:*
Info: [timestamp=2021-02-01 20:24:18.948, qtime=156, results=192195]
Log:  INFO  (qtp1761061602-458) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=182908&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=156

Query: *:*
Info: [timestamp=2021-02-01 20:13:27.731, qtime=153, results=192195]
Log:  INFO  (qtp1761061602-420) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=145801&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=153

Query: *:*
Info: [timestamp=2021-02-01 20:22:33.316, qtime=150, results=192195]
Log:  INFO  (qtp1761061602-481) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=151641&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=150

Query: *:*
Info: [timestamp=2021-02-01 20:15:01.417, qtime=150, results=192195]
Log:  INFO  (qtp1761061602-421) [   x:catalog-next] o.a.s.c.S.Request [catalog-next]  webapp=/solr path=/select 
params={facet.limit=50&q=*:*&fl=id+validated_data_dict&start=136766&sort=views_recent+desc&fq=%2Bcapacity:public++-dataset_type:harvest+-collection_package_id:[""+TO+*]&fq=%2Bsite_id:"geo.gov"&fq=%2Bstate:active&fq=%2Bpermission_labels:("public")&facet.mincount=1&rows=101&facet=true&wt=json} hits=192195 status=0 QTime=150

[thejuliekramer]

NewRelic breakdown of the solr search also says there are no slow queries

[ghost]

Hi @thejuliekramer and @avdata99. Could you estimate this issue?

[avdata99]

The slowest queries are those we use to get random datasets in our load testing tool
And they are not really slow: 0.175 seconds
In the load tests we call api-package-search ~1000 times and see:

• 10 errors (0.94%)
• 10224 milliseconds avg time
• 186 Minimum time (like the real SOLR time)
• 10000 median time

SOLR seems to work fine.

[avdata99]

PySolr was updated in catalog-next
Solr instances look good in the load tests.
With the correct weights defined in the tests, New Relic show us an acceptable Solr performance.

[FuhuXia]

Solr error found with version 3.9.0. Going back to 3.8.0. Need to check Solr performance.

[adborden]

Hmm, I thought we reverted back to pysolr 3.6, I guess that got lost in the fcs branch split? Or did we just not update the manifest file?