[ https://issues.apache.org/jira/browse/SOLR-12998?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Varun Thacker updated SOLR-12998: --------------------------------- Description: I started Solr ( 7_6 branch ) using {{bin/solr start -e cloud -noprompt}} and indexed 25M documents which amounts to roughly 1GB per replica in raw disk space. Whenever I restart the cluster, node2 ( 7574 ) get's these errors in the logs which seems to indicate that request recovery is trying to find a core which isn't completely loaded yet. {code:java} 2018-11-18 21:06:09.845 INFO (coreLoadExecutor-9-thread-2-processing-n:192.168.0.7:7574_solr) [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] o.a.s.c.SolrCore [[gettingstarted_shard2_replica_n6] ] Opening new SolrCore at [/Users/varunthacker/apache-work/lucene-solr/solr/example/cloud/node2/solr/gettingstarted_shard2_replica_n6], dataDir=[/Users/varunthacker/apache-work/lucene-solr/solr/example/cloud/node2/solr/gettingstarted_shard2_replica_n6/data/] ... 2018-11-18 21:06:10.501 INFO (qtp690521419-148) [ x:gettingstarted_shard2_replica_n6] o.a.s.h.a.CoreAdminOperation It has been requested that we recover: core=gettingstarted_shard2_replica_n6 ... 2018-11-18 21:06:10.503 ERROR (qtp690521419-141) [ x:gettingstarted_shard1_replica_n1] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Unable to locate core gettingstarted_shard1_replica_n1 at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$5(CoreAdminOperation.java:167) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:395) at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:180) ... 2018-11-18 21:06:10.503 INFO (qtp690521419-148) [ x:gettingstarted_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=gettingstarted_shard2_replica_n6&action=REQUESTRECOVERY&wt=javabin&version=2} status=400 QTime=3 ... still the core is loading 2018-11-18 21:06:10.876 INFO (coreLoadExecutor-9-thread-2-processing-n:192.168.0.7:7574_solr) [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@2d17168a[gettingstarted_shard2_replica_n6] main] ... now done 2018-11-18 21:06:10.953 INFO (searcherExecutor-10-thread-1-processing-n:192.168.0.7:7574_solr x:gettingstarted_shard2_replica_n6 c:gettingstarted s:shard2 r:core_node8) [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] o.a.s.c.SolrCore [gettingstarted_shard2_replica_n6] Registered new searcher Searcher@2d17168a[gettingstarted_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader(_49(7.6.0):C2416916/4913:delGen=2 _a4(7.6.0):C2474322 _71(7.6.0):C2723220 _4k(7.6.0):c111317 _d7(7.6.0):C2501101 _bt(7.6.0):c91922 _di(7.6.0):c339286 _eb(7.6.0):c163244 _ds(7.6.0):c92780 _e1(7.6.0):c337329 _em(7.6.0):c360003 _ew(7.6.0):c263533 _fg(7.6.0):c226118 _f6(7.6.0):c266132 _es(7.6.0):C2361 _f8(7.6.0):C2251 _ff(7.6.0):C1821 _fh(7.6.0):C20079 _fi(7.6.0):C35733 _fj(7.6.0):C37203 _fk(7.6.0):C34780 _fl(7.6.0):C262 _fm(7.6.0):C2148 _fn(7.6.0):C2503))}{code} was: I started Solr ( 7_6 branch ) using {{bin/solr start -e cloud -noprompt}} and indexed 25M documents which amounts to roughly 1GB per replica in raw disk space. Whenever I restart the cluster node2 ( 7574 ) get's these errors in the logs which seem to indicate that request recovery is trying to find a core which isn't completely loaded yet. {code:java} 2018-11-18 21:06:09.845 INFO (coreLoadExecutor-9-thread-2-processing-n:192.168.0.7:7574_solr) [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] o.a.s.c.SolrCore [[gettingstarted_shard2_replica_n6] ] Opening new SolrCore at [/Users/varunthacker/apache-work/lucene-solr/solr/example/cloud/node2/solr/gettingstarted_shard2_replica_n6], dataDir=[/Users/varunthacker/apache-work/lucene-solr/solr/example/cloud/node2/solr/gettingstarted_shard2_replica_n6/data/] ... 2018-11-18 21:06:10.501 INFO (qtp690521419-148) [ x:gettingstarted_shard2_replica_n6] o.a.s.h.a.CoreAdminOperation It has been requested that we recover: core=gettingstarted_shard2_replica_n6 ... 2018-11-18 21:06:10.503 ERROR (qtp690521419-141) [ x:gettingstarted_shard1_replica_n1] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Unable to locate core gettingstarted_shard1_replica_n1 at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$5(CoreAdminOperation.java:167) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:395) at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:180) ... 2018-11-18 21:06:10.503 INFO (qtp690521419-148) [ x:gettingstarted_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=gettingstarted_shard2_replica_n6&action=REQUESTRECOVERY&wt=javabin&version=2} status=400 QTime=3 ... still the core is loading 2018-11-18 21:06:10.876 INFO (coreLoadExecutor-9-thread-2-processing-n:192.168.0.7:7574_solr) [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@2d17168a[gettingstarted_shard2_replica_n6] main] ... now done 2018-11-18 21:06:10.953 INFO (searcherExecutor-10-thread-1-processing-n:192.168.0.7:7574_solr x:gettingstarted_shard2_replica_n6 c:gettingstarted s:shard2 r:core_node8) [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] o.a.s.c.SolrCore [gettingstarted_shard2_replica_n6] Registered new searcher Searcher@2d17168a[gettingstarted_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader(_49(7.6.0):C2416916/4913:delGen=2 _a4(7.6.0):C2474322 _71(7.6.0):C2723220 _4k(7.6.0):c111317 _d7(7.6.0):C2501101 _bt(7.6.0):c91922 _di(7.6.0):c339286 _eb(7.6.0):c163244 _ds(7.6.0):c92780 _e1(7.6.0):c337329 _em(7.6.0):c360003 _ew(7.6.0):c263533 _fg(7.6.0):c226118 _f6(7.6.0):c266132 _es(7.6.0):C2361 _f8(7.6.0):C2251 _ff(7.6.0):C1821 _fh(7.6.0):C20079 _fi(7.6.0):C35733 _fj(7.6.0):C37203 _fk(7.6.0):C34780 _fl(7.6.0):C262 _fm(7.6.0):C2148 _fn(7.6.0):C2503))}{code} > Race condition between requery recovery and the core load completing > -------------------------------------------------------------------- > > Key: SOLR-12998 > URL: https://issues.apache.org/jira/browse/SOLR-12998 > Project: Solr > Issue Type: Bug > Security Level: Public(Default Security Level. Issues are Public) > Reporter: Varun Thacker > Priority: Major > > I started Solr ( 7_6 branch ) using {{bin/solr start -e cloud -noprompt}} and > indexed 25M documents which amounts to roughly 1GB per replica in raw disk > space. > > Whenever I restart the cluster, node2 ( 7574 ) get's these errors in the logs > which seems to indicate that request recovery is trying to find a core which > isn't completely loaded yet. > > {code:java} > 2018-11-18 21:06:09.845 INFO > (coreLoadExecutor-9-thread-2-processing-n:192.168.0.7:7574_solr) > [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] > o.a.s.c.SolrCore [[gettingstarted_shard2_replica_n6] ] Opening new SolrCore > at > [/Users/varunthacker/apache-work/lucene-solr/solr/example/cloud/node2/solr/gettingstarted_shard2_replica_n6], > > dataDir=[/Users/varunthacker/apache-work/lucene-solr/solr/example/cloud/node2/solr/gettingstarted_shard2_replica_n6/data/] > ... > 2018-11-18 21:06:10.501 INFO (qtp690521419-148) [ > x:gettingstarted_shard2_replica_n6] o.a.s.h.a.CoreAdminOperation It has been > requested that we recover: core=gettingstarted_shard2_replica_n6 > ... > 2018-11-18 21:06:10.503 ERROR (qtp690521419-141) [ > x:gettingstarted_shard1_replica_n1] o.a.s.h.RequestHandlerBase > org.apache.solr.common.SolrException: Unable to locate core > gettingstarted_shard1_replica_n1 > at > org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$5(CoreAdminOperation.java:167) > at > org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) > at > org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:395) > at > org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:180) > ... > 2018-11-18 21:06:10.503 INFO (qtp690521419-148) [ > x:gettingstarted_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null > path=/admin/cores > params={core=gettingstarted_shard2_replica_n6&action=REQUESTRECOVERY&wt=javabin&version=2} > status=400 QTime=3 > ... still the core is loading > 2018-11-18 21:06:10.876 INFO > (coreLoadExecutor-9-thread-2-processing-n:192.168.0.7:7574_solr) > [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] > o.a.s.s.SolrIndexSearcher Opening > [Searcher@2d17168a[gettingstarted_shard2_replica_n6] main] > ... now done > 2018-11-18 21:06:10.953 INFO > (searcherExecutor-10-thread-1-processing-n:192.168.0.7:7574_solr > x:gettingstarted_shard2_replica_n6 c:gettingstarted s:shard2 r:core_node8) > [c:gettingstarted s:shard2 r:core_node8 x:gettingstarted_shard2_replica_n6] > o.a.s.c.SolrCore [gettingstarted_shard2_replica_n6] Registered new searcher > Searcher@2d17168a[gettingstarted_shard2_replica_n6] > main{ExitableDirectoryReader(UninvertingDirectoryReader(_49(7.6.0):C2416916/4913:delGen=2 > _a4(7.6.0):C2474322 _71(7.6.0):C2723220 _4k(7.6.0):c111317 > _d7(7.6.0):C2501101 _bt(7.6.0):c91922 _di(7.6.0):c339286 _eb(7.6.0):c163244 > _ds(7.6.0):c92780 _e1(7.6.0):c337329 _em(7.6.0):c360003 _ew(7.6.0):c263533 > _fg(7.6.0):c226118 _f6(7.6.0):c266132 _es(7.6.0):C2361 _f8(7.6.0):C2251 > _ff(7.6.0):C1821 _fh(7.6.0):C20079 _fi(7.6.0):C35733 _fj(7.6.0):C37203 > _fk(7.6.0):C34780 _fl(7.6.0):C262 _fm(7.6.0):C2148 _fn(7.6.0):C2503))}{code} -- This message was sent by Atlassian JIRA (v7.6.3#76005) --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org