Great!!! Great Erick! It was a buildOnCommit. Many thanks for your help.
On Wed, Dec 16, 2015 at 6:30 PM, Erick Erickson <erickerick...@gmail.com> wrote: > Quick scan, but probably this: > INFO > o.a.solr.spelling.suggest.Suggester - build() > > The suggester build process can easily take many minutes, there's some > explanation here: > https://lucidworks.com/blog/2015/03/04/solr-suggester/ > > the short form is that depending on how it's defined, it may have to > read _all_ the > documents in your entire corpus to build the suggester structures. And > you apparently > have buildOnCommit set to true. > > Note particularly the caveats there about the Solr version required so that > buildOnStartup=false is honored. > > Best, > Erick > > On Wed, Dec 16, 2015 at 2:34 AM, Vincenzo D'Amore <v.dam...@gmail.com> > wrote: > > 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 > -- Vincenzo D'Amore email: v.dam...@gmail.com skype: free.dev mobile: +39 349 8513251
