cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Arne Claassen <a...@emotient.com>
Subject Re: 100% CPU utilization, ParNew and never completing compactions
Date Wed, 17 Dec 2014 16:58:02 GMT
Ryan, thanks for all the information
> Data loss could be a couple of possibilities. One you have to understand what is happening
with a dropped mutation. This means that the know was never able to acknowledge that write
even though it accepted a request to take it. Furthermore if you're writing at CL one and
reading back at CL one..it's pretty trivial to get the 'wrong answer' with lots of dropped
mutations, however, repairs will restore that data. The other possibility (if you're doing
deletes) is that your servers are out of sync time wise, since the timestamp of a write will
be determined by the coordinator node you can effectively have deletes in the future and so
your writes never are stored. Tracing with CL ALL should give you more information on an individual
case, whether there are tombstones in the path, or there is a different answer between servers.
Final crappy answer is your client code is not actually catching exceptions correctly, I've
seen people do this using async and  never blocking on the futures, so they never catch their
exceptions.
The deletes i am doing before re-inserting is most likely the culprit. I am using scala for
comprehension to chain the delete and insert, so unless my adapter code to scala futures has
a bug, the delete should have completed before the inserts begin. I will set up some tests
for that scenario. More likely we do have time issue between replicas. Since the delete basically
happens microseconds before the inserts, is simple NTP time sync even reliable enough, or
is a delete immediately followed by inserts just a risky pattern?
> How much fragmentation are you seeing? what is your sstable count (histograms again)?
Very little right now. 2 sstables per table (likely because we started with a fresh keyspace)
> Have you tried changing the heap settings to reduce the length of gc pauses.
Over the last day we've gone through a number of Heap/new settings, none seem to have done
anything to alleviate the problems we see under insert loads.
> What is your disk setup? Are you using RAID 1? RAID 0? JBOD?
> Are you sure you're on the SSD drives of the instance? I know it sounds silly but I've
had I can't tell you how many customers on EBS backed root drives, ignoring the much much
faster local SSD drives that are provided with modern instances.
EBS optimized instance, writing to the root gp2 SSD device
> Which compaction strategy are you on? What is the throughput?
Strategy is SizeTieredCompactionStrategy and throughput is using the default of 16mb/s
> Have you upped flush writers?  the default setting is conservative, and if you're pushing
through as fast of writes as you possibly can that maybe just too much for the default.
Flush writers are at default
> Are you using LWT like IF NOT EXISTS on every insert?
no
> It may pay to have someone with production Cassandra experience review you're whole setup,
from code to cassandra to ec2 tuning, this maybe a multifaceted problem.
> 
For better worse, it is easy to reproduce these performance issues, so i'm going to set myself
up a separate cluster and just hammer it under various settings. But you are right, it's time
to get someone with experience to review, since clearly we're not using Cassandra correct
to so easily get into trouble and could use some advice. I'll contact you out of band.

thanks,
arne

> 
> On Wed, Dec 17, 2014 at 2:22 AM, Arne Claassen <arne@emotient.com> wrote:
> Ok, tonight we rolled out on the production cluster. This one has 4 nodes and we dropped
and recreated the keyspace before re-processing to avoid all possibility of  Everything seemed
ok, even if the CPU load was pegged and we saw lots of MUTATION dropped message, but after
all the reprocessing was done we noticed data loss, as in QA found some reports missing data.
Looking at the app logs it showed 300 rows being written, but in C* there were only 4 rows.
> 
> We brought up a brand new cluster, going to c3.2xlarge (more than doubling per node CPU)
and increased the cluster to 6 nodes and turned processing down to do one media record at
a time (still means a lot of rows written with a fanout of 50 async inserts at once). Even
with that we're seeing fairly frequent MUTATION dropped messages.
> 
> Clearly we're doing something fundamentally wrong but other than changing my inserts
to batches, I just don't know what else i can do. We're pushing data loads that single server
relational databases wouldn't be too concerned about right now.
> 
> Any suggestions at all would be greatly appreciated.
> 
> arne
> 
> On Dec 16, 2014, at 4:48 PM, Ryan Svihla <rsvihla@datastax.com> wrote:
> 
>> What version of Cassandra?
>> 
>> On Dec 16, 2014 6:36 PM, "Arne Claassen" <arne@emotient.com> wrote:
>> That's just the thing. There is nothing in the logs except the constant ParNew collections
like
>> 
>> DEBUG [ScheduledTasks:1] 2014-12-16 19:03:35,042 GCInspector.java (line 118) GC for
ParNew: 166 ms for 10 collections, 4400928736 used; max is 8000634888
>> 
>> But the load is staying continuously high.
>> 
>> There's always some compaction on just that one table, media_tracks_raw going on
and those values rarely changed (certainly the remaining time is meaningless)
>> 
>> pending tasks: 17
>>           compaction type        keyspace           table       completed       
   total      unit  progress
>>                Compaction           mediamedia_tracks_raw       444294932      1310653468
    bytes    33.90%
>>                Compaction           mediamedia_tracks_raw       131931354      3411631999
    bytes     3.87%
>>                Compaction           mediamedia_tracks_raw        30308970     23097672194
    bytes     0.13%
>>                Compaction           mediamedia_tracks_raw       899216961      1815591081
    bytes    49.53%
>> Active compaction remaining time :   0h27m56s
>> 
>> Here's a sample of a query trace:
>> 
>>  activity                                                                       
                 | timestamp    | source        | source_elapsed
>> --------------------------------------------------------------------------------------------------+--------------+---------------+----------------
>>                                                                                execute_cql3_query
| 00:11:46,612 | 10.140.22.236 |              0
>>  Parsing select * from media_tracks_raw where id =74fe9449-8ac4-accb-a723-4bad024101e3
limit 100; | 00:11:46,612 | 10.140.22.236 |             47
>>                                                                               Preparing
statement | 00:11:46,612 | 10.140.22.236 |            234
>>                                                                  Sending message
to /10.140.21.54 | 00:11:46,619 | 10.140.22.236 |           7190
>>                                                              Message received from
/10.140.22.236 | 00:11:46,622 |  10.140.21.54 |             12
>>                                              Executing single-partition query on
media_tracks_raw | 00:11:46,644 |  10.140.21.54 |          21971
>>                                                                      Acquiring sstable
references | 00:11:46,644 |  10.140.21.54 |          22029
>>                                                                       Merging memtable
tombstones | 00:11:46,644 |  10.140.21.54 |          22131
>>                                                         Bloom filter allows skipping
sstable 1395 | 00:11:46,644 |  10.140.21.54 |          22245
>>                                                         Bloom filter allows skipping
sstable 1394 | 00:11:46,644 |  10.140.21.54 |          22279
>>                                                         Bloom filter allows skipping
sstable 1391 | 00:11:46,644 |  10.140.21.54 |          22293
>>                                                         Bloom filter allows skipping
sstable 1381 | 00:11:46,644 |  10.140.21.54 |          22304
>>                                                         Bloom filter allows skipping
sstable 1376 | 00:11:46,644 |  10.140.21.54 |          22317
>>                                                         Bloom filter allows skipping
sstable 1368 | 00:11:46,644 |  10.140.21.54 |          22328
>>                                                         Bloom filter allows skipping
sstable 1365 | 00:11:46,644 |  10.140.21.54 |          22340
>>                                                         Bloom filter allows skipping
sstable 1351 | 00:11:46,644 |  10.140.21.54 |          22352
>>                                                         Bloom filter allows skipping
sstable 1367 | 00:11:46,644 |  10.140.21.54 |          22363
>>                                                         Bloom filter allows skipping
sstable 1380 | 00:11:46,644 |  10.140.21.54 |          22374
>>                                                         Bloom filter allows skipping
sstable 1343 | 00:11:46,644 |  10.140.21.54 |          22386
>>                                                         Bloom filter allows skipping
sstable 1342 | 00:11:46,644 |  10.140.21.54 |          22397
>>                                                         Bloom filter allows skipping
sstable 1334 | 00:11:46,644 |  10.140.21.54 |          22408
>>                                                         Bloom filter allows skipping
sstable 1377 | 00:11:46,644 |  10.140.21.54 |          22429
>>                                                         Bloom filter allows skipping
sstable 1330 | 00:11:46,644 |  10.140.21.54 |          22441
>>                                                         Bloom filter allows skipping
sstable 1329 | 00:11:46,644 |  10.140.21.54 |          22452
>>                                                         Bloom filter allows skipping
sstable 1328 | 00:11:46,644 |  10.140.21.54 |          22463
>>                                                         Bloom filter allows skipping
sstable 1327 | 00:11:46,644 |  10.140.21.54 |          22475
>>                                                         Bloom filter allows skipping
sstable 1326 | 00:11:46,644 |  10.140.21.54 |          22488
>>                                                         Bloom filter allows skipping
sstable 1320 | 00:11:46,644 |  10.140.21.54 |          22506
>>                                                         Bloom filter allows skipping
sstable 1319 | 00:11:46,644 |  10.140.21.54 |          22518
>>                                                         Bloom filter allows skipping
sstable 1318 | 00:11:46,644 |  10.140.21.54 |          22528
>>                                                         Bloom filter allows skipping
sstable 1317 | 00:11:46,644 |  10.140.21.54 |          22540
>>                                                         Bloom filter allows skipping
sstable 1316 | 00:11:46,644 |  10.140.21.54 |          22552
>>                                                         Bloom filter allows skipping
sstable 1315 | 00:11:46,644 |  10.140.21.54 |          22563
>>                                                         Bloom filter allows skipping
sstable 1314 | 00:11:46,644 |  10.140.21.54 |          22572
>>                                                         Bloom filter allows skipping
sstable 1313 | 00:11:46,644 |  10.140.21.54 |          22583
>>                                                         Bloom filter allows skipping
sstable 1312 | 00:11:46,644 |  10.140.21.54 |          22594
>>                                                         Bloom filter allows skipping
sstable 1311 | 00:11:46,644 |  10.140.21.54 |          22605
>>                                                         Bloom filter allows skipping
sstable 1310 | 00:11:46,644 |  10.140.21.54 |          22616
>>                                                         Bloom filter allows skipping
sstable 1309 | 00:11:46,644 |  10.140.21.54 |          22628
>>                                                         Bloom filter allows skipping
sstable 1308 | 00:11:46,644 |  10.140.21.54 |          22640
>>                                                         Bloom filter allows skipping
sstable 1307 | 00:11:46,644 |  10.140.21.54 |          22651
>>                                                         Bloom filter allows skipping
sstable 1306 | 00:11:46,644 |  10.140.21.54 |          22663
>>                                                         Bloom filter allows skipping
sstable 1305 | 00:11:46,644 |  10.140.21.54 |          22674
>>                                                         Bloom filter allows skipping
sstable 1304 | 00:11:46,644 |  10.140.21.54 |          22684
>>                                                         Bloom filter allows skipping
sstable 1303 | 00:11:46,644 |  10.140.21.54 |          22696
>>                                                         Bloom filter allows skipping
sstable 1302 | 00:11:46,644 |  10.140.21.54 |          22707
>>                                                         Bloom filter allows skipping
sstable 1301 | 00:11:46,644 |  10.140.21.54 |          22718
>>                                                         Bloom filter allows skipping
sstable 1300 | 00:11:46,644 |  10.140.21.54 |          22729
>>                                                         Bloom filter allows skipping
sstable 1299 | 00:11:46,644 |  10.140.21.54 |          22740
>>                                                         Bloom filter allows skipping
sstable 1298 | 00:11:46,644 |  10.140.21.54 |          22752
>>                                                         Bloom filter allows skipping
sstable 1297 | 00:11:46,644 |  10.140.21.54 |          22763
>>                                                         Bloom filter allows skipping
sstable 1296 | 00:11:46,644 |  10.140.21.54 |          22774
>>                                                                    Key cache hit
for sstable 1295 | 00:11:46,644 |  10.140.21.54 |          22817
>>                                                       Seeking to partition beginning
in data file | 00:11:46,644 |  10.140.21.54 |          22842
>>                        Skipped 0/89 non-slice-intersecting sstables, included 0 due
to tombstones | 00:11:46,646 |  10.140.21.54 |          24109
>>                                                        Merging data from memtables
and 1 sstables | 00:11:46,646 |  10.140.21.54 |          24238
>>                                                              Read 101 live and 0
tombstoned cells | 00:11:46,663 |  10.140.21.54 |          41389
>>                                                              Enqueuing response to
/10.140.22.236 | 00:11:46,663 |  10.140.21.54 |          41831
>>                                                                 Sending message to
/10.140.22.236 | 00:11:46,664 |  10.140.21.54 |          41972
>>                                                               Message received from
/10.140.21.54 | 00:11:46,671 | 10.140.22.236 |          59498
>>                                                            Processing response from
/10.140.21.54 | 00:11:46,672 | 10.140.22.236 |          59563
>>                                                                                 
Request complete | 00:11:46,704 | 10.140.22.236 |          92781
>> 
>> Every query I did always just had three mentions of tombstones
>>   Merging memtable tombstones
>>   Skipped 0/89 non-slice-intersecting sstables, included 0 due to tombstones  
>>   Read 101 live and 0 tombstoned cells
>> And unless i misread those, not of them claim that there are any tombstones.
>> 
>> 
>> On Dec 16, 2014, at 4:26 PM, Ryan Svihla <rsvihla@datastax.com> wrote:
>> 
>>> manual forced compactions create more problems than they solve, if you have no
evidence of tombstones in your selects (which seems odd, can you share some of the tracing
output?), then I'm not sure what it would solve for you.
>>> 
>>> Compaction running could explain a high load, logs messages with ERRORS, WARN,
GCInspector are all meaningful there, I suggest search jira for your version to see if there
are any interesting bugs.
>>> 
>>> 
>>> 
>>> On Tue, Dec 16, 2014 at 6:14 PM, Arne Claassen <arne@emotient.com> wrote:
>>> I just did a wide set of selects and ran across no tombstones. But while on the
subject of gc_grace_seconds, any reason, on a small cluster not to set it to something low
like a single day. It seems like 10 days is only need to large clusters undergoing long partition
splits, or am i misunderstanding gc_grace_seconds.
>>> 
>>> Now, given all that, does any of this explain a high load when the cluster is
idle? Is it compaction catching up and would manual forced compaction alleviate that?
>>> 
>>> thanks,
>>> arne
>>> 
>>> 
>>> On Dec 16, 2014, at 3:28 PM, Ryan Svihla <rsvihla@datastax.com> wrote:
>>> 
>>>> so a delete is really another write for gc_grace_seconds (default 10 days),
if you get enough tombstones it can make managing your cluster a challenge as is. open up
cqlsh, turn on tracing and try a few queries..how many tombstones are scanned for a given
query? It's possible the heap problems you're seeing are actually happening on the query side
and not on the ingest side, the severity of this depends on driver and cassandra version,
but older drivers and versions of cassandra could easily overload heap with expensive selects,
when layered over tombstones it's certainly becomes a possibility this is your root cause.
>>>> 
>>>> Now this will primarily create more load on compaction and depending on your
cassandra version there maybe some other issue at work, but something I can tell you is every
time I see 1 dropped mutation I see a cluster that was overloaded enough it had to shed load.
If I see 200k I see a cluster/configuration/hardware that is badly overloaded.
>>>> 
>>>> I suggest the following
>>>> trace some of the queries used in prod
>>>> monitor your ingest rate, see at what levels you run into issues (GCInspector
log messages, dropped mutations, etc)
>>>> heap configuration we mentioned earlier..go ahead and monitor heap usage,
if it hits 75% repeated this is an indication of heavy load
>>>> monitor dropped mutations..any dropped mutation is evidence of an overloaded
server, again the root cause can be many other problems that are solvable with current hardware,
and LOTS of people runs with nodes with similar configuration.
>>>> 
>>>> On Tue, Dec 16, 2014 at 5:08 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>> Not using any secondary indicies and memtable_flush_queue_size is the default
4.
>>>> 
>>>> But let me tell you how data is "mutated" right now, maybe that will give
you an insight on how this is happening
>>>> 
>>>> Basically the frame data table has the following primary key: PRIMARY KEY
((id), trackid, "timestamp")
>>>> 
>>>> Generally data is inserted once. So day to day writes are all new rows.
>>>> However, when out process for generating analytics for these rows changes,
we run the media back through again, causing overwrites.
>>>> 
>>>> Up until last night, this was just a new insert because the PK never changed
so it was always 1-to-1 overwrite of every row.
>>>> 
>>>> Last night was the first time that a new change went in where the PK could
actually change so now the process is always, DELETE by partition key, insert all rows for
partition key, repeat.
>>>> 
>>>> We two tables that have similar frame data projections and some other aggregates
with much smaller row count per partition key.
>>>> 
>>>> hope that helps,
>>>> arne
>>>> 
>>>> On Dec 16, 2014, at 2:46 PM, Ryan Svihla <rsvihla@datastax.com> wrote:
>>>> 
>>>>> so you've got some blocked flush writers but you have a incredibly large
number of dropped mutations, are you using secondary indexes? and if so how many? what is
your flush queue set to?
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 4:43 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> Of course QA decided to start a test batch (still relatively low traffic),
so I hope it doesn't throw the tpstats off too much
>>>>> 
>>>>> Node 1:
>>>>> Pool Name                    Active   Pending      Completed   Blocked
 All time blocked
>>>>> MutationStage                     0         0       13804928        
0                 0
>>>>> ReadStage                         0         0          10975        
0                 0
>>>>> RequestResponseStage              0         0        7725378        
0                 0
>>>>> ReadRepairStage                   0         0           1247        
0                 0
>>>>> ReplicateOnWriteStage             0         0              0        
0                 0
>>>>> MiscStage                         0         0              0        
0                 0
>>>>> HintedHandoff                     1         1             50        
0                 0
>>>>> FlushWriter                       0         0            306        
0                31
>>>>> MemoryMeter                       0         0            719        
0                 0
>>>>> GossipStage                       0         0         286505        
0                 0
>>>>> CacheCleanupExecutor              0         0              0        
0                 0
>>>>> InternalResponseStage             0         0              0        
0                 0
>>>>> CompactionExecutor                4        14            159        
0                 0
>>>>> ValidationExecutor                0         0              0        
0                 0
>>>>> MigrationStage                    0         0              0        
0                 0
>>>>> commitlog_archiver                0         0              0        
0                 0
>>>>> AntiEntropyStage                  0         0              0        
0                 0
>>>>> PendingRangeCalculator            0         0             11        
0                 0
>>>>> MemtablePostFlusher               0         0           1781        
0                 0
>>>>> 
>>>>> Message type           Dropped
>>>>> READ                         0
>>>>> RANGE_SLICE                  0
>>>>> _TRACE                       0
>>>>> MUTATION                391041
>>>>> COUNTER_MUTATION             0
>>>>> BINARY                       0
>>>>> REQUEST_RESPONSE             0
>>>>> PAGED_RANGE                  0
>>>>> READ_REPAIR                  0
>>>>> 
>>>>> Node 2:
>>>>> Pool Name                    Active   Pending      Completed   Blocked
 All time blocked
>>>>> MutationStage                     0         0         997042        
0                 0
>>>>> ReadStage                         0         0           2623        
0                 0
>>>>> RequestResponseStage              0         0         706650        
0                 0
>>>>> ReadRepairStage                   0         0            275        
0                 0
>>>>> ReplicateOnWriteStage             0         0              0        
0                 0
>>>>> MiscStage                         0         0              0        
0                 0
>>>>> HintedHandoff                     2         2             12        
0                 0
>>>>> FlushWriter                       0         0             37        
0                 4
>>>>> MemoryMeter                       0         0             70        
0                 0
>>>>> GossipStage                       0         0          14927        
0                 0
>>>>> CacheCleanupExecutor              0         0              0        
0                 0
>>>>> InternalResponseStage             0         0              0        
0                 0
>>>>> CompactionExecutor                4         7             94        
0                 0
>>>>> ValidationExecutor                0         0              0        
0                 0
>>>>> MigrationStage                    0         0              0        
0                 0
>>>>> commitlog_archiver                0         0              0        
0                 0
>>>>> AntiEntropyStage                  0         0              0        
0                 0
>>>>> PendingRangeCalculator            0         0              3        
0                 0
>>>>> MemtablePostFlusher               0         0            114        
0                 0
>>>>> 
>>>>> Message type           Dropped
>>>>> READ                         0
>>>>> RANGE_SLICE                  0
>>>>> _TRACE                       0
>>>>> MUTATION                     0
>>>>> COUNTER_MUTATION             0
>>>>> BINARY                       0
>>>>> REQUEST_RESPONSE             0
>>>>> PAGED_RANGE                  0
>>>>> READ_REPAIR                  0
>>>>> 
>>>>> Node 3:
>>>>> Pool Name                    Active   Pending      Completed   Blocked
 All time blocked
>>>>> MutationStage                     0         0        1539324        
0                 0
>>>>> ReadStage                         0         0           2571        
0                 0
>>>>> RequestResponseStage              0         0         373300        
0                 0
>>>>> ReadRepairStage                   0         0            325        
0                 0
>>>>> ReplicateOnWriteStage             0         0              0        
0                 0
>>>>> MiscStage                         0         0              0        
0                 0
>>>>> HintedHandoff                     1         1             21        
0                 0
>>>>> FlushWriter                       0         0             38        
0                 5
>>>>> MemoryMeter                       0         0             59        
0                 0
>>>>> GossipStage                       0         0          21491        
0                 0
>>>>> CacheCleanupExecutor              0         0              0        
0                 0
>>>>> InternalResponseStage             0         0              0        
0                 0
>>>>> CompactionExecutor                4         9             85        
0                 0
>>>>> ValidationExecutor                0         0              0        
0                 0
>>>>> MigrationStage                    0         0              0        
0                 0
>>>>> commitlog_archiver                0         0              0        
0                 0
>>>>> AntiEntropyStage                  0         0              0        
0                 0
>>>>> PendingRangeCalculator            0         0              6        
0                 0
>>>>> MemtablePostFlusher               0         0            164        
0                 0
>>>>> 
>>>>> Message type           Dropped
>>>>> READ                         0
>>>>> RANGE_SLICE                  0
>>>>> _TRACE                       0
>>>>> MUTATION                205259
>>>>> COUNTER_MUTATION             0
>>>>> BINARY                       0
>>>>> REQUEST_RESPONSE             0
>>>>> PAGED_RANGE                  0
>>>>> READ_REPAIR                 18
>>>>> 
>>>>> 
>>>>> Compaction seems like the only thing consistently active and pending
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 2:18 PM, Ryan Svihla <rsvihla@datastax.com>
wrote:
>>>>> Ok based on those numbers I have a theory..
>>>>> 
>>>>> can you show me nodetool tptats for all 3 nodes?
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 4:04 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> No problem with the follow up questions. I'm on a crash course here trying
to understand what makes C* tick so I appreciate all feedback.
>>>>> 
>>>>> We reprocessed all media (1200 partition keys) last night where partition
keys had somewhere between 4k and 200k "rows". After that completed, no traffic went to cluster
at all for ~8 hours and throughout today, we may get a couple (less than 10) queries per second
and maybe 3-4 write batches per hour.
>>>>> 
>>>>> I assume the last value in the Partition Size histogram is the largest
row:
>>>>> 
>>>>> 20924300 bytes: 79
>>>>> 25109160 bytes: 57
>>>>> 
>>>>> The majority seems clustered around 200000 bytes.
>>>>> 
>>>>> I will look at switching my inserts to unlogged batches since they are
always for one partition key.
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 1:47 PM, Ryan Svihla <rsvihla@datastax.com>
wrote:
>>>>> Can you define what is "virtual no traffic" sorry to be repetitive about
that, but I've worked on a lot of clusters in the past year and people have wildly different
ideas what that means.
>>>>> 
>>>>> unlogged batches of the same partition key are definitely a performance
optimization. Typically async is much faster and easier on the cluster when you're using multip
partition key batches.
>>>>> 
>>>>> nodetool cfhistograms <keyspace> <tablename>
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 3:42 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> Actually not sure why the machine was originally configured at 6GB since
we even started it on an r3.large with 15GB.
>>>>> 
>>>>> Re: Batches
>>>>> 
>>>>> Not using batches. I actually have that as a separate question on the
list. Currently I fan out async single inserts and I'm wondering if batches are better since
my data is inherently inserted in blocks of ordered rows for a single partition key.
>>>>> 
>>>>> 
>>>>> Re: Traffic
>>>>> 
>>>>> There isn't all that much traffic. Inserts come in as blocks per partition
key, but then can be 5k-200k rows for that partition key. Each of these rows is less than
100k. It's small, lots of ordered rows. It's frame and sub-frame information for media. and
rows for one piece of media is inserted at once (the partition key).
>>>>> 
>>>>> For the last 12 hours, where the load on all these machine has been stuck
there's been virtually no traffic at all. This is the nodes basically sitting idle, except
that they had  load of 4 each. 
>>>>> 
>>>>> BTW, how do you determine widest row or for that matter number of tombstones
in a row?
>>>>> 
>>>>> thanks,
>>>>> arne
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 1:24 PM, Ryan Svihla <rsvihla@datastax.com>
wrote:
>>>>> So 1024 is still a good 2.5 times what I'm suggesting, 6GB is hardly
enough to run Cassandra well in, especially if you're going full bore on loads. However, you
maybe just flat out be CPU bound on your write throughput, how many TPS and what size writes
do you have? Also what is your widest row?
>>>>> 
>>>>> Final question what is compaction throughput at?
>>>>> 
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 3:20 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> The starting configuration I had, which is still running on two of the
nodes, was 6GB Heap, 1024MB parnew which is close to what you are suggesting and those have
been pegged at load 4 for the over 12 hours with hardly and read or write traffic. I will
set one to 8GB/400MB and see if its load changes.
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 1:12 PM, Ryan Svihla <rsvihla@datastax.com>
wrote:
>>>>> So heap of that size without some tuning will create a number of problems
(high cpu usage one of them), I suggest either 8GB heap and 400mb parnew (which I'd only set
that low for that low cpu count) , or attempt the tunings as indicated in https://issues.apache.org/jira/browse/CASSANDRA-8150
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 3:06 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> Changed the 15GB node to 25GB heap and the nice CPU is down to ~20% now.
Checked my dev cluster to see if the ParNew log entries are just par for the course, but not
seeing them there. However, both have the following every 30 seconds:
>>>>> 
>>>>> DEBUG [BatchlogTasks:1] 2014-12-16 21:00:44,898 BatchlogManager.java
(line 165) Started replayAllFailedBatches
>>>>> DEBUG [MemtablePostFlusher:1] 2014-12-16 21:00:44,899 ColumnFamilyStore.java
(line 866) forceFlush requested but everything is clean in batchlog
>>>>> DEBUG [BatchlogTasks:1] 2014-12-16 21:00:44,899 BatchlogManager.java
(line 200) Finished replayAllFailedBatches
>>>>> 
>>>>> Is that just routine scheduled house-keeping or a sign of something else?
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 12:52 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> Sorry, I meant 15GB heap on the one machine that has less nice CPU% now.
The others are 6GB
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 12:50 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> AWS r3.xlarge, 30GB, but only using a Heap of 10GB, new 2GB because we
might go c3.2xlarge instead if CPU is more important than RAM
>>>>> Storage is optimized EBS SSD (but iostat shows no real IO going on)
>>>>> Each node only has about 10GB with ownership of 67%, 64.7% & 68.3%.
>>>>> 
>>>>> The node on which I set the Heap to 10GB from 6GB the utlilization has
dropped to 46%nice now, but the ParNew log messages still continue at the same pace. I'm gonna
up the HEAP to 20GB for a bit, see if that brings that nice CPU further down.
>>>>> 
>>>>> No TombstoneOverflowingExceptions.
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 11:50 AM, Ryan Svihla <rsvihla@datastax.com>
wrote:
>>>>> What's CPU, RAM, Storage layer, and data density per node? Exact heap
settings would be nice. In the logs look for TombstoneOverflowingException
>>>>> 
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 1:36 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> I'm running 2.0.10.
>>>>> 
>>>>> The data is all time series data and as we change our pipeline, we've
been periodically been reprocessing the data sources, which causes each time series to be
overwritten, i.e. every row per partition key is deleted and re-written, so I assume i've
been collecting a bunch of tombstones.
>>>>> 
>>>>> Also, the presence of the ever present and never completing compaction
types, i assumed were an artifact of tombstoning, but i fully admit to conjecture based on
about ~20 blog posts and stackoverflow questions i've surveyed.
>>>>> 
>>>>> I doubled the Heap on one node and it changed nothing regarding the load
or the ParNew log statements. New Generation Usage is 50%, Eden itself is 56%.
>>>>> 
>>>>> Anything else i should look at and report, let me know.
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 11:14 AM, Jonathan Lacefield <jlacefield@datastax.com>
wrote:
>>>>> Hello,
>>>>> 
>>>>>   What version of Cassandra are you running?  
>>>>> 
>>>>>   If it's 2.0, we recently experienced something similar with 8447 [1],
which 8485 [2] should hopefully resolve.  
>>>>> 
>>>>>   Please note that 8447 is not related to tombstones.  Tombstone processing
can put a lot of pressure on the heap as well. Why do you think you have a lot of tombstones
in that one particular table?
>>>>> 
>>>>>   [1] https://issues.apache.org/jira/browse/CASSANDRA-8447
>>>>>   [2] https://issues.apache.org/jira/browse/CASSANDRA-8485
>>>>> 
>>>>> Jonathan
>>>>> 
>>>>> 
>>>>> Jonathan Lacefield
>>>>> Solution Architect | (404) 822 3487 | jlacefield@datastax.com
>>>>> 
>>>>>      
>>>>> 
>>>>> On Tue, Dec 16, 2014 at 2:04 PM, Arne Claassen <arne@emotient.com>
wrote:
>>>>> I have a three node cluster that has been sitting at a load of 4 (for
each node), 100% CPI utilization (although 92% nice) for that last 12 hours, ever since some
significant writes finished. I'm trying to determine what tuning I should be doing to get
it out of this state. The debug log is just an endless series of:
>>>>> 
>>>>> DEBUG [ScheduledTasks:1] 2014-12-16 19:03:35,042 GCInspector.java (line
118) GC for ParNew: 166 ms for 10 collections, 4400928736 used; max is 8000634880
>>>>> DEBUG [ScheduledTasks:1] 2014-12-16 19:03:36,043 GCInspector.java (line
118) GC for ParNew: 165 ms for 10 collections, 4440011176 used; max is 8000634880
>>>>> DEBUG [ScheduledTasks:1] 2014-12-16 19:03:37,043 GCInspector.java (line
118) GC for ParNew: 135 ms for 8 collections, 4402220568 used; max is 8000634880
>>>>> 
>>>>> iostat shows virtually no I/O.
>>>>> 
>>>>> Compaction may enter into this, but i don't really know what to make
of compaction stats since they never change:
>>>>> 
>>>>> [root@cassandra-37919c3a ~]# nodetool compactionstats
>>>>> pending tasks: 10
>>>>>           compaction type        keyspace           table       completed
          total      unit  progress
>>>>>                Compaction           mediamedia_tracks_raw       271651482
      563615497     bytes    48.20%
>>>>>                Compaction           mediamedia_tracks_raw        30308910
    21676695677     bytes     0.14%
>>>>>                Compaction           mediamedia_tracks_raw      1198384080
     1815603161     bytes    66.00%
>>>>> Active compaction remaining time :   0h22m24s
>>>>> 
>>>>> 5 minutes later:
>>>>> 
>>>>> [root@cassandra-37919c3a ~]# nodetool compactionstats
>>>>> pending tasks: 9
>>>>>           compaction type        keyspace           table       completed
          total      unit  progress
>>>>>                Compaction           mediamedia_tracks_raw       271651482
      563615497     bytes    48.20%
>>>>>                Compaction           mediamedia_tracks_raw        30308910
    21676695677     bytes     0.14%
>>>>>                Compaction           mediamedia_tracks_raw      1198384080
     1815603161     bytes    66.00%
>>>>> Active compaction remaining time :   0h22m24s
>>>>> 
>>>>> Sure the pending tasks went down by one, but the rest is identical. media_tracks_raw
likely has a bunch of tombstones (can't figure out how to get stats on that).
>>>>> 
>>>>> Is this behavior something that indicates that i need more Heap, larger
new generation? Should I be manually running compaction on tables with lots of tombstones?
>>>>> 
>>>>> Any suggestions or places to educate myself better on performance tuning
would be appreciated.
>>>>> 
>>>>> arne
>>>>> 
>>>>> 
>>>>> -- 
>>>>> 
>>>>> Ryan Svihla
>>>>> Solution Architect
>>>>> 
>>>>>  
>>>>> 
>>>>> DataStax is the fastest, most scalable distributed database technology,
delivering Apache Cassandra to the world’s most innovative enterprises. Datastax is built
to be agile, always-on, and predictably scalable to any size. With more than 500 customers
in 45 countries, DataStax is the database technology and transactional backbone of choice
for the worlds most innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>>>> 
>>>>> 
>>>>> 
>>>>> -- 
>>>>> 
>>>>> Ryan Svihla
>>>>> Solution Architect
>>>>> 
>>>>>  
>>>>> 
>>>>> DataStax is the fastest, most scalable distributed database technology,
delivering Apache Cassandra to the world’s most innovative enterprises. Datastax is built
to be agile, always-on, and predictably scalable to any size. With more than 500 customers
in 45 countries, DataStax is the database technology and transactional backbone of choice
for the worlds most innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>>>> 
>>>>> 
>>>>> 
>>>>> -- 
>>>>> 
>>>>> Ryan Svihla
>>>>> Solution Architect
>>>>> 
>>>>>  
>>>>> 
>>>>> DataStax is the fastest, most scalable distributed database technology,
delivering Apache Cassandra to the world’s most innovative enterprises. Datastax is built
to be agile, always-on, and predictably scalable to any size. With more than 500 customers
in 45 countries, DataStax is the database technology and transactional backbone of choice
for the worlds most innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>>>> 
>>>>> 
>>>>> 
>>>>> -- 
>>>>> 
>>>>> Ryan Svihla
>>>>> Solution Architect
>>>>> 
>>>>>  
>>>>> 
>>>>> DataStax is the fastest, most scalable distributed database technology,
delivering Apache Cassandra to the world’s most innovative enterprises. Datastax is built
to be agile, always-on, and predictably scalable to any size. With more than 500 customers
in 45 countries, DataStax is the database technology and transactional backbone of choice
for the worlds most innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>>>> 
>>>>> 
>>>>> 
>>>>> -- 
>>>>> 
>>>>> Ryan Svihla
>>>>> Solution Architect
>>>>> 
>>>>>  
>>>>> 
>>>>> DataStax is the fastest, most scalable distributed database technology,
delivering Apache Cassandra to the world’s most innovative enterprises. Datastax is built
to be agile, always-on, and predictably scalable to any size. With more than 500 customers
in 45 countries, DataStax is the database technology and transactional backbone of choice
for the worlds most innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>>>> 
>>>>> 
>>>>> 
>>>>> -- 
>>>>> 
>>>>> Ryan Svihla
>>>>> Solution Architect
>>>>> 
>>>>>  
>>>>> 
>>>>> DataStax is the fastest, most scalable distributed database technology,
delivering Apache Cassandra to the world’s most innovative enterprises. Datastax is built
to be agile, always-on, and predictably scalable to any size. With more than 500 customers
in 45 countries, DataStax is the database technology and transactional backbone of choice
for the worlds most innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>>>> 
>>>> 
>>>> 
>>>> 
>>>> -- 
>>>> 
>>>> Ryan Svihla
>>>> Solution Architect
>>>> 
>>>>  
>>>> 
>>>> DataStax is the fastest, most scalable distributed database technology, delivering
Apache Cassandra to the world’s most innovative enterprises. Datastax is built to be agile,
always-on, and predictably scalable to any size. With more than 500 customers in 45 countries,
DataStax is the database technology and transactional backbone of choice for the worlds most
innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>>> 
>>> 
>>> 
>>> 
>>> -- 
>>> 
>>> Ryan Svihla
>>> Solution Architect
>>> 
>>>  
>>> 
>>> DataStax is the fastest, most scalable distributed database technology, delivering
Apache Cassandra to the world’s most innovative enterprises. Datastax is built to be agile,
always-on, and predictably scalable to any size. With more than 500 customers in 45 countries,
DataStax is the database technology and transactional backbone of choice for the worlds most
innovative companies such as Netflix, Adobe, Intuit, and eBay. 
>>> 
>> 
> 
> 
> 
> -- 
> 
> Ryan Svihla
> Solution Architect
> 
>  
> 
> DataStax is the fastest, most scalable distributed database technology, delivering Apache
Cassandra to the world’s most innovative enterprises. Datastax is built to be agile, always-on,
and predictably scalable to any size. With more than 500 customers in 45 countries, DataStax
is the database technology and transactional backbone of choice for the worlds most innovative
companies such as Netflix, Adobe, Intuit, and eBay. 
> 


Mime
View raw message