Hi, an update. Hope you can help me.
I have stopped all the other working collections, in order to have a clean log file. at 11:01:16 an hard commit has been issued 2015-12-16 11:01:49,839 [http-bio-8080-exec-824] INFO org.apache.solr.update.UpdateHandler - start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} at 11:11:31,344 the commit has been completed. The commit was ended logging this line, I suppose 615021 is the wait time (roughly 10 minutes) : 2015-12-16 11:11:31,343 [http-bio-8080-exec-991] INFO o.a.s.u.processor.LogUpdateProcessor - [catalogo_shard2_replica3] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {commit=} 0 615021 During this 10 minutes, the server logged "only" thes lines, looking at them I don't see anything of strange: 2015-12-16 11:01:50,705 [http-bio-8080-exec-824] INFO o.a.solr.search.SolrIndexSearcher - Opening Searcher@6d5c31e2[catalogo_shard1_replica2] main 2015-12-16 11:01:50,724 [http-bio-8080-exec-824] INFO org.apache.solr.update.UpdateHandler - end_commit_flush 2015-12-16 11:02:20,722 [searcherExecutor-108-thread-1] INFO o.a.solr.spelling.suggest.Suggester - build() 2015-12-16 11:02:21,846 [http-bio-8080-exec-824] INFO o.a.s.u.processor.LogUpdateProcessor - [catalogo_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from= http://192.168.101.118:8080/solr/catalogo_shard2_replica3/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false} {commit=} 0 32007 2015-12-16 11:05:47,162 [http-bio-8080-exec-1037] INFO org.apache.solr.update.UpdateHandler - start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} 2015-12-16 11:05:47,970 [http-bio-8080-exec-1037] INFO o.a.solr.search.SolrIndexSearcher - Opening Searcher@4ede7ac5[catalogo_shard2_replica3] main 2015-12-16 11:05:47,989 [http-bio-8080-exec-1037] INFO org.apache.solr.update.UpdateHandler - end_commit_flush 2015-12-16 11:06:03,063 [commitScheduler-115-thread-1] INFO org.apache.solr.update.UpdateHandler - start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} 2015-12-16 11:06:03,896 [commitScheduler-115-thread-1] INFO o.a.solr.search.SolrIndexSearcher - Opening Searcher@2bf4fd3a[catalogo_shard3_replica1] realtime 2015-12-16 11:06:03,913 [commitScheduler-115-thread-1] INFO org.apache.solr.update.UpdateHandler - end_commit_flush 2015-12-16 11:06:19,435 [searcherExecutor-111-thread-1] INFO o.a.solr.spelling.suggest.Suggester - build() 2015-12-16 11:06:20,589 [http-bio-8080-exec-1037] INFO o.a.s.u.processor.LogUpdateProcessor - [catalogo_shard2_replica3] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from= http://192.168.101.118:8080/solr/catalogo_shard2_replica3/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false} {commit=} 0 33427 2015-12-16 11:08:07,076 [http-bio-8080-exec-1037] INFO org.apache.solr.update.UpdateHandler - start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} 2015-12-16 11:08:07,076 [http-bio-8080-exec-1037] INFO org.apache.solr.update.UpdateHandler - No uncommitted changes. Skipping IW.commit. 2015-12-16 11:08:07,076 [http-bio-8080-exec-1037] INFO o.a.solr.search.SolrIndexSearcher - Opening Searcher@75b2727f[catalogo_shard3_replica1] main 2015-12-16 11:08:07,084 [http-bio-8080-exec-1037] INFO org.apache.solr.update.UpdateHandler - end_commit_flush 2015-12-16 11:08:39,040 [searcherExecutor-114-thread-1] INFO o.a.solr.spelling.suggest.Suggester - build() 2015-12-16 11:08:40,286 [http-bio-8080-exec-1037] INFO o.a.s.u.processor.LogUpdateProcessor - [catalogo_shard3_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from= http://192.168.101.118:8080/solr/catalogo_shard2_replica3/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false} {commit=} 0 33211 Could some component be the cause of this wait? Something like a suggester or a spellchecker cache? But if yes, I should see the activity in log file, isn't it? Best regards, Vincenzo On Sat, Dec 12, 2015 at 7:50 PM, Erick Erickson <erickerick...@gmail.com> wrote: > Autowarm times will only happen when the commit has openSearcher=true > or on a soft commit. But maybe your log levels aren't at INFO for the right > code... > > That said, your autowarm counts at 0 probably means that you're not seeing > any autowarming really, so that might be a red herring. Your newSearcher > event in solrconfig.xml will still be fired, but may be commented out. > > This is still something of a puzzle. With an index this size, your hard > commits should never take more than a second or two unless you're > in some very strange state. Stack traces would be in order if lengthening > the commit interval doesn't work. > > Best, > Erick > > On Fri, Dec 11, 2015 at 5:58 PM, Vincenzo D'Amore <v.dam...@gmail.com> > wrote: > > Hi All, > > > > an update, I have switched logging from WARN to INFO for all except for > > those two: > > > > - org.apache.solr.core > > - org.apache.solr.handler.component.SpellCheckComponent > > > > Well, looking at log file I'm unable to find any autowarm log line, even > > after few updates and commits. > > > > Looking at solrconfig.xml I see most autowarmCount parameters are set to > 0 > > > > <filterCache class="solr.FastLRUCache" size="1500" initialSize="1000" > > autowarmCount="0" /> > > <queryResultCache class="solr.LRUCache" size="8096" initialSize="1024" > > autowarmCount="0" /> > > <documentCache class="solr.FastLRUCache" size="10240" initialSize="4096" > > autowarmCount="0" /> > > <cache name="perSegFilter" class="solr.search.LRUCache" > size > > ="10" initialSize="0" autowarmCount="10" > regenerator="solr.NoOpRegenerator" > > /> > > > > Not sure what this means... > > > > On Sat, Dec 12, 2015 at 1:13 AM, Vincenzo D'Amore <v.dam...@gmail.com> > > wrote: > > > >> Thanks Erick, Mark, > >> > >> I'll raise maxTime asap. > >> Just to be sure understand, given that I have openSearcher=false, I > >> suppose it shouldn't trigger autowarming at least until a commit is > >> executed, shouldn't it? > >> > >> Anyway, I don't understand, given that maxTime is very aggressive, why > >> hard commit takes so long. > >> > >> Thanks again for your answers. > >> Vincenzo > >> > >> > >> On Fri, Dec 11, 2015 at 7:22 PM, Erick Erickson < > erickerick...@gmail.com> > >> wrote: > >> > >>> First of all, your autocommit settings are _very_ aggressive. > Committing > >>> every second is far to frequent IMO. > >>> > >>> As an aside, I generally prefer to omit the maxDocs as it's not all > >>> that predictable, > >>> but that's a personal preference and really doesn't bear on your > problem.. > >>> > >>> My _guess_ is that you are doing a lot of autowarming. The number of > docs > >>> doesn't really matter if your autowarming is taking forever, your Solr > >>> logs > >>> should report the autowarm times at INFO level, have you checked those? > >>> > >>> The commit settings shouldn't be a problem in terms of your server > dying, > >>> the indexing process flushes docs to the tlog independent of > committing so > >>> upon restart they should be recovered. Here's a blog on the subject: > >>> > >>> > >>> > https://lucidworks.com/blog/2013/08/23/understanding-transaction-logs-softcommit-and-commit-in-sorlcloud/ > >>> > >>> Best, > >>> Erick > >>> > >>> On Fri, Dec 11, 2015 at 8:24 AM, Vincenzo D'Amore <v.dam...@gmail.com> > >>> wrote: > >>> > Hi all, > >>> > > >>> > I have a SolrCloud cluster with a collection (2.5M docs) with 3 > shards > >>> and > >>> > 15 replicas. > >>> > There is a solrj application that feeds the collection, updating few > >>> > documents every hour, I don't understand why, at end of process, the > >>> hard > >>> > commit takes about 8/10 minutes. > >>> > > >>> > Even if there are only few hundreds of documents. > >>> > > >>> > This is the autocommit configuration: > >>> > > >>> > <autoCommit> > >>> > <maxDocs>10000</maxDocs> > >>> > <maxTime>1000</maxTime> > >>> > <openSearcher>false</openSearcher> > >>> > </autoCommit> > >>> > > >>> > In your experience why hard commit takes so long even for so few > >>> documents? > >>> > > >>> > Now I'm changing the code to softcommit, calling commit (waitFlush = > >>> > false, waitSearcher > >>> > = false, softCommit = true); > >>> > > >>> > solrServer.commit(false, false, true);. > >>> > > >>> > I have configured NRTCachingDirectoryFactory, but I'm a little bit > >>> worried > >>> > if a server goes down (something like: kill -9, SolrCloud crashes, > out > >>> of > >>> > memory, etc.), and if, using this strategy > >>> softcommit+NRTCachingDirectory, > >>> > SolrCloud instance could not recover a replica. > >>> > > >>> > Should I worry about this new configuration? I was thinking to take a > >>> > snapshot of everything every day, in order to recover immediately the > >>> > index. Could this be considered a best practice? > >>> > > >>> > Thanks in advance for your time, > >>> > Vincenzo > >>> > > >>> > -- > >>> > Vincenzo D'Amore > >>> > email: v.dam...@gmail.com > >>> > skype: free.dev > >>> > mobile: +39 349 8513251 > >>> > >> > >> > >> > >> -- > >> Vincenzo D'Amore > >> email: v.dam...@gmail.com > >> skype: free.dev > >> mobile: +39 349 8513251 > >> > > > > > > > > -- > > Vincenzo D'Amore > > email: v.dam...@gmail.com > > skype: free.dev > > mobile: +39 349 8513251 > -- Vincenzo D'Amore email: v.dam...@gmail.com skype: free.dev mobile: +39 349 8513251