Websphere Commerce + SolR: Burst of identical SolR queries fired - how to debug it?

Question

Out store is based on FEP4 and Madisons.

When we reload our store front page, we see bursts of identical SolR calls like these below.

EDIT: Note that it's lookups for the exact same product. So if we have 2 products we see 2 * 12 = 24 lookups, with two groups of 12 identical calls bursted right after each other.

How do we find out what causes these to be fired off? Yes, the results will likely be cached, but this is for each product, and on a heavy page the xmit/get/unpack/store work adds up to several seconds...

[10/23/13 18:27:26:933 CEST] 00000160 SystemOut     O WARN  [threadName='WebContainer : 0'] UserDataHelper.getXMBRCLUBRELAccessBean - No XMbrClubRel entry was found for userId -1002 in club 001
[10/23/13 18:27:27:217 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:250059&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=7 
[10/23/13 18:27:27:282 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:250059&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=7 
[10/23/13 18:27:27:353 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:250059&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=7 
[10/23/13 18:27:27:445 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:246411&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=6 
[10/23/13 18:27:27:526 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:246411&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=6 
[10/23/13 18:27:27:594 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:246411&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=7 
[10/23/13 18:27:27:681 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:243989&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=5 
[10/23/13 18:27:27:748 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:243989&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=7 
[10/23/13 18:27:27:818 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:243989&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=8 
[10/23/13 18:27:27:902 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:250059&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=8 
[10/23/13 18:27:27:965 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:246411&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=6 
[10/23/13 18:27:28:033 CEST] 00000162 SolrCore      I org.apache.solr.core.SolrCore execute [MC_10001_CatalogEntry_da_DK] webapp=/solr path=/select params={q=catentry_id:243989&start=0&timeAllowed=5000&wt=javabin&version=1&fq=storeent_id:("10151"+"10051")&fq=published:1&fq=(+%2B((((+%2BparentCatgroup_id_search:10001_10001+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_24451+%2Bads_f17_ntk_cs:"1")+(+%2BparentCatgroup_id_search:10001_32968+%2Bads_f17_ntk_cs:"1")+parentCatgroup_id_search:10001_32972+(+%2BparentCatgroup_id_search:10001_32973+%2Bads_f17_ntk_cs:"1"))+productset_id:("10004")+)+productset_id:("10003")+)+%2B*:*)&debugQuery=false&fl=catentry_id,price_DKK,storeent_id&rows=50} hits=1 status=0 QTime=7 

Answer 1

One really easy and quick win for websphere commerce performance is turing on the data object cache, I really don't know why they don't turn this on be default.

http://pic.dhe.ibm.com/infocenter/wchelp/v7r0m0/topic/com.ibm.commerce.admin.doc/tasks/tdcenabcommdatacache.htm

Answer 2

Looks like this is one for some category or search page. where for each and every product/item panel you are running a solr call (CatalogNavigationView BOD call from jsp which internally fires) to get a details.

You can change the way of you code flow by getting all data in a single BOD call, by passing multiple unique ids to single BOD call.

Moreover i feel SOLR calls are very light in nature so there is no much performance drawback for these number of calls.