lucene-solr-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jim Murphy <jim.mur...@pobox.com>
Subject Re: Slow Commits
Date Wed, 28 Oct 2009 16:34:28 GMT

Thanks Jerome,


1. I have shut off autowarming by setting params to 0.
2. My JVM Settings: -Xmx1200m -Xms1200m -XX:-UseGCOverheadLimit
-XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=50
3. I am using autocommits - every 60000 ms.  But the commit blocks all the
master request threadpool threads as it spends 2-3 minutes commiting.
4. I'm reluctant to NOT waitFlush since I don't want commits stacking up. 


Any other thoughts?

Thanks

Jim




Jérôme Etévé wrote:
> 
> Hi, here's two thing that can slow down commits:
> 
> 1) Autowarming the caches.
> 2) The Java old generation object garbage collection.
> 
> You can try:
> - Turning autowarming off (set autowarmCount="0"  in the caches
> configuration)
> - If you use the sun jvm, use  -XX:+UseConcMarkSweepGC to get a less
> blocking garbage collection.
> 
> You may also try to:
> - Not wait for the new searcher when you commit. The commit will then
> be instant from your posting application point of view. ( option
> waitSearcher=false  ).
> - Leave the commits to the server ( by setting autocommits in the
> solrconfig.xml). This is the best strategy if you've got lot of
> concurrent processes who posts.
> 
> Cheers.
> 
> Jerome.
> 
> 2009/10/28 Jim Murphy <jim.murphy@pobox.com>:
>>
>> Hi All,
>>
>> We have 8 solr shards, index is ~ 90M documents 190GB.  :)
>>
>> 4 of the shards have acceptable commit time - 30-60 seconds.  The other 4
>> have drifted over the last couple months to but up around 2-3 minutes. 
>> This
>> is killing our write throughput as you can imagine.
>>
>> I've included a log dump of a typical commit.  Not the large time period
>> (3:40) between the start commit log message and the OnCommit log message.
>> So, I think warming issues are not relevant.
>>
>> Any ideas what to debug at this point?
>>
>> I'm about to issue an optimize and see where that goes.  Its been a while
>> since I did that.
>>
>> Cheers,
>>
>> Jim
>>
>>
>>
>>
>> Oct 28, 2009 11:47:02 AM org.apache.solr.update.DirectUpdateHandler2
>> commit
>> INFO: start commit(optimize=false,waitFlush=true,waitSearcher=true)
>> Oct 28, 2009 11:50:43 AM org.apache.solr.core.SolrDeletionPolicy onCommit
>> INFO: SolrDeletionPolicy.onCommit: commits:num=2
>>
>> commit{dir=/master/data/index,segFN=segments_8us4,version=1228872482131,generation=413140,filenames=[segments_8us4,
>> _alae.fnm, _ai
>> lk.tis, _ala9.fnm, _ala9.fdx, _alac.fnm, _al9w_h.del, _alab.prx,
>> _ala9.fdt,
>> _a61p_b76.del, _alab.fnm, _al8x.frq, _al7i_2f.del, _akh1.tis,
>> _add1.frq, _alae.tis, _alad_1.del, _alaa.fnm, _alad.nrm, _al9w.frq,
>> _alae.tii, _ailk.tii, _add1.tis, _alac.tii, _akuu.tis, _add1.tii, _ail
>> k.frq, _alac.tis, _7zfh.tii, _962y.tis, _ala7.frq, _ah91.prx, _akuu.tii,
>> _alab_3.del, _ah91.fnm, _7zfh.tis, _ala8.frq, _962y.tii, _alae.pr
>> x, _a61p.fdt, _akuu.frq, _a61p.fdx, _al7i.fdx, _al2o.tis, _al9w.tis,
>> _ala7.fnm, _a61p.frq, _akzu.fnm, _9wzn.fnm, _akh1.prx, _al7i.fdt, _al
>> a9_2.del, _962y.prx, _al7i.prx, _al9w.tii, _alaa_4.del, _al7i.frq,
>> _ah91.tii, _ala8.nrm, _962y.fdt, _add1_62u.del, _alae.nrm, _ah91.tis, _
>> 962y.fdx, _akh1.fnm, _al8x.prx, _al2o.tii, _ala7.fdx, _ala9.prx,
>> _ala7.fdt,
>> _al9w.prx, _ala8.prx, _akh1.tii, _al2o.fdx, _7zfh.frq, _alac_3
>> .del, _akzu.tii, _akzu.fdt, _alad.fnm, _akzu.tis, _alab.nrm, _akzu.fdx,
>> _al2o.fnm, _al2o.fdt, _alaa.prx, _alaa.nrm, _962y.fnm, _ala7.prx,
>> _alaa.tis, _ailk.fdt, _akzu_8d.del, _alac.frq, _akzu.prx, _ala9.nrm,
>> _ailk.prx, _ala9.tis, _alaa.tii, _alae.frq, _add1.fnm, _7zfh.prx, _al
>> 9w.fnm, _ala9.tii, _ala9.frq, _962y.nrm, _alab.frq, _ala8.fdx, _al8x.fnm,
>> _a61p.prx, _7zfh.fnm, _ala8.fdt, _ailk.fdx, _alaa.frq, _7zfh.fdx
>> , _al7i.tis, _ah91.fdt, _ailk.fnm, _9wzn_i0m.del, _ah91.fdx, _al7i.tii,
>> _ailk_24j.del, _alad.fdx, _al8x.tii, _alae.fdx, _add1.prx, _akuu.f
>> nm, _al8x.tis, _ah91.frq, _ala8.fnm, _7zfh.fdt, _alad.fdt, _alae_1.del,
>> _alae.fdt, _akzu.frq, _a61p.fnm, _9wzn.frq, _ala8.tii, _7zfh_1gsd.
>> del, _7zfh.nrm, _ala7_6.del, _a61p.tis, _9wzn.tii, _alad.frq, _alad.tii,
>> _akuu.fdt, _alab.tii, _ala8.tis, _962y_xgg.del, _akh1.frq, _akuu.
>> fdx, _alab.tis, _al7i.fnm, _alad.tis, _alac.nrm, _alab.fdx, _ala8_5.del,
>> _add1.fdx, _ala7.tii, _akuu_cc.del, _alab.fdt, _9wzn.prx, _alaa.f
>> dx, _al9w.fdt, _al2o.frq, _akh1_nf.del, _alac.prx, _akh1.fdx, _alaa.fdt,
>> _al9w.fdx, _al8x_17.del, _add1.fdt, _al2o.prx, _akh1.fdt, _alad.p
>> rx, _akuu.prx, _962y.frq, _al2o_66.del, _alac.fdt, _ala7.tis, _a61p.tii,
>> _alac.fdx, _al8x.fdt, _9wzn.tis, _9wzn.fdt, _al8x.fdx, _9wzn.fdx,
>>  _ah91_35l.del]
>>
>> commit{dir=/master/data/index,segFN=segments_8us5,version=1228872482132,generation=413141,filenames=[_ala9.fnm,
>> _alaa_5.del, _alab
>> .fnm, _962y_xgh.del, _al8x.frq, _akh1.tis, _add1.frq, _alae.tis,
>> _7zfh_1gse.del, _alad.nrm, _alae.tii, _akuu.tis, _ah91_35m.del, _ailk.frq
>> , _7zfh.tii, _962y.tis, _akuu.tii, _ah91.prx, _7zfh.tis, _ala8.frq,
>> _962y.tii, _ala7.fnm, _akzu.fnm, _9wzn.fnm, _ala9_2.del, _ala8.nrm, _a
>> laf.fnm, _alae.nrm, _ala9.prx, _ailk_24k.del, _alaf.prx, _al9w.prx,
>> _ala8.prx, _akh1.tii, _akzu.tii, _akzu.tis, _alad.fnm, _al2o.fnm, _962
>> y.fnm, _al8x_18.del, _ala7_7.del, _alaa.tis, _ala9.nrm, _ala9.tis,
>> _alaa.tii, _962y.nrm, _ala9.tii, _a61p.prx, _add1_62v.del, _al8x.fnm, _
>> 7zfh.fnm, _al7i_2g.del, _ailk.fnm, _al8x.tii, _al8x.tis, _ala8.fnm,
>> _akzu.frq, _9wzn.frq, _7zfh.nrm, _akuu.fdt, _alad.tii, _akuu.fdx, _aku
>> u_cd.del, _a61p_b77.del, _alad.tis, _al2o_67.del, _add1.fdx, _9wzn.prx,
>> _al9w.fdt, _add1.fdt, _al9w.fdx, _akuu.prx, _962y.frq, _9wzn.fdt,
>> _alab_4.del, _9wzn.fdx, segments_8us5, _alac_4.del, _alae.fnm, _ailk.tis,
>> _ala9.fdx, _alac.fnm, _ala9.fdt, _alab.prx, _alae_2.del, _alaa.f
>> nm, _alad_1.del, _al9w.frq, _ailk.tii, _add1.tis, _alac.tii, _add1.tii,
>> _alac.tis, _ala7.frq, _ah91.fnm, _a61p.fdt, _alae.prx, _akuu.frq,
>> _a61p.fdx, _akh1_ng.del, _al7i.fdx, _al2o.tis, _al9w.tis, _a61p.frq,
>> _akh1.prx, _9wzn_i0n.del, _al7i.fdt, _al7i.prx, _962y.prx, _al9w.tii,
>>  _al7i.frq, _ah91.tii, _962y.fdt, _akh1.fnm, _962y.fdx, _ah91.tis,
>> _al8x.prx, _al2o.tii, _ala7.fdx, _ala7.fdt, _alaf.fdx, _alaf.fdt, _al2o
>> .fdx, _7zfh.frq, _akzu.fdt, _alaf.nrm, _akzu.fdx, _alab.nrm, _al2o.fdt,
>> _alaa.prx, _alaa.nrm, _ala7.prx, _ailk.fdt, _akzu.prx, _alac.frq,
>> _ailk.prx, _alaf.tii, _alaf_1.del, _alae.frq, _add1.fnm, _alaf.tis,
>> _7zfh.prx, _al9w.fnm, _ala9.frq, _alab.frq, _ala8.fdx, _akzu_8e.del, _
>> ala8.fdt, _ailk.fdx, _alaa.frq, _al7i.tis, _7zfh.fdx, _al9w_i.del,
>> _ah91.fdt, _al7i.tii, _ah91.fdx, _alad.fdx, _akuu.fnm, _add1.prx, _alae
>> .fdx, _ah91.frq, _7zfh.fdt, _alad.fdt, _alae.fdt, _a61p.fnm, _alaf.frq,
>> _ala8.tii, _a61p.tis, _9wzn.tii, _alad.frq, _ala8.tis, _alab.tii,
>> _akh1.frq, _alab.tis, _al7i.fnm, _alab.fdx, _alac.nrm, _ala8_5.del,
>> _ala7.tii, _alab.fdt, _alaa.fdx, _al2o.frq, _akh1.fdx, _alac.prx, _ala
>> a.fdt, _al2o.prx, _akh1.fdt, _alad.prx, _ala7.tis, _alac.fdt, _a61p.tii,
>> _9wzn.tis, _al8x.fdt, _alac.fdx, _al8x.fdx]
>> Oct 28, 2009 11:50:43 AM org.apache.solr.core.SolrDeletionPolicy
>> updateCommits
>> INFO: last commit = 1228872482132
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher <init>
>> INFO: Opening Searcher@5df12234 main
>> Oct 28, 2009 11:50:45 AM org.apache.solr.update.DirectUpdateHandler2
>> commit
>> INFO: end_commit_flush
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming Searcher@5df12234 main from Searcher@50e40833 main
>>
>> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cu
>> mulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming result for Searcher@5df12234 main
>>
>> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cu
>> mulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming Searcher@5df12234 main from Searcher@50e40833 main
>>
>> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumula
>> tive_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming result for Searcher@5df12234 main
>>
>> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumula
>> tive_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming Searcher@5df12234 main from Searcher@50e40833 main
>>
>> queryResultCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,c
>> umulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming result for Searcher@5df12234 main
>>
>> queryResultCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,c
>> umulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming Searcher@5df12234 main from Searcher@50e40833 main
>>
>> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumu
>> lative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher warm
>> INFO: autowarming result for Searcher@5df12234 main
>>
>> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumu
>> lative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.core.QuerySenderListener
>> newSearcher
>> INFO: QuerySenderListener sending requests to Searcher@5df12234 main
>> Oct 28, 2009 11:50:45 AM org.apache.solr.core.QuerySenderListener
>> newSearcher
>> INFO: QuerySenderListener done.
>> Oct 28, 2009 11:50:45 AM org.apache.solr.core.SolrCore registerSearcher
>> INFO: [] Registered new searcher Searcher@5df12234 main
>> Oct 28, 2009 11:50:45 AM org.apache.solr.search.SolrIndexSearcher close
>> INFO: Closing Searcher@50e40833 main
>>
>> fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cu
>> mulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>>
>> filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumula
>> tive_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>>
>> queryResultCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,c
>> umulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>>
>> documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumu
>> lative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
>> Oct 28, 2009 11:50:45 AM org.apache.solr.core.SolrDeletionPolicy onInit
>> INFO: SolrDeletionPolicy.onInit: commits:num=1
>>
>> commit{dir=/master/data/index,segFN=segments_8us5,version=1228872482132,generation=413141,filenames=[_ala9.fnm,
>> _alaa_5.del, _alab
>> .fnm, _962y_xgh.del, _al8x.frq, _akh1.tis, _add1.frq, _alae.tis,
>> _7zfh_1gse.del, _alad.nrm, _alae.tii, _akuu.tis, _ah91_35m.del, _ailk.frq
>> , _7zfh.tii, _962y.tis, _akuu.tii, _ah91.prx, _7zfh.tis, _ala8.frq,
>> _962y.tii, _ala7.fnm, _akzu.fnm, _9wzn.fnm, _ala9_2.del, _ala8.nrm, _a
>> laf.fnm, _alae.nrm, _ala9.prx, _ailk_24k.del, _alaf.prx, _al9w.prx,
>> _ala8.prx, _akh1.tii, _akzu.tii, _akzu.tis, _alad.fnm, _al2o.fnm, _962
>> y.fnm, _al8x_18.del, _ala7_7.del, _alaa.tis, _ala9.nrm, _ala9.tis,
>> _alaa.tii, _962y.nrm, _ala9.tii, _a61p.prx, _add1_62v.del, _al8x.fnm, _
>> 7zfh.fnm, _al7i_2g.del, _ailk.fnm, _al8x.tii, _al8x.tis, _ala8.fnm,
>> _akzu.frq, _9wzn.frq, _7zfh.nrm, _akuu.fdt, _alad.tii, _akuu.fdx, _aku
>> u_cd.del, _a61p_b77.del, _alad.tis, _al2o_67.del, _add1.fdx, _9wzn.prx,
>> _al9w.fdt, _add1.fdt, _al9w.fdx, _akuu.prx, _962y.frq, _9wzn.fdt,
>> _alab_4.del, _9wzn.fdx, segments_8us5, _alac_4.del, _alae.fnm, _ailk.tis,
>> _ala9.fdx, _alac.fnm, _ala9.fdt, _alab.prx, _alae_2.del, _alaa.f
>> nm, _alad_1.del, _al9w.frq, _ailk.tii, _add1.tis, _alac.tii, _add1.tii,
>> _alac.tis, _ala7.frq, _ah91.fnm, _a61p.fdt, _alae.prx, _akuu.frq,
>> _a61p.fdx, _akh1_ng.del, _al7i.fdx, _al2o.tis, _al9w.tis, _a61p.frq,
>> _akh1.prx, _9wzn_i0n.del, _al7i.fdt, _al7i.prx, _962y.prx, _al9w.tii,
>>  _al7i.frq, _ah91.tii, _962y.fdt, _akh1.fnm, _962y.fdx, _ah91.tis,
>> _al8x.prx, _al2o.tii, _ala7.fdx, _ala7.fdt, _alaf.fdx, _alaf.fdt, _al2o
>> .fdx, _7zfh.frq, _akzu.fdt, _alaf.nrm, _akzu.fdx, _alab.nrm, _al2o.fdt,
>> _alaa.prx, _alaa.nrm, _ala7.prx, _ailk.fdt, _akzu.prx, _alac.frq,
>> _ailk.prx, _alaf.tii, _alaf_1.del, _alae.frq, _add1.fnm, _alaf.tis,
>> _7zfh.prx, _al9w.fnm, _ala9.frq, _alab.frq, _ala8.fdx, _akzu_8e.del, _
>> ala8.fdt, _ailk.fdx, _alaa.frq, _al7i.tis, _7zfh.fdx, _al9w_i.del,
>> _ah91.fdt, _al7i.tii, _ah91.fdx, _alad.fdx, _akuu.fnm, _add1.prx, _alae
>> .fdx, _ah91.frq, _7zfh.fdt, _alad.fdt, _alae.fdt, _a61p.fnm, _alaf.frq,
>> _ala8.tii, _a61p.tis, _9wzn.tii, _alad.frq, _ala8.tis, _alab.tii,
>> _akh1.frq, _alab.tis, _al7i.fnm, _alab.fdx, _alac.nrm, _ala8_5.del,
>> _ala7.tii, _alab.fdt, _alaa.fdx, _al2o.frq, _akh1.fdx, _alac.prx, _ala
>> a.fdt, _al2o.prx, _akh1.fdt, _alad.prx, _ala7.tis, _alac.fdt, _a61p.tii,
>> _9wzn.tis, _al8x.fdt, _alac.fdx, _al8x.fdx]
>> Oct 28, 2009 11:50:45 AM org.apache.solr.core.SolrDeletionPolicy
>> updateCommits
>> INFO: last commit = 1228872482132
>> Oct 28, 2009 11:50:45 AM
>> org.apache.solr.update.processor.LogUpdateProcessor
>> finish
>> INFO: {add=[8e0d826fd83005f535bc930dac9fe65f]} 0 222916
>> Oct 28, 2009 11:50:45 AM org.apache.solr.core.SolrCore execute
>> INFO: [] webapp=/solrmaster path=/update params={} status=0 QTime=222916
>> Oct 28,
>> --
>> View this message in context:
>> http://www.nabble.com/Slow-Commits-tp26097538p26097538.html
>> Sent from the Solr - User mailing list archive at Nabble.com.
>>
>>
> 
> 
> 
> -- 
> Jerome Eteve.
> http://www.eteve.net
> jerome@eteve.net
> 
> 

-- 
View this message in context: http://www.nabble.com/Slow-Commits-tp26097538p26097871.html
Sent from the Solr - User mailing list archive at Nabble.com.


Mime
View raw message