> You can also set this online w/ nodetool, fyi.
Oh, thanks! Will use this approach from now on
> If you have SSD-esque devices, it is common to be CPU bound on
compaction.
We use spinning disks, unfortunately we can not afford SSDs in EC2 yet
> How effective are compactions in this CF? "grep %
/var/log/cassandra/system.log"?
I'm not sure what type of logs should I share, when I do "grep %
/var/log/cassandra/system.log" I don't see anything related to this
long-running compaction. But here is the result of this grep:
INFO [main] 2014-12-30 23:00:40,526 ColumnFamilyStore.java:840 - Enqueuing
flush of my_table: 364699 (0%) on-heap, 0 (0%) off-heap
INFO [main] 2014-12-30 23:00:40,533 ColumnFamilyStore.java:840 - Enqueuing
flush of my_table: 25794266 (3%) on-heap, 0 (0%) off-heap
INFO [main] 2014-12-30 23:00:40,539 ColumnFamilyStore.java:840 - Enqueuing
flush of my_table: 8264449 (1%) on-heap, 0 (0%) off-heap
INFO [main] 2014-12-30 23:00:40,543 ColumnFamilyStore.java:840 - Enqueuing
flush of my_table: 5412060 (1%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:4] 2014-12-30 23:00:41,451 Memtable.java:325 -
Writing Memtable-my_table@1782855450(38932 serialized bytes, 1095 ops,
0%/0% of on/off-heap limit)
INFO [MemtableFlushWriter:3] 2014-12-30 23:00:42,651 Memtable.java:325 -
Writing Memtable-my_table@264369308(3531963 serialized bytes, 75282 ops,
3%/0% of on/off-heap limit)
INFO [MemtableFlushWriter:4] 2014-12-30 23:00:44,517 Memtable.java:325 -
Writing Memtable-my_table@86745313(1102266 serialized bytes, 25363 ops,
1%/0% of on/off-heap limit)
INFO [MemtableFlushWriter:3] 2014-12-30 23:00:45,242 Memtable.java:325 -
Writing Memtable-my_table@1278005967(690491 serialized bytes, 15108 ops,
1%/0% of on/off-heap limit)
INFO [CompactionExecutor:4] 2014-12-30 23:05:45,547
CompactionTask.java:251 - Compacted 22 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15759,].
131,389,927 bytes to 121,512,669 (~92% of original) in 65,894ms =
1.758635MB/s. 451,590 total partitions merged to 399,267. Partition merge
counts were {1:355582, 2:36885, 3:5419, 4:1047, 5:267, 6:35, 7:15, 8:14,
9:1, 11:2, }
INFO [CompactionExecutor:4] 2014-12-30 23:17:23,623
CompactionTask.java:251 - Compacted 8 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15760,].
1,738,753,881 bytes to 1,476,109,336 (~84% of original) in 512,207ms =
2.748357MB/s. 3,247,902 total partitions merged to 2,385,154. Partition
merge counts were {1:1715058, 2:528147, 3:101962, 4:30801, 5:7811, 6:1223,
7:149, 8:3, }
INFO [SlabPoolCleaner] 2014-12-31 00:05:30,027 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 85966001 (9%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:15] 2014-12-31 00:05:30,056 Memtable.java:325 -
Writing Memtable-my_table@10851234(12262873 serialized bytes, 252870 ops,
9%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 01:00:39,378 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 44588638 (5%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:28] 2014-12-31 01:00:39,387 Memtable.java:325 -
Writing Memtable-my_table@1841118651(6184711 serialized bytes, 128067 ops,
5%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 01:45:30,918 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 38680171 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:39] 2014-12-31 01:45:30,923 Memtable.java:325 -
Writing Memtable-my_table@1306793378(5447759 serialized bytes, 122613 ops,
4%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 02:25:29,569 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 39115167 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:47] 2014-12-31 02:25:29,573 Memtable.java:325 -
Writing Memtable-my_table@1557457372(5578046 serialized bytes, 120738 ops,
4%/0% of on/off-heap limit)
INFO [CompactionExecutor:29] 2014-12-31 02:25:48,200
CompactionTask.java:251 - Compacted 4 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15765,].
11,186,540 bytes to 10,790,796 (~96% of original) in 5,209ms =
1.975601MB/s. 59,772 total partitions merged to 52,907. Partition merge
counts were {1:46474, 2:6002, 3:430, 4:1, }
INFO [SlabPoolCleaner] 2014-12-31 03:04:28,648 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 40405331 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:60] 2014-12-31 03:04:28,698 Memtable.java:325 -
Writing Memtable-my_table@1428270342(5795663 serialized bytes, 115755 ops,
4%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 03:55:30,729 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 38355077 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:71] 2014-12-31 03:55:30,733 Memtable.java:325 -
Writing Memtable-my_table@1739462674(5408790 serialized bytes, 108294 ops,
4%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 04:35:31,836 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 36459849 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:80] 2014-12-31 04:35:31,859 Memtable.java:325 -
Writing Memtable-my_table@1089653804(5263176 serialized bytes, 109032 ops,
4%/0% of on/off-heap limit)
INFO [CompactionExecutor:62] 2014-12-31 04:35:48,720
CompactionTask.java:251 - Compacted 4 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15769,].
18,495,110 bytes to 18,301,195 (~98% of original) in 7,754ms =
2.250887MB/s. 93,699 total partitions merged to 85,074. Partition merge
counts were {1:77512, 2:6622, 3:817, 4:123, }
INFO [SlabPoolCleaner] 2014-12-31 05:10:28,816 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 30461904 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:87] 2014-12-31 05:10:28,818 Memtable.java:325 -
Writing Memtable-my_table@315450786(3448600 serialized bytes, 83799 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 05:20:30,729 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 37115445 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:89] 2014-12-31 05:20:30,732 Memtable.java:325 -
Writing Memtable-my_table@1486359870(5399508 serialized bytes, 107070 ops,
4%/0% of on/off-heap limit)
INFO [CompactionExecutor:73] 2014-12-31 05:20:47,202
CompactionTask.java:251 - Compacted 14 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15771,].
20,698,978 bytes to 20,609,542 (~99% of original) in 9,167ms =
2.144081MB/s. 96,182 total partitions merged to 93,244. Partition merge
counts were {1:90317, 2:2926, 13:1, }
INFO [SlabPoolCleaner] 2014-12-31 06:16:30,811 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 35766486 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:101] 2014-12-31 06:16:30,813 Memtable.java:325 -
Writing Memtable-my_table@1280322127(5240924 serialized bytes, 98292 ops,
4%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 07:35:26,460 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 28663200 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:112] 2014-12-31 07:35:26,462 Memtable.java:325 -
Writing Memtable-my_table@267459796(3899505 serialized bytes, 79253 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 07:58:05,718 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 33479375 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:114] 2014-12-31 07:58:05,722 Memtable.java:325 -
Writing Memtable-my_table@665282393(4859465 serialized bytes, 92016 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 11:44:39,599 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 30708248 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:132] 2014-12-31 11:44:39,601 Memtable.java:325 -
Writing Memtable-my_table@1998398430(4472812 serialized bytes, 86103 ops,
3%/0% of on/off-heap limit)
INFO [CompactionExecutor:125] 2014-12-31 11:44:57,968
CompactionTask.java:251 - Compacted 5 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15775,].
27,120,360 bytes to 26,931,236 (~99% of original) in 11,221ms =
2.288889MB/s. 121,377 total partitions merged to 114,660. Partition merge
counts were {1:108729, 2:5244, 3:588, 4:99, }
INFO [SlabPoolCleaner] 2014-12-31 13:45:26,869 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 28126174 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:160] 2014-12-31 13:45:26,872 Memtable.java:325 -
Writing Memtable-my_table@1412410434(3910836 serialized bytes, 81657 ops,
3%/0% of on/off-heap limit)
INFO [CompactionExecutor:155] 2014-12-31 13:45:45,898
CompactionTask.java:251 - Compacted 4 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15777,].
28,793,666 bytes to 28,760,029 (~99% of original) in 11,577ms =
2.369154MB/s. 121,737 total partitions merged to 120,410. Partition merge
counts were {1:119084, 2:1325, 3:1, }
INFO [SlabPoolCleaner] 2014-12-31 14:40:28,817 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 32143831 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:180] 2014-12-31 14:40:28,820 Memtable.java:325 -
Writing Memtable-my_table@7590922(4380198 serialized bytes, 98796 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 15:07:46,504 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 31448877 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:191] 2014-12-31 15:07:46,507 Memtable.java:325 -
Writing Memtable-my_table@777111131(4360026 serialized bytes, 99060 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 15:41:52,680 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 32373438 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:205] 2014-12-31 15:41:52,710 Memtable.java:325 -
Writing Memtable-my_table@1710510960(4321845 serialized bytes, 96774 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 16:10:36,129 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 34999678 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:216] 2014-12-31 16:10:36,133 Memtable.java:325 -
Writing Memtable-my_table@684707049(4916068 serialized bytes, 115119 ops,
4%/0% of on/off-heap limit)
INFO [CompactionExecutor:217] 2014-12-31 16:11:01,966
CompactionTask.java:251 - Compacted 5 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15782,].
37,451,574 bytes to 37,354,219 (~99% of original) in 17,232ms =
2.067303MB/s. 177,344 total partitions merged to 168,683. Partition merge
counts were {1:161023, 2:6821, 3:707, 4:102, 5:30, }
INFO [SlabPoolCleaner] 2014-12-31 16:40:35,090 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 34600047 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:226] 2014-12-31 16:40:35,097 Memtable.java:325 -
Writing Memtable-my_table@525875217(4587265 serialized bytes, 103659 ops,
4%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 17:06:04,160 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 35753307 (4%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:234] 2014-12-31 17:06:04,163 Memtable.java:325 -
Writing Memtable-my_table@1323431665(4981225 serialized bytes, 116037 ops,
4%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 17:25:35,868 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 27903527 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:244] 2014-12-31 17:25:35,875 Memtable.java:325 -
Writing Memtable-my_table@104826231(3664888 serialized bytes, 84585 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 17:35:40,684 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 26205347 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:249] 2014-12-31 17:35:40,689 Memtable.java:325 -
Writing Memtable-my_table@1470315263(2961340 serialized bytes, 71673 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 17:52:22,433 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 33333676 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:254] 2014-12-31 17:52:22,437 Memtable.java:325 -
Writing Memtable-my_table@486102858(4387667 serialized bytes, 100470 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 18:10:37,886 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 31226838 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:260] 2014-12-31 18:10:37,889 Memtable.java:325 -
Writing Memtable-my_table@223958072(4346215 serialized bytes, 112773 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 18:35:33,526 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 32308831 (3%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:269] 2014-12-31 18:35:33,536 Memtable.java:325 -
Writing Memtable-my_table@1792549833(4240004 serialized bytes, 97545 ops,
3%/0% of on/off-heap limit)
INFO [SlabPoolCleaner] 2014-12-31 19:04:53,806 ColumnFamilyStore.java:840
- Enqueuing flush of my_table: 48032705 (5%) on-heap, 0 (0%) off-heap
INFO [MemtableFlushWriter:279] 2014-12-31 19:04:53,813 Memtable.java:325 -
Writing Memtable-my_table@845350451(6682895 serialized bytes, 152226 ops,
5%/0% of on/off-heap limit)
INFO [CompactionExecutor:275] 2014-12-31 19:05:00,126
CompactionTask.java:251 - Compacted 4 sstables to
[/raid0/cassandra/data/my_keyspace/my_table-6b40d819520d35c1957008d343f23ccd/my_keyspace-my_table-ka-15791,].
9,240,024 bytes to 9,033,786 (~97% of original) in 5,235ms = 1.645710MB/s.
64,845 total partitions merged to 57,007. Partition merge counts were
{1:50249, 2:5800, 3:836, 4:122, }
On Wed, Dec 31, 2014 at 10:11 AM, Robert Coli <rc...@eventbrite.com> wrote:
> On Wed, Dec 31, 2014 at 12:01 AM, Mikhail Strebkov <streb...@gmail.com>
> wrote:
>
>> I set compaction_throughput_mb_per_sec to 0 and restarted Cassandra.
>>
>
> You can also set this online w/ nodetool, fyi.
>
>> It looks to me that compaction thread is busy doing something that
>> produces quite a lot of garbage for GC to collect. Compaction performance
>> is bounded by CPU, which is a surprise for me, I would expect disk IO to be
>> a bottleneck.
>>
>> If you have SSD-esque devices, it is common to be CPU bound on
> compaction.
>
> And yes, compaction creates huge amounts of heap garbage pressure.
>
>> I don't think increasing the heap size if going to help in this case,
>> what do you think? Should I try JMX call userDefinedCompaction?
>>
>> I don't really understand the scenario where unthrottling reduces GC
> pre-fail. It's somewhat unclear to me from the stats you pasted how
> effective the actual GCs are. In general, increasing heap is a workaround
> to having a working set that peaks into GC pre-fail when compaction or
> write traffic spikes garbage creation.
>
> How effective are compactions in this CF? "grep %
> /var/log/cassandra/system.log"?
>
> =Rob
>
