You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Yuki Morishita (Issue Comment Edited) (JIRA)" <ji...@apache.org> on 2012/02/08 17:25:00 UTC
[jira] [Issue Comment Edited] (CASSANDRA-3712) Can't cleanup after
I moved a token.
[ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13203676#comment-13203676 ]
Yuki Morishita edited comment on CASSANDRA-3712 at 2/8/12 4:23 PM:
-------------------------------------------------------------------
When updating/deleting CFS backed secondary index, currently it doesn't acquire Memtable lock. So when flush and cleanup occurred at the same time on indexed column family, there is a chance of getting this AssertionError.
Test case attached to reproduce the same error. Note that test does not fail always, so you may run several times to see the error.
To fix this, I added CFS#applyDirect method which just acquire and release lock before/after CFS update, and call it from KeysIndex.
Both patches are for 1.0 branch.
was (Author: yukim):
When updating/deleting CFS backed secondary index, currently it doesn't acquire Memtable lock. So when flush and cleanup occurred at the same time on indexed column family, there is a chance of getting this AssertionError.
Test case attached to reproduce the same error. Note that test does not fail always, so you may run several times to see the error.
To fix this, I added CFS#applyDirect method which just acquire and release lock before/after CFS update, and call it from KeysIndex.
> Can't cleanup after I moved a token.
> ------------------------------------
>
> Key: CASSANDRA-3712
> URL: https://issues.apache.org/jira/browse/CASSANDRA-3712
> Project: Cassandra
> Issue Type: Bug
> Affects Versions: 1.0.6
> Environment: java version "1.6.0_26"
> Java(TM) SE Runtime Environment (build 1.6.0_26-b03)
> Java HotSpot(TM) 64-Bit Server VM (build 20.1-b02, mixed mode)
> Ubuntu 10.04.2 LTS 64-Bit
> RAM: 2GB / 1GB free
> Data partition: 80% free on the most used server.
> Reporter: Herve Nicol
> Assignee: Yuki Morishita
> Attachments: 0001-Add-flush-and-cleanup-race-test.patch, 0002-Acquire-lock-when-updating-index.patch
>
>
> Before cleanup failed, I moved one node's token.
> My cluster had 10GB data on 2 nodes. Data repartition was bad, tokens were 165[...] and 155[...].
> I moved 155 to 075[...], then adjusted to 076[...]. The moves were correctly processed, with no exception.
> But then, when I wanted to cleanup, it failed and keeps failing, on both nodes.
> Other maintenance procedures like repair, compact or scrub work.
> All the data is in the URLs CF.
> Example session log:
> nodetool cleanup fails:
> $ ./nodetool --host cnode1 cleanup
> Error occured during cleanup
> java.util.concurrent.ExecutionException: java.lang.AssertionError
> at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
> at java.util.concurrent.FutureTask.get(FutureTask.java:83)
> at org.apache.cassandra.db.compaction.CompactionManager.performAllSSTableOperation(CompactionManager.java:203)
> at org.apache.cassandra.db.compaction.CompactionManager.performCleanup(CompactionManager.java:237)
> at org.apache.cassandra.db.ColumnFamilyStore.forceCleanup(ColumnFamilyStore.java:958)
> at org.apache.cassandra.service.StorageService.forceTableCleanup(StorageService.java:1604)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:93)
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:27)
> at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:208)
> at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:120)
> at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:262)
> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:836)
> at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:761)
> at javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1427)
> at javax.management.remote.rmi.RMIConnectionImpl.access$200(RMIConnectionImpl.java:72)
> at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1265)
> at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1360)
> at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:788)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305)
> at sun.rmi.transport.Transport$1.run(Transport.java:159)
> at java.security.AccessController.doPrivileged(Native Method)
> at sun.rmi.transport.Transport.serviceCall(Transport.java:155)
> at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535)
> at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
> at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
> 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.AssertionError
> at org.apache.cassandra.db.Memtable.put(Memtable.java:136)
> at org.apache.cassandra.db.ColumnFamilyStore.apply(ColumnFamilyStore.java:780)
> at org.apache.cassandra.db.index.keys.KeysIndex.deleteColumn(KeysIndex.java:82)
> at org.apache.cassandra.db.index.SecondaryIndexManager.deleteFromIndexes(SecondaryIndexManager.java:438)
> at org.apache.cassandra.db.compaction.CompactionManager.doCleanupCompaction(CompactionManager.java:754)
> at org.apache.cassandra.db.compaction.CompactionManager.access$300(CompactionManager.java:63)
> at org.apache.cassandra.db.compaction.CompactionManager$5.perform(CompactionManager.java:241)
> at org.apache.cassandra.db.compaction.CompactionManager$2.call(CompactionManager.java:182)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> ... 3 more
> The server log looks like this:
> INFO [CompactionExecutor:260] 2012-01-09 14:08:41,716 CompactionManager.java (line 702) Cleaning up SSTableReader(path='/ke/cassandra/data/kev3/URLs-hc-457-Data.db')
> INFO [OptionalTasks:1] 2012-01-09 14:08:47,220 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='kev3', ColumnFamily='URLs') (estimated 156787206 bytes)
> INFO [OptionalTasks:1] 2012-01-09 14:08:47,226 ColumnFamilyStore.java (line 692) Enqueuing flush of Memtable-URLs.URLs_1_idx@1347180703(16324791/156973287 serialized/live bytes, 173288 ops)
> INFO [FlushWriter:23] 2012-01-09 14:08:47,236 Memtable.java (line 240) Writing Memtable-URLs.URLs_1_idx@1347180703(16324791/156973287 serialized/live bytes, 173288 ops)
> INFO [pool-1-thread-1] 2012-01-09 14:08:51,003 Memtable.java (line 180) CFS(Keyspace='kev3', ColumnFamily='URLs.URLs_1_idx') liveRatio is 7.692510757866615 (just-counted was 4.512127842861816). calculation took 8648ms for 97329 columns
> INFO [FlushWriter:23] 2012-01-09 14:08:54,360 Memtable.java (line 277) Completed flushing /ke/cassandra/data/kev3/URLs.URLs_1_idx-hc-143-Data.db (26375495 bytes)
> INFO [ScheduledTasks:1] 2012-01-09 14:08:55,566 GCInspector.java (line 123) GC for ParNew: 206 ms for 1 collections, 934108624 used; max is 2034237440
> INFO [OptionalTasks:1] 2012-01-09 14:08:57,289 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='kev3', ColumnFamily='URLs') (estimated 188842513 bytes)
> INFO [OptionalTasks:1] 2012-01-09 14:08:57,297 ColumnFamilyStore.java (line 692) Enqueuing flush of Memtable-URLs.URLs_1_idx@164871630(19662738/189069779 serialized/live bytes, 208494 ops)
> INFO [FlushWriter:23] 2012-01-09 14:08:57,297 Memtable.java (line 240) Writing Memtable-URLs.URLs_1_idx@164871630(19662738/189069779 serialized/live bytes, 208494 ops)
> INFO [ScheduledTasks:1] 2012-01-09 14:08:57,619 GCInspector.java (line 123) GC for ParNew: 402 ms for 2 collections, 981893424 used; max is 2034237440
> INFO [FlushWriter:23] 2012-01-09 14:09:05,944 Memtable.java (line 277) Completed flushing /ke/cassandra/data/kev3/URLs.URLs_1_idx-hc-144-Data.db (31755390 bytes)
> INFO [OptionalTasks:1] 2012-01-09 14:09:06,447 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='kev3', ColumnFamily='URLs') (estimated 174605041 bytes)
> INFO [OptionalTasks:1] 2012-01-09 14:09:06,447 ColumnFamilyStore.java (line 692) Enqueuing flush of Memtable-URLs.URLs_1_idx@284469330(18158445/174605041 serialized/live bytes, 192702 ops)
> INFO [FlushWriter:23] 2012-01-09 14:09:06,447 Memtable.java (line 240) Writing Memtable-URLs.URLs_1_idx@284469330(18158445/174605041 serialized/live bytes, 192702 ops)
> ERROR [CompactionExecutor:260] 2012-01-09 14:09:06,448 AbstractCassandraDaemon.java (line 133) Fatal exception in thread Thread[CompactionExecutor:260,1,RMI Runtime]
> java.lang.AssertionError
> at org.apache.cassandra.db.Memtable.put(Memtable.java:136)
> at org.apache.cassandra.db.ColumnFamilyStore.apply(ColumnFamilyStore.java:780)
> at org.apache.cassandra.db.index.keys.KeysIndex.deleteColumn(KeysIndex.java:82)
> at org.apache.cassandra.db.index.SecondaryIndexManager.deleteFromIndexes(SecondaryIndexManager.java:438)
> at org.apache.cassandra.db.compaction.CompactionManager.doCleanupCompaction(CompactionManager.java:754)
> at org.apache.cassandra.db.compaction.CompactionManager.access$300(CompactionManager.java:63)
> at org.apache.cassandra.db.compaction.CompactionManager$5.perform(CompactionManager.java:241)
> at org.apache.cassandra.db.compaction.CompactionManager$2.call(CompactionManager.java:182)
> 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)
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira