Solrcloud performance issues
Hi Erick, We have following configuration of our solr cloud 1. 10 Shards 2. 15 replicas per shard 3. 9 GB of index size per shard 4. a total of around 90 mil documents 5. 2 collection viz search1 serving live traffic and search 2 for indexing. We swap collection when indexing finishes 6. On 150 hosts we have 2 JVMs running one for search1 collection and other for search2 collection 7. Each jvm has 12 GB of heap assigned to it while the host has 50GB in total 8. Each host has 16 processors 9. Linux XXX 2.6.32-431.5.1.el6.x86_64 #1 SMP Wed Feb 12 00:41:43 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux 10. We have two ways to index data. 1. Bulk indexing . All 90 million docs pumped in from 14 parallel process (on 14 different client hosts). This is done on collection that is not serving live traffic 2. Incremental indexing . Only delta changes (Range from 100K to 5 Mil) every two hours. This is done on collection also serving live traffic 11. The request per second count on live collection is around 300 TPS 12. Hard commit setting is every 30 second with open searcher false and soft commit setting is every 15 minutes . We have tried a lot of different setting here BTW. Now we have two issues with indexing 1) Solr just could not keep up with the bulk indexing when replicas are also active. We have concluded this by changing the number of replicas to just 2 , to 4 and then to 15. When the number of replicas increases the bulk indexing time increase almost exponentially We seem to have encountered the same issue reported here https://issues.apache.org/jira/browse/SOLR-6816 It gets to a point that even to index 100 docs the solr cluster would take 300 second. It would start of indexing 100 docs in 55 millisecond and slowly increase over time and within hour and a half just could not keep up. We have a workaround for this and i.e we stop all the replicas , do the bulk indexing and bring all the replicas up one by one . This sort of defeats the purpose of solr cloud but we can still work with this workaround. We can do this because , bulk indexing happen on the collection that is not serving live traffic. However we would love to have a solution from the solr cloud itself like ask it to stop replication and start via an API at the end of indexing. 2) This issues is related to soft commit with incremental indexing . When we do incremental indexing, it is done on the same collection serving live traffic with 300 request per second throughput. Everything is fine except whenever the soft commit happens. Each time soft commit (autosoftcommit in sorlconfig.xml) happens which BTW happens almost at the same time throughout the cluster , there is a spike in the response times and throughput decreases almost to 150 tps. The spike continues for 2 minutes and then it happens again at the exact interval when the soft commit happens. We have monitored the logs and found a direct co relation when the soft commit happens and when the response time tanks. Now the latter issue is quite disturbing , because it is serving live traffic and we cannot sustain these periodic degradation. We have played around with different soft commit setting . Interval ranging from 2 minutes to 30 minutes . Auto warming half cache , auto warming full cache, auto warming only 10 %. Doing warm up queries on every new searcher , doing NONE warm up queries on every new searching and all the different setting yields the same results . As and when soft commit happens the response time tanks and throughput deceases. The difference is almost 50 % in response times and 50 % in throughput Our workaround for this solution is to also do incremental delta indexing on the collection not serving live traffic and swap when it is done. As you can see that this also defeats the purpose of solr cloud . We cannot do bulk indexing because replicas cannot keeps up and we cannot do incremental indexing because of soft commit performance. Is there a way to make the cluster not do soft commit all at the same time or is there a way to make soft commit not cause this degradation ? We are open to any ideas at this time now. -- * Vijay Sekhri *
Re: replicas goes in recovery mode right after update
Hi Erick, @ichattopadhyaya beat me to it already yesterday. So we are good -cheers Vijay On Wed, Jan 28, 2015 at 1:30 PM, Erick Erickson wrote: > Vijay: > > Thanks for reporting this back! Could I ask you to post a new patch with > your correction? Please use the same patch name > (SOLR-5850.patch), and include a note about what you found (I've already > added a comment). > > Thanks! > Erick > > On Wed, Jan 28, 2015 at 9:18 AM, Vijay Sekhri > wrote: > > > Hi Shawn, > > Thank you so much for the assistance. Building is not a problem . Back in > > the days I have worked with linking, compiling and building C , C++ > > software . Java is a piece of cake. > > We have built the new war from the source version 4.10.3 and our > > preliminary tests have shown that our issue (replicas in recovery on high > > load)* is resolved *. We will continue to do more testing and confirm . > > Please note that the *patch is BUGGY*. > > > > It removed the break statement within while loop because of which, > whenever > > we send a list of docs it would hang (API CloudSolrServer.add) , but it > > would work if send one doc at a time. > > > > It took a while to figure out why that is happening. Once we put the > break > > statement back it worked like a charm. > > Furthermore the patch has > > > > > solr/solrj/src/java/org/apache/solr/client/solrj/impl/ConcurrentUpdateSolrClient.java > > which should be > > > > > solr/solrj/src/java/org/apache/solr/client/solrj/impl/ConcurrentUpdateSolrServer.java > > > > Finally checking if(!offer) is sufficient than using if(offer == false) > > Last but not the least having a configurable queue size and timeouts > > (managed via solrconfig) would be quite helpful > > Thank you once again for your help. > > > > Vijay > > > > On Tue, Jan 27, 2015 at 6:20 PM, Shawn Heisey > wrote: > > > > > On 1/27/2015 2:52 PM, Vijay Sekhri wrote: > > > > Hi Shawn, > > > > Here is some update. We found the main issue > > > > We have configured our cluster to run under jetty and when we tried > > full > > > > indexing, we did not see the original Invalid Chunk error. However > the > > > > replicas still went into recovery > > > > All this time we been trying to look into replicas logs to diagnose > the > > > > issue. The problem seem to be at the leader side. When we looked into > > > > leader logs, we found the following on all the leaders > > > > > > > > 3439873 [qtp1314570047-92] WARN > > > > org.apache.solr.update.processor.DistributedUpdateProcessor – Error > > > > sending update > > > > *java.lang.IllegalStateException: Queue full* > > > > > > > > > > > > > There is a similar bug reported around this > > > > https://issues.apache.org/jira/browse/SOLR-5850 > > > > > > > > and it seem to be in OPEN status. Is there a way we can configure the > > > queue > > > > size and increase it ? or is there a version of solr that has this > > issue > > > > resolved already? > > > > Can you suggest where we go from here to resolve this ? We can > repatch > > > the > > > > war file if that is what you would recommend . > > > > In the end our initial speculation about solr unable to handle so > many > > > > update is correct. We do not see this issue when the update load is > > less. > > > > > > Are you in a position where you can try the patch attached to > > > SOLR-5850? You would need to get the source code for the version > you're > > > on (or perhaps a newer 4.x version), patch it, and build Solr yourself. > > > If you have no experience building java packages from source, this > might > > > prove to be difficult. > > > > > > Thanks, > > > Shawn > > > > > > > > > > > > -- > > * > > Vijay Sekhri > > * > > > -- * Vijay Sekhri *
Re: replicas goes in recovery mode right after update
Hi Shawn, Thank you so much for the assistance. Building is not a problem . Back in the days I have worked with linking, compiling and building C , C++ software . Java is a piece of cake. We have built the new war from the source version 4.10.3 and our preliminary tests have shown that our issue (replicas in recovery on high load)* is resolved *. We will continue to do more testing and confirm . Please note that the *patch is BUGGY*. It removed the break statement within while loop because of which, whenever we send a list of docs it would hang (API CloudSolrServer.add) , but it would work if send one doc at a time. It took a while to figure out why that is happening. Once we put the break statement back it worked like a charm. Furthermore the patch has solr/solrj/src/java/org/apache/solr/client/solrj/impl/ConcurrentUpdateSolrClient.java which should be solr/solrj/src/java/org/apache/solr/client/solrj/impl/ConcurrentUpdateSolrServer.java Finally checking if(!offer) is sufficient than using if(offer == false) Last but not the least having a configurable queue size and timeouts (managed via solrconfig) would be quite helpful Thank you once again for your help. Vijay On Tue, Jan 27, 2015 at 6:20 PM, Shawn Heisey wrote: > On 1/27/2015 2:52 PM, Vijay Sekhri wrote: > > Hi Shawn, > > Here is some update. We found the main issue > > We have configured our cluster to run under jetty and when we tried full > > indexing, we did not see the original Invalid Chunk error. However the > > replicas still went into recovery > > All this time we been trying to look into replicas logs to diagnose the > > issue. The problem seem to be at the leader side. When we looked into > > leader logs, we found the following on all the leaders > > > > 3439873 [qtp1314570047-92] WARN > > org.apache.solr.update.processor.DistributedUpdateProcessor – Error > > sending update > > *java.lang.IllegalStateException: Queue full* > > > > > There is a similar bug reported around this > > https://issues.apache.org/jira/browse/SOLR-5850 > > > > and it seem to be in OPEN status. Is there a way we can configure the > queue > > size and increase it ? or is there a version of solr that has this issue > > resolved already? > > Can you suggest where we go from here to resolve this ? We can repatch > the > > war file if that is what you would recommend . > > In the end our initial speculation about solr unable to handle so many > > update is correct. We do not see this issue when the update load is less. > > Are you in a position where you can try the patch attached to > SOLR-5850? You would need to get the source code for the version you're > on (or perhaps a newer 4.x version), patch it, and build Solr yourself. > If you have no experience building java packages from source, this might > prove to be difficult. > > Thanks, > Shawn > > -- * Vijay Sekhri *
Re: replicas goes in recovery mode right after update
e if that is what you would recommend .
In the end our initial speculation about solr unable to handle so many
update is correct. We do not see this issue when the update load is less.
Here is the log from the replica FYI. No invalid chunk error with Jetty but
the issue at hand is unrelated
2382763 [Thread-74] INFO org.apache.solr.cloud.ZkController – Wrote
recovering to /collections/search1/leader_initiated_recovery
/shard7/core_node214
2382776 [Thread-74] INFO org.apache.solr.update.DefaultSolrCoreState –
Running recovery - first canceling any ongoing recovery
2382777 [Thread-74] WARN org.apache.solr.cloud.RecoveryStrategy –
Stopping recovery for core=search1_shard7_replica1 coreNodeName=core_node214
2382778 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
Starting recovery process. core=search1_shard7_replica1
recoveringAfterStartup=false
2382779 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
Publishing state of core search1_shard7_replica1 as recovering, leader is
http://:/solr/search1_shard7_replica2/
and I am http://X:
/solr/search1_shard7_replica1/
2382779 [RecoveryThread] INFO org.apache.solr.cloud.ZkController –
publishing core=search1_shard7_replica1 state=recovering collection=search1
2382779 [RecoveryThread] INFO org.apache.solr.cloud.ZkController –
numShards not found on descriptor - reading it from system property
2382785 [zkCallback-2-thread-5] INFO
org.apache.solr.common.cloud.ZkStateReader – A cluster state change:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 40)
2382796 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
Sending prep recovery command to http://XX:/solr;
WaitForState:
action=PREPRECOVERY&core=search1_shard7_replica2&nodeName=XX%3AXXX_solr&coreNodeName=core_node214&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
2382953 [zkCallback-2-thread-5] INFO
org.apache.solr.common.cloud.ZkStateReader – A cluster state change:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 40)
2385815 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
Attempting to PeerSync from
http://s:YY/solr/search1_shard7_replica2/
core=search1_shard7_replica1 - recoveringAfterStartup=false
2385815 [RecoveryThread] INFO org.apache.solr.update.PeerSync – PeerSync:
core=search1_shard7_replica1 url=http://XX:/solr START
replicas=[http://XX:YY/solr/search1_shard7_replica2/]
nUpdates=100
2385816 [RecoveryThread] WARN org.apache.solr.update.PeerSync – PeerSync:
core=search1_shard7_replica1 url=http://:YY/solr
too many updates received since start - startingUpdates no longer overlaps
with our currentUpdates
2385817 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
PeerSync Recovery was not successful - trying replication.
core=search1_shard7_replica1
2385817 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
Starting Replication Recovery. core=search1_shard7_replica1
2385817 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
Begin buffering updates. core=search1_shard7_replica1
2385817 [RecoveryThread] INFO org.apache.solr.update.UpdateLog – Starting
to buffer updates. FSUpdateLog{state=ACTIVE,
tlog=tlog{file=/opt/solr/solrnodes/solrnode1/search1_shard7_replica1/data/tlog/tlog.407
refcount=1}}
2385817 [RecoveryThread] INFO org.apache.solr.cloud.RecoveryStrategy –
Attempting to replicate from
http://XX:Y/solr/search1_shard7_replica2/.
core=search1_shard7_replica1
2386469 [RecoveryThread] INFO org.apache.solr.handler.SnapPuller – No
value set for 'pollInterval'. Timer Task not started.
2386477 [RecoveryThread] INFO org.apache.solr.handler.SnapPuller –
Master's generation: 963
2386478 [RecoveryThread] INFO org.apache.solr.handler.SnapPuller –
Slave's generation: 962
2386478 [RecoveryThread] INFO org.apache.solr.handler.SnapPuller –
Starting replication process
2386489 [RecoveryThread] INFO org.apache.solr.handler.SnapPuller – Number
of files in latest index in master: 250
2386489 [RecoveryThread] INFO org.apache.solr.core.CachingDirectoryFactory
– return new directory for
/opt/solr/solrnodes/solrnode1/search1_shard7_replica1/data/index.20150127135840219
2386491 [RecoveryThread] WARN org.apache.solr.handler.SnapPuller – File
_89e.fdt expected to be 811432 while it is 4204287
-regards
Vijay
On Tue, Jan 27, 2015 at 12:07 AM, Shawn Heisey wrote:
> On 1/26/2015 9:34 PM, Vijay Sekhri wrote:
> > Hi Shawn, Erick
> > So it turned out that once we increased our
Re: replicas goes in recovery mode right after update
Hi Shawn, Erick
>From another replicas right after the same error it seems the leader
initiates the recovery of the replicas. This one has a bit different log
information than the other one that went into recovery. I am not sure if
this helps in diagnosing
Caused by: java.io.IOException: JBWEB002020: Invalid chunk header
at
org.apache.coyote.http11.filters.ChunkedInputFilter.parseChunkHeader(ChunkedInputFilter.java:281)
at
org.apache.coyote.http11.filters.ChunkedInputFilter.doRead(ChunkedInputFilter.java:134)
at
org.apache.coyote.http11.InternalInputBuffer.doRead(InternalInputBuffer.java:697)
at org.apache.coyote.Request.doRead(Request.java:438)
at
org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:341)
... 31 more
21:55:07,678 INFO [org.apache.solr.handler.admin.CoreAdminHandler]
(http-/10.235.43.57:8680-32) It has been requested that we recover:
core=search1_shard4_replica13
21:55:07,678 INFO [org.apache.solr.servlet.SolrDispatchFilter]
(http-/10.235.43.57:8680-32) [admin] webapp=null path=/admin/cores
params={action=REQUESTRECOVERY&core=search1_shard4_replica13&wt=javabin&version=2}
status=0 QTime=0
21:55:07,678 INFO [org.apache.solr.cloud.ZkController] (Thread-443)
publishing core=search1_shard4_replica13 state=recovering collection=search1
21:55:07,678 INFO [org.apache.solr.cloud.ZkController] (Thread-443)
numShards not found on descriptor - reading it from system property
21:55:07,681 INFO [org.apache.solr.cloud.ZkController] (Thread-443) Wrote
recovering to /collections/search1/leader_initiated_recovery
/shard4/core_node192
On Mon, Jan 26, 2015 at 10:34 PM, Vijay Sekhri
wrote:
> Hi Shawn, Erick
> So it turned out that once we increased our indexing rate to the original
> full indexing rate the replicas went back into recovery no matter what the
> zk timeout setting was. Initially we though that increasing the timeout is
> helping but apparently not . We just decreased indexing rate and that
> caused less replicas to go in recovery. Once we have our full indexing rate
> almost all replicas went into recovery no matter what the zk timeout or the
> ticktime setting were. We reverted back the ticktime to original 2 seconds
>
> So we investigated further and after checking the logs we found this
> exception happening right before the recovery process is initiated. We
> observed this on two different replicas that went into recovery. We are not
> sure if this is a coincidence or a real problem . Notice we were also
> putting some search query load while indexing to trigger the recovery
> behavior
>
> 22:00:32,493 INFO [org.apache.solr.cloud.RecoveryStrategy]
> (rRecoveryThread) Finished recovery process. core=search1_shard5_replica2
> 22:00:32,503 INFO [org.apache.solr.common.cloud.ZkStateReader]
> (zkCallback-2-thread-66) A cluster state change: WatchedEvent
> state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has
> occurred - updating... (live nodes size: 22)
> 22:00:40,450 INFO [org.apache.solr.update.LoggingInfoStream]
> (http-/10.235.46.36:8580-27) [FP][http-/10.235.46.36:8580-27]: trigger
> flush: activeBytes=101796784 deleteBytes=3061644 vs limit=104857600
> 22:00:40,450 INFO [org.apache.solr.update.LoggingInfoStream]
> (http-/10.235.46.36:8580-27) [FP][http-/10.235.46.36:8580-27]: thread
> state has 12530488 bytes; docInRAM=2051
> 22:00:40,450 INFO [org.apache.solr.update.LoggingInfoStream]
> (http-/10.235.46.36:8580-27) [FP][http-/10.235.46.36:8580-27]: thread
> state has 12984633 bytes; docInRAM=2205
>
>
> 22:00:40,861 ERROR [org.apache.solr.core.SolrCore]
> (http-/10.235.46.36:8580-32)
> ClientAbortException: * java.io.IOException: JBWEB002020: Invalid chunk
> header*
> at
> org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:351)
> at
> org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:422)
> at
> org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:373)
> at
> org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:193)
> at
> org.apache.solr.common.util.FastInputStream.readWrappedStream(FastInputStream.java:80)
> at
> org.apache.solr.common.util.FastInputStream.refill(FastInputStream.java:89)
> at
> org.apache.solr.common.util.FastInputStream.readByte(FastInputStream.java:192)
> at
> org.apache.solr.common.util.JavaBinCodec.unmarshal(JavaBinCodec.java:111)
> at
> org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec.unmarshal(JavaBinUpdateRequestCodec.java:173)
> at
> org.apache.solr.handler.loader.JavabinLoader.parseAndLoadDocs(JavabinLoader.java:106)
> at
> org.apache.solr.handler.loader.JavabinLoader.load(JavabinLo
Re: replicas goes in recovery mode right after update
rty
22:00:41,889 INFO [org.apache.solr.common.cloud.ZkStateReader]
(zkCallback-2-thread-66) A cluster state change: WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has
occurred - updating... (live nodes size: 22)
22:00:41,890 INFO [org.apache.solr.cloud.ZkController] (Thread-472)* Wrote
recovering to
/collections/search1/leader_initiated_recovery/shard5/core_node223*
22:00:41,892 INFO [org.apache.solr.update.DefaultSolrCoreState]
(Thread-472) Running recovery - first canceling any ongoing recovery
22:00:41,893 INFO [org.apache.solr.cloud.RecoveryStrategy]
(RecoveryThread) Starting recovery process. core=search1_shard5_replica2
recoveringAfterStartup=false
22:00:41,894 INFO [org.apache.solr.cloud.RecoveryStrategy]
(RecoveryThread) Publishing state of core search1_shard5_replica2 as
recovering, leader is http://XXCHANGEDONPURPOSE:8680/solr/search1/
and I am http://solrx341p.qa.ch3.s.com:8580/solr/search1_shard5_replica2/
22:00:41,894 INFO [org.apache.solr.cloud.ZkController] (RecoveryThread)
publishing core=search1_shard5_replica2 state=recovering collection=search1
22:00:41,894 INFO [org.apache.solr.cloud.ZkController] (RecoveryThread)
numShards not found on descriptor - reading it from system property
22:00:41,896 INFO [org.apache.solr.cloud.RecoveryStrategy]
(RecoveryThread) Sending prep recovery command to
http://XCHANGEDONPURPOSE:8680/solr; WaitForState:
action=PREPRECOVERY&core=search1&nodeName=XXCHANGEDONPURPOSE
XXX%3A8580_solr&coreNodeName=core_node223&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
22:00:42,006 INFO [org.apache.solr.common.cloud.ZkStateReader]
(zkCallback-2-thread-66) A cluster state change: WatchedEvent
state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has
occurred - updating... (live nodes size: 22)
15Gb of heap is allocated to these searchers and it hardly goes over 8GB.
Full GC does not happen. We write gc logs to separate file and also
monitored these process via visualvm . It seems to have enough memory
On Mon, Jan 26, 2015 at 5:13 PM, Shawn Heisey wrote:
> On 1/26/2015 2:26 PM, Vijay Sekhri wrote:
> > Hi Erick,
> > In solr.xml file I had zk timeout set to/ > name="zkClientTimeout">${zkClientTimeout:45}/
> > One thing that made a it a bit better now is the zk tick time and
> > syncLimit settings. I set it to a higher value as below. This may not
> > be advisable though.
> >
> > tickTime=3
> > initLimit=30
> > syncLimit=20
> >
> > Now we observed that replicas do not go in recovery that often as
> > before. In the whole cluster at a given time I would have a couple of
> > replicas in recovery whereas earlier it were multiple replicas from
> > every shard .
> > On the wiki https://wiki.apache.org/solr/SolrCloudit says the "The
> > maximum is 20 times the tickTime." in the FAQ so I decided to increase
> > the tick time. Is this the correct approach ?
>
> The default zkClientTimeout on recent Solr versions is 30 seconds, up
> from 15 in slightly older releases.
>
> Those values of 15 or 30 seconds are a REALLY long time in computer
> terms, and if you are exceeding that timeout on a regular basis,
> something is VERY wrong with your Solr install. Rather than take steps
> to increase your timeout beyond the normal maximum of 40 seconds (20
> times a tickTime of 2 seconds), figure out why you're exceeding that
> timeout and fix the performance problem. The zkClientTimeout value that
> you have set, 450 seconds, is seven and a half *MINUTES*. Nothing in
> Solr should ever take that long.
>
> "Not enough memory in the server" is by far the most common culprit for
> performance issues. Garbage collection pauses are a close second.
>
> I don't actually know this next part for sure, because I've never looked
> into the code, but I believe that increasing the tickTime, especially to
> a value 15 times higher than default, might make all zookeeper
> operations a lot slower.
>
> Thanks,
> Shawn
>
>
--
*
Vijay Sekhri
*
solr cloud replicas goes in recovery mode after update
.7313777596572674 skew=0.341 nonDelRatio=0.852 tooLarge=false size=2506.203 MB . 14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream] (searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete "_5p7_1.del" 14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream] (searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete "_5nx_1.del" 14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream] (searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete "_5co_a.del" 14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream] (searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete "_5q0_6.del" 14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream] (searcherExecutor-6-thread-1) [ -- * Vijay Sekhri *
Re: replicas goes in recovery mode right after update
Hi Erick,
In solr.xml file I had zk timeout set to* ${zkClientTimeout:45}*
One thing that made a it a bit better now is the zk tick time and syncLimit
settings. I set it to a higher value as below. This may not be advisable
though.
tickTime=3
initLimit=30
syncLimit=20
Now we observed that replicas do not go in recovery that often as before.
In the whole cluster at a given time I would have a couple of replicas in
recovery whereas earlier it were multiple replicas from every shard .
On the wiki https://wiki.apache.org/solr/SolrCloud it says the "The maximum
is 20 times the tickTime." in the FAQ so I decided to increase the tick
time. Is this the correct approach ?
One question I have is that if auto commit settings has anything to do with
this or not ? Does it induce extra work for the searchers because of which
this would happen? I have tried with following settings
* *
*50*
*90*
**
**
*20*
*3*
*false*
**
I have increased the heap size to 15GB for each JVM instance . I
monitored during full indexing how the heap usage looks like and it never
goes beyond 8 GB . I don't see any Full GC happening at any point .
I had some attached screenshots but they were marked as spam so not sending
them again
Our rate is a variable rate . It is not a sustained rate of 6000/second ,
however there are intervals where it would reach that much and come down
and grow again and come down. So if I would take an average it would be
600/second only but that is not real rate at any given time.
Version of solr cloud is 4.10. All indexers are basically java programs
running on different host using CloudSolrServer api.
As I mentioned it is much better now than before , however not completely
as expected . We would want none of them to go in recovery if really there
is no need.
I captured some logs before and after recovery
4:13:54,298 INFO [org.apache.solr.handler.SnapPuller] (RecoveryThread)
New index installed. Updating index properties...
index=index.20150126140904697
14:13:54,301 INFO [org.apache.solr.handler.SnapPuller] (RecoveryThread)
removing old index directory
NRTCachingDirectory(MMapDirectory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126134945417
lockFactory=NativeFSLockFactory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126134945417;
maxCacheMB=48.0 maxMergeSizeMB=4.0)
14:13:54,302 INFO [org.apache.solr.update.DefaultSolrCoreState]
(RecoveryThread) Creating new IndexWriter...
14:13:54,302 INFO [org.apache.solr.update.DefaultSolrCoreState]
(RecoveryThread) Waiting until IndexWriter is unused...
core=search1_shard7_replica4
14:13:54,302 INFO [org.apache.solr.update.DefaultSolrCoreState]
(RecoveryThread) Rollback old IndexWriter... core=search1_shard7_replica4
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: rollback
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: all running merges have aborted
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: rollback: done finish merges
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [DW][RecoveryThread]: abort
14:13:54,303 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [DW][RecoveryThread]: done abort; abortedFiles=[]
success=true
14:13:54,306 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: rollback:
infos=_4qe(4.10.0):C4312879/1370002:delGen=56
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93841:delGen=10 _5m7(4.10.0):C122852/31645:delGen=11
_5hm(4.10.0):C457977/32465:delGen=11 _5q2(4.10.0):C13189/649:delGen=6
_5kb(4.10.0):C424868/19148:delGen=11 _5f5(4.10.0):C116528/42495:delGen=1
_5nx(4.10.0):C33236/20668:delGen=1 _5ql(4.10.0):C25924/2:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/648:delGen=1 _5r5(4.10.0):C4260 _5qv(4.10.0):C1750
_5qi(4.10.0):C842 _5qp(4.10.0):C2247 _5qm(4.10.0):C2214 _5qo(4.10.0):C1785
_5qn(4.10.0):C1962 _5qu(4.10.0):C2390 _5qy(4.10.0):C2129 _5qx(4.10.0):C2192
_5qw(4.10.0):C2157/1:delGen=1 _5r6(4.10.0):C159 _5r4(4.10.0):C742
_5r8(4.10.0):C334 _5r7(4.10.0):C390 _5r3(4.10.0):C1122
14:13:54,306 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IFD][RecoveryThread]: now checkpoint
"_4qe(4.10.0):C4312879/1370002:delGen=56
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93841:delGen=10 _5m7(4.10.0):C122852/31645:delGen=11
_5hm(4.10.0):C457977/32465:delGen=11 _5q2(4.10.0):C13189/649:delGen=6
_5kb(4.10.0):C424868/19148:delGen=11 _5f5(4.10.0):C116528/42495:delGen=1
_5nx(4.10.0):C33236/20668:delGen=1 _5ql(4.10.0):C25924/2:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:
Re: replicas goes in recovery mode right after update
Thank you for the reply Eric. I am sorry I had wrong information posted. I posted our DEV env configuration by mistake. After double checking our stress and Prod Beta env where we have found the original issue, I found all the searchers have around 50 GB of RAM available and two instances of JVM running (2 different ports). Both instances have 12 GB allocated. The rest 26 GB is available for the OS. 1st instance on a host has search1 collection (live collection) and the 2nd instance on the same host has search2 collection (for full indexing ). There is plenty room for OS related tasks. Our issue is not in anyway related to OS starving as shown from our dashboards. We have been through https://lucidworks.com/blog/understanding-transaction-logs-softcommit-and-commit-in-sorlcloud/ a lot of times but we have two modes of operation a) 1st collection (Live traffic) - heavy searches and medium indexing b) 2nd collection (Not serving traffic) - very heavy indexing, no searches When our indexing finishes we swap the alias for these collection . So essentially we need to have a configuration that can support both the use cases together. We have tried a lot of different configuration options and none of them seems to work. My suspicion is that solr cloud is unable to keep up with the updates at the rate we are sending while it is trying to be consistent with all the replicas. On Sun, Jan 25, 2015 at 5:30 PM, Erick Erickson wrote: > Shawn directed you over here to the user list, but I see this note on > SOLR-7030: > "All our searchers have 12 GB of RAM available and have quad core Intel(R) > Xeon(R) CPU X5570 @ 2.93GHz. There is only one java process running i.e > jboss and solr in it . All 12 GB is available as heap for the java > process..." > > So you have 12G physical memory and have allocated 12G to the Java process? > This is an anti-pattern. If that's > the case, your operating system is being starved for memory, probably > hitting a state where it spends all of its > time in stop-the-world garbage collection, eventually it doesn't respond to > Zookeeper's ping so Zookeeper > thinks the node is down and puts it into recovery. Where it spends a lot of > time doing... essentially nothing. > > About the hard and soft commits: I suspect these are entirely unrelated, > but here's a blog on what they do, you > should pick the configuration that supports your use case (i.e. how much > latency can you stand between indexing > and being able to search?). > > > https://lucidworks.com/blog/understanding-transaction-logs-softcommit-and-commit-in-sorlcloud/ > > Here's one very good reason you shouldn't starve your op system by > allocating all the physical memory to the JVM: > http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html > > > But your biggest problem is that you have far too much of your physical > memory allocated to the JVM. This > will cause you endless problems, you just need more physical memory on > those boxes. It's _possible_ you could > get by with less memory for the JVM, counterintuitive as it seems try 8G or > maybe even 6G. At some point > you'll hit OOM errors, but that'll give you a lower limit on what the JVM > needs. > > Unless I've mis-interpreted what you've written, though, I doubt you'll get > stable with that much memory allocated > to the JVM. > > Best, > Erick > > > > On Sun, Jan 25, 2015 at 1:02 PM, Vijay Sekhri > wrote: > > > We have a cluster of solr cloud server with 10 shards and 4 replicas in > > each shard in our stress environment. In our prod environment we will > have > > 10 shards and 15 replicas in each shard. Our current commit settings are > as > > follows > > > > ** > > *50* > > *18* > > ** > > ** > > *200* > > *18* > > *false* > > ** > > > > > > We indexed roughly 90 Million docs. We have two different ways to index > > documents a) Full indexing. It takes 4 hours to index 90 Million docs and > > the rate of docs coming to the searcher is around 6000 per second b) > > Incremental indexing. It takes an hour to indexed delta changes. Roughly > > there are 3 million changes and rate of docs coming to the searchers is > > 2500 > > per second > > > > We have two collections search1 and search2. When we do full indexing , > we > > do it in search2 collection while search1 is serving live traffic. After > it > > finishes we swap the collection using aliases so that the search2 > > collection serves live traffic while search1 becomes available for next > > full indexing run. When
replicas goes in recovery mode right after update
We have a cluster of solr cloud server with 10 shards and 4 replicas in each shard in our stress environment. In our prod environment we will have 10 shards and 15 replicas in each shard. Our current commit settings are as follows ** *50* *18* ** ** *200* *18* *false* ** We indexed roughly 90 Million docs. We have two different ways to index documents a) Full indexing. It takes 4 hours to index 90 Million docs and the rate of docs coming to the searcher is around 6000 per second b) Incremental indexing. It takes an hour to indexed delta changes. Roughly there are 3 million changes and rate of docs coming to the searchers is 2500 per second We have two collections search1 and search2. When we do full indexing , we do it in search2 collection while search1 is serving live traffic. After it finishes we swap the collection using aliases so that the search2 collection serves live traffic while search1 becomes available for next full indexing run. When we do incremental indexing we do it in the search1 collection which is serving live traffic. All our searchers have 12 GB of RAM available and have quad core Intel(R) Xeon(R) CPU X5570 @ 2.93GHz. There is only one java process running i.e jboss and solr in it . All 12 GB is available as heap for the java process. We have observed that the heap memory of the java process average around 8 - 10 GB. All searchers have final index size of 9 GB. So in total there are 9X10 (shards) = 90GB worth of index files. We have observed the following issue when we trigger indexing . In about 10 minutes after we trigger indexing on 14 parallel hosts, the replicas goes in to recovery mode. This happens to all the shards . In about 20 minutes more and more replicas start going into recovery mode. After about half an hour all replicas except the leader are in recovery mode. We cannot throttle the indexing load as that will increase our overall indexing time. So to overcome this issue, we remove all the replicas before we trigger the indexing and then add them back after the indexing finishes. We observe the same behavior of replicas going into recovery when we do incremental indexing. We cannot remove replicas during our incremental indexing because it is also serving live traffic. We tried to throttle our indexing speed , however the cluster still goes into recovery . If we leave the cluster as it , when the indexing finishes , it eventually recovers after a while. As it is serving live traffic we cannot have these replicas go into recovery mode because it degrades the search performance also , our tests have shown. We have tried different commit settings like below a) No auto soft commit, no auto hard commit and a commit triggered at the end of indexing b) No auto soft commit, yes auto hard commit and a commit in the end of indexing c) Yes auto soft commit , no auto hard commit d) Yes auto soft commit , yes auto hard commit e) Different frequency setting for commits for above. Please NOTE that we have tried 15 minute soft commit setting and 30 minutes hard commit settings. Same time settings for both, 30 minute soft commit and an hour hard commit setting Unfortunately all the above yields the same behavior . The replicas still goes in recovery We have increased the zookeeper timeout from 30 seconds to 5 minutes and the problem persists. Is there any setting that would fix this issue ? -- * Vijay Sekhri *
