cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Bo Finnerup Madsen <bo.gunder...@gmail.com>
Subject Debugging out of memory
Date Tue, 12 Apr 2016 17:53:44 GMT
Hi,

We have an application that reads data from a set of external sources and
loads them into our cassandra cluster. The load goes ok for some time
(~24h) and then some servers in the cluster starts flapping between being
down and up, and finally they go out of memory.
The cluster consists of 5 m4.xlarge machines with 16gb memory, cassandra
has an 8gb heap. All machines have a high load while data is being written,
with a load between 6 and 20.

I have tried sifting through the information available from nodetool, but I
am unable to find anything helping me determine what is causing the oom. I
am quite new to cassandra, so I might very well overlook the obvious. So
any pointers on how to proceed with identifying the problem will be much
appriciated :)

In the following I have included information from 10.61.70.110 when it was
flapping.

Status for ddp keyspace(only keyspace containing any real data):
-----------------------------------------------------------------------------
Datacenter: datacenter1
=======================
Status=Up/Down
|/ State=Normal/Leaving/Joining/Moving
--  Address       Load       Tokens       Owns (effective)  Host ID
                      Rack
UN  10.61.70.108  65.97 GB   256          59,1%
de79a554-9296-4575-8b79-2089f92069cd  rack1
UN  10.61.70.110  58.95 GB   256          63,3%
310460f6-b7ce-45a7-be63-a7dd409f6b17  rack1
UN  10.61.70.72   58.17 GB   256          60,3%
44fd4f8e-18cd-4487-8174-3a22fb9ed24f  rack1
UN  10.61.70.107  58.69 GB   256          58,5%
f8118fc2-e340-45db-a06e-a5842107d6c8  rack1
UN  10.61.70.64   68 GB      256          58,7%
84bee9fe-2adc-48aa-915c-f43d972f5a2f  rack1
-----------------------------------------------------------------------------


Snippet from system.log:
-----------------------------------------------------------------------------
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,547 MessagingService.java:980
- MUTATION messages were dropped in last 5000 ms: 5776 for internal timeout
and 0 for cross node timeout
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,547 StatusLogger.java:52 -
Pool Name                    Active   Pending      Completed   Blocked  All
Time Blocked
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,551 StatusLogger.java:56 -
MutationStage                    32   4881705    17826061870         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,552 StatusLogger.java:56 -
ViewMutationStage                 0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,552 StatusLogger.java:56 -
ReadStage                         0         0        3266887         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,553 StatusLogger.java:56 -
RequestResponseStage              0         0      389429305         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,553 StatusLogger.java:56 -
ReadRepairStage                   0         0         322804         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,554 StatusLogger.java:56 -
CounterMutationStage              0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,554 StatusLogger.java:56 -
MiscStage                         0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,554 StatusLogger.java:56 -
CompactionExecutor                4        54          31305         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,555 StatusLogger.java:56 -
MemtableReclaimMemory             0         0           3310         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,555 StatusLogger.java:56 -
PendingRangeCalculator            0         0             10         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,555 StatusLogger.java:56 -
GossipStage                       0         0         338170         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,555 StatusLogger.java:56 -
SecondaryIndexManagement          0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,556 StatusLogger.java:56 -
HintsDispatcher                   1         4           6264         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,558 StatusLogger.java:56 -
MigrationStage                    0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,559 StatusLogger.java:56 -
MemtablePostFlush                 0         0           3451         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,560 StatusLogger.java:56 -
ValidationExecutor                0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,561 StatusLogger.java:56 -
Sampler                           0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,563 StatusLogger.java:56 -
MemtableFlushWriter               0         0           3310         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,564 StatusLogger.java:56 -
InternalResponseStage             0         0        1873184         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,565 StatusLogger.java:56 -
AntiEntropyStage                  0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,565 StatusLogger.java:56 -
CacheCleanupExecutor              0         0              0         0
            0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,566 StatusLogger.java:56 -
Native-Transport-Requests         3         2      212872837         0
         1796
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,566 StatusLogger.java:66 -
CompactionManager                 4        32
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,566 StatusLogger.java:78 -
MessagingService                n/a       0/0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,567 StatusLogger.java:88 -
Cache Type                     Size                 Capacity
KeysToSave
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,568 StatusLogger.java:90 -
KeyCache                   88654200                104857600
       all
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,568 StatusLogger.java:96 -
RowCache                          0                        0
       all
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,568 StatusLogger.java:103 -
Table                       Memtable ops,data
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,569 StatusLogger.java:106 -
ddp.fingerprint_by_content_uuid_mv      99624,17726363
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,569 StatusLogger.java:106 -
ddp.sync                            4747,1551
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,569 StatusLogger.java:106 -
ddp.log_portal                            0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,570 StatusLogger.java:106 -
ddp.meta_data                    2083,3829424
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,570 StatusLogger.java:106 -
ddp.configuration                   199,13915
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,570 StatusLogger.java:106 -
ddp.uuids_by_related_uuid     414431,17721698
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,570 StatusLogger.java:106 -
ddp.file_by_file_id                       0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,571 StatusLogger.java:106 -
ddp.fingerprint_by_content_type_mv       83007,3317002
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,571 StatusLogger.java:106 -
ddp.heartbeat                     35855,13407
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,574 StatusLogger.java:106 -
ddp.concept                               0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,575 StatusLogger.java:106 -
ddp.classification_scheme                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,576 StatusLogger.java:106 -
ddp.rendering_relations_mv        9665,1201123
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,576 StatusLogger.java:106 -
ddp.file                             41,19826
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,576 StatusLogger.java:106 -
ddp.rendering_relations       276049,13465909
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,576 StatusLogger.java:106 -
ddp.semantic_group                        0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,577 StatusLogger.java:106 -
ddp.rendering                  23344,68861340
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,577 StatusLogger.java:106 -
ddp.thesauri                             44,8
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,577 StatusLogger.java:106 -
ddp.file_download                         0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,577 StatusLogger.java:106 -
ddp.uuids_by_related_uuid_mv     172394,14524712
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,578 StatusLogger.java:106 -
ddp.fingerprint               124884,54955730
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,578 StatusLogger.java:106 -
ddp.ddp_status                            0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,578 StatusLogger.java:106 -
ddp.log_portal_mv                         0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,578 StatusLogger.java:106 -
system_distributed.parent_repair_history                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,579 StatusLogger.java:106 -
system_distributed.repair_history                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,579 StatusLogger.java:106 -
system.compaction_history             20,4595
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,580 StatusLogger.java:106 -
system.hints                              0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,580 StatusLogger.java:106 -
system.schema_aggregates                  0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,580 StatusLogger.java:106 -
system.IndexInfo                          0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,581 StatusLogger.java:106 -
system.schema_columnfamilies                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,581 StatusLogger.java:106 -
system.schema_triggers                    0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,582 StatusLogger.java:106 -
system.size_estimates            50400,764904
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,582 StatusLogger.java:106 -
system.schema_functions                   0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,582 StatusLogger.java:106 -
system.paxos                              0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,582 StatusLogger.java:106 -
system.views_builds_in_progress                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,583 StatusLogger.java:106 -
system.built_views                        0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,583 StatusLogger.java:106 -
system.peer_events                        0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,583 StatusLogger.java:106 -
system.range_xfers                        0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,583 StatusLogger.java:106 -
system.peers                              0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,584 StatusLogger.java:106 -
system.batches                188441,33975764
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,584 StatusLogger.java:106 -
system.schema_keyspaces                   0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,585 StatusLogger.java:106 -
system.schema_usertypes                   0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,585 StatusLogger.java:106 -
system.local                              0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,585 StatusLogger.java:106 -
system.sstable_activity            1376,24807
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,587 StatusLogger.java:106 -
system.available_ranges                   0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,587 StatusLogger.java:106 -
system.batchlog                           0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,588 StatusLogger.java:106 -
system.schema_columns                     0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,589 StatusLogger.java:106 -
system_schema.columns                     0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,589 StatusLogger.java:106 -
system_schema.types                       0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,590 StatusLogger.java:106 -
system_schema.indexes                     0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,590 StatusLogger.java:106 -
system_schema.keyspaces                   0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,590 StatusLogger.java:106 -
system_schema.dropped_columns                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,592 StatusLogger.java:106 -
system_schema.aggregates                  0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,592 StatusLogger.java:106 -
system_schema.triggers                    0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,592 StatusLogger.java:106 -
system_schema.tables                      0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,592 StatusLogger.java:106 -
system_schema.views                       0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,593 StatusLogger.java:106 -
system_schema.functions                   0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,593 StatusLogger.java:106 -
system_auth.roles                         0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,593 StatusLogger.java:106 -
system_auth.role_members                  0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,593 StatusLogger.java:106 -
system_auth.resource_role_permissons_index                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,594 StatusLogger.java:106 -
system_auth.role_permissions                 0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,594 StatusLogger.java:106 -
system_traces.sessions                    0,0
INFO  [ScheduledTasks:1] 2016-04-12 17:35:35,594 StatusLogger.java:106 -
system_traces.events                      0,0
-----------------------------------------------------------------------------

compactionstats:
-----------------------------------------------------------------------------
pending tasks: 32
                                     id   compaction type   keyspace
            table   completed       total    unit   progress
   3bf89310-00d1-11e6-a5a3-f125ce747d55        Compaction        ddp
rendering_relations     1,09 GB     5,43 GB   bytes     20,10%
   9c5bd6b1-00d4-11e6-a5a3-f125ce747d55        Compaction        ddp
        meta_data   243,64 MB   338,56 MB   bytes     71,96%
   50308cb0-00d2-11e6-a5a3-f125ce747d55        Compaction        ddp
uuids_by_related_uuid     1,37 GB     2,17 GB   bytes     63,11%
   e8965d90-00c3-11e6-a5a3-f125ce747d55        Compaction        ddp
        rendering    19,02 GB    24,09 GB   bytes     78,96%
-----------------------------------------------------------------------------

Thank you in advance :)

Yours sincerely,
  Bo Madsen

Mime
View raw message