lucene-solr-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Aswath Srinivasan (TMS)" <aswath.sriniva...@toyota.com>
Subject RE: PERFORMANCE WARNING: Overlapping onDeckSearchers=2
Date Mon, 21 Mar 2016 22:27:56 GMT
I really could not see anything else in the log. This is how I was able to reproduce the issue,


*         Install a standalone solr 5.3.2 in my PC

*         Indexed some 10 db records

*         Hit core reload/call commit frequently in quick internals

*         Seeing the  o.a.s.c.SolrCore [db] PERFORMANCE WARNING: Overlapping onDeckSearchers=2

*         Collection crashes

*         Only way to recover is to stop solr - delete the data folder - start solr - reindex

I don't know why  o.a.s.c.SolrCore [db] PERFORMANCE WARNING: Overlapping onDeckSearchers=2
crashes my Solr.

Like I said I can try avoiding frequent commits but in a production environment if two commits
happen near by accidently I cannot delete the data collection in my Production, right?

2016-03-21 22:18:36.653 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.highlight.SimpleBoundaryScanner
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.653 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.highlight.BreakIteratorBoundaryScanner
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.653 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
2016-03-21 22:18:36.653 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.core.PluginInfo from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.653 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.lang.String from null
2016-03-21 22:18:36.653 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.common.util.StrUtils from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.655 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.lang.ThreadLocal from null
2016-03-21 22:18:36.657 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.io.IOException from null
2016-03-21 22:18:36.657 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.io.Reader from null
2016-03-21 22:18:36.657 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.io.StringReader from null
2016-03-21 22:18:36.658 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.lang.UnsupportedOperationException from
null
2016-03-21 22:18:36.658 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded interface org.apache.lucene.analysis.util.ResourceLoader
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.658 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded interface org.xml.sax.EntityResolver from null
2016-03-21 22:18:36.658 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded interface org.xml.sax.ErrorHandler from null
2016-03-21 22:18:36.658 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded interface java.util.List from null
2016-03-21 22:18:36.658 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.common.util.XMLErrorLogger
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.659 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.lang.Enum from null
2016-03-21 22:18:36.659 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.util.Properties from null
2016-03-21 22:18:36.660 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.util.concurrent.atomic.AtomicLong from
null
2016-03-21 22:18:36.660 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.util.concurrent.ConcurrentHashMap from
null
2016-03-21 22:18:36.660 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class java.util.concurrent.locks.ReentrantLock
from null
2016-03-21 22:18:36.660 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.core.SolrCore from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.660 INFO  (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.c.SolrCore
QuerySenderListener sending requests to Searcher@932efd[db] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.3.2):C10)))}
2016-03-21 22:18:36.660 INFO  (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.c.PluginBag
Going to create a new requestHandler with {type = requestHandler,name = /select,class = solr.SearchHandler,args
= {defaults={df=text,spellcheck.dictionary=default,spellcheck.dictionary=wordbreak,spellcheck=on,spellcheck.extendedResults=true,spellcheck.count=10,spellcheck.alternativeTermCount=5,spellcheck.maxResultsForSuggest=5,spellcheck.collate=true,spellcheck.collateExtendedResults=true,spellcheck.maxCollationTries=10,spellcheck.maxCollations=5},last-components=[spellcheck]}}
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.c.S.Request
[db] webapp=null path=null params={q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false&event=firstSearcher}
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.handler.component.QueryComponent@1ab2e9f
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.handler.component.FacetComponent@16cd35a
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.search.facet.FacetModule@15345ef
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@51d961
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.handler.component.HighlightComponent@caca62
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.handler.component.StatsComponent@1c92de2
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.handler.component.ExpandComponent@b86049
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  component:org.apache.solr.handler.component.SpellCheckComponent@7e262e
2016-03-21 22:18:36.661 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.SearchHandler
Adding  debug component:org.apache.solr.handler.component.DebugComponent@2763d9
2016-03-21 22:18:36.662 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
2016-03-21 22:18:36.663 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.update.TransactionLog$FSReverseReader$1
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.664 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.solr.update.UpdateLog$Update from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.664 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets
from index
2016-03-21 22:18:36.665 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.lucene.index.FilterLeafReader$FilterTermsEnum
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.665 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.lucene.index.ExitableDirectoryReader$ExitableTermsEnum
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.665 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.h.c.QueryComponent
process: spellcheck.collateExtendedResults=true&distrib=false&df=text&spellcheck.dictionary=default&spellcheck.dictionary=wordbreak&spellcheck.maxCollations=5&spellcheck.maxCollationTries=10&spellcheck.alternativeTermCount=5&spellcheck.extendedResults=true&q=static+firstSearcher+warming+in+solrconfig.xml&spellcheck.maxResultsForSuggest=5&spellcheck=on&spellcheck.count=10&event=firstSearcher&spellcheck.collate=true
2016-03-21 22:18:36.666 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.s.s.LocalStatsCache
## GET {spellcheck.collateExtendedResults=true&distrib=false&df=text&spellcheck.dictionary=default&spellcheck.dictionary=wordbreak&spellcheck.maxCollations=5&spellcheck.maxCollationTries=10&spellcheck.alternativeTermCount=5&spellcheck.extendedResults=true&q=static+firstSearcher+warming+in+solrconfig.xml&spellcheck.maxResultsForSuggest=5&spellcheck=on&spellcheck.count=10&event=firstSearcher&spellcheck.collate=true}
2016-03-21 22:18:36.666 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.HitQueue from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.667 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.TopScoreDocCollector$SimpleTopScoreDocCollector from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.667 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.TopScoreDocCollector$PagingTopScoreDocCollector from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.667 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.TopDocs$ScoreMergeSortQueue from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.668 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.TopDocs$MergeSortQueue from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.668 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.ScoreDoc from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.669 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.671 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.lucene.index.FilteredTermsEnum$1
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.671 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.lucene.index.FilteredTermsEnum$AcceptStatus
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.673 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.VersionInfo Found MAX value 1529451588346707968 from Terms for _version_
in index
2016-03-21 22:18:36.673 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.Explanation from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.676 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.TopScoreDocCollector$ScorerLeafCollector from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.677 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.TopScoreDocCollector$SimpleTopScoreDocCollector$1 from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.677 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.UpdateLog Took 15 ms to seed version buckets with highest version 1529451588346707968
2016-03-21 22:18:36.677 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.DefaultSolrCoreState Creating new IndexWriter...
2016-03-21 22:18:36.677 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.DefaultSolrCoreState Waiting until IndexWriter is unused... core=db
2016-03-21 22:18:36.677 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.DefaultSolrCoreState Closing old IndexWriter... core=db
2016-03-21 22:18:36.677 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.SolrIndexWriter Closing Writer DirectUpdateHandler2
2016-03-21 22:18:36.677 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.a.s.s.DirectSolrSpellChecker
getSuggestions: [static, firstsearcher, warming, warm, warmed, warmer, warmest, warms, solrconfig,
xml]
2016-03-21 22:18:36.678 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.FuzzyTermsEnum from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.679 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory Releasing directory: C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data\index
2 false
2016-03-21 22:18:36.679 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.FuzzyTermsEnum$AutomatonFuzzyTermsEnum from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.680 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded interface org.apache.lucene.search.BoostAttribute from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.680 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.BoostAttributeImpl from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.680 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory Reusing cached directory: CachedDir<<refCount=1;path=C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data;done=false>>
2016-03-21 22:18:36.681 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory Releasing directory: C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data
0 false
2016-03-21 22:18:36.681 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory Reusing cached directory: CachedDir<<refCount=3;path=C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data\index;done=false>>
2016-03-21 22:18:36.681 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded interface org.apache.lucene.search.FuzzyTermsEnum$LevenshteinAutomataAttribute from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.681 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.lucene.index.TieredMergePolicy
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.681 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.search.FuzzyTermsEnum$LevenshteinAutomataAttributeImpl from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.681 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.w.WebAppClassLoader loaded class org.apache.lucene.index.ConcurrentMergeScheduler
from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.683 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.LevenshteinAutomata from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.684 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.LevenshteinAutomata$ParametricDescription from
WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.684 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Lev1TParametricDescription from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.684 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Lev1ParametricDescription from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.685 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Lev2TParametricDescription from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.685 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Lev2ParametricDescription from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.688 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Automata from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.689 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Automaton from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.690 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.InPlaceMergeSorter from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.690 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Automaton$1 from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.690 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Automaton$2 from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.691 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
      commit{dir=NRTCachingDirectory(SimpleFSDirectory@C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data\index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@cbfb8f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
2016-03-21 22:18:36.691 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
      commit{dir=NRTCachingDirectory(SimpleFSDirectory@C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data\index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@cbfb8f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0.si,
_0_Lucene50_0.doc, _0_Lucene50_0.tim, _0_Lucene50_0.pos, segments_2, _0.nvd, _0.fdx, _0_Lucene50_0.tip,
_0.fdt, _0.tvx, _0.tvd, _0.nvm, _0.fnm]}
2016-03-21 22:18:36.691 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.SolrCore newest commit generation = 2
2016-03-21 22:18:36.691 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class java.util.BitSet
2016-03-21 22:18:36.691 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.SolrIndexWriter Opened Writer DirectUpdateHandler2
2016-03-21 22:18:36.691 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class java.util.BitSet from null
2016-03-21 22:18:36.691 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
2016-03-21 22:18:36.691 WARN  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.SolrCore [db] PERFORMANCE WARNING: Overlapping onDeckSearchers=2
2016-03-21 22:18:36.691 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory Reusing cached directory: CachedDir<<refCount=1;path=C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data;done=false>>
2016-03-21 22:18:36.692 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory Releasing directory: C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data
0 false
2016-03-21 22:18:36.692 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.CompiledAutomaton from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.693 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.index.SingleTermsEnum from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.694 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Transition from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.694 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.CompiledAutomaton$AUTOMATON_TYPE from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.695 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.UTF32ToUTF8 from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.695 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.UTF32ToUTF8$UTF8Sequence from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.696 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.UTF32ToUTF8$UTF8Byte from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.697 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Automaton$Builder from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.697 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Automaton$Builder$1 from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.701 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.Operations from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.702 DEBUG (searcherExecutor-12-thread-1-processing-x:db) [   x:db] o.e.j.w.WebAppClassLoader
loaded class org.apache.lucene.util.automaton.TooComplexToDeterminizeException from WebAppClassLoader=16954289@102b3b1
2016-03-21 22:18:36.705 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.s.SolrIndexSearcher Opening Searcher@229472[db] main
2016-03-21 22:18:36.705 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory incRef'ed: CachedDir<<refCount=4;path=C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data\index;done=false>>
2016-03-21 22:18:36.705 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CoreContainer replacing core: db
2016-03-21 22:18:36.705 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.SolrCore [db]  CLOSING SolrCore org.apache.solr.core.SolrCore@bdb273
2016-03-21 22:18:36.706 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.u.UpdateHandler closing DirectUpdateHandler2{commits=1,autocommits=0,soft
autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=10,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=21568,transaction_logs_total_number=1}
2016-03-21 22:18:36.707 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.SolrCore [db] Closing main searcher on request.
2016-03-21 22:18:36.708 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.s.SolrIndexSearcher Closing Searcher@171dcee[db] main
      fieldValueCache{lookups=0,hits=0,hitratio=0.0,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.0,cumulative_inserts=0,cumulative_evictions=0}
      filterCache{lookups=0,hits=0,hitratio=0.0,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.0,cumulative_inserts=0,cumulative_evictions=0}
      queryResultCache{lookups=0,hits=0,hitratio=0.0,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.0,cumulative_inserts=0,cumulative_evictions=0}
      documentCache{lookups=0,hits=0,hitratio=0.0,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.0,cumulative_inserts=0,cumulative_evictions=0}
      perSegFilter{lookups=0,hits=0,hitratio=0.0,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.0,cumulative_inserts=0,cumulative_evictions=0}
2016-03-21 22:18:36.708 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.c.CachingDirectoryFactory Releasing directory: C:\Users\400376\Downloads\Solr\solr-5.3.2\server\solr\db\data\index
3 false
2016-03-21 22:18:36.709 INFO  (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.s.SolrDispatchFilter [admin] webapp=null path=/admin/cores params={core=db&action=RELOAD&wt=json&_=1458598715653}
status=0 QTime=1045
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpConnection org.eclipse.jetty.server.HttpConnection$SendCallback@1f3b3df[PROCESSING][i=ResponseInfo{HTTP/1.1
200 null,-1,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1e71de2] generate:
NEED_HEADER (null,[p=0,l=45,c=32768,r=45],false)@START
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpConnection org.eclipse.jetty.server.HttpConnection$SendCallback@1f3b3df[PROCESSING][i=ResponseInfo{HTTP/1.1
200 null,-1,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1e71de2] generate:
FLUSH ([p=0,l=98,c=8192,r=98],[p=0,l=45,c=32768,r=45],false)@COMMITTED
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.WriteFlusher write: WriteFlusher@1d28c9f{IDLE} [HeapByteBuffer@ae509a[p=0,l=98,c=8192,r=98]={<<<HTTP/1.1
200 OK\r\n...chunked\r\n\r\n2D\r\n>>>ve\r\nAccept: appli...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},HeapByteBuffer@1b8bcd3[p=0,l=45,c=32768,r=45]={<<<{"responseHeader"..."QTime":1045}}\n>>>tFailures":{},"st...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.WriteFlusher update WriteFlusher@1d28c9f{WRITING}:IDLE-->WRITING
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.ChannelEndPoint flushed 143 SelectChannelEndPoint@112fcdf{/0:0:0:0:0:0:0:1:64966<->8983,Open,in,out,-,W,1047/50000,HttpConnection}{io=0,kio=0,kro=1}
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.WriteFlusher update WriteFlusher@1d28c9f{IDLE}:WRITING-->IDLE
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpConnection org.eclipse.jetty.server.HttpConnection$SendCallback@1f3b3df[PROCESSING][i=ResponseInfo{HTTP/1.1
200 null,-1,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1e71de2] generate:
DONE ([p=98,l=98,c=8192,r=0],[p=45,l=45,c=32768,r=0],false)@COMMITTED
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.a.s.s.SolrDispatchFilter Closing out SolrRequest: {core=db&action=RELOAD&wt=json&_=1458598715653}
2016-03-21 22:18:36.709 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.Server RESPONSE /solr/admin/cores  200 handled=true
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpChannelState HttpChannelState@a58534{s=DISPATCHED i=true a=null} unhandle
DISPATCHED
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpConnection org.eclipse.jetty.server.HttpConnection$SendCallback@1f3b3df[PROCESSING][i=null,cb=Blocker@1c3a831{null}]
generate: CONTINUE (null,[p=0,l=0,c=0,r=0],true)@COMPLETING
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpConnection org.eclipse.jetty.server.HttpConnection$SendCallback@1f3b3df[PROCESSING][i=null,cb=Blocker@1c3a831{null}]
generate: NEED_CHUNK (null,[p=0,l=0,c=0,r=0],true)@COMPLETING
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpConnection org.eclipse.jetty.server.HttpConnection$SendCallback@1f3b3df[PROCESSING][i=null,cb=Blocker@1c3a831{null}]
generate: FLUSH (null,[p=0,l=0,c=0,r=0],true)@COMPLETING
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.WriteFlusher write: WriteFlusher@1d28c9f{IDLE} [HeapByteBuffer@e92141[p=0,l=7,c=1024,r=7]={<<<\r\n0\r\n\r\n>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.WriteFlusher update WriteFlusher@1d28c9f{WRITING}:IDLE-->WRITING
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.ChannelEndPoint flushed 7 SelectChannelEndPoint@112fcdf{/0:0:0:0:0:0:0:1:64966<->8983,Open,in,out,-,W,1/50000,HttpConnection}{io=0,kio=0,kro=1}
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.i.WriteFlusher update WriteFlusher@1d28c9f{IDLE}:WRITING-->IDLE
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.s.HttpConnection org.eclipse.jetty.server.HttpConnection$SendCallback@1f3b3df[PROCESSING][i=null,cb=Blocker@1c3a831{null}]
generate: DONE (null,[p=0,l=0,c=0,r=0],true)@END
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.h.HttpParser reset HttpParser{s=END,0 of -1}
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19 - /solr/admin/cores?wt=json&action=RELOAD&core=db&_=1458598715653)
[   x:db] o.e.j.h.HttpParser END --> START
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19) [   x:db] o.e.j.s.HttpChannel HttpChannelOverHttp@ac24d3{r=14,c=false,a=IDLE,uri=-}
handle exit, result COMPLETE
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19) [   x:db] o.e.j.i.ChannelEndPoint filled 0 SelectChannelEndPoint@112fcdf{/0:0:0:0:0:0:0:1:64966<->8983,Open,in,out,-,-,0/50000,HttpConnection}{io=0,kio=0,kro=1}
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19) [   x:db] o.e.j.i.ChannelEndPoint filled 0 SelectChannelEndPoint@112fcdf{/0:0:0:0:0:0:0:1:64966<->8983,Open,in,out,-,-,0/50000,HttpConnection}{io=0,kio=0,kro=1}
2016-03-21 22:18:36.710 DEBUG (qtp7980742-19) [   x:db] o.e.j.h.HttpParser parseNext s=START
HeapByteBuffer@72c884[p=0,l=0,c=8192,r=0]={<<<>>>GET /solr/js/scri...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}

Thank you,
Aswath NS
Mobile +1 424 345 5340
Office +1 310 468 6729


-----Original Message-----
From: Aswath Srinivasan (TMS) [mailto:aswath.srinivasan@toyota.com]
Sent: Monday, March 21, 2016 2:55 PM
To: solr-user@lucene.apache.org
Subject: RE: PERFORMANCE WARNING: Overlapping onDeckSearchers=2

If you're seeing a crash, then that's a distinct problem from the WARN -- it might be related
tothe warning, but it's not identical -- Solr doesn't always (or even normally) crash in the
"Overlapping onDeckSearchers"
situation

That is what I hoped for. But I could see nothing else in the log. All I'm trying to do is
run a full import in the DIH handler and index some 10 records from DB and check the "commit'
check box. Then when I immediately re-run the full import again OR do a reload config, I start
seeing this warning and my collection crashes.

I have turn off autocommit in the solrconfig.

I can try and avoid frequent hard commits but I wanted a solution to overcome this WARN if
an accidental frequent hard commit happens.

Thank you,
Aswath NS



-----Original Message-----
From: Chris Hostetter [mailto:hossman_lucene@fucit.org]
Sent: Monday, March 21, 2016 2:26 PM
To: solr-user@lucene.apache.org
Subject: RE: PERFORMANCE WARNING: Overlapping onDeckSearchers=2


: What I'm wondering is, what should one do to fix this issue when it
: happens. Is there a way to recover? after the WARN appears.

It's just a warning that you have a sub-optimal situation from a performance standpoint --
either committing too fast, or warming too much.
It's not a failure, and Solr will continue to serve queries and process updates -- but meanwhile
it's detected that the situation it's in involves wasted CPU/RAM.

: In my observation, this WARN comes when I hit frequent hard commits or
: hit re-load config. I'm not planning on to hit frequent hard commits,
: however sometimes accidently it happens. And when it happens the
: collection crashes without a recovery.

If you're seeing a crash, then that's a distinct problem from the WARN -- it might be related
tothe warning, but it's not identical -- Solr doesn't always (or even normally) crash in the
"Overlapping onDeckSearchers"
sitaution

So if you are seeing crashes, please give us more detials about these
crashes: namely more details about everything you are seeing in your logs (on all the nodes,
even if only one node is crashing)

https://wiki.apache.org/solr/UsingMailingLists



-Hoss
http://www.lucidworks.com/

Mime
View raw message