[
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
