[
https://issues.apache.org/jira/browse/CASSANDRA-5220?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13855774#comment-13855774
]
Donald Smith edited comment on CASSANDRA-5220 at 12/23/13 8:49 PM:
-------------------------------------------------------------------
We ran "nodetool repair" on a 3 node cassandra cluster with production-quality
hardware, using version 2.0.3. Each node had about 1TB of data. This is still
testing. After 5 days the repair job still hasn't finished. I can see it's
still running.
Here's the process:
{noformat}
root 30835 30774 0 Dec17 pts/0 00:03:53 /usr/bin/java -cp
/etc/cassandra/conf:/usr/share/java/jna.jar:/usr/share/cassandra/lib/antlr-3.2.jar:/usr/share/cassandra/lib/apache-cassandra-2.0.3.jar:/usr/share/cassandra/lib/apache-cassandra-clientutil-2.0.3.jar:/usr/share/cassandra/lib/apache-cassandra-thrift-2.0.3.jar:/usr/share/cassandra/lib/commons-cli-1.1.jar:/usr/share/cassandra/lib/commons-codec-1.2.jar:/usr/share/cassandra/lib/commons-lang3-3.1.jar:/usr/share/cassandra/lib/compress-lzf-0.8.4.jar:/usr/share/cassandra/lib/concurrentlinkedhashmap-lru-1.3.jar:/usr/share/cassandra/lib/disruptor-3.0.1.jar:/usr/share/cassandra/lib/guava-15.0.jar:/usr/share/cassandra/lib/high-scale-lib-1.1.2.jar:/usr/share/cassandra/lib/jackson-core-asl-1.9.2.jar:/usr/share/cassandra/lib/jackson-mapper-asl-1.9.2.jar:/usr/share/cassandra/lib/jamm-0.2.5.jar:/usr/share/cassandra/lib/jbcrypt-0.3m.jar:/usr/share/cassandra/lib/jline-1.0.jar:/usr/share/cassandra/lib/json-simple-1.1.jar:/usr/share/cassandra/lib/libthrift-0.9.1.jar:/usr/share/cassandra/lib/log4j-1.2.16.jar:/usr/share/cassandra/lib/lz4-1.2.0.jar:/usr/share/cassandra/lib/metrics-core-2.2.0.jar:/usr/share/cassandra/lib/netty-3.6.6.Final.jar:/usr/share/cassandra/lib/reporter-config-2.1.0.jar:/usr/share/cassandra/lib/servlet-api-2.5-20081211.jar:/usr/share/cassandra/lib/slf4j-api-1.7.2.jar:/usr/share/cassandra/lib/slf4j-log4j12-1.7.2.jar:/usr/share/cassandra/lib/snakeyaml-1.11.jar:/usr/share/cassandra/lib/snappy-java-1.0.5.jar:/usr/share/cassandra/lib/snaptree-0.1.jar:/usr/share/cassandra/lib/stress.jar:/usr/share/cassandra/lib/thrift-server-0.3.2.jar
-Xmx32m -Dlog4j.configuration=log4j-tools.properties
-Dstorage-config=/etc/cassandra/conf org.apache.cassandra.tools.NodeCmd -p 7199
repair -pr as_reports
{noformat}
The log output has just:
{noformat}
xss = -ea -javaagent:/usr/share/cassandra/lib/jamm-0.2.5.jar
-XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms8192M -Xmx8192M
-Xmn2048M -XX:+HeapDumpOnOutOfMemoryError -Xss256k
[2013-12-17 23:26:48,144] Starting repair command #1, repairing 256 ranges for
keyspace as_reports
{noformat}
Here's the output of "nodetool tpstats":
{noformat}
cass3 /tmp> nodetool tpstats
xss = -ea -javaagent:/usr/share/cassandra/lib/jamm-0.2.5.jar
-XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms8192M -Xmx8192M
-Xmn2048M -XX:+HeapDumpOnOutOfMemoryError -Xss256k
Pool Name Active Pending Completed Blocked All
time blocked
ReadStage 1 0 38083403 0
0
RequestResponseStage 0 0 1951200451 0
0
MutationStage 0 0 2853354069 0
0
ReadRepairStage 0 0 3794926 0
0
ReplicateOnWriteStage 0 0 0 0
0
GossipStage 0 0 4880147 0
0
AntiEntropyStage 1 3 9 0
0
MigrationStage 0 0 30 0
0
MemoryMeter 0 0 115 0
0
MemtablePostFlusher 0 0 75121 0
0
FlushWriter 0 0 49934 0
52
MiscStage 0 0 0 0
0
PendingRangeCalculator 0 0 7 0
0
commitlog_archiver 0 0 0 0
0
AntiEntropySessions 1 1 1 0
0
InternalResponseStage 0 0 9 0
0
HintedHandoff 0 0 1141 0
0
Message type Dropped
RANGE_SLICE 0
READ_REPAIR 0
PAGED_RANGE 0
BINARY 0
READ 884
MUTATION 1407711
_TRACE 0
REQUEST_RESPONSE 0
{noformat}
The cluster has some write traffic to it. We decided to test it under load.
This is the busiest column family, as reported by "nodetool cfstats":
{noformat}
Read Count: 38084316
Read Latency: 9.409910464927346 ms.
Write Count: 2850436738
Write Latency: 0.8083138546641199 ms.
Pending Tasks: 0
....
Table: data_report_details
SSTable count: 592
Space used (live), bytes: 160644106183
Space used (total), bytes: 160663248847
SSTable Compression Ratio: 0.5296494510512617
Number of keys (estimate): 51015040
Memtable cell count: 311180
Memtable data size, bytes: 46275953
Memtable switch count: 6100
Local read count: 6147
Local read latency: 154.539 ms
Local write count: 750865416
Local write latency: 0.029 ms
Pending tasks: 0
Bloom filter false positives: 265
Bloom filter false ratio: 0.06009
Bloom filter space used, bytes: 64690104
Compacted partition minimum bytes: 30
Compacted partition maximum bytes: 10090808
Compacted partition mean bytes: 5267
Average live cells per slice (last five minutes): 1.0
Average tombstones per slice (last five minutes): 0.0
{noformat}
We're gonna restart the node. We barely do deletes or updates (only if a
report is re-uploaded), so we suspect that we can get by without doing repairs.
Correct me if we're wrong about that.
nodetool compactionstats outputs:
{noformat}
xss = -ea -javaagent:/usr/share/cassandra/lib/jamm-0.2.5.jar
-XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms8192M -Xmx8192M
-Xmn2048M -XX:+HeapDumpOnOutOfMemoryError -Xss256k
pending tasks: 166
compaction type keyspace table completed
total unit progress
Compaction as_reportsdata_report_details_below_threshold
971187148 1899419306 bytes 51.13%
Compaction as_reportsdata_report_details_below_threshold
950086203 1941500979 bytes 48.94%
Compaction as_reportsdata_hierarchy_details 2968934609
5808990354 bytes 51.11%
Compaction as_reportsdata_report_details_below_threshold
945816183 1900166474 bytes 49.78%
Compaction as_reportsdata_report_details_below_threshold
899143344 1943534395 bytes 46.26%
Compaction as_reportsdata_report_details_below_threshold
856329840 1946566670 bytes 43.99%
Compaction as_reportsdata_report_details 195235688
915395763 bytes 21.33%
Compaction as_reportsdata_report_details_below_threshold
982460217 1931001761 bytes 50.88%
Compaction as_reportsdata_report_details_below_threshold
896609409 1931075688 bytes 46.43%
Compaction as_reportsdata_report_details_below_threshold
869219044 1928977382 bytes 45.06%
Compaction as_reportsdata_report_details_below_threshold
870931112 1901729646 bytes 45.80%
Compaction as_reportsdata_report_details_below_threshold
879343635 1939491280 bytes 45.34%
Compaction as_reportsdata_report_details_below_threshold
981888944 1893024439 bytes 51.87%
Compaction as_reportsdata_report_details_below_threshold
871785587 1884652607 bytes 46.26%
Compaction as_reportsdata_report_details_below_threshold
902340327 1913280943 bytes 47.16%
Compaction as_reportsdata_report_details_below_threshold
1025069846 1901568674 bytes 53.91%
Compaction as_reportsdata_report_details_below_threshold
920112020 1893272832 bytes 48.60%
Compaction as_reportsdata_hierarchy_details 2962138268
5774762866 bytes 51.29%
Compaction as_reportsdata_report_details_below_threshold
790782860 1918640911 bytes 41.22%
Compaction as_reportsdata_hierarchy_details 2972501409
5885217724 bytes 50.51%
Compaction as_reportsdata_report_details_below_threshold
1611697659 1939040337 bytes 83.12%
Compaction as_reportsdata_report_details_below_threshold
943130526 1943713837 bytes 48.52%
Compaction as_reportsdata_report_details_below_threshold
911127302 1952885196 bytes 46.66%
Compaction as_reportsdata_report_details_below_threshold
911230087 1927967871 bytes 47.26%
{noformat}
Now "nodetool tpstats" says:
{noformat}
Pool Name Active Pending Completed Blocked All
time blocked
AntiEntropyStage 1 3 9 0
0
{noformat}
We ran "nodetool repair -pr" on 10.1.40.43. Here are references to it. So,
maybe the nodetool repair job hung.
{noformat}
cass3 /var/log/cassandra> grep -i repair system.log.? | grep -i merkle
system.log.1: INFO [AntiEntropySessions:1] 2013-12-17 23:26:48,459
RepairJob.java (line 116) [repair #c1540f60-67b5-11e3-b8b7-fb178cd88033]
requesting merkle trees for data_report_details_by_uus (to [/10.1.40.42,
dc1-cassandra-staging-03.dc01.revsci.net/10.1.40.43])
system.log.1: INFO [AntiEntropyStage:1] 2013-12-17 23:26:48,807
RepairSession.java (line 157) [repair #c1540f60-67b5-11e3-b8b7-fb178cd88033]
Received merkle tree for data_report_details_by_uus from /10.1.40.42
system.log.1: INFO [AntiEntropyStage:1] 2013-12-17 23:26:49,091
RepairSession.java (line 157) [repair #c1540f60-67b5-11e3-b8b7-fb178cd88033]
Received merkle tree for data_report_details_by_uus from /10.1.40.43
system.log.1: INFO [AntiEntropyStage:1] 2013-12-19 03:58:31,007 RepairJob.java
(line 116) [repair #c1540f60-67b5-11e3-b8b7-fb178cd88033] requesting merkle
trees for data_hierarchy_details (to [/10.1.40.42,
dc1-cassandra-staging-03.dc01.revsci.net/10.1.40.43])
system.log.1: INFO [AntiEntropySessions:5] 2013-12-19 03:58:31,012
RepairJob.java (line 116) [repair #e0ff9ba0-68a4-11e3-b8b7-fb178cd88033]
requesting merkle trees for data_report_details_by_uus (to [/10.1.40.41,
dc1-cassandra-staging-03.dc01.revsci.net/10.1.40.43])
system.log.1: INFO [AntiEntropyStage:1] 2013-12-19 03:58:31,316
RepairSession.java (line 157) [repair #e0ff9ba0-68a4-11e3-b8b7-fb178cd88033]
Received merkle tree for data_report_details_by_uus from /10.1.40.41
system.log.1: INFO [AntiEntropyStage:1] 2013-12-19 03:58:31,431
RepairSession.java (line 157) [repair #e0ff9ba0-68a4-11e3-b8b7-fb178cd88033]
Received merkle tree for data_report_details_by_uus from /10.1.40.43
{noformat}
was (Author: thinkerfeeler):
We ran "nodetool repair" on a 3 node cassandra cluster with production-quality
hardware, using version 2.0.3. Each node had about 1TB of data. This is still
testing. After 5 days the repair job still hasn't finished. I can see it's
still running.
Here's the process:
{noformat}
root 30835 30774 0 Dec17 pts/0 00:03:53 /usr/bin/java -cp
/etc/cassandra/conf:/usr/share/java/jna.jar:/usr/share/cassandra/lib/antlr-3.2.jar:/usr/share/cassandra/lib/apache-cassandra-2.0.3.jar:/usr/share/cassandra/lib/apache-cassandra-clientutil-2.0.3.jar:/usr/share/cassandra/lib/apache-cassandra-thrift-2.0.3.jar:/usr/share/cassandra/lib/commons-cli-1.1.jar:/usr/share/cassandra/lib/commons-codec-1.2.jar:/usr/share/cassandra/lib/commons-lang3-3.1.jar:/usr/share/cassandra/lib/compress-lzf-0.8.4.jar:/usr/share/cassandra/lib/concurrentlinkedhashmap-lru-1.3.jar:/usr/share/cassandra/lib/disruptor-3.0.1.jar:/usr/share/cassandra/lib/guava-15.0.jar:/usr/share/cassandra/lib/high-scale-lib-1.1.2.jar:/usr/share/cassandra/lib/jackson-core-asl-1.9.2.jar:/usr/share/cassandra/lib/jackson-mapper-asl-1.9.2.jar:/usr/share/cassandra/lib/jamm-0.2.5.jar:/usr/share/cassandra/lib/jbcrypt-0.3m.jar:/usr/share/cassandra/lib/jline-1.0.jar:/usr/share/cassandra/lib/json-simple-1.1.jar:/usr/share/cassandra/lib/libthrift-0.9.1.jar:/usr/share/cassandra/lib/log4j-1.2.16.jar:/usr/share/cassandra/lib/lz4-1.2.0.jar:/usr/share/cassandra/lib/metrics-core-2.2.0.jar:/usr/share/cassandra/lib/netty-3.6.6.Final.jar:/usr/share/cassandra/lib/reporter-config-2.1.0.jar:/usr/share/cassandra/lib/servlet-api-2.5-20081211.jar:/usr/share/cassandra/lib/slf4j-api-1.7.2.jar:/usr/share/cassandra/lib/slf4j-log4j12-1.7.2.jar:/usr/share/cassandra/lib/snakeyaml-1.11.jar:/usr/share/cassandra/lib/snappy-java-1.0.5.jar:/usr/share/cassandra/lib/snaptree-0.1.jar:/usr/share/cassandra/lib/stress.jar:/usr/share/cassandra/lib/thrift-server-0.3.2.jar
-Xmx32m -Dlog4j.configuration=log4j-tools.properties
-Dstorage-config=/etc/cassandra/conf org.apache.cassandra.tools.NodeCmd -p 7199
repair -pr as_reports
{noformat}
The log output has just:
{noformat}
xss = -ea -javaagent:/usr/share/cassandra/lib/jamm-0.2.5.jar
-XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms8192M -Xmx8192M
-Xmn2048M -XX:+HeapDumpOnOutOfMemoryError -Xss256k
[2013-12-17 23:26:48,144] Starting repair command #1, repairing 256 ranges for
keyspace as_reports
{noformat}
Here's the output of "nodetool tpstats":
{noformat}
cass3 /tmp> nodetool tpstats
xss = -ea -javaagent:/usr/share/cassandra/lib/jamm-0.2.5.jar
-XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms8192M -Xmx8192M
-Xmn2048M -XX:+HeapDumpOnOutOfMemoryError -Xss256k
Pool Name Active Pending Completed Blocked All
time blocked
ReadStage 1 0 38083403 0
0
RequestResponseStage 0 0 1951200451 0
0
MutationStage 0 0 2853354069 0
0
ReadRepairStage 0 0 3794926 0
0
ReplicateOnWriteStage 0 0 0 0
0
GossipStage 0 0 4880147 0
0
AntiEntropyStage 1 3 9 0
0
MigrationStage 0 0 30 0
0
MemoryMeter 0 0 115 0
0
MemtablePostFlusher 0 0 75121 0
0
FlushWriter 0 0 49934 0
52
MiscStage 0 0 0 0
0
PendingRangeCalculator 0 0 7 0
0
commitlog_archiver 0 0 0 0
0
AntiEntropySessions 1 1 1 0
0
InternalResponseStage 0 0 9 0
0
HintedHandoff 0 0 1141 0
0
Message type Dropped
RANGE_SLICE 0
READ_REPAIR 0
PAGED_RANGE 0
BINARY 0
READ 884
MUTATION 1407711
_TRACE 0
REQUEST_RESPONSE 0
{noformat}
The cluster has some write traffic to it. We decided to test it under load.
This is the busiest column family, as reported by "nodetool cfstats":
{noformat}
Read Count: 38084316
Read Latency: 9.409910464927346 ms.
Write Count: 2850436738
Write Latency: 0.8083138546641199 ms.
Pending Tasks: 0
....
Table: data_report_details
SSTable count: 592
Space used (live), bytes: 160644106183
Space used (total), bytes: 160663248847
SSTable Compression Ratio: 0.5296494510512617
Number of keys (estimate): 51015040
Memtable cell count: 311180
Memtable data size, bytes: 46275953
Memtable switch count: 6100
Local read count: 6147
Local read latency: 154.539 ms
Local write count: 750865416
Local write latency: 0.029 ms
Pending tasks: 0
Bloom filter false positives: 265
Bloom filter false ratio: 0.06009
Bloom filter space used, bytes: 64690104
Compacted partition minimum bytes: 30
Compacted partition maximum bytes: 10090808
Compacted partition mean bytes: 5267
Average live cells per slice (last five minutes): 1.0
Average tombstones per slice (last five minutes): 0.0
{noformat}
We're gonna restart the node. We barely do deletes or updates (only if a
report is re-uploaded), so we suspect that we can get by without doing repairs.
Correct me if we're wrong about that.
nodetool compactionstats outputs:
{noformat}
xss = -ea -javaagent:/usr/share/cassandra/lib/jamm-0.2.5.jar
-XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms8192M -Xmx8192M
-Xmn2048M -XX:+HeapDumpOnOutOfMemoryError -Xss256k
pending tasks: 166
compaction type keyspace table completed
total unit progress
Compaction as_reportsdata_report_details_below_threshold
971187148 1899419306 bytes 51.13%
Compaction as_reportsdata_report_details_below_threshold
950086203 1941500979 bytes 48.94%
Compaction as_reportsdata_hierarchy_details 2968934609
5808990354 bytes 51.11%
Compaction as_reportsdata_report_details_below_threshold
945816183 1900166474 bytes 49.78%
Compaction as_reportsdata_report_details_below_threshold
899143344 1943534395 bytes 46.26%
Compaction as_reportsdata_report_details_below_threshold
856329840 1946566670 bytes 43.99%
Compaction as_reportsdata_report_details 195235688
915395763 bytes 21.33%
Compaction as_reportsdata_report_details_below_threshold
982460217 1931001761 bytes 50.88%
Compaction as_reportsdata_report_details_below_threshold
896609409 1931075688 bytes 46.43%
Compaction as_reportsdata_report_details_below_threshold
869219044 1928977382 bytes 45.06%
Compaction as_reportsdata_report_details_below_threshold
870931112 1901729646 bytes 45.80%
Compaction as_reportsdata_report_details_below_threshold
879343635 1939491280 bytes 45.34%
Compaction as_reportsdata_report_details_below_threshold
981888944 1893024439 bytes 51.87%
Compaction as_reportsdata_report_details_below_threshold
871785587 1884652607 bytes 46.26%
Compaction as_reportsdata_report_details_below_threshold
902340327 1913280943 bytes 47.16%
Compaction as_reportsdata_report_details_below_threshold
1025069846 1901568674 bytes 53.91%
Compaction as_reportsdata_report_details_below_threshold
920112020 1893272832 bytes 48.60%
Compaction as_reportsdata_hierarchy_details 2962138268
5774762866 bytes 51.29%
Compaction as_reportsdata_report_details_below_threshold
790782860 1918640911 bytes 41.22%
Compaction as_reportsdata_hierarchy_details 2972501409
5885217724 bytes 50.51%
Compaction as_reportsdata_report_details_below_threshold
1611697659 1939040337 bytes 83.12%
Compaction as_reportsdata_report_details_below_threshold
943130526 1943713837 bytes 48.52%
Compaction as_reportsdata_report_details_below_threshold
911127302 1952885196 bytes 46.66%
Compaction as_reportsdata_report_details_below_threshold
911230087 1927967871 bytes 47.26%
{noformat}
Now "nodetool tpstats" says:
{noformat}
Pool Name Active Pending Completed Blocked All
time blocked
AntiEntropyStage 1 3 9 0
0
{noformat}
> Repair improvements when using vnodes
> -------------------------------------
>
> Key: CASSANDRA-5220
> URL: https://issues.apache.org/jira/browse/CASSANDRA-5220
> Project: Cassandra
> Issue Type: Improvement
> Components: Core
> Affects Versions: 1.2.0 beta 1
> Reporter: Brandon Williams
> Assignee: Yuki Morishita
> Fix For: 2.1
>
>
> Currently when using vnodes, repair takes much longer to complete than
> without them. This appears at least in part because it's using a session per
> range and processing them sequentially. This generates a lot of log spam
> with vnodes, and while being gentler and lighter on hard disk deployments,
> ssd-based deployments would often prefer that repair be as fast as possible.
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)
