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 >>> >> >>> >>
