I am also seeing 2 threads loading the cores, I am using Solr 6.6.0. On Sat, Aug 26, 2017 at 11:53 AM, Erick Erickson <erickerick...@gmail.com> wrote:
> Setting loadOnStartup=false won't work for you in the long run, > although it does provide something of a hint. Setting this to false > means the core at that location simply has its coreDescriptor read and > stashed away in memory. The first time you _use_ that core an attempt > will be made to load it and that should fail with the write.lock > problem. > > There is extensive locking of core loading to prevent two threads from > trying to open the same core at the same time, if it were > fundamentally broken you wouldn't be the only person seeing this error > I'd guess. > > I see several errors in the stack trace "... is not multivalued and > destination for multiple copyFields". I do wonder if there's something > weird there with the error checking, that's a long shot. If you change > the fields identified to mulitValued=true does this still occur? I > absolutely expect it to, grasping at straws here. > > I do see that corePropertiesLocator only finds a single > core.properties file so that's as I'd expect. > > So this is puzzling, all the usual suspects seem to be eliminated. I > cant get over the fact that you copied things around though, that > usually means there's something we're not seeing that changed at the > same time although it's not obvious what that would be. > > Personally I'd blow the core away, start Solr and work back up from there. > > It looks like both times the core is being opened it's from > "coreLoadExecutor-6-thread-1" so it looks like it's the same thread. > So I'm pretty clueless. > > Best, > Erick > > On Fri, Aug 25, 2017 at 11:22 PM, Nawab Zada Asad Iqbal > <khi...@gmail.com> wrote: > > Hi Erick, > > > > I spent some more time on this and found that if I modify > 'core.properties' > > to contain the following values (my core.propreties file is empty > otherwise > > and only being used for shard discovery), then the solr server works > fine. > > > > loadOnStartup=false > > transient=false > > > > The fact is that shards are being loaded more than one time at the time > of > > startup. There is one possible cause (which I couldn't confirm), that if > > some ping request or query arrives while the shard is loading and the > > transient cache hasn't been initialized yet, will solr try to load the > > core? What if the shard is already being loaded (due to loadOnStartup) > but > > not in the cache yet? Can that cause the problem which I am seeing. My > test > > machine, constantly gets ping traffic from an haproxy (which i don't have > > control of), so I cannot test this hypothesis. > > > > However, on another machine with identical setup (except without haproxy > > traffic), I was able to make start and use (index 100s GB and queries for > > many hours) this solr version (6.6.1) without any problem. > > > > > > > > Thanks > > Nawab > > > > > > > > > > On Fri, Aug 25, 2017 at 3:38 PM, Nawab Zada Asad Iqbal <khi...@gmail.com > > > > wrote: > > > >> Thanks Erik > >> I expected that but it is really not the case . I have only one core per > >> solr installation . Though i run 3 solr processes on each host. > >> > >> If you see the thread names they are :coreLoadExecutor and > qtp761960786-31 > >> . If it was the case of two core pointing to one index (though it does > not > >> look like one based on my verification), then I expect to see two > threads > >> of > >> coreLoadExecutor trying to load the core twice. > >> Does the thread name prefix give any hint ? > >> > >> > >> Nawab > >> > >> > >> On Fri, Aug 25, 2017 at 1:55 PM Erick Erickson <erickerick...@gmail.com > > > >> wrote: > >> > >>> In that case you probably have two different cores pointing to the > >>> _same_ data directory. Examine your core.properties files and see if > >>> any dataDir variables are set.... > >>> > >>> Best, > >>> Erick > >>> > >>> On Fri, Aug 25, 2017 at 1:12 PM, Nawab Zada Asad Iqbal < > khi...@gmail.com> > >>> wrote: > >>> > Ok, after looking at the logs for some more time, i found that there > are > >>> > more than one threads trying to load the core at startup time. This > >>> doesn't > >>> > make sense to me, is it configurable? Is there any reason why this is > >>> even > >>> > an option? > >>> > > >>> > > >>> > Aug 25, 2017 12:04:37 PM INFO (main) [ ] o.e.j.s.Server > >>> > jetty-9.3.14.v20161028 > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > o.a.s.s.SolrDispatchFilter > >>> > ___ _ Welcome to Apache Solr™ version 6.6.1-SNAPSHOT > >>> > 1a390a91b5b658150478e6fc3c43381bedd3c6d3 - niqbal - 2017-08-09 > 10:31:27 > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > o.a.s.s.SolrDispatchFilter / > >>> > __| ___| |_ _ Starting in standalone mode on port 8984 > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > o.a.s.s.SolrDispatchFilter > >>> \__ > >>> > \/ _ \ | '_| Install dir: /local/bin/solr6/latest_solr > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > o.a.s.s.SolrDispatchFilter > >>> > |___/\___/_|_| Start time: 2017-08-25T20:04:38.231Z > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > o.a.s.s.StartupLoggingUtils > >>> > Property solr.log.muteconsole given. Muting ConsoleAppender named > >>> CONSOLE > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > o.a.s.c.SolrResourceLoader > >>> > Using system property solr.solr.home: /local/etc/solr/shard1 > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] o.a.s.c.SolrXmlConfig > >>> Loading > >>> > container configuration from /local/etc/solr/shard1/solr.xml > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > o.a.s.u.UpdateShardHandler > >>> > Creating UpdateShardHandler HTTP client with params: > >>> > socketTimeout=600000&connTimeout=60000&retry=true > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > >>> o.a.s.c.CorePropertiesLocator > >>> > Found 1 core definitions underneath /local/etc/solr/shard1 > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] > >>> o.a.s.c.CorePropertiesLocator > >>> > Cores are: [mysearch] > >>> > Aug 25, 2017 12:04:38 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.u.SolrIndexConfig IndexWriter infoStream solr > logging > >>> is > >>> > enabled > >>> > Aug 25, 2017 12:04:38 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.2 > >>> > Aug 25, 2017 12:04:38 PM INFO (qtp761960786-29) [ ] > >>> > o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for > >>> > 2147483647 <(214)%20748-3647> transient cores > >>> > Aug 25, 2017 12:04:38 PM INFO (main) [ ] o.e.j.s.Server Started > >>> @1225ms > >>> > Aug 25, 2017 12:04:38 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.s.IndexSchema [mysearch] Schema name=local > >>> > Aug 25, 2017 12:04:38 PM WARN (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.s.IndexSchema Field name_token is not multivalued > and > >>> > destination for multiple copyFields (7) > >>> > Aug 25, 2017 12:04:38 PM WARN (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.s.IndexSchema Field name_shingle is not multivalued > >>> and > >>> > destination for multiple copyFields (5) > >>> > Aug 25, 2017 12:04:38 PM WARN (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.s.IndexSchema Field name_sort is not multivalued > and > >>> > destination for multiple copyFields (7) > >>> > Aug 25, 2017 12:04:38 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.s.IndexSchema Loaded schema local/1.5 with uniqueid > >>> field > >>> > id > >>> > Aug 25, 2017 12:04:39 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.c.CoreContainer Creating SolrCore 'mysearch' using > >>> > configuration from instancedir /local/etc/solr/shard1/mysearch, > >>> trusted=true > >>> > Aug 25, 2017 12:04:39 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder > >>> > Aug 25, 2017 12:04:39 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.c.SolrCore [[mysearch] ] Opening new SolrCore at > >>> > [/local/etc/solr/shard1/mysearch], > >>> > dataDir=[/local/etc/solr/shard1/mysearch/data/] > >>> > Aug 25, 2017 12:04:39 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.r.XSLTResponseWriter xsltCacheLifetimeSeconds=5 > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.u.SolrIndexConfig IndexWriter infoStream solr logging is > enabled > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.2 > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.s.IndexSchema [mysearch] Schema name=local > >>> > Aug 25, 2017 12:04:39 PM WARN (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.s.IndexSchema Field name_token is not multivalued and > destination > >>> for > >>> > multiple copyFields (7) > >>> > Aug 25, 2017 12:04:39 PM WARN (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.s.IndexSchema Field name_shingle is not multivalued and > >>> destination > >>> > for multiple copyFields (5) > >>> > Aug 25, 2017 12:04:39 PM WARN (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.s.IndexSchema Field name_sort is not multivalued and > destination > >>> for > >>> > multiple copyFields (7) > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.s.IndexSchema Loaded schema local/1.5 with uniqueid field id > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.c.CoreContainer Creating SolrCore 'mysearch' using > configuration > >>> from > >>> > instancedir /local/etc/solr/shard1/mysearch, trusted=true > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.c.SolrCore solr.RecoveryStrategy.Builder > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.c.SolrCore [[mysearch] ] Opening new SolrCore at > >>> > [/local/etc/solr/shard1/mysearch], > >>> > dataDir=[/local/etc/solr/shard1/mysearch/data/] > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.r.XSLTResponseWriter xsltCacheLifetimeSeconds=5 > >>> > Aug 25, 2017 12:04:39 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.u.CommitTracker Hard AutoCommit: disabled > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.u.CommitTracker Hard AutoCommit: disabled > >>> > Aug 25, 2017 12:04:39 PM INFO (coreLoadExecutor-6-thread-1) [ > >>> > x:mysearch] o.a.s.u.CommitTracker Soft AutoCommit: disabled > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.u.CommitTracker Soft AutoCommit: disabled > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.c.SolrCore [mysearch] CLOSING SolrCore > >>> > org.apache.solr.core.SolrCore@3f24b393 > >>> > Aug 25, 2017 12:04:39 PM INFO (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.m.SolrMetricManager Closing metric reporters for: > >>> solr.core.mysearch > >>> > Aug 25, 2017 12:04:39 PM ERROR (qtp761960786-31) [ x:mysearch] > >>> > o.a.s.s.HttpSolrCall null:org.apache.solr.common.SolrException: > Unable > >>> to > >>> > create core [mysearch] > >>> > at org.apache.solr.core.CoreContainer.create( > >>> CoreContainer.java:935) > >>> > at > >>> > org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:1331) > >>> > at org.apache.solr.servlet.HttpSolrCall.init( > >>> HttpSolrCall.java:268) > >>> > at org.apache.solr.servlet.HttpSolrCall.call( > >>> HttpSolrCall.java:483) > >>> > at > >>> > org.apache.solr.servlet.SolrDispatchFilter.doFilter( > >>> SolrDispatchFilter.java:361) > >>> > at > >>> > org.apache.solr.servlet.SolrDispatchFilter.doFilter( > >>> SolrDispatchFilter.java:305) > >>> > at > >>> > org.eclipse.jetty.servlet.ServletHandler$CachedChain. > >>> doFilter(ServletHandler.java:1691) > >>> > at > >>> > org.eclipse.jetty.servlet.ServletHandler.doHandle( > >>> ServletHandler.java:582) > >>> > at > >>> > org.eclipse.jetty.server.handler.ScopedHandler.handle( > >>> ScopedHandler.java:143) > >>> > > >>> > > >>> > On Fri, Aug 25, 2017 at 10:47 AM, Nawab Zada Asad Iqbal < > >>> khi...@gmail.com> > >>> > wrote: > >>> > > >>> >> Hi, > >>> >> > >>> >> I am getting this error. i have deleted the file and restarted the > >>> server, > >>> >> but this error doesn't go away. > >>> >> > >>> >> What should I do to fix it? > >>> >> > >>> >> > >>> >> > >>> >> Caused by: org.apache.solr.common.SolrException: Error opening new > >>> >> searcher > >>> >> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:977) > >>> >> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:830) > >>> >> at org.apache.solr.core.CoreContainer.create( > >>> >> CoreContainer.java:920) > >>> >> ... 32 more > >>> >> Caused by: org.apache.solr.common.SolrException: Error opening new > >>> >> searcher > >>> >> at org.apache.solr.core.SolrCore. > >>> openNewSearcher(SolrCore.java: > >>> >> 2069) > >>> >> at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java: > >>> 2189) > >>> >> at org.apache.solr.core.SolrCore. > initSearcher(SolrCore.java: > >>> 1071) > >>> >> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:949) > >>> >> ... 34 more > >>> >> Caused by: org.apache.lucene.store.LockObtainFailedException: Lock > >>> held > >>> >> by this virtual machine: /local/var/solr/shard1/ > >>> >> mysearch/data/index/write.lock > >>> >> at org.apache.lucene.store.NativeFSLockFactory. > obtainFSLock( > >>> >> NativeFSLockFactory.java:127) > >>> >> at org.apache.lucene.store.FSLockFactory.obtainLock( > >>> >> FSLockFactory.java:41) > >>> >> at org.apache.lucene.store.BaseDirectory.obtainLock( > >>> >> BaseDirectory.java:45) > >>> >> at org.apache.lucene.index.IndexWriter.<init>( > >>> >> IndexWriter.java:800) > >>> >> at org.apache.solr.update.SolrIndexWriter.<init>( > >>> >> SolrIndexWriter.java:118) > >>> >> at org.apache.solr.update.SolrIndexWriter.create( > >>> >> SolrIndexWriter.java:93) > >>> >> at org.apache.solr.update.DefaultSolrCoreState. > >>> >> createMainIndexWriter(DefaultSolrCoreState.java:248) > >>> >> at org.apache.solr.update.DefaultSolrCoreState. > getIndexWriter( > >>> >> DefaultSolrCoreState.java:122) > >>> >> at org.apache.solr.core.SolrCore. > >>> openNewSearcher(SolrCore.java: > >>> >> 2030) > >>> >> ... 37 more > >>> >> > >>> >> > >>> >> > >>> >> Thanks > >>> >> Nawab > >>> >> > >>> > >> >
