Hi there, I currently see Cassandra crash every couple of days. I run a 3 node cluster on version 1.1.2. Does anyone have a clue why it crashes? I couldn't find it as fix in a newer release. Is this an actual bug or did I do something wrong?
Thank you in advance for your time. Last 100 log lines before crash: * INFO [FlushWriter:39] 2012-08-11 12:51:00,933 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/OpsCenter/rollups60/OpsCenter-rollups60-hd-7-Data.db (10778171 bytes) for commitlog position ReplayPosition(segmentId=2831860362157183, position=89962041)* * INFO [OptionalTasks:1] 2012-08-11 13:12:30,940 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='CloudPelican', ColumnFamily='wordevents') (estimated 74393593 bytes)* * INFO [OptionalTasks:1] 2012-08-11 13:12:30,941 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-wordevents@32552383(22883734/74393593 serialized/live bytes, 227279 ops)* * INFO [FlushWriter:40] 2012-08-11 13:12:30,941 Memtable.java (line 266) Writing Memtable-wordevents@32552383(22883734/74393593 serialized/live bytes, 227279 ops)* * INFO [FlushWriter:40] 2012-08-11 13:12:31,703 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-158-Data.db (11800327 bytes) for commitlog position ReplayPosition(segmentId=2831860362157183, position=116934579)* * INFO [MemoryMeter:1] 2012-08-11 14:01:36,942 Memtable.java (line 213) CFS(Keyspace='OpsCenter', ColumnFamily='rollups7200') liveRatio is 6.158919689235077 (just-counted was 4.408341190092955). calculation took 100ms for 16409 columns* * INFO [CompactionExecutor:88] 2012-08-11 14:08:27,875 AutoSavingCache.java (line 262) Saved KeyCache (38164 items) in 70 ms* * INFO [OptionalTasks:1] 2012-08-11 14:18:37,519 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='CloudPelican', ColumnFamily='wordevents') (estimated 74346493 bytes)* * INFO [OptionalTasks:1] 2012-08-11 14:18:37,519 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-wordevents@10789879(22869246/74346493 serialized/live bytes, 226341 ops)* * INFO [FlushWriter:41] 2012-08-11 14:18:37,520 Memtable.java (line 266) Writing Memtable-wordevents@10789879(22869246/74346493 serialized/live bytes, 226341 ops)* * INFO [FlushWriter:41] 2012-08-11 14:18:38,288 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-159-Data.db (11796722 bytes) for commitlog position ReplayPosition(segmentId=2838466681767183, position=67094743)* * WARN [MemoryMeter:1] 2012-08-11 14:21:55,676 Memtable.java (line 197) setting live ratio to minimum of 1.0 instead of 0.45760196307363504* * INFO [MemoryMeter:1] 2012-08-11 14:21:55,676 Memtable.java (line 213) CFS(Keyspace='Wupa', ColumnFamily='PageViewsHost') liveRatio is 1.0421914932457101 (just-counted was 1.0). calculation took 2ms for 175 columns* * INFO [MemoryMeter:1] 2012-08-11 14:33:20,916 Memtable.java (line 213) CFS(Keyspace='OpsCenter', ColumnFamily='rollups60') liveRatio is 4.067582667928898 (just-counted was 4.031462910772899). calculation took 711ms for 169224 columns* * INFO [OptionalTasks:1] 2012-08-11 14:59:20,909 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='OpsCenter', ColumnFamily='pdps') (estimated 74395427 bytes)* * INFO [OptionalTasks:1] 2012-08-11 14:59:20,909 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-pdps@30500189(9222554/74395427 serialized/live bytes, 214478 ops)* * INFO [FlushWriter:42] 2012-08-11 14:59:20,910 Memtable.java (line 266) Writing Memtable-pdps@30500189(9222554/74395427 serialized/live bytes, 214478 ops)* * INFO [FlushWriter:42] 2012-08-11 14:59:21,420 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11351-Data.db (6928124 bytes) for commitlog position ReplayPosition(segmentId=2838466681767183, position=117115966)* * INFO [MemoryMeter:1] 2012-08-11 14:59:31,138 Memtable.java (line 213) CFS(Keyspace='OpsCenter', ColumnFamily='pdps') liveRatio is 14.460953759840738 (just-counted was 14.460953759840738). calculation took 28ms for 878 columns* * INFO [OptionalTasks:1] 2012-08-11 15:25:41,366 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='CloudPelican', ColumnFamily='wordevents') (estimated 74974061 bytes)* * INFO [OptionalTasks:1] 2012-08-11 15:25:41,367 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-wordevents@24703812(23062288/74974061 serialized/live bytes, 228878 ops)* * INFO [FlushWriter:43] 2012-08-11 15:25:41,367 Memtable.java (line 266) Writing Memtable-wordevents@24703812(23062288/74974061 serialized/live bytes, 228878 ops)* * INFO [FlushWriter:43] 2012-08-11 15:25:42,144 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-160-Data.db (11891766 bytes) for commitlog position ReplayPosition(segmentId=2844308891384183, position=29935798)* * INFO [OptionalTasks:1] 2012-08-11 15:50:30,630 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='CloudPelican', ColumnFamily='events') (estimated 74318657 bytes)* * INFO [OptionalTasks:1] 2012-08-11 15:50:30,631 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-events@6204038(14756712/74318657 serialized/live bytes, 224254 ops)* * INFO [FlushWriter:44] 2012-08-11 15:50:30,631 Memtable.java (line 266) Writing Memtable-events@6204038(14756712/74318657 serialized/live bytes, 224254 ops)* * INFO [FlushWriter:44] 2012-08-11 15:50:31,428 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/CloudPelican/events/CloudPelican-events-hd-97-Data.db (5654663 bytes) for commitlog position ReplayPosition(segmentId=2844308891384183, position=65470717)* * INFO [OptionalTasks:1] 2012-08-11 15:59:32,864 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='OpsCenter', ColumnFamily='pdps') (estimated 74304013 bytes)* * INFO [OptionalTasks:1] 2012-08-11 15:59:32,864 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-pdps@14242177(4110601/74304013 serialized/live bytes, 95731 ops)* * INFO [FlushWriter:45] 2012-08-11 15:59:32,865 Memtable.java (line 266) Writing Memtable-pdps@14242177(4110601/74304013 serialized/live bytes, 95731 ops)* * INFO [FlushWriter:45] 2012-08-11 15:59:33,117 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11352-Data.db (3190253 bytes) for commitlog position ReplayPosition(segmentId=2844308891384183, position=81207982)* * INFO [OptionalTasks:1] 2012-08-11 16:14:00,792 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='OpsCenter', ColumnFamily='rollups60') (estimated 72855795 bytes)* * INFO [OptionalTasks:1] 2012-08-11 16:14:00,793 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-rollups60@6896103(14329060/72855795 serialized/live bytes, 334552 ops)* * INFO [FlushWriter:46] 2012-08-11 16:14:00,793 Memtable.java (line 266) Writing Memtable-rollups60@6896103(14329060/72855795 serialized/live bytes, 334552 ops)* * INFO [MemoryMeter:1] 2012-08-11 16:14:01,140 Memtable.java (line 213) CFS(Keyspace='CloudPelican', ColumnFamily='wordevents') liveRatio is 2.174146758479727 (just-counted was 1.7475433700933507). calculation took 792ms for 185473 columns* * INFO [FlushWriter:46] 2012-08-11 16:14:01,627 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/OpsCenter/rollups60/OpsCenter-rollups60-hd-8-Data.db (10595913 bytes) for commitlog position ReplayPosition(segmentId=2844308891384183, position=104879371)* * INFO [CompactionExecutor:94] 2012-08-11 16:14:01,629 CompactionTask.java (line 109) Compacting [SSTableReader(path='/var/lib/cassandra/data/OpsCenter/rollups60/OpsCenter-rollups60-hd-7-Data.db'), SSTableReader(path='/var/lib/cassandra/data/OpsCenter/rollups60/OpsCenter-rollups60-hd-6-Data.db'), SSTableReader(path='/var/lib/cassandra/data/OpsCenter/rollups60/OpsCenter-rollups60-hd-5-Data.db'), SSTableReader(path='/var/lib/cassandra/data/OpsCenter/rollups60/OpsCenter-rollups60-hd-8-Data.db')] * * INFO [CompactionExecutor:94] 2012-08-11 16:14:07,291 CompactionTask.java (line 221) Compacted to [/var/lib/cassandra/data/OpsCenter/rollups60/OpsCenter-rollups60-hd-9-Data.db,]. 72,023,724 to 71,518,964 (~99% of original) bytes for 1,692 keys at 12.046238MB/s. Time: 5,662ms.* * INFO [OptionalTasks:1] 2012-08-11 16:38:47,081 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='CloudPelican', ColumnFamily='wordevents') (estimated 74301547 bytes)* * INFO [OptionalTasks:1] 2012-08-11 16:38:47,082 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-wordevents@29484922(27340030/74301547 serialized/live bytes, 270671 ops)* * INFO [FlushWriter:47] 2012-08-11 16:38:47,082 Memtable.java (line 266) Writing Memtable-wordevents@29484922(27340030/74301547 serialized/live bytes, 270671 ops)* * INFO [FlushWriter:47] 2012-08-11 16:38:47,990 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-161-Data.db (14090192 bytes) for commitlog position ReplayPosition(segmentId=2850431735255183, position=8234095)* * INFO [CompactionExecutor:96] 2012-08-11 16:38:47,991 CompactionTask.java (line 109) Compacting [SSTableReader(path='/var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-160-Data.db'), SSTableReader(path='/var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-159-Data.db'), SSTableReader(path='/var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-158-Data.db'), SSTableReader(path='/var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-161-Data.db')] * * INFO [CompactionExecutor:96] 2012-08-11 16:38:53,790 CompactionTask.java (line 221) Compacted to [/var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-162-Data.db,]. 49,579,007 to 49,570,164 (~99% of original) bytes for 20,466 keys at 8.152059MB/s. Time: 5,799ms.* * INFO [OptionalTasks:1] 2012-08-11 16:57:39,570 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='OpsCenter', ColumnFamily='pdps') (estimated 74387670 bytes)* * INFO [OptionalTasks:1] 2012-08-11 16:57:39,572 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-pdps@5605254(4115229/74387670 serialized/live bytes, 95703 ops)* * INFO [FlushWriter:48] 2012-08-11 16:57:39,573 Memtable.java (line 266) Writing Memtable-pdps@5605254(4115229/74387670 serialized/live bytes, 95703 ops)* * INFO [FlushWriter:48] 2012-08-11 16:57:39,783 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11353-Data.db (3180163 bytes) for commitlog position ReplayPosition(segmentId=2850431735255183, position=37579163)* * INFO [CompactionExecutor:98] 2012-08-11 16:57:39,785 CompactionTask.java (line 109) Compacting [SSTableReader(path='/var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11353-Data.db'), SSTableReader(path='/var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11351-Data.db'), SSTableReader(path='/var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11352-Data.db'), SSTableReader(path='/var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11350-Data.db')] * * INFO [CompactionExecutor:98] 2012-08-11 16:57:41,389 CompactionTask.java (line 221) Compacted to [/var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11354-Data.db,]. 20,221,486 to 19,712,175 (~97% of original) bytes for 1,707 keys at 11.720072MB/s. Time: 1,604ms.* * INFO [MemoryMeter:1] 2012-08-11 17:02:59,319 Memtable.java (line 213) CFS(Keyspace='CloudPelican', ColumnFamily='events') liveRatio is 3.8540099961262424 (just-counted was 3.6790109706521132). calculation took 744ms for 97943 columns* * INFO [OptionalTasks:1] 2012-08-11 17:54:55,132 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='OpsCenter', ColumnFamily='pdps') (estimated 74327820 bytes)* * INFO [OptionalTasks:1] 2012-08-11 17:54:55,133 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-pdps@32988119(4111918/74327820 serialized/live bytes, 95626 ops)* * INFO [FlushWriter:49] 2012-08-11 17:54:55,133 Memtable.java (line 266) Writing Memtable-pdps@32988119(4111918/74327820 serialized/live bytes, 95626 ops)* * INFO [FlushWriter:49] 2012-08-11 17:54:55,346 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/OpsCenter/pdps/OpsCenter-pdps-hd-11355-Data.db (3177704 bytes) for commitlog position ReplayPosition(segmentId=2850431735255183, position=115958680)* * INFO [OptionalTasks:1] 2012-08-11 18:03:15,246 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='CloudPelican', ColumnFamily='wordevents') (estimated 74433332 bytes)* * INFO [OptionalTasks:1] 2012-08-11 18:03:15,246 ColumnFamilyStore.java (line 643) Enqueuing flush of Memtable-wordevents@10570291(27388522/74433332 serialized/live bytes, 271607 ops)* * INFO [FlushWriter:50] 2012-08-11 18:03:15,247 Memtable.java (line 266) Writing Memtable-wordevents@10570291(27388522/74433332 serialized/live bytes, 271607 ops)* * INFO [FlushWriter:50] 2012-08-11 18:03:16,196 Memtable.java (line 307) Completed flushing /var/lib/cassandra/data/CloudPelican/wordevents/CloudPelican-wordevents-hd-163-Data.db (14091793 bytes) for commitlog position ReplayPosition(segmentId=2850431735255183, position=127624265)* *ERROR [COMMIT-LOG-ALLOCATOR] 2012-08-11 18:05:45,050 AbstractCassandraDaemon.java (line 134) Exception in thread Thread[COMMIT-LOG-ALLOCATOR,5,main]* *java.io.IOError: java.io.IOException: Map failed* * at org.apache.cassandra.db.commitlog.CommitLogSegment.<init>(CommitLogSegment.java:127) * * at org.apache.cassandra.db.commitlog.CommitLogSegment.freshSegment(CommitLogSegment.java:81) * * at org.apache.cassandra.db.commitlog.CommitLogAllocator.createFreshSegment(CommitLogAllocator.java:257) * * at org.apache.cassandra.db.commitlog.CommitLogAllocator.access$500(CommitLogAllocator.java:49) * * at org.apache.cassandra.db.commitlog.CommitLogAllocator$1.runMayThrow(CommitLogAllocator.java:105) * * at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)* * at java.lang.Thread.run(Unknown Source)* *Caused by: java.io.IOException: Map failed* * at sun.nio.ch.FileChannelImpl.map(Unknown Source)* * at org.apache.cassandra.db.commitlog.CommitLogSegment.<init>(CommitLogSegment.java:119) * * ... 6 more* *Caused by: java.lang.OutOfMemoryError: Map failed* * at sun.nio.ch.FileChannelImpl.map0(Native Method)* * ... 8 more* * INFO [StorageServiceShutdownHook] 2012-08-11 18:05:45,053 CassandraDaemon.java (line 218) Stop listening to thrift clients* * INFO [StorageServiceShutdownHook] 2012-08-11 18:05:45,054 Gossiper.java (line 1133) Announcing shutdown* * INFO [StorageServiceShutdownHook] 2012-08-11 18:05:46,065 MessagingService.java (line 534) Waiting for messaging service to quiesce* * INFO [ACCEPT-/85.17.231.89] 2012-08-11 18:05:46,066 MessagingService.java (line 690) MessagingService shutting down server thread.* *ERROR [Thrift:1532] 2012-08-11 18:05:46,813 CustomTThreadPoolServer.java (line 204) Error occurred during processing of message.* *java.util.concurrent.RejectedExecutionException: ThreadPoolExecutor has shut down* * at org.apache.cassandra.concurrent.DebuggableThreadPoolExecutor$1.rejectedExecution(DebuggableThreadPoolExecutor.java:60) * * at java.util.concurrent.ThreadPoolExecutor.reject(Unknown Source)* * at java.util.concurrent.ThreadPoolExecutor.execute(Unknown Source)* * at org.apache.cassandra.service.StorageProxy.insertLocal(StorageProxy.java:457) * * at org.apache.cassandra.service.StorageProxy.sendToHintedEndpoints(StorageProxy.java:314) * * at org.apache.cassandra.service.StorageProxy$2.apply(StorageProxy.java:119)* * at org.apache.cassandra.service.StorageProxy.performWrite(StorageProxy.java:260) * * at org.apache.cassandra.service.StorageProxy.mutate(StorageProxy.java:193)* * at org.apache.cassandra.thrift.CassandraServer.doInsert(CassandraServer.java:632) * * at org.apache.cassandra.thrift.CassandraServer.internal_batch_mutate(CassandraServer.java:582) * * at org.apache.cassandra.thrift.CassandraServer.batch_mutate(CassandraServer.java:590) * * at org.apache.cassandra.thrift.Cassandra$Processor$batch_mutate.getResult(Cassandra.java:3176) * * at org.apache.cassandra.thrift.Cassandra$Processor$batch_mutate.getResult(Cassandra.java:3164) * * at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:32)* * at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:34) * * at org.apache.cassandra.thrift.CustomTThreadPoolServer$WorkerProcess.run(CustomTThreadPoolServer.java:186) * * at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)* * at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)* * at java.lang.Thread.run(Unknown Source)* With kind regards, Robin Verlangen *Software engineer* * * W http://www.robinverlangen.nl E ro...@us2.nl Disclaimer: The information contained in this message and attachments is intended solely for the attention and use of the named addressee and may be confidential. If you are not the intended recipient, you are reminded that the information remains the property of the sender. You must not use, disclose, distribute, copy, print or rely on this e-mail. If you have received this message in error, please contact the sender immediately and irrevocably delete this message and any copies.
