[
https://issues.apache.org/jira/browse/CASSANDRA-6653?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14517122#comment-14517122
]
Pete Cheslock commented on CASSANDRA-6653:
------------------------------------------
[~keithwrightbos] - While this is an older ticket, we experienced the exact
same problem. Running a very similar setup - i2.2xlarge nodes on EC2 - about
1TB of data per node, using vnodes, with 12G Heap and HEAP_NEWSIZE = 800m. We
would only see GC pauses when bootstrapping new nodes in the cluster. And the
Par New GC pauses would be anywhere from 50 seconds to 150 seconds (crazy).
The following changes helped us (with help from the DataStax ppl)
Increasing Heap New Size to 512M * num CPU (in our case 4G)
Setting memtable_flush_writers = 8
Setting concurrent_compactors = total CPU / 2 (in our case 4)
After making those changes we were finally able to bootstrap a node, and during
the inital stages or bootstrapping Par New GC never exceeded 1000ms -and zero
nodes GC'd out and our new node was able to start streaming.
Hope that helps.
> Attempting to bootstrap causes nodes to lock up in GC
> -----------------------------------------------------
>
> Key: CASSANDRA-6653
> URL: https://issues.apache.org/jira/browse/CASSANDRA-6653
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Environment: VNodes using Murmur3
> Reporter: Keith Wright
>
> We have been struggling with the inability to bootstrap nodes into our 1.2.13
> environment with Vnodes using centos 6.4 with Java 7. We have an 8 node
> cluster (32 GB RAM, dual hex core, SSDs, 8 GB heap with 1200 MB eden space,
> RF3) with around 1 TB per node using murmur3. When we go to bootstrap a new
> node this is what we see:
> - Bootstrapping node assigns tokens and requests data from cluster
> - 5-6 nodes within the cluster begin to stream data
> - Around 2 minutes after bootstrap start, between 1 and 4 nodes (sometimes
> the bootstrapping node and sometimes not) become unresponsive in par new GCs
> - IF no nodes go down during the first 5 minutes of bootstrap, then the
> bootstrap will succeed without issue
> GC mired nodes tend to recover after a minute or two but the receiving node
> stops attempting to get more data from the nodes
> - Bootstrap eventually fails (after streaming all the data from nodes that
> did not go down) with Unable to Fetch Ranges
> We have tried the following and it appears that sometimes a bootstrap will
> succeed (perhaps 1 in 10) but with no discernible pattern:
> - Increase phi_convict to 16
> - Restart all nodes prior to bootstrap (to ensure heap is as “clean” as
> possible)
> - Stop production load against the cluster (to reduce par new churn); after 5
> minutes we know if the bootstrap will succeed so we then re-enable load
> - Distribute soft interrupts across all CPUs
> Below is an output from the GC log of the bootstrapping node when it was
> stuck in GC.
> {Heap before GC invocations=109 (full 0):
> par new generation total 1105920K, used 1021140K [0x00000005fae00000,
> 0x0000000645e00000, 0x0000000645e00000)
> eden space 983040K, 100% used [0x00000005fae00000, 0x0000000636e00000,
> 0x0000000636e00000)
> from space 122880K, 31% used [0x000000063e600000, 0x0000000640b350f0,
> 0x0000000645e00000)
> to space 122880K, 0% used [0x0000000636e00000, 0x0000000636e00000,
> 0x000000063e600000)
> concurrent mark-sweep generation total 7159808K, used 3826815K
> [0x0000000645e00000, 0x00000007fae00000, 0x00000007fae00000)
> concurrent-mark-sweep perm gen total 24512K, used 24368K
> [0x00000007fae00000, 0x00000007fc5f0000, 0x0000000800000000)
> 2014-02-05T13:27:49.621+0000: 210.242: [GC 210.242: [ParNew:
> 1021140K->122880K(1105920K), 0.2963210 secs] 4847955K->4024095K(8265728K),
> 0.2965270 secs] [Times: user=4.97 sys=0.00, real=0.30 secs]
> Heap after GC invocations=110 (full 0):
> par new generation total 1105920K, used 122880K [0x00000005fae00000,
> 0x0000000645e00000, 0x0000000645e00000)
> eden space 983040K, 0% used [0x00000005fae00000, 0x00000005fae00000,
> 0x0000000636e00000)
> from space 122880K, 100% used [0x0000000636e00000, 0x000000063e600000,
> 0x000000063e600000)
> to space 122880K, 0% used [0x000000063e600000, 0x000000063e600000,
> 0x0000000645e00000)
> concurrent mark-sweep generation total 7159808K, used 3901215K
> [0x0000000645e00000, 0x00000007fae00000, 0x00000007fae00000)
> concurrent-mark-sweep perm gen total 24512K, used 24368K
> [0x00000007fae00000, 0x00000007fc5f0000, 0x0000000800000000)
> }
> Total time for which application threads were stopped: 0.2968550 seconds
> Application time: 1.5953840 seconds
> Total time for which application threads were stopped: 0.0002040 seconds
> Application time: 0.0000510 seconds
> Relevant portion of GC log from non-bootstrapping node:
> {Heap before GC invocations=518 (full 1):
> par new generation total 1105920K, used 17921K [0x00000005fae00000,
> 0x0000000645e00000, 0x0000000645e00000)
> eden space 983040K, 1% used [0x00000005fae00000, 0x00000005fbf29db8,
> 0x0000000636e00000)
> from space 122880K, 0% used [0x0000000636e00000, 0x0000000636e56938,
> 0x000000063e600000)
> to space 122880K, 0% used [0x000000063e600000, 0x000000063e600000,
> 0x0000000645e00000)
> concurrent mark-sweep generation total 7159808K, used 6367511K
> [0x0000000645e00000, 0x00000007fae00000, 0x00000007fae00000)
> concurrent-mark-sweep perm gen total 29888K, used 29784K
> [0x00000007fae00000, 0x00000007fcb30000, 0x0000000800000000)
> 2014-02-04T16:16:44.471+0000: 945.646: [GC 945.646: [ParNew:
> 17921K->364K(1105920K), 0.0090810 secs]945.655:
> [CMS2014-02-04T16:16:48.373+0000: 949.548: [CMS-concurrent-sweep: 3.938/4.362
> secs] [Times: user=9.10 sys=0.19, real=4.36 secs]
> (concurrent mode failure): 6367540K->4453666K(7159808K), 16.4971830 secs]
> 6385433K->4453666K(8265728K), [CMS Perm : 29784K->29740K(29888K)], 16.5083610
> secs] [Times: user=16.61 sys=0.00, real=16.50 secs]
> Heap after GC invocations=519 (full 2):
> par new generation total 1105920K, used 0K [0x00000005fae00000,
> 0x0000000645e00000, 0x0000000645e00000)
> eden space 983040K, 0% used [0x00000005fae00000, 0x00000005fae00000,
> 0x0000000636e00000)
> from space 122880K, 0% used [0x000000063e600000, 0x000000063e600000,
> 0x0000000645e00000)
> to space 122880K, 0% used [0x0000000636e00000, 0x0000000636e00000,
> 0x000000063e600000)
> concurrent mark-sweep generation total 7159808K, used 4453666K
> [0x0000000645e00000, 0x00000007fae00000, 0x00000007fae00000)
> concurrent-mark-sweep perm gen total 49568K, used 29740K
> [0x00000007fae00000, 0x00000007fde68000, 0x0000000800000000)
> }
> Total time for which application threads were stopped: 16.5111290 seconds
> Application time: 0.0094340 seconds
> Total time for which application threads were stopped: 0.2300320 seconds
> Application time: 0.0000550 seconds
> 2014-02-04T16:17:01.221+0000: 962.396: [GC [1 CMS-initial-mark:
> 5584142K(7159808K)] 5614460K(8265728K), 0.0240930 secs] [Times: user=0.03
> sys=0.00, real=0.03 secs]
> Total time for which application threads were stopped: 0.0259820 seconds
> 2014-02-04T16:17:01.246+0000: 962.420: [CMS-concurrent-mark-start]
> Application time: 0.6072530 seconds
> {Heap before GC invocations=519 (full 3):
> par new generation total 1105920K, used 983040K [0x00000005fae00000,
> 0x0000000645e00000, 0x0000000645e00000)
> eden space 983040K, 100% used [0x00000005fae00000, 0x0000000636e00000,
> 0x0000000636e00000)
> from space 122880K, 0% used [0x000000063e600000, 0x000000063e600000,
> 0x0000000645e00000)
> to space 122880K, 0% used [0x0000000636e00000, 0x0000000636e00000,
> 0x000000063e600000)
> concurrent mark-sweep generation total 7159808K, used 5584142K
> [0x0000000645e00000, 0x00000007fae00000, 0x00000007fae00000)
> concurrent-mark-sweep perm gen total 49568K, used 29776K
> [0x00000007fae00000, 0x00000007fde68000, 0x0000000800000000)
> 2014-02-04T16:17:01.855+0000: 963.030: [GC 963.030: [ParNew:
> 983040K->21724K(1105920K), 0.0249840 secs] 6567182K->5605866K(8265728K),
> 0.0254720 secs] [Times: user=0.42 sys=0.00, real=0.02 secs]
> Heap after GC invocations=520 (full 3):
> par new generation total 1105920K, used 21724K [0x00000005fae00000,
> 0x0000000645e00000, 0x0000000645e00000)
> eden space 983040K, 0% used [0x00000005fae00000, 0x00000005fae00000,
> 0x0000000636e00000)
> from space 122880K, 17% used [0x0000000636e00000, 0x0000000638337290,
> 0x000000063e600000)
> to space 122880K, 0% used [0x000000063e600000, 0x000000063e600000,
> 0x0000000645e00000)
> concurrent mark-sweep generation total 7159808K, used 5584142K
> [0x0000000645e00000, 0x00000007fae00000, 0x00000007fae00000)
> concurrent-mark-sweep perm gen total 49568K, used 29776K
> [0x00000007fae00000, 0x00000007fde68000, 0x0000000800000000)
> }
> Total time for which application threads were stopped: 0.0280980 seconds
> Application time: 0.5525030 seconds
> Total time for which application threads were stopped: 0.0547220 seconds
> Application time: 0.0009410 seconds
> {Heap before GC invocations=520 (full 3):
> Java flags:
> /usr/java/default/bin/java -ea
> -javaagent:/usr/local/cassandra/lib/jamm-0.2.5.jar -XX:+UseThreadPriorities
> -XX:ThreadPriorityPolicy=42 -Xms8G -Xmx8G -Xmn1200M
> -XX:+HeapDumpOnOutOfMemoryError -Xss256k -XX:+UseParNewGC
> -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled -XX:SurvivorRatio=8
> -XX:MaxTenuringThreshold=1 -XX:CMSInitiatingOccupancyFraction=75
> -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedOops -XX:+UseTLAB
> -XX:+UseCondCardMark -XX:-UseBiasedLocking -XX:+PrintGCDetails
> -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintGCApplicationStoppedTime
> -XX:+PrintGCApplicationConcurrentTime -Xloggc:/var/log/cassandra/gc.log
> -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=10M
> -Djava.net.preferIPv4Stack=true -Dcom.sun.management.jmxremote.port=7199
> -Dcom.sun.management.jmxremote.ssl=false
> -Dcom.sun.management.jmxremote.authenticate=false
> -Djava.util.logging.config.file=/usr/local/cassandra/conf/logging.properties
> -javaagent:/usr/local/cassandra/lib/jmxetric-1.0.4.jar=host=lxpcas001.nanigans.com,port=8649,wireformat31x=true,config=/usr/local/cassandra/conf/jmxetric.xml
> -Dlog4j.configuration=log4j-server.properties
> -Dlog4j.defaultInitOverride=true -Dcassandra-foreground=yes -cp
> /usr/local/cassandra/conf:/usr/local/cassandra/build/classes/main:/usr/local/cassandra/build/classes/thrift:/usr/local/cassandra/lib/antlr-3.2.jar:/usr/local/cassandra/lib/apache-cassandra-1.2.12.jar:/usr/local/cassandra/lib/apache-cassandra-clientutil-1.2.12.jar:/usr/local/cassandra/lib/apache-cassandra-thrift-1.2.12.jar:/usr/local/cassandra/lib/avro-1.4.0-fixes.jar:/usr/local/cassandra/lib/avro-1.4.0-sources-fixes.jar:/usr/local/cassandra/lib/commons-cli-1.1.jar:/usr/local/cassandra/lib/commons-codec-1.2.jar:/usr/local/cassandra/lib/commons-lang-2.6.jar:/usr/local/cassandra/lib/compress-lzf-0.8.4.jar:/usr/local/cassandra/lib/concurrentlinkedhashmap-lru-1.3.jar:/usr/local/cassandra/lib/gmetric4j-1.0.3.jar:/usr/local/cassandra/lib/guava-13.0.1.jar:/usr/local/cassandra/lib/high-scale-lib-1.1.2.jar:/usr/local/cassandra/lib/jackson-core-asl-1.9.2.jar:/usr/local/cassandra/lib/jackson-mapper-asl-1.9.2.jar:/usr/local/cassandra/lib/jamm-0.2.5.jar:/usr/local/cassandra/lib/jbcrypt-0.3m.jar:/usr/local/cassandra/lib/jline-1.0.jar:/usr/local/cassandra/lib/jmxetric-1.0.4.jar:/usr/local/cassandra/lib/jna.jar:/usr/local/cassandra/lib/json-simple-1.1.jar:/usr/local/cassandra/lib/libthrift-0.7.0.jar:/usr/local/cassandra/lib/log4j-1.2.16.jar:/usr/local/cassandra/lib/lz4-1.1.0.jar:/usr/local/cassandra/lib/metrics-core-2.2.0.jar:/usr/local/cassandra/lib/netty-3.6.6.Final.jar:/usr/local/cassandra/lib/oncrpc-1.0.7.jar:/usr/local/cassandra/lib/servlet-api-2.5-20081211.jar:/usr/local/cassandra/lib/slf4j-api-1.7.2.jar:/usr/local/cassandra/lib/slf4j-log4j12-1.7.2.jar:/usr/local/cassandra/lib/snakeyaml-1.6.jar:/usr/local/cassandra/lib/snappy-java-1.0.5.jar:/usr/local/cassandra/lib/snaptree-0.1.jar
> org.apache.cassandra.service.CassandraDaemon
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
