You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@cassandra.apache.org by Alexandru Dan Sicoe <si...@googlemail.com> on 2011/12/01 11:16:37 UTC
Insufficient disk space to flush
Hello everyone,
4 node Cassandra 0.8.5 cluster with RF =2.
One node started throwing exceptions in its log:
ERROR 10:02:46,837 Fatal exception in thread Thread[FlushWriter:1317,5,main]
java.lang.RuntimeException: java.lang.RuntimeException: Insufficient disk
space to flush 17296 bytes
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.RuntimeException: Insufficient disk space to flush
17296 bytes
at
org.apache.cassandra.db.ColumnFamilyStore.getFlushPath(ColumnFamilyStore.java:714)
at
org.apache.cassandra.db.ColumnFamilyStore.createFlushWriter(ColumnFamilyStore.java:2301)
at
org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:246)
at org.apache.cassandra.db.Memtable.access$400(Memtable.java:49)
at org.apache.cassandra.db.Memtable$3.runMayThrow(Memtable.java:270)
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
... 3 more
Checked disk and obviously it's 100% full.
How do I recover from this without loosing the data? I've got plenty of
space on the other nodes, so I thought of doing a decommission which I
understand reassigns ranges to the other nodes and replicates data to them.
After that's done I plan on manually deleting the data on the node and then
joining in the same cluster position with auto-bootstrap turned off so that
I won't get back the old data and I can continue getting new data with the
node.
Note, I would like to have 4 nodes in because the other three barely take
the input load alone. These are just long running tests until I get some
better machines.
On strange thing I found is that the data folder on the ndoe that filled up
the disk is 150 GB (as measured with du) while the data folder on all other
3 nodes is 50 GB. At the same time, DataStax OpsCenter shows a size of
around 50GB for all 4 nodes. I though that the node was making a major
compaction at which time it filled up the disk....but even that doesn't
make sense because shouldn't a major compaction just be capable of doubling
the size, not triple-ing it? Doesn anyone know how to explain this behavior?
Thanks,
Alex
Re: Repair failure under 0.8.6
Posted by Peter Schuller <pe...@infidyne.com>.
Filed https://issues.apache.org/jira/browse/CASSANDRA-3569 to fix it
so that streams don't die due to conviction.
--
/ Peter Schuller (@scode, http://worldmodscode.wordpress.com)
Re: Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
Please disregard the GC part of the question -- I found it.
On 12/4/2011 4:12 PM, Maxim Potekhin wrote:
> Thanks Peter!
>
> I will try to increase phi_convict -- I will just need to restart the
> cluster after
> the edit, right?
>
> I do recall that I see nodes temporarily marked as down, only to pop
> up later.
>
> In the current situation, there is no load on the cluster at all,
> outside the
> maintenance like the repair.
>
> How do I configure the print level for the GC report?
>
> Thank you,
> Maxim
>
>
> On 12/4/2011 2:09 PM, Peter Schuller wrote:
>>> I capped heap and the error is still there. So I keep seeing "node
>>> dead"
>>> messages even when I know the nodes were OK. Where and how do I tweak
>>> timeouts?
>> You can increase phi_convict_threshold in the configuration. However,
>> I would rather want to find out why they are being marked as down to
>> begin with. In a healthy situation, especially if you are not putting
>> extreme load on the cluster, there is very little reason for hosts to
>> be marked as down unless there's some bug somewhere.
>>
>> Is this cluster under constant traffic? Are you seeing slow requests
>> from the point of view of the client (indicating that some requests
>> are routed to nodes that are temporarily inaccessible)?
>>
>> With respect to GC, I would recommend running with -XX:+PrintGC and
>> -XX:PrintGCDetails and -XX:+PrintGCTimeStamps and
>> -XX:+PrintGCDateStamps and then look at the system log. A fallback to
>> full GC should be findable by grepping for "Full".
>>
>> Also, is this a problem with one specific host, or is it happening to
>> all hosts every now and then? And I mean either the host being flagged
>> as down, or the host that is flagging others as down.
>>
>> As for uncapped heap: Generally a larger heap is not going to make it
>> more likely to fall back to full GC; usually the opposite is true.
>> However, a larger heap can make some of the non-full GC pauses longer,
>> depending. In either case, r unning with the above GC options will
>> give you specific information on GC pauses and should allow you to
>> rule that out (or not).
>>
Re: Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
I'm still having tons of problems with repairs and compactions, where
the nodes
are declared dead in their log files, although they were online at all
times.
This leads to problem behavior, i.e. once again I see that repair fails,
and the cluster
becomes unusable since there is no space to compact, with all the
garbage left.
There are no signs of GC in the logs, I had increased the verbosity.
The first piece of log is from the node #2 (IP address ending in 194)
where a repair was attempted (and ran for a while),
the second after that -- from node #1 (IP address ending in 192)
#2
=======================================================================================================================
INFO [HintedHandoff:1] 2011-12-07 19:00:37,134
HintedHandOffManager.java (line 379) Finished hinted handoff of 0 rows
to endpoint /130.199.185.193
INFO [GossipTasks:1] 2011-12-07 19:00:37,136 Gossiper.java (line 697)
InetAddress /130.199.185.193 is now dead.
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,136 GCInspector.java (line
122) GC for ParNew: 190691 ms for 1 collections, 4752799432 used; max is
8178892800
ERROR [GossipTasks:1] 2011-12-07 19:00:37,136 AntiEntropyService.java
(line 711) Problem during repair session
manual-repair-e6264aa6-bc19-487e-8de1-3b6c1e5c735a, endpoint /130.199.185.
193 died
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,136 StatusLogger.java
(line 50) Pool Name Active Pending Blocked
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,138 StatusLogger.java
(line 65) ReadStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,139 StatusLogger.java
(line 65) RequestResponseStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,140 StatusLogger.java
(line 65) ReadRepairStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,140 StatusLogger.java
(line 65) MutationStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,141 StatusLogger.java
(line 65) ReplicateOnWriteStage 0 0 0
INFO [GossipStage:1] 2011-12-07 19:00:37,141 Gossiper.java (line 683)
InetAddress /130.199.185.193 is now UP
INFO [GossipStage:1] 2011-12-07 19:00:37,142 Gossiper.java (line 683)
InetAddress /130.199.185.195 is now UP
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,142 StatusLogger.java
(line 65) GossipStage 1 335 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,142 StatusLogger.java
(line 65) AntiEntropyStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,143 StatusLogger.java
(line 65) MigrationStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,143 StatusLogger.java
(line 65) StreamStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,143 StatusLogger.java
(line 65) MemtablePostFlusher 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,143 StatusLogger.java
(line 65) FlushWriter 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,144 StatusLogger.java
(line 65) MiscStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,144 StatusLogger.java
(line 65) FlushSorter 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,144 StatusLogger.java
(line 65) InternalResponseStage 0 0 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,144 StatusLogger.java
(line 65) AntiEntropySessions 1 1 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,145 StatusLogger.java
(line 65) HintedHandoff 1 2 0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,145 StatusLogger.java
(line 69) CompactionManager n/a 3
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,145 StatusLogger.java
(line 81) MessagingService n/a 0,0
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,145 StatusLogger.java
(line 85) ColumnFamily Memtable ops,data Row cache
size/cap Key cache size/cap
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,145 StatusLogger.java
(line 88) system.NodeIdInfo 0,0
0/0 0/1
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,146 StatusLogger.java
(line 88) system.IndexInfo 0,0
0/0 2/2
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,146 StatusLogger.java
(line 88) system.LocationInfo 0,0
0/0 1/1
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,146 StatusLogger.java
(line 88) system.Migrations 0,0
0/0 2/2
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,146 StatusLogger.java
(line 88) system.HintsColumnFamily 0,0
0/0 2/2
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,146 StatusLogger.java
(line 88) system.Schema 0,0
0/0 2/2
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,147 StatusLogger.java
(line 88) PANDA.indexRegistry 8,0
0/0 0/200000
INFO [ScheduledTasks:1] 2011-12-07 19:00:37,147 StatusLogger.java
(line 88) PANDA.jobs 0,0
0/0 200000/200000
ERROR [AntiEntropySessions:5] 2011-12-07 19:00:37,155
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[AntiEntropySessions:5,5,RMI Runtime]
java.lang.RuntimeException: java.io.IOException: Problem during repair
session manual-repair-e6264aa6-bc19-487e-8de1-3b6c1e5c735a, endpoint
/130.199.185.193 died
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.io.IOException: Problem during repair session
manual-repair-e6264aa6-bc19-487e-8de1-3b6c1e5c735a, endpoint
/130.199.185.193 died
at
org.apache.cassandra.service.AntiEntropyService$RepairSession.failedNode(AntiEntropyService.java:712)
at
org.apache.cassandra.service.AntiEntropyService$RepairSession.convict(AntiEntropyService.java:749)
at
org.apache.cassandra.gms.FailureDetector.interpret(FailureDetector.java:155)
at
org.apache.cassandra.gms.Gossiper.doStatusCheck(Gossiper.java:527)
at org.apache.cassandra.gms.Gossiper.access$700(Gossiper.java:57)
#1
=================================================================================================================================================
INFO [FlushWriter:5] 2011-12-07 17:36:34,694 Memtable.java (line 254)
Completed flushing
/data/cassandra_data/data/PANDA/jobs.date-g-5836-Data.db (75743 bytes)
INFO [Thread-13] 2011-12-07 17:36:34,695 ColumnFamilyStore.java (line
390) Index build of 12+DATE,47+12+DATE,60,71+2+12,71+DATE,DATE, complete
INFO [Thread-13] 2011-12-07 17:36:34,695 StreamInSession.java (line
167) Finished streaming session 8671541101513055 from /130.199.185.194
INFO [GossipTasks:1] 2011-12-07 18:54:36,874 Gossiper.java (line 697)
InetAddress /130.199.185.194 is now dead.
INFO [GossipStage:1] 2011-12-07 18:54:39,800 Gossiper.java (line 683)
InetAddress /130.199.185.194 is now UP
INFO [HintedHandoff:1] 2011-12-07 18:55:29,858
HintedHandOffManager.java (line 323) Started hinted handoff for endpoint
/130.199.185.194
INFO [HintedHandoff:1] 2011-12-07 18:55:29,860
HintedHandOffManager.java (line 379) Finished hinted handoff of 0 rows
to endpoint /130.199.185.194
INFO [GossipTasks:1] 2011-12-07 18:55:37,886 Gossiper.java (line 697)
InetAddress /130.199.185.194 is now dead.
INFO [GossipStage:1] 2011-12-07 18:56:02,038 Gossiper.java (line 683)
InetAddress /130.199.185.194 is now UP
INFO [HintedHandoff:1] 2011-12-07 18:56:14,026
HintedHandOffManager.java (line 323) Started hinted handoff for endpoint
/130.199.185.194
INFO [HintedHandoff:1] 2011-12-07 18:56:14,027
HintedHandOffManager.java (line 379) Finished hinted handoff of 0 rows
to endpoint /130.199.185.194
INFO [GossipTasks:1] 2011-12-07 18:57:01,899 Gossiper.java (line 697)
InetAddress /130.199.185.194 is now dead.
INFO [GossipStage:1] 2011-12-07 18:57:24,648 Gossiper.java (line 683)
InetAddress /130.199.185.194 is now UP
INFO [GossipTasks:1] 2011-12-07 18:57:58,907 Gossiper.java (line 697)
InetAddress /130.199.185.194 is now dead.
INFO [HintedHandoff:1] 2011-12-07 18:58:16,741
HintedHandOffManager.java (line 314) Endpoint /130.199.185.194 died
before hint delivery, aborting
INFO [GossipStage:1] 2011-12-07 19:00:37,136 Gossiper.java (line 683)
InetAddress /130.199.185.194 is now UP
INFO [HintedHandoff:1] 2011-12-07 19:01:13,000
HintedHandOffManager.java (line 323) Started hinted handoff for endpoint
/130.199.185.194
INFO [HintedHandoff:1] 2011-12-07 19:01:13,001
HintedHandOffManager.java (line 379) Finished hinted handoff of 0 rows
to endpoint /130.199.185.194
On 12/4/2011 7:17 PM, Peter Schuller wrote:
>> As a side effect of the failed repair (so it seems) the disk usage on the
>> affected node prevents compaction from working. It still works on
>> the remaining nodes (we have 3 total).
>> Is there a way to scrub the extraneous data?
> This is one of the reasons why killing an in-process repair is a bad thing :(
>
> If you do not have enough disk space for any kind of compaction to
> work, then no, unfortunately there is no easy way to get rid of the
> data.
>
> You can go to extra trouble such as moving the entire node to some
> other machine (e.g. firewalled from the cluster) with more disk and
> run compaction there and then "move it back", but that is kind of
> painful to do. Another option is to decommission the node and replace
> it. However, be aware that (1) that leaves the ring with less capacity
> for a while, and (2) when you decommission, the data you stream from
> that node to others would be artificially inflated due to the repair
> so there is some risk of "infecting" the other nodes with a large data
> set.
>
> I should mention that if you have no traffic running against the
> cluster, one way is to just remove all the data and then run repair
> afterwards. But that implies that you're trusting that (1) no reads
> are going to the cluster (else you might serve reads based on missing
> data) and (2) that you are comfortable with loss of the data on the
> node. (2) might be okay if you're e.g. writing at QUORUM at all times
> and have RF>= 3 (basically, this is as if the node would have been
> lost due to hardware breakage).
>
> A faster way to reconstruct the node would be to delete the data from
> your keyspaces (except the system keyspace), start the node (now
> missing data), and run 'nodetool rebuild' after
> https://issues.apache.org/jira/browse/CASSANDRA-3483 is done. The
> patch attached to that ticket should work for 0.8.6 I suspect (but no
> guarantees). This also assumes you have no reads running against the
> cluster.
>
Re: Could not reach schema agreement... 0.8.6
Posted by Jonathan Ellis <jb...@gmail.com>.
http://wiki.apache.org/cassandra/FAQ#schema_disagreement
On Mon, Dec 5, 2011 at 7:03 PM, Maxim Potekhin <po...@bnl.gov> wrote:
> Hello,
>
> upon startup, in my cluster of 3 machines, I see similar messages in
> system.log
> on each node (below). I start nodes one by one, after I ascertain the
> previous one
> is online. So they can't reach schema agreement, all of them. Why? No
> unusual
> load visible in Ganglia plots.
>
> ERROR [HintedHandoff:1] 2011-12-05 19:52:17,426 AbstractCassandraDaemon.java
> (line 139) Fatal exception in thread Thread[Hint
> edHandoff:1,1,main]
> java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
> schema agreement with /130.199.185.194 in 60000ms
> at
> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:662)
>
--
Jonathan Ellis
Project Chair, Apache Cassandra
co-founder of DataStax, the source for professional Cassandra support
http://www.datastax.com
forceUserDefinedCompaction -- how to use it?
Posted by Maxim Potekhin <po...@bnl.gov>.
Can anyone provide an example of how to use forceUserDefinedCompaction?
Thanks
Maxim
Could not reach schema agreement... 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
Hello,
upon startup, in my cluster of 3 machines, I see similar messages in
system.log
on each node (below). I start nodes one by one, after I ascertain the
previous one
is online. So they can't reach schema agreement, all of them. Why? No
unusual
load visible in Ganglia plots.
ERROR [HintedHandoff:1] 2011-12-05 19:52:17,426
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[Hint
edHandoff:1,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.194 in 60000ms
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Re: Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
Basically I tweaked the phi, put in more verbose GC reporting and
decided to do a compaction before I proceed. I'm getting this on the
node where compaction is being run. And the system log for the other two
nodes follows. It's obvious that the cluster is sick, but I
can't determine why -- there are no overwhelming GC evidence as far as I
can see. I didn't start compaction on node #3, somehow
it attempts to do it anyhow.
===============================================
Node #2 (compaction is being run):
INFO [CompactionExecutor:2] 2011-12-05 14:19:36,741
CompactionManager.java (line 608) Compacted to
/data/cassandra_data/data/system/LocationInfo-tmp-g-72-Data.db. 967 to
561 (~58% of
original) bytes for 4 keys. Time: 71ms.
INFO [main] 2011-12-05 14:19:36,941 Mx4jTool.java (line 67) mx4j
successfuly loaded
INFO [GossipStage:1] 2011-12-05 14:19:36,943 Gossiper.java (line 715)
Node /130.199.185.193 has restarted, now UP again
INFO [GossipStage:1] 2011-12-05 14:19:36,943 Gossiper.java (line 683)
InetAddress /130.199.185.193 is now UP
INFO [GossipStage:1] 2011-12-05 14:19:36,971 StorageService.java (line
819) Node /130.199.185.193 state jump to normal
INFO [GossipStage:1] 2011-12-05 14:19:36,971 Gossiper.java (line 715)
Node /130.199.185.195 has restarted, now UP again
INFO [GossipStage:1] 2011-12-05 14:19:36,971 Gossiper.java (line 683)
InetAddress /130.199.185.195 is now UP
INFO [GossipStage:1] 2011-12-05 14:19:36,974 StorageService.java (line
819) Node /130.199.185.195 state jump to normal
INFO [main] 2011-12-05 14:19:37,003 CassandraDaemon.java (line 115)
Binding thrift service to cassandra02.usatlas.bnl.gov/130.199.185.194:9160
INFO [main] 2011-12-05 14:19:37,016 CassandraDaemon.java (line 124)
Using TFastFramedTransport with a max frame size of 15728640 bytes.
INFO [main] 2011-12-05 14:19:37,018 CassandraDaemon.java (line 151)
Using synchronous/threadpool thrift server on
cassandra02.usatlas.bnl.gov/130.199.185.194 : 9160
INFO [Thread-6] 2011-12-05 14:19:37,019 CassandraDaemon.java (line
203) Listening for thrift clients...
INFO [GossipTasks:1] 2011-12-05 14:19:50,601 Gossiper.java (line 697)
InetAddress /130.199.185.195 is now dead.
ERROR [HintedHandoff:1] 2011-12-05 14:20:37,954
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.193 in 60000ms
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: Could not reach schema agreement
with /130.199.185.193 in 60000ms
at
org.apache.cassandra.db.HintedHandOffManager.waitForSchemaAgreement(HintedHandOffManager.java:293)
at
org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:304)
at
org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffManager.java:89)
at
org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandOffManager.java:397)
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
... 3 more
ERROR [HintedHandoff:1] 2011-12-05 14:20:37,956
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.193 in 60000ms
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: Could not reach schema agreement
with /130.199.185.193 in 60000ms
at
org.apache.cassandra.db.HintedHandOffManager.waitForSchemaAgreement(HintedHandOffManager.java:293)
at
org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:304)
at
org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffManager.java:89)
at
org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandOffManager.java:397)
=====================================================================
Node #1 (nothing run)
INFO [main] 2011-12-05 14:16:15,779 CassandraDaemon.java (line 115)
Binding thrift service to cassandra01.usatlas.bnl.gov/130.199.185.193:9160
INFO [main] 2011-12-05 14:16:15,782 CassandraDaemon.java (line 124)
Using TFastFramedTransport with a max frame size of 15728640 bytes.
INFO [main] 2011-12-05 14:16:15,784 CassandraDaemon.java (line 151)
Using synchronous/threadpool thrift server on
cassandra01.usatlas.bnl.gov/130.199.185.193 : 9160
INFO [Thread-5] 2011-12-05 14:16:15,785 CassandraDaemon.java (line
203) Listening for thrift clients...
INFO [HintedHandoff:1] 2011-12-05 14:16:50,578
HintedHandOffManager.java (line 323) Started hinted handoff for endpoint
/130.199.185.195
INFO [ScheduledTasks:1] 2011-12-05 14:16:53,220 GCInspector.java (line
122) GC for ParNew: 284 ms for 1 collections, 1434456744 used; max is
8178892800
INFO [HintedHandoff:1] 2011-12-05 14:16:56,166
HintedHandOffManager.java (line 379) Finished hinted handoff of 0 rows
to endpoint /130.199.185.195
INFO [GossipTasks:1] 2011-12-05 14:17:19,310 Gossiper.java (line 697)
InetAddress /130.199.185.194 is now dead.
INFO [GossipTasks:1] 2011-12-05 14:17:50,326 Gossiper.java (line 697)
InetAddress /130.199.185.195 is now dead.
ERROR [HintedHandoff:1] 2011-12-05 14:17:57,173
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.194 in 60000ms
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: Could not reach schema agreement
with /130.199.185.194 in 60000ms
at
org.apache.cassandra.db.HintedHandOffManager.waitForSchemaAgreement(HintedHandOffManager.java:293)
at
org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:304)
at
org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffManager.java:89)
at
org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandOffManager.java:397)
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
... 3 more
ERROR [HintedHandoff:1] 2011-12-05 14:17:57,175
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.194 in 60000ms
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: Could not reach schema agreement
with /130.199.185.194 in 60000ms
at
org.apache.cassandra.db.HintedHandOffManager.waitForSchemaAgreement(HintedHandOffManager.java:293)
at
org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:304)
at
org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffManager.java:89)
at
org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandOffManager.java:397)
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
... 3 more
INFO [GossipStage:1] 2011-12-05 14:19:36,938 Gossiper.java (line 715)
Node /130.199.185.194 has restarted, now UP again
INFO [GossipStage:1] 2011-12-05 14:19:36,938 Gossiper.java (line 683)
InetAddress /130.199.185.194 is now UP
INFO [GossipStage:1] 2011-12-05 14:19:36,939 StorageService.java (line
819) Node /130.199.185.194 state jump to normal
ERROR [HintedHandoff:2] 2011-12-05 14:20:37,944
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[HintedHandoff:2,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.194 in 60000ms
========================================================================================
Node #3 (nothing run):
INFO [GossipStage:1] 2011-12-05 14:23:17,762 StorageService.java (line
819) Node /130.199.185.193 state jump to normal
INFO [GossipStage:1] 2011-12-05 14:23:17,762 Gossiper.java (line 715)
Node /130.199.185.194 has restarted, now UP again
INFO [GossipStage:1] 2011-12-05 14:23:17,763 Gossiper.java (line 683)
InetAddress /130.199.185.194 is now UP
INFO [GossipStage:1] 2011-12-05 14:23:18,045 StorageService.java (line
819) Node /130.199.185.194 state jump to normal
INFO [CompactionExecutor:2] 2011-12-05 14:23:18,055
CompactionManager.java (line 608) Compacted to
/data/cassandra_data/data/system/LocationInfo-tmp-g-32-Data.db. 967 to
561 (~58% of origina
l) bytes for 4 keys. Time: 323ms.
INFO [main] 2011-12-05 14:23:18,074 CassandraDaemon.java (line 115)
Binding thrift service to cassandra03.usatlas.bnl.gov/130.199.185.195:9160
INFO [main] 2011-12-05 14:23:18,077 CassandraDaemon.java (line 124)
Using TFastFramedTransport with a max frame size of 15728640 bytes.
INFO [main] 2011-12-05 14:23:18,080 CassandraDaemon.java (line 151)
Using synchronous/threadpool thrift server on
cassandra03.usatlas.bnl.gov/130.199.185.195 : 9160
INFO [Thread-6] 2011-12-05 14:23:18,080 CassandraDaemon.java (line
203) Listening for thrift clients...
INFO [HintedHandoff:1] 2011-12-05 14:23:24,535
HintedHandOffManager.java (line 323) Started hinted handoff for endpoint
/130.199.185.193
INFO [HintedHandoff:1] 2011-12-05 14:23:24,537
HintedHandOffManager.java (line 379) Finished hinted handoff of 0 rows
to endpoint /130.199.185.193
ERROR [HintedHandoff:1] 2011-12-05 14:24:25,553
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.194 in 60000ms
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: Could not reach schema agreement
with /130.199.185.194 in 60000ms
at
org.apache.cassandra.db.HintedHandOffManager.waitForSchemaAgreement(HintedHandOffManager.java:293)
at
org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:304)
at
org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffManager.java:89)
at
org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandOffManager.java:397)
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
... 3 more
ERROR [HintedHandoff:1] 2011-12-05 14:24:25,555
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.lang.RuntimeException: Could not reach
schema agreement with /130.199.185.194 in 60000ms
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: Could not reach schema agreement
with /130.199.185.194 in 60000ms
at
org.apache.cassandra.db.HintedHandOffManager.waitForSchemaAgreement(HintedHandOffManager.java:293)
at
org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:304)
at
org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffManager.java:89)
at
org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandOffManager.java:397)
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
... 3 more
INFO [CompactionExecutor:5] 2011-12-05 14:27:11,220
CompactionManager.java (line 494) Nothing to compact in IndexInfo; use
forceUserDefinedCompaction if you wish to force compaction of single
sstables (e.g. for tombstone collection)
INFO [CompactionExecutor:6] 2011-12-05 14:27:11,221
CompactionManager.java (line 494) Nothing to compact in LocationInfo;
use forceUserDefinedCompaction if you wish to force compaction of sin
gle sstables (e.g. for tombstone collection)
INFO [CompactionExecutor:7] 2011-12-05 14:27:11,222
CompactionManager.java (line 542) Compacting Major:
[SSTableReader(path='/data/cassandra_data/data/system/Migrations-g-72-Data.db'),
SSTabl
eReader(path='/data/cassandra_data/data/system/Migrations-g-71-Data.db')]
INFO [CompactionExecutor:7] 2011-12-05 14:27:11,258
CompactionManager.java (line 608) Compacted to
/data/cassandra_data/data/system/Migrations-tmp-g-73-Data.db. 398,726
to 398,662 (~99% of o
riginal) bytes for 1 keys. Time: 36ms.
INFO [CompactionExecutor:10] 2011-12-05 14:27:11,260
CompactionManager.java (line 542) Compacting Major:
[SSTableReader(path='/data/cassandra_data/data/system/Schema-g-72-Data.db'),
SSTableRe
ader(path='/data/cassandra_data/data/system/Schema-g-71-Data.db')]
INFO [CompactionExecutor:10] 2011-12-05 14:27:11,291
CompactionManager.java (line 608) Compacted to
/data/cassandra_data/data/system/Schema-tmp-g-73-Data.db. 175,627 to
175,518 (~99% of orig
inal) bytes for 54 keys. Time: 30ms.
INFO [CompactionExecutor:12] 2011-12-05 14:27:11,293
CompactionManager.java (line 494) Nothing to compact in indexRegistry;
use forceUserDefinedCompaction if you wish to force compaction of s
ingle sstables (e.g. for tombstone collection)
INFO [CompactionExecutor:13] 2011-12-05 14:27:11,295
StorageService.java (line 2228) requesting GC to free disk space
WARN [CompactionExecutor:13] 2011-12-05 14:27:34,920
CompactionManager.java (line 509) insufficient space to compact all
requested files SSTableReader(path='/data/cassandra_data/data/PANDA/jo
bs-g-54-Data.db'),
SSTableReader(path='/data/cassandra_data/data/PANDA/jobs-g-55-Data.db')
ERROR [CompactionExecutor:13] 2011-12-05 14:27:34,920
CompactionManager.java (line 513) insufficient space to compact even the
two smallest files, aborting
On 12/4/2011 7:17 PM, Peter Schuller wrote:
>> As a side effect of the failed repair (so it seems) the disk usage on the
>> affected node prevents compaction from working. It still works on
>> the remaining nodes (we have 3 total).
>> Is there a way to scrub the extraneous data?
> This is one of the reasons why killing an in-process repair is a bad thing :(
>
> If you do not have enough disk space for any kind of compaction to
> work, then no, unfortunately there is no easy way to get rid of the
> data.
>
> You can go to extra trouble such as moving the entire node to some
> other machine (e.g. firewalled from the cluster) with more disk and
> run compaction there and then "move it back", but that is kind of
> painful to do. Another option is to decommission the node and replace
> it. However, be aware that (1) that leaves the ring with less capacity
> for a while, and (2) when you decommission, the data you stream from
> that node to others would be artificially inflated due to the repair
> so there is some risk of "infecting" the other nodes with a large data
> set.
>
> I should mention that if you have no traffic running against the
> cluster, one way is to just remove all the data and then run repair
> afterwards. But that implies that you're trusting that (1) no reads
> are going to the cluster (else you might serve reads based on missing
> data) and (2) that you are comfortable with loss of the data on the
> node. (2) might be okay if you're e.g. writing at QUORUM at all times
> and have RF>= 3 (basically, this is as if the node would have been
> lost due to hardware breakage).
>
> A faster way to reconstruct the node would be to delete the data from
> your keyspaces (except the system keyspace), start the node (now
> missing data), and run 'nodetool rebuild' after
> https://issues.apache.org/jira/browse/CASSANDRA-3483 is done. The
> patch attached to that ticket should work for 0.8.6 I suspect (but no
> guarantees). This also assumes you have no reads running against the
> cluster.
>
Re: Repair failure under 0.8.6
Posted by Edward Capriolo <ed...@gmail.com>.
You can say the min compaction threshold to 2 and the max Compaction
Threshold to 3. If you have enough disk space for a few minor compaction
this should free up some disk space.
On Sun, Dec 4, 2011 at 7:17 PM, Peter Schuller
<pe...@infidyne.com>wrote:
> > As a side effect of the failed repair (so it seems) the disk usage on the
> > affected node prevents compaction from working. It still works on
> > the remaining nodes (we have 3 total).
> > Is there a way to scrub the extraneous data?
>
> This is one of the reasons why killing an in-process repair is a bad thing
> :(
>
> If you do not have enough disk space for any kind of compaction to
> work, then no, unfortunately there is no easy way to get rid of the
> data.
>
> You can go to extra trouble such as moving the entire node to some
> other machine (e.g. firewalled from the cluster) with more disk and
> run compaction there and then "move it back", but that is kind of
> painful to do. Another option is to decommission the node and replace
> it. However, be aware that (1) that leaves the ring with less capacity
> for a while, and (2) when you decommission, the data you stream from
> that node to others would be artificially inflated due to the repair
> so there is some risk of "infecting" the other nodes with a large data
> set.
>
> I should mention that if you have no traffic running against the
> cluster, one way is to just remove all the data and then run repair
> afterwards. But that implies that you're trusting that (1) no reads
> are going to the cluster (else you might serve reads based on missing
> data) and (2) that you are comfortable with loss of the data on the
> node. (2) might be okay if you're e.g. writing at QUORUM at all times
> and have RF >= 3 (basically, this is as if the node would have been
> lost due to hardware breakage).
>
> A faster way to reconstruct the node would be to delete the data from
> your keyspaces (except the system keyspace), start the node (now
> missing data), and run 'nodetool rebuild' after
> https://issues.apache.org/jira/browse/CASSANDRA-3483 is done. The
> patch attached to that ticket should work for 0.8.6 I suspect (but no
> guarantees). This also assumes you have no reads running against the
> cluster.
>
> --
> / Peter Schuller (@scode, http://worldmodscode.wordpress.com)
>
Re: Repair failure under 0.8.6
Posted by Peter Schuller <pe...@infidyne.com>.
> As a side effect of the failed repair (so it seems) the disk usage on the
> affected node prevents compaction from working. It still works on
> the remaining nodes (we have 3 total).
> Is there a way to scrub the extraneous data?
This is one of the reasons why killing an in-process repair is a bad thing :(
If you do not have enough disk space for any kind of compaction to
work, then no, unfortunately there is no easy way to get rid of the
data.
You can go to extra trouble such as moving the entire node to some
other machine (e.g. firewalled from the cluster) with more disk and
run compaction there and then "move it back", but that is kind of
painful to do. Another option is to decommission the node and replace
it. However, be aware that (1) that leaves the ring with less capacity
for a while, and (2) when you decommission, the data you stream from
that node to others would be artificially inflated due to the repair
so there is some risk of "infecting" the other nodes with a large data
set.
I should mention that if you have no traffic running against the
cluster, one way is to just remove all the data and then run repair
afterwards. But that implies that you're trusting that (1) no reads
are going to the cluster (else you might serve reads based on missing
data) and (2) that you are comfortable with loss of the data on the
node. (2) might be okay if you're e.g. writing at QUORUM at all times
and have RF >= 3 (basically, this is as if the node would have been
lost due to hardware breakage).
A faster way to reconstruct the node would be to delete the data from
your keyspaces (except the system keyspace), start the node (now
missing data), and run 'nodetool rebuild' after
https://issues.apache.org/jira/browse/CASSANDRA-3483 is done. The
patch attached to that ticket should work for 0.8.6 I suspect (but no
guarantees). This also assumes you have no reads running against the
cluster.
--
/ Peter Schuller (@scode, http://worldmodscode.wordpress.com)
Re: Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
As a side effect of the failed repair (so it seems) the disk usage on the
affected node prevents compaction from working. It still works on
the remaining nodes (we have 3 total).
Is there a way to scrub the extraneous data?
Thanks
Maxim
On 12/4/2011 4:29 PM, Peter Schuller wrote:
>> I will try to increase phi_convict -- I will just need to restart the
>> cluster after
>> the edit, right?
> You will need to restart the nodes for which you want the phi convict
> threshold to be different. You might want to do on e.g. half of the
> cluster to do A/B testing.
>
>> I do recall that I see nodes temporarily marked as down, only to pop up
>> later.
> I recommend grepping through the logs on all the clusters (e.g., cat
> /var/log/cassandra/cassandra.log | grep UP | wc -l). That should tell
> you quickly whether they all seem to be seeing roughly as many node
> flaps, or whether some particular node or set of nodes is/are
> over-represented.
>
> Next, look at the actual nodes flapping (remove wc -l) and see if all
> nodes are flapping or if it is a single node, or a subset of the nodes
> (e.g., sharing a switch perhaps).
>
>> In the current situation, there is no load on the cluster at all, outside
>> the
>> maintenance like the repair.
> Ok. So what i'm getting at then is that there may be real legitimate
> connectivity problems that you aren't noticing in any other way since
> you don't have active traffic to the cluster.
>
>
Re: Repair failure under 0.8.6
Posted by Peter Schuller <pe...@infidyne.com>.
> I will try to increase phi_convict -- I will just need to restart the
> cluster after
> the edit, right?
You will need to restart the nodes for which you want the phi convict
threshold to be different. You might want to do on e.g. half of the
cluster to do A/B testing.
> I do recall that I see nodes temporarily marked as down, only to pop up
> later.
I recommend grepping through the logs on all the clusters (e.g., cat
/var/log/cassandra/cassandra.log | grep UP | wc -l). That should tell
you quickly whether they all seem to be seeing roughly as many node
flaps, or whether some particular node or set of nodes is/are
over-represented.
Next, look at the actual nodes flapping (remove wc -l) and see if all
nodes are flapping or if it is a single node, or a subset of the nodes
(e.g., sharing a switch perhaps).
> In the current situation, there is no load on the cluster at all, outside
> the
> maintenance like the repair.
Ok. So what i'm getting at then is that there may be real legitimate
connectivity problems that you aren't noticing in any other way since
you don't have active traffic to the cluster.
--
/ Peter Schuller (@scode, http://worldmodscode.wordpress.com)
Re: Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
Thanks Peter!
I will try to increase phi_convict -- I will just need to restart the
cluster after
the edit, right?
I do recall that I see nodes temporarily marked as down, only to pop up
later.
In the current situation, there is no load on the cluster at all,
outside the
maintenance like the repair.
How do I configure the print level for the GC report?
Thank you,
Maxim
On 12/4/2011 2:09 PM, Peter Schuller wrote:
>> I capped heap and the error is still there. So I keep seeing "node dead"
>> messages even when I know the nodes were OK. Where and how do I tweak
>> timeouts?
> You can increase phi_convict_threshold in the configuration. However,
> I would rather want to find out why they are being marked as down to
> begin with. In a healthy situation, especially if you are not putting
> extreme load on the cluster, there is very little reason for hosts to
> be marked as down unless there's some bug somewhere.
>
> Is this cluster under constant traffic? Are you seeing slow requests
> from the point of view of the client (indicating that some requests
> are routed to nodes that are temporarily inaccessible)?
>
> With respect to GC, I would recommend running with -XX:+PrintGC and
> -XX:PrintGCDetails and -XX:+PrintGCTimeStamps and
> -XX:+PrintGCDateStamps and then look at the system log. A fallback to
> full GC should be findable by grepping for "Full".
>
> Also, is this a problem with one specific host, or is it happening to
> all hosts every now and then? And I mean either the host being flagged
> as down, or the host that is flagging others as down.
>
> As for uncapped heap: Generally a larger heap is not going to make it
> more likely to fall back to full GC; usually the opposite is true.
> However, a larger heap can make some of the non-full GC pauses longer,
> depending. In either case, r unning with the above GC options will
> give you specific information on GC pauses and should allow you to
> rule that out (or not).
>
Re: Repair failure under 0.8.6
Posted by Peter Schuller <pe...@infidyne.com>.
> I capped heap and the error is still there. So I keep seeing "node dead"
> messages even when I know the nodes were OK. Where and how do I tweak
> timeouts?
You can increase phi_convict_threshold in the configuration. However,
I would rather want to find out why they are being marked as down to
begin with. In a healthy situation, especially if you are not putting
extreme load on the cluster, there is very little reason for hosts to
be marked as down unless there's some bug somewhere.
Is this cluster under constant traffic? Are you seeing slow requests
from the point of view of the client (indicating that some requests
are routed to nodes that are temporarily inaccessible)?
With respect to GC, I would recommend running with -XX:+PrintGC and
-XX:PrintGCDetails and -XX:+PrintGCTimeStamps and
-XX:+PrintGCDateStamps and then look at the system log. A fallback to
full GC should be findable by grepping for "Full".
Also, is this a problem with one specific host, or is it happening to
all hosts every now and then? And I mean either the host being flagged
as down, or the host that is flagging others as down.
As for uncapped heap: Generally a larger heap is not going to make it
more likely to fall back to full GC; usually the opposite is true.
However, a larger heap can make some of the non-full GC pauses longer,
depending. In either case, r unning with the above GC options will
give you specific information on GC pauses and should allow you to
rule that out (or not).
--
/ Peter Schuller (@scode, http://worldmodscode.wordpress.com)
Re: Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
I capped heap and the error is still there. So I keep seeing "node dead"
messages even when I know the nodes were OK. Where and how do I tweak
timeouts?
9d-cfc9-4cbc-9f1d-1467341388b8, endpoint /130.199.185.193 died
INFO [GossipStage:1] 2011-12-04 00:26:16,362 Gossiper.java (line 683)
InetAddress /130.199.185.193 is now UP
ERROR [AntiEntropySessions:1] 2011-12-04 00:26:16,518
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[Anti\
EntropySessions:1,5,RMI Runtime]
java.lang.RuntimeException: java.io.IOException: Problem during repair
session manual-repair-a6a655dc-63f0-4c1c-9c0b-0621f5692ba2, \
endpoint /130.199.185.194 died
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.io.IOException: Problem during repair session
manual-repair-a6a655dc-63f0-4c1c-9c0b-0621f5692ba2, endpoint /130.199\
.185.194 died
at
org.apache.cassandra.service.AntiEntropyService$RepairSession.failedNode(AntiEntropyService.java:712)
at
org.apache.cassandra.service.AntiEntropyService$RepairSession.convict(AntiEntropyService.java:749)
at
org.apache.cassandra.gms.FailureDetector.interpret(FailureDetector.java:155)
at
org.apache.cassandra.gms.Gossiper.doStatusCheck(Gossiper.java:527)
at org.apache.cassandra.gms.Gossiper.access$700(Gossiper.java:57)
at
org.apache.cassandra.gms.Gossiper$GossipTask.run(Gossiper.java:157)
On 12/3/2011 8:34 PM, Maxim Potekhin wrote:
> Thank you Peter. Before I look into details as you suggest,
> may I ask what you mean "automatically restarted"? They way
> the box and Cassandra are set up in my case is such that the
> death of either if final.
>
> Also, how do I look for full GC? I just realized that in the latest
> install, I might have omitted capping the heap size -- and the
> nodes have 48GB each. I guess this could be a problem, precipitating
> GC death, right?
>
> Thank you
>
> Maxim
>
>
> On 12/3/2011 7:46 PM, Peter Schuller wrote:
>>> quite understand how Cassandra declared a node dead (in the below).
>>> Was is a
>>> timeout? How do I fix that?
>> I was about to respond to say that repair doesn't fail just due to
>> failure detection, but this appears to have been broken by
>> CASSANDRA-2433 :(
>>
>> Unless there is a subtle bug the exception you're seeing should be
>> indicative that it really was considered Down by the node. You might
>> grep the log for references ot the node in question (UP or DOWN) to
>> confirm. The question is why though. I would check if the node has
>> maybe automatically restarted, or went into full GC, etc.
>>
Re: Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
Thank you Peter. Before I look into details as you suggest,
may I ask what you mean "automatically restarted"? They way
the box and Cassandra are set up in my case is such that the
death of either if final.
Also, how do I look for full GC? I just realized that in the latest
install, I might have omitted capping the heap size -- and the
nodes have 48GB each. I guess this could be a problem, precipitating
GC death, right?
Thank you
Maxim
On 12/3/2011 7:46 PM, Peter Schuller wrote:
>> quite understand how Cassandra declared a node dead (in the below). Was is a
>> timeout? How do I fix that?
> I was about to respond to say that repair doesn't fail just due to
> failure detection, but this appears to have been broken by
> CASSANDRA-2433 :(
>
> Unless there is a subtle bug the exception you're seeing should be
> indicative that it really was considered Down by the node. You might
> grep the log for references ot the node in question (UP or DOWN) to
> confirm. The question is why though. I would check if the node has
> maybe automatically restarted, or went into full GC, etc.
>
Re: Repair failure under 0.8.6
Posted by Peter Schuller <pe...@infidyne.com>.
> quite understand how Cassandra declared a node dead (in the below). Was is a
> timeout? How do I fix that?
I was about to respond to say that repair doesn't fail just due to
failure detection, but this appears to have been broken by
CASSANDRA-2433 :(
Unless there is a subtle bug the exception you're seeing should be
indicative that it really was considered Down by the node. You might
grep the log for references ot the node in question (UP or DOWN) to
confirm. The question is why though. I would check if the node has
maybe automatically restarted, or went into full GC, etc.
--
/ Peter Schuller (@scode, http://worldmodscode.wordpress.com)
Repair failure under 0.8.6
Posted by Maxim Potekhin <po...@bnl.gov>.
Please help -- I've been having pretty consistent failures that look
like this one. Don't know how to proceed.
Below text comes from the system log. The cluster was all up before and
after the attempted repair, so I don't
quite understand how Cassandra declared a node dead (in the below). Was
is a timeout? How do I fix that?
Thanks,
Maxim
INFO [GossipStage:1] 2011-12-02 17:12:07,293 Gossiper.java (line 683)
InetAddress /130.199.185.194 is now UP
ERROR [AntiEntropySessions:1] 2011-12-02 17:12:07,354
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[AntiEntropySessions:1,5,RMI Runtime]
java.lang.RuntimeException: java.io.IOException: Problem during repair
session manual-repair-618fad49-387f-44df-a25e-aa57b314768a, endpoint
/130.199.185.194 died
at
org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.io.IOException: Problem during repair session
manual-repair-618fad49-387f-44df-a25e-aa57b314768a, endpoint
/130.199.185.194 died
at
org.apache.cassandra.service.AntiEntropyService$RepairSession.failedNode(AntiEntropyService.java:712)
at
org.apache.cassandra.service.AntiEntropyService$RepairSession.convict(AntiEntropyService.java:749)
at
org.apache.cassandra.gms.FailureDetector.interpret(FailureDetector.java:155)
at
org.apache.cassandra.gms.Gossiper.doStatusCheck(Gossiper.java:527)
at org.apache.cassandra.gms.Gossiper.access$700(Gossiper.java:57)
at
org.apache.cassandra.gms.Gossiper$GossipTask.run(Gossiper.java:157)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
... 3 more
INFO [AntiEntropyStage:1] 2011-12-02 17:12:07,392
AntiEntropyService.java (line 215) Sending AEService tree for
#<TreeRequest manual-repair-c721c217-4b70-4a15-91fc-374b39b8b05\
3, cassandra03.usatlas.bnl.gov/130.199.185.195, (PANDA,files),
(56713727820156410577229101238628035242,113427455640312821154458202477256070484]>
Re: Insufficient disk space to flush
Posted by Alexandru Dan Sicoe <si...@googlemail.com>.
Understood. Thanks Edward!
On Sat, Dec 3, 2011 at 6:35 AM, Edward Capriolo <ed...@gmail.com>wrote:
> There is no way to set a max size on an sstable file. If your Cassandra
> data directory is not your / filesystem you could reformat it as ext4 (or
> at least ext3 with better options)
>
>
> On Fri, Dec 2, 2011 at 8:35 AM, Alexandru Dan Sicoe <
> sicoe.alexandru@googlemail.com> wrote:
>
>> Ok, so my problem persisted. On the node that is filling up the harddisk,
>> I have a 230 GB disk. Right after I restart the node I it deletes tmp files
>> and reaches 55GB of data on disk. Then it start to quickly fill up the disk
>> - I see gigs added fast - it's not real data because other nodes don't have
>> this.
>>
>> While all this is happening I am seeing the node do a minor compaction of
>> the main data CF but extremely slowly. Today I saw the error:
>>
>> ERROR 09:44:57,605 Fatal exception in thread
>> Thread[CompactionExecutor:15,1,main]
>>
>> java.io.IOException: File too
>> large
>>
>> at java.io.RandomAccessFile.writeBytes(Native
>> Method)
>>
>> at
>> java.io.RandomAccessFile.write(RandomAccessFile.java:466)
>>
>> at
>> org.apache.cassandra.io.util.BufferedRandomAccessFile.flush(BufferedRandomAccessFile.java:168)
>>
>> at
>> org.apache.cassandra.io.util.BufferedRandomAccessFile.reBuffer(BufferedRandomAccessFile.java:242)
>>
>> at
>> org.apache.cassandra.io.util.BufferedRandomAccessFile.writeAtMost(BufferedRandomAccessFile.java:369)
>>
>> at
>> org.apache.cassandra.io.util.BufferedRandomAccessFile.write(BufferedRandomAccessFile.java:348)
>>
>> at
>> org.apache.cassandra.db.compaction.PrecompactedRow.write(PrecompactedRow.java:114)
>>
>> at
>> org.apache.cassandra.io.sstable.SSTableWriter.append(SSTableWriter.java:132)
>>
>> at
>> org.apache.cassandra.db.compaction.CompactionManager.doCompactionWithoutSizeEstimation(CompactionManager.java:576)
>>
>> at
>> org.apache.cassandra.db.compaction.CompactionManager.doCompaction(CompactionManager.java:507)
>>
>> at
>> org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:142)
>>
>> at
>> org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:108)
>>
>> at
>> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>>
>> at
>> java.util.concurrent.FutureTask.run(FutureTask.java:138)
>>
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>
>> at java.lang.Thread.run(Thread.java:619)
>>
>> which means that it cannot finish that compaction because it hit the max
>> file size. So I checked the file system and block size and I got ext3 and
>> 1K which means that the max file size is 16GB.
>>
>> I didn't know what to do in this case so I just decommisioned the node.
>>
>> Is there a way to get around this max file limit? Is there some Cassandra
>> configuration that helps avoid this? I'm asking here because I couldn't
>> find anything in the documentation about that.
>>
>> I'm waiting for new machines to run Cassandra on....what file systems are
>> people using?
>>
>> Cheers,
>> Alex
>>
>>
>>
>> On Thu, Dec 1, 2011 at 10:08 PM, Jahangir Mohammed <
>> md.jahangir27@gmail.com> wrote:
>>
>>> Yes, mostly sounds like it. In our case failed repairs were causing
>>> accumulation of the tmp files.
>>>
>>> Thanks,
>>> Jahangir Mohammed.
>>>
>>> On Thu, Dec 1, 2011 at 2:43 PM, Alexandru Dan Sicoe <
>>> sicoe.alexandru@googlemail.com> wrote:
>>>
>>>> Hi Jeremiah,
>>>> My commitlog was indeed on another disk. I did what you said and yes
>>>> the node restart brings back the disk size to the around 50 GB I was
>>>> expecting. Still I do not understand how the node managed to get itself in
>>>> the situation of having these tmp files? Could you clarify what these are,
>>>> how they are produced and why? I've tried to find a clear definition but
>>>> all I could come up with is hints that they are produced during compaction.
>>>> I also found a thread that described a similar problem:
>>>>
>>>> http://cassandra-user-incubator-apache-org.3065146.n2.nabble.com/Errors-During-Compaction-td5953493.html
>>>> as described there it seems like compaction fails and tmp files don't
>>>> get cleaned up until they fill the disk. Is this what happened in my case?
>>>> Compactions did not finish properly because the disk utilization was more
>>>> than half and then more and more files tmp started getting accumulated at
>>>> each other attempt. The Cassandra log would indicate this because I get
>>>> many of these:
>>>> ERROR [CompactionExecutor:22850] 2011-12-01 04:12:15,200
>>>> CompactionManager.java (line 513) insufficie
>>>> nt space to compact even the two smallest files, aborting
>>>>
>>>> before I started getting many of these:
>>>> ERROR [FlushWriter:283] 2011-12-01 04:12:22,917
>>>> AbstractCassandraDaemon.java (line 139) Fatal exception in thread
>>>> Thread[FlushWriter:283,5,main] java.lang.RuntimeException:
>>>> java.lang.RuntimeException: Insufficient disk space to flush 42531 bytes
>>>>
>>>> I just want to clearly understand what happened.
>>>>
>>>> Thanks,
>>>> Alex
>>>>
>>>>
>>>> On Thu, Dec 1, 2011 at 6:58 PM, Jeremiah Jordan <
>>>> jeremiah.jordan@morningstar.com> wrote:
>>>>
>>>>> If you are writing data with QUORUM or ALL you should be safe to
>>>>> restart cassandra on that node. If the extra space is all from *tmp* files
>>>>> from compaction they will get deleted at startup. You will then need to
>>>>> run repair on that node to get back any data that was missed while it was
>>>>> full. If your commit log was on a different device you may not even have
>>>>> lost much.
>>>>>
>>>>> -Jeremiah
>>>>>
>>>>>
>>>>> On 12/01/2011 04:16 AM, Alexandru Dan Sicoe wrote:
>>>>>
>>>>> Hello everyone,
>>>>> 4 node Cassandra 0.8.5 cluster with RF =2.
>>>>> One node started throwing exceptions in its log:
>>>>>
>>>>> ERROR 10:02:46,837 Fatal exception in thread
>>>>> Thread[FlushWriter:1317,5,main]
>>>>> java.lang.RuntimeException: java.lang.RuntimeException: Insufficient
>>>>> disk space to flush 17296 bytes
>>>>> at
>>>>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
>>>>> at
>>>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>>>> at
>>>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>>>> at java.lang.Thread.run(Thread.java:619)
>>>>> Caused by: java.lang.RuntimeException: Insufficient disk space to
>>>>> flush 17296 bytes
>>>>> at
>>>>> org.apache.cassandra.db.ColumnFamilyStore.getFlushPath(ColumnFamilyStore.java:714)
>>>>> at
>>>>> org.apache.cassandra.db.ColumnFamilyStore.createFlushWriter(ColumnFamilyStore.java:2301)
>>>>> at
>>>>> org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:246)
>>>>> at
>>>>> org.apache.cassandra.db.Memtable.access$400(Memtable.java:49)
>>>>> at
>>>>> org.apache.cassandra.db.Memtable$3.runMayThrow(Memtable.java:270)
>>>>> at
>>>>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
>>>>> ... 3 more
>>>>>
>>>>> Checked disk and obviously it's 100% full.
>>>>>
>>>>> How do I recover from this without loosing the data? I've got plenty
>>>>> of space on the other nodes, so I thought of doing a decommission which I
>>>>> understand reassigns ranges to the other nodes and replicates data to them.
>>>>> After that's done I plan on manually deleting the data on the node and then
>>>>> joining in the same cluster position with auto-bootstrap turned off so that
>>>>> I won't get back the old data and I can continue getting new data with the
>>>>> node.
>>>>>
>>>>> Note, I would like to have 4 nodes in because the other three barely
>>>>> take the input load alone. These are just long running tests until I get
>>>>> some better machines.
>>>>>
>>>>> On strange thing I found is that the data folder on the ndoe that
>>>>> filled up the disk is 150 GB (as measured with du) while the data folder on
>>>>> all other 3 nodes is 50 GB. At the same time, DataStax OpsCenter shows a
>>>>> size of around 50GB for all 4 nodes. I though that the node was making a
>>>>> major compaction at which time it filled up the disk....but even that
>>>>> doesn't make sense because shouldn't a major compaction just be capable of
>>>>> doubling the size, not triple-ing it? Doesn anyone know how to explain this
>>>>> behavior?
>>>>>
>>>>> Thanks,
>>>>> Alex
>>>>>
>>>>>
>>>>
>>>
>>
>>
>> --
>> Alexandru Dan Sicoe
>> MEng, CERN Marie Curie ACEOLE Fellow
>>
>>
>
--
Alexandru Dan Sicoe
MEng, CERN Marie Curie ACEOLE Fellow
Re: Insufficient disk space to flush
Posted by Edward Capriolo <ed...@gmail.com>.
There is no way to set a max size on an sstable file. If your Cassandra
data directory is not your / filesystem you could reformat it as ext4 (or
at least ext3 with better options)
On Fri, Dec 2, 2011 at 8:35 AM, Alexandru Dan Sicoe <
sicoe.alexandru@googlemail.com> wrote:
> Ok, so my problem persisted. On the node that is filling up the harddisk,
> I have a 230 GB disk. Right after I restart the node I it deletes tmp files
> and reaches 55GB of data on disk. Then it start to quickly fill up the disk
> - I see gigs added fast - it's not real data because other nodes don't have
> this.
>
> While all this is happening I am seeing the node do a minor compaction of
> the main data CF but extremely slowly. Today I saw the error:
>
> ERROR 09:44:57,605 Fatal exception in thread
> Thread[CompactionExecutor:15,1,main]
>
> java.io.IOException: File too
> large
>
> at java.io.RandomAccessFile.writeBytes(Native
> Method)
>
> at
> java.io.RandomAccessFile.write(RandomAccessFile.java:466)
>
> at
> org.apache.cassandra.io.util.BufferedRandomAccessFile.flush(BufferedRandomAccessFile.java:168)
>
> at
> org.apache.cassandra.io.util.BufferedRandomAccessFile.reBuffer(BufferedRandomAccessFile.java:242)
>
> at
> org.apache.cassandra.io.util.BufferedRandomAccessFile.writeAtMost(BufferedRandomAccessFile.java:369)
>
> at
> org.apache.cassandra.io.util.BufferedRandomAccessFile.write(BufferedRandomAccessFile.java:348)
>
> at
> org.apache.cassandra.db.compaction.PrecompactedRow.write(PrecompactedRow.java:114)
>
> at
> org.apache.cassandra.io.sstable.SSTableWriter.append(SSTableWriter.java:132)
>
> at
> org.apache.cassandra.db.compaction.CompactionManager.doCompactionWithoutSizeEstimation(CompactionManager.java:576)
>
> at
> org.apache.cassandra.db.compaction.CompactionManager.doCompaction(CompactionManager.java:507)
>
> at
> org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:142)
>
> at
> org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:108)
>
> at
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>
> at
> java.util.concurrent.FutureTask.run(FutureTask.java:138)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>
> at java.lang.Thread.run(Thread.java:619)
>
> which means that it cannot finish that compaction because it hit the max
> file size. So I checked the file system and block size and I got ext3 and
> 1K which means that the max file size is 16GB.
>
> I didn't know what to do in this case so I just decommisioned the node.
>
> Is there a way to get around this max file limit? Is there some Cassandra
> configuration that helps avoid this? I'm asking here because I couldn't
> find anything in the documentation about that.
>
> I'm waiting for new machines to run Cassandra on....what file systems are
> people using?
>
> Cheers,
> Alex
>
>
>
> On Thu, Dec 1, 2011 at 10:08 PM, Jahangir Mohammed <
> md.jahangir27@gmail.com> wrote:
>
>> Yes, mostly sounds like it. In our case failed repairs were causing
>> accumulation of the tmp files.
>>
>> Thanks,
>> Jahangir Mohammed.
>>
>> On Thu, Dec 1, 2011 at 2:43 PM, Alexandru Dan Sicoe <
>> sicoe.alexandru@googlemail.com> wrote:
>>
>>> Hi Jeremiah,
>>> My commitlog was indeed on another disk. I did what you said and yes
>>> the node restart brings back the disk size to the around 50 GB I was
>>> expecting. Still I do not understand how the node managed to get itself in
>>> the situation of having these tmp files? Could you clarify what these are,
>>> how they are produced and why? I've tried to find a clear definition but
>>> all I could come up with is hints that they are produced during compaction.
>>> I also found a thread that described a similar problem:
>>>
>>> http://cassandra-user-incubator-apache-org.3065146.n2.nabble.com/Errors-During-Compaction-td5953493.html
>>> as described there it seems like compaction fails and tmp files don't
>>> get cleaned up until they fill the disk. Is this what happened in my case?
>>> Compactions did not finish properly because the disk utilization was more
>>> than half and then more and more files tmp started getting accumulated at
>>> each other attempt. The Cassandra log would indicate this because I get
>>> many of these:
>>> ERROR [CompactionExecutor:22850] 2011-12-01 04:12:15,200
>>> CompactionManager.java (line 513) insufficie
>>> nt space to compact even the two smallest files, aborting
>>>
>>> before I started getting many of these:
>>> ERROR [FlushWriter:283] 2011-12-01 04:12:22,917
>>> AbstractCassandraDaemon.java (line 139) Fatal exception in thread
>>> Thread[FlushWriter:283,5,main] java.lang.RuntimeException:
>>> java.lang.RuntimeException: Insufficient disk space to flush 42531 bytes
>>>
>>> I just want to clearly understand what happened.
>>>
>>> Thanks,
>>> Alex
>>>
>>>
>>> On Thu, Dec 1, 2011 at 6:58 PM, Jeremiah Jordan <
>>> jeremiah.jordan@morningstar.com> wrote:
>>>
>>>> If you are writing data with QUORUM or ALL you should be safe to
>>>> restart cassandra on that node. If the extra space is all from *tmp* files
>>>> from compaction they will get deleted at startup. You will then need to
>>>> run repair on that node to get back any data that was missed while it was
>>>> full. If your commit log was on a different device you may not even have
>>>> lost much.
>>>>
>>>> -Jeremiah
>>>>
>>>>
>>>> On 12/01/2011 04:16 AM, Alexandru Dan Sicoe wrote:
>>>>
>>>> Hello everyone,
>>>> 4 node Cassandra 0.8.5 cluster with RF =2.
>>>> One node started throwing exceptions in its log:
>>>>
>>>> ERROR 10:02:46,837 Fatal exception in thread
>>>> Thread[FlushWriter:1317,5,main]
>>>> java.lang.RuntimeException: java.lang.RuntimeException: Insufficient
>>>> disk space to flush 17296 bytes
>>>> at
>>>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
>>>> at
>>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>>> at
>>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>>> at java.lang.Thread.run(Thread.java:619)
>>>> Caused by: java.lang.RuntimeException: Insufficient disk space to flush
>>>> 17296 bytes
>>>> at
>>>> org.apache.cassandra.db.ColumnFamilyStore.getFlushPath(ColumnFamilyStore.java:714)
>>>> at
>>>> org.apache.cassandra.db.ColumnFamilyStore.createFlushWriter(ColumnFamilyStore.java:2301)
>>>> at
>>>> org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:246)
>>>> at org.apache.cassandra.db.Memtable.access$400(Memtable.java:49)
>>>> at
>>>> org.apache.cassandra.db.Memtable$3.runMayThrow(Memtable.java:270)
>>>> at
>>>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
>>>> ... 3 more
>>>>
>>>> Checked disk and obviously it's 100% full.
>>>>
>>>> How do I recover from this without loosing the data? I've got plenty of
>>>> space on the other nodes, so I thought of doing a decommission which I
>>>> understand reassigns ranges to the other nodes and replicates data to them.
>>>> After that's done I plan on manually deleting the data on the node and then
>>>> joining in the same cluster position with auto-bootstrap turned off so that
>>>> I won't get back the old data and I can continue getting new data with the
>>>> node.
>>>>
>>>> Note, I would like to have 4 nodes in because the other three barely
>>>> take the input load alone. These are just long running tests until I get
>>>> some better machines.
>>>>
>>>> On strange thing I found is that the data folder on the ndoe that
>>>> filled up the disk is 150 GB (as measured with du) while the data folder on
>>>> all other 3 nodes is 50 GB. At the same time, DataStax OpsCenter shows a
>>>> size of around 50GB for all 4 nodes. I though that the node was making a
>>>> major compaction at which time it filled up the disk....but even that
>>>> doesn't make sense because shouldn't a major compaction just be capable of
>>>> doubling the size, not triple-ing it? Doesn anyone know how to explain this
>>>> behavior?
>>>>
>>>> Thanks,
>>>> Alex
>>>>
>>>>
>>>
>>
>
>
> --
> Alexandru Dan Sicoe
> MEng, CERN Marie Curie ACEOLE Fellow
>
>
Re: Insufficient disk space to flush
Posted by Alexandru Dan Sicoe <si...@googlemail.com>.
Ok, so my problem persisted. On the node that is filling up the harddisk, I
have a 230 GB disk. Right after I restart the node I it deletes tmp files
and reaches 55GB of data on disk. Then it start to quickly fill up the disk
- I see gigs added fast - it's not real data because other nodes don't have
this.
While all this is happening I am seeing the node do a minor compaction of
the main data CF but extremely slowly. Today I saw the error:
ERROR 09:44:57,605 Fatal exception in thread
Thread[CompactionExecutor:15,1,main]
java.io.IOException: File too
large
at java.io.RandomAccessFile.writeBytes(Native
Method)
at
java.io.RandomAccessFile.write(RandomAccessFile.java:466)
at
org.apache.cassandra.io.util.BufferedRandomAccessFile.flush(BufferedRandomAccessFile.java:168)
at
org.apache.cassandra.io.util.BufferedRandomAccessFile.reBuffer(BufferedRandomAccessFile.java:242)
at
org.apache.cassandra.io.util.BufferedRandomAccessFile.writeAtMost(BufferedRandomAccessFile.java:369)
at
org.apache.cassandra.io.util.BufferedRandomAccessFile.write(BufferedRandomAccessFile.java:348)
at
org.apache.cassandra.db.compaction.PrecompactedRow.write(PrecompactedRow.java:114)
at
org.apache.cassandra.io.sstable.SSTableWriter.append(SSTableWriter.java:132)
at
org.apache.cassandra.db.compaction.CompactionManager.doCompactionWithoutSizeEstimation(CompactionManager.java:576)
at
org.apache.cassandra.db.compaction.CompactionManager.doCompaction(CompactionManager.java:507)
at
org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:142)
at
org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:108)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at
java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
which means that it cannot finish that compaction because it hit the max
file size. So I checked the file system and block size and I got ext3 and
1K which means that the max file size is 16GB.
I didn't know what to do in this case so I just decommisioned the node.
Is there a way to get around this max file limit? Is there some Cassandra
configuration that helps avoid this? I'm asking here because I couldn't
find anything in the documentation about that.
I'm waiting for new machines to run Cassandra on....what file systems are
people using?
Cheers,
Alex
On Thu, Dec 1, 2011 at 10:08 PM, Jahangir Mohammed
<md...@gmail.com>wrote:
> Yes, mostly sounds like it. In our case failed repairs were causing
> accumulation of the tmp files.
>
> Thanks,
> Jahangir Mohammed.
>
> On Thu, Dec 1, 2011 at 2:43 PM, Alexandru Dan Sicoe <
> sicoe.alexandru@googlemail.com> wrote:
>
>> Hi Jeremiah,
>> My commitlog was indeed on another disk. I did what you said and yes the
>> node restart brings back the disk size to the around 50 GB I was expecting.
>> Still I do not understand how the node managed to get itself in the
>> situation of having these tmp files? Could you clarify what these are, how
>> they are produced and why? I've tried to find a clear definition but all I
>> could come up with is hints that they are produced during compaction. I
>> also found a thread that described a similar problem:
>>
>> http://cassandra-user-incubator-apache-org.3065146.n2.nabble.com/Errors-During-Compaction-td5953493.html
>> as described there it seems like compaction fails and tmp files don't get
>> cleaned up until they fill the disk. Is this what happened in my case?
>> Compactions did not finish properly because the disk utilization was more
>> than half and then more and more files tmp started getting accumulated at
>> each other attempt. The Cassandra log would indicate this because I get
>> many of these:
>> ERROR [CompactionExecutor:22850] 2011-12-01 04:12:15,200
>> CompactionManager.java (line 513) insufficie
>> nt space to compact even the two smallest files, aborting
>>
>> before I started getting many of these:
>> ERROR [FlushWriter:283] 2011-12-01 04:12:22,917
>> AbstractCassandraDaemon.java (line 139) Fatal exception in thread
>> Thread[FlushWriter:283,5,main] java.lang.RuntimeException:
>> java.lang.RuntimeException: Insufficient disk space to flush 42531 bytes
>>
>> I just want to clearly understand what happened.
>>
>> Thanks,
>> Alex
>>
>>
>> On Thu, Dec 1, 2011 at 6:58 PM, Jeremiah Jordan <
>> jeremiah.jordan@morningstar.com> wrote:
>>
>>> If you are writing data with QUORUM or ALL you should be safe to
>>> restart cassandra on that node. If the extra space is all from *tmp* files
>>> from compaction they will get deleted at startup. You will then need to
>>> run repair on that node to get back any data that was missed while it was
>>> full. If your commit log was on a different device you may not even have
>>> lost much.
>>>
>>> -Jeremiah
>>>
>>>
>>> On 12/01/2011 04:16 AM, Alexandru Dan Sicoe wrote:
>>>
>>> Hello everyone,
>>> 4 node Cassandra 0.8.5 cluster with RF =2.
>>> One node started throwing exceptions in its log:
>>>
>>> ERROR 10:02:46,837 Fatal exception in thread
>>> Thread[FlushWriter:1317,5,main]
>>> java.lang.RuntimeException: java.lang.RuntimeException: Insufficient
>>> disk space to flush 17296 bytes
>>> at
>>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
>>> at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>> at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>> at java.lang.Thread.run(Thread.java:619)
>>> Caused by: java.lang.RuntimeException: Insufficient disk space to flush
>>> 17296 bytes
>>> at
>>> org.apache.cassandra.db.ColumnFamilyStore.getFlushPath(ColumnFamilyStore.java:714)
>>> at
>>> org.apache.cassandra.db.ColumnFamilyStore.createFlushWriter(ColumnFamilyStore.java:2301)
>>> at
>>> org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:246)
>>> at org.apache.cassandra.db.Memtable.access$400(Memtable.java:49)
>>> at
>>> org.apache.cassandra.db.Memtable$3.runMayThrow(Memtable.java:270)
>>> at
>>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
>>> ... 3 more
>>>
>>> Checked disk and obviously it's 100% full.
>>>
>>> How do I recover from this without loosing the data? I've got plenty of
>>> space on the other nodes, so I thought of doing a decommission which I
>>> understand reassigns ranges to the other nodes and replicates data to them.
>>> After that's done I plan on manually deleting the data on the node and then
>>> joining in the same cluster position with auto-bootstrap turned off so that
>>> I won't get back the old data and I can continue getting new data with the
>>> node.
>>>
>>> Note, I would like to have 4 nodes in because the other three barely
>>> take the input load alone. These are just long running tests until I get
>>> some better machines.
>>>
>>> On strange thing I found is that the data folder on the ndoe that filled
>>> up the disk is 150 GB (as measured with du) while the data folder on all
>>> other 3 nodes is 50 GB. At the same time, DataStax OpsCenter shows a size
>>> of around 50GB for all 4 nodes. I though that the node was making a major
>>> compaction at which time it filled up the disk....but even that doesn't
>>> make sense because shouldn't a major compaction just be capable of doubling
>>> the size, not triple-ing it? Doesn anyone know how to explain this behavior?
>>>
>>> Thanks,
>>> Alex
>>>
>>>
>>
>
--
Alexandru Dan Sicoe
MEng, CERN Marie Curie ACEOLE Fellow
Re: Insufficient disk space to flush
Posted by Jahangir Mohammed <md...@gmail.com>.
Yes, mostly sounds like it. In our case failed repairs were causing
accumulation of the tmp files.
Thanks,
Jahangir Mohammed.
On Thu, Dec 1, 2011 at 2:43 PM, Alexandru Dan Sicoe <
sicoe.alexandru@googlemail.com> wrote:
> Hi Jeremiah,
> My commitlog was indeed on another disk. I did what you said and yes the
> node restart brings back the disk size to the around 50 GB I was expecting.
> Still I do not understand how the node managed to get itself in the
> situation of having these tmp files? Could you clarify what these are, how
> they are produced and why? I've tried to find a clear definition but all I
> could come up with is hints that they are produced during compaction. I
> also found a thread that described a similar problem:
>
> http://cassandra-user-incubator-apache-org.3065146.n2.nabble.com/Errors-During-Compaction-td5953493.html
> as described there it seems like compaction fails and tmp files don't get
> cleaned up until they fill the disk. Is this what happened in my case?
> Compactions did not finish properly because the disk utilization was more
> than half and then more and more files tmp started getting accumulated at
> each other attempt. The Cassandra log would indicate this because I get
> many of these:
> ERROR [CompactionExecutor:22850] 2011-12-01 04:12:15,200
> CompactionManager.java (line 513) insufficie
> nt space to compact even the two smallest files, aborting
>
> before I started getting many of these:
> ERROR [FlushWriter:283] 2011-12-01 04:12:22,917
> AbstractCassandraDaemon.java (line 139) Fatal exception in thread
> Thread[FlushWriter:283,5,main] java.lang.RuntimeException:
> java.lang.RuntimeException: Insufficient disk space to flush 42531 bytes
>
> I just want to clearly understand what happened.
>
> Thanks,
> Alex
>
>
> On Thu, Dec 1, 2011 at 6:58 PM, Jeremiah Jordan <
> jeremiah.jordan@morningstar.com> wrote:
>
>> If you are writing data with QUORUM or ALL you should be safe to restart
>> cassandra on that node. If the extra space is all from *tmp* files from
>> compaction they will get deleted at startup. You will then need to run
>> repair on that node to get back any data that was missed while it was
>> full. If your commit log was on a different device you may not even have
>> lost much.
>>
>> -Jeremiah
>>
>>
>> On 12/01/2011 04:16 AM, Alexandru Dan Sicoe wrote:
>>
>> Hello everyone,
>> 4 node Cassandra 0.8.5 cluster with RF =2.
>> One node started throwing exceptions in its log:
>>
>> ERROR 10:02:46,837 Fatal exception in thread
>> Thread[FlushWriter:1317,5,main]
>> java.lang.RuntimeException: java.lang.RuntimeException: Insufficient disk
>> space to flush 17296 bytes
>> at
>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>> at java.lang.Thread.run(Thread.java:619)
>> Caused by: java.lang.RuntimeException: Insufficient disk space to flush
>> 17296 bytes
>> at
>> org.apache.cassandra.db.ColumnFamilyStore.getFlushPath(ColumnFamilyStore.java:714)
>> at
>> org.apache.cassandra.db.ColumnFamilyStore.createFlushWriter(ColumnFamilyStore.java:2301)
>> at
>> org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:246)
>> at org.apache.cassandra.db.Memtable.access$400(Memtable.java:49)
>> at
>> org.apache.cassandra.db.Memtable$3.runMayThrow(Memtable.java:270)
>> at
>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
>> ... 3 more
>>
>> Checked disk and obviously it's 100% full.
>>
>> How do I recover from this without loosing the data? I've got plenty of
>> space on the other nodes, so I thought of doing a decommission which I
>> understand reassigns ranges to the other nodes and replicates data to them.
>> After that's done I plan on manually deleting the data on the node and then
>> joining in the same cluster position with auto-bootstrap turned off so that
>> I won't get back the old data and I can continue getting new data with the
>> node.
>>
>> Note, I would like to have 4 nodes in because the other three barely take
>> the input load alone. These are just long running tests until I get some
>> better machines.
>>
>> On strange thing I found is that the data folder on the ndoe that filled
>> up the disk is 150 GB (as measured with du) while the data folder on all
>> other 3 nodes is 50 GB. At the same time, DataStax OpsCenter shows a size
>> of around 50GB for all 4 nodes. I though that the node was making a major
>> compaction at which time it filled up the disk....but even that doesn't
>> make sense because shouldn't a major compaction just be capable of doubling
>> the size, not triple-ing it? Doesn anyone know how to explain this behavior?
>>
>> Thanks,
>> Alex
>>
>>
>
Re: Insufficient disk space to flush
Posted by Alexandru Dan Sicoe <si...@googlemail.com>.
Hi Jeremiah,
My commitlog was indeed on another disk. I did what you said and yes the
node restart brings back the disk size to the around 50 GB I was expecting.
Still I do not understand how the node managed to get itself in the
situation of having these tmp files? Could you clarify what these are, how
they are produced and why? I've tried to find a clear definition but all I
could come up with is hints that they are produced during compaction. I
also found a thread that described a similar problem:
http://cassandra-user-incubator-apache-org.3065146.n2.nabble.com/Errors-During-Compaction-td5953493.html
as described there it seems like compaction fails and tmp files don't get
cleaned up until they fill the disk. Is this what happened in my case?
Compactions did not finish properly because the disk utilization was more
than half and then more and more files tmp started getting accumulated at
each other attempt. The Cassandra log would indicate this because I get
many of these:
ERROR [CompactionExecutor:22850] 2011-12-01 04:12:15,200
CompactionManager.java (line 513) insufficie
nt space to compact even the two smallest files, aborting
before I started getting many of these:
ERROR [FlushWriter:283] 2011-12-01 04:12:22,917
AbstractCassandraDaemon.java (line 139) Fatal exception in thread
Thread[FlushWriter:283,5,main] java.lang.RuntimeException:
java.lang.RuntimeException: Insufficient disk space to flush 42531 bytes
I just want to clearly understand what happened.
Thanks,
Alex
On Thu, Dec 1, 2011 at 6:58 PM, Jeremiah Jordan <
jeremiah.jordan@morningstar.com> wrote:
> If you are writing data with QUORUM or ALL you should be safe to restart
> cassandra on that node. If the extra space is all from *tmp* files from
> compaction they will get deleted at startup. You will then need to run
> repair on that node to get back any data that was missed while it was
> full. If your commit log was on a different device you may not even have
> lost much.
>
> -Jeremiah
>
>
> On 12/01/2011 04:16 AM, Alexandru Dan Sicoe wrote:
>
> Hello everyone,
> 4 node Cassandra 0.8.5 cluster with RF =2.
> One node started throwing exceptions in its log:
>
> ERROR 10:02:46,837 Fatal exception in thread
> Thread[FlushWriter:1317,5,main]
> java.lang.RuntimeException: java.lang.RuntimeException: Insufficient disk
> space to flush 17296 bytes
> at
> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> Caused by: java.lang.RuntimeException: Insufficient disk space to flush
> 17296 bytes
> at
> org.apache.cassandra.db.ColumnFamilyStore.getFlushPath(ColumnFamilyStore.java:714)
> at
> org.apache.cassandra.db.ColumnFamilyStore.createFlushWriter(ColumnFamilyStore.java:2301)
> at
> org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:246)
> at org.apache.cassandra.db.Memtable.access$400(Memtable.java:49)
> at
> org.apache.cassandra.db.Memtable$3.runMayThrow(Memtable.java:270)
> at
> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
> ... 3 more
>
> Checked disk and obviously it's 100% full.
>
> How do I recover from this without loosing the data? I've got plenty of
> space on the other nodes, so I thought of doing a decommission which I
> understand reassigns ranges to the other nodes and replicates data to them.
> After that's done I plan on manually deleting the data on the node and then
> joining in the same cluster position with auto-bootstrap turned off so that
> I won't get back the old data and I can continue getting new data with the
> node.
>
> Note, I would like to have 4 nodes in because the other three barely take
> the input load alone. These are just long running tests until I get some
> better machines.
>
> On strange thing I found is that the data folder on the ndoe that filled
> up the disk is 150 GB (as measured with du) while the data folder on all
> other 3 nodes is 50 GB. At the same time, DataStax OpsCenter shows a size
> of around 50GB for all 4 nodes. I though that the node was making a major
> compaction at which time it filled up the disk....but even that doesn't
> make sense because shouldn't a major compaction just be capable of doubling
> the size, not triple-ing it? Doesn anyone know how to explain this behavior?
>
> Thanks,
> Alex
>
>
Re: Insufficient disk space to flush
Posted by Jeremiah Jordan <je...@morningstar.com>.
If you are writing data with QUORUM or ALL you should be safe to restart
cassandra on that node. If the extra space is all from *tmp* files from
compaction they will get deleted at startup. You will then need to run
repair on that node to get back any data that was missed while it was
full. If your commit log was on a different device you may not even
have lost much.
-Jeremiah
On 12/01/2011 04:16 AM, Alexandru Dan Sicoe wrote:
> Hello everyone,
> 4 node Cassandra 0.8.5 cluster with RF =2.
> One node started throwing exceptions in its log:
>
> ERROR 10:02:46,837 Fatal exception in thread
> Thread[FlushWriter:1317,5,main]
> java.lang.RuntimeException: java.lang.RuntimeException: Insufficient
> disk space to flush 17296 bytes
> at
> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> Caused by: java.lang.RuntimeException: Insufficient disk space to
> flush 17296 bytes
> at
> org.apache.cassandra.db.ColumnFamilyStore.getFlushPath(ColumnFamilyStore.java:714)
> at
> org.apache.cassandra.db.ColumnFamilyStore.createFlushWriter(ColumnFamilyStore.java:2301)
> at
> org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:246)
> at org.apache.cassandra.db.Memtable.access$400(Memtable.java:49)
> at
> org.apache.cassandra.db.Memtable$3.runMayThrow(Memtable.java:270)
> at
> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
> ... 3 more
>
> Checked disk and obviously it's 100% full.
>
> How do I recover from this without loosing the data? I've got plenty
> of space on the other nodes, so I thought of doing a decommission
> which I understand reassigns ranges to the other nodes and replicates
> data to them. After that's done I plan on manually deleting the data
> on the node and then joining in the same cluster position with
> auto-bootstrap turned off so that I won't get back the old data and I
> can continue getting new data with the node.
>
> Note, I would like to have 4 nodes in because the other three barely
> take the input load alone. These are just long running tests until I
> get some better machines.
>
> On strange thing I found is that the data folder on the ndoe that
> filled up the disk is 150 GB (as measured with du) while the data
> folder on all other 3 nodes is 50 GB. At the same time, DataStax
> OpsCenter shows a size of around 50GB for all 4 nodes. I though that
> the node was making a major compaction at which time it filled up the
> disk....but even that doesn't make sense because shouldn't a major
> compaction just be capable of doubling the size, not triple-ing it?
> Doesn anyone know how to explain this behavior?
>
> Thanks,
> Alex
>