lucene-solr-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Joe Obernberger <joseph.obernber...@gmail.com>
Subject Re: Recovery Issue - Solr 6.6.1 and HDFS
Date Tue, 21 Nov 2017 18:20:23 GMT
Erick - thank you very much for the reply.  I'm still working through 
restarting the nodes one by one.

I'm stopping the nodes with the script, but yes - they are being killed 
forcefully because they are in this recovery, failed, retry loop.  I 
could increase the timeout, but they never seem to recover.

The largest tlog file that I see currently is 222MBytes. Autocommit is 
set to 1800000 and autoSoftCommit is set to 120000. Errors when they are 
in the long recovery are things like:

2017-11-20 21:41:29.755 ERROR 
(recoveryExecutor-3-thread-4-processing-n:frodo:9100_solr 
x:UNCLASS_shard37_replica1 s:shard37 c:UNCLASS r:core_node196) 
[c:UNCLASS s:shard37 r:core_node196 x:UNCLASS_shard37_replica1] 
o.a.s.h.IndexFetcher Error closing file: _8dmn.cfs
org.apache.hadoop.ipc.RemoteException(java.io.IOException): File 
/solr6.6.0/UNCLASS/core_node196/data/index.20171120195705961/_8dmn.cfs 
could only be replicated to 0 nodes instead of minReplication (=1).  
There are 39 datanode(s) running and no node(s) are excluded in this 
operation.
         at 
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.chooseTarget4NewBlock(BlockManager.java:1716)
         at 
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalBlock(FSNamesystem.java:3385)

Complete log is here for one of the shards that was forcefully stopped.
http://lovehorsepower.com/solr.log

As to what is in the logs when it is recovering for several hours, it's 
many WARN messages from the DFSClient such as:
Abandoning 
BP-1714598269-10.2.100.220-1341346046854:blk_4366207808_1103082741732
and
Excluding datanode 
DatanodeInfoWithStorage[172.16.100.229:50010,&#8203;DS-5985e40d-830a-44e7-a2ea-fc60bebabc30,&#8203;DISK]

or from the IndexFetcher:

File _a96y.cfe did not match. expected checksum is 3502268220 and actual 
is checksum 2563579651. expected length is 405 and actual length is 405

Unfortunately, I'm not getting errors from some of the nodes (still 
working through restarting them) about zookeeper:

org.apache.solr.common.SolrException: Could not get leader props
     at 
org.apache.solr.cloud.ZkController.getLeaderProps(ZkController.java:1043)
     at 
org.apache.solr.cloud.ZkController.getLeaderProps(ZkController.java:1007)
     at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:963)
     at org.apache.solr.cloud.ZkController.register(ZkController.java:902)
     at org.apache.solr.cloud.ZkController.register(ZkController.java:846)
     at 
org.apache.solr.core.ZkContainer.lambda$registerInZk$0(ZkContainer.java:181)
     at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
     at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
     at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
     at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.zookeeper.KeeperException$NoNodeException: 
KeeperErrorCode = NoNode for /collections/UNCLASS/leaders/shard21/leader
     at 
org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
     at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
     at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
     at 
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:357)
     at 
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:354)
     at 
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
     at 
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:354)
     at 
org.apache.solr.cloud.ZkController.getLeaderProps(ZkController.java:1021)

Any idea what those could be?  Those shards are not coming back up. 
Sorry so many questions!

-Joe

On 11/21/2017 12:11 PM, Erick Erickson wrote:
> How are you stopping Solr? Nodes should not go into recovery on
> startup unless Solr was killed un-gracefully (i.e. kill -9 or the
> like). If you use the bin/solr script to stop Solr and see a message
> about "killing XXX forcefully" then you can lengthen out the time the
> script waits for shutdown (there's a sysvar you can set, look in the
> script).
>
> Actually I'll correct myself a bit. Shards _do_ go into recovery but
> it should be very short in the graceful shutdown case. Basically
> shards temporarily go into recovery as part of normal processing just
> long enough to see there's no recovery necessary, but that should be
> measured in a few seconds.
>
> What it sounds like from this "The shards go into recovery and start
> to utilize nearly all of their network" is that your nodes go into
> "full recovery" where the entire index is copied down because the
> replica thinks it's "too far" out of date. That indicates something
> weird about the state when the Solr nodes stopped.
>
> wild-shot-in-the-dark question. How big are your tlogs? If you don't
> hard commit very often, the tlogs can replay at startup for a very
> long time.
>
> This makes no sense to me, I'm surely missing something:
>
> The process at this point is to start one node, find out the lock
> files, wait for it to come up completely (hours), stop it, delete the
> write.lock files, and restart.  Usually this second restart is faster,
> but it still can take 20-60 minutes.
>
> When you start one node it may take a few minutes for leader electing
> to kick in (the default is 180 seconds) but absent replication it
> should just be there. Taking hours totally violates my expectations.
> What does Solr _think_ it's doing? What's in the logs at that point?
> And if you stop solr gracefully, there shouldn't be a problem with
> write.lock.
>
> You could also try increasing the timeouts, and the HDFS directory
> factory has some parameters to tweak that are a mystery to me...
>
> All in all, this is behavior that I find mystifying.
>
> Best,
> Erick
>
> On Tue, Nov 21, 2017 at 5:07 AM, Joe Obernberger
> <joseph.obernberger@gmail.com> wrote:
>> Hi All - we have a system with 45 physical boxes running solr 6.6.1 using
>> HDFS as the index.  The current index size is about 31TBytes.  With 3x
>> replication that takes up 93TBytes of disk. Our main collection is split
>> across 100 shards with 3 replicas each.  The issue that we're running into
>> is when restarting the solr6 cluster.  The shards go into recovery and start
>> to utilize nearly all of their network interfaces.  If we start too many of
>> the nodes at once, the shards will go into a recovery, fail, and retry loop
>> and never come up.  The errors are related to HDFS not responding fast
>> enough and warnings from the DFSClient.  If we stop a node when this is
>> happening, the script will force a stop (180 second timeout) and upon
>> restart, we have lock files (write.lock) inside of HDFS.
>>
>> The process at this point is to start one node, find out the lock files,
>> wait for it to come up completely (hours), stop it, delete the write.lock
>> files, and restart.  Usually this second restart is faster, but it still can
>> take 20-60 minutes.
>>
>> The smaller indexes recover much faster (less than 5 minutes). Should we
>> have not used so many replicas with HDFS?  Is there a better way we should
>> have built the solr6 cluster?
>>
>> Thank you for any insight!
>>
>> -Joe
>>
> ---
> This email has been checked for viruses by AVG.
> http://www.avg.com
>


Mime
View raw message