You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Herve Nicol (Created) (JIRA)" <ji...@apache.org> on 2012/01/09 15:38:39 UTC

[jira] [Created] (CASSANDRA-3712) Can't cleanup after I moved a token.

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


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

        

[jira] [Issue Comment Edited] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Yuki Morishita (Issue Comment Edited) (JIRA)" <ji...@apache.org>.
    [ 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

        

[jira] [Commented] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Herve Nicol (Commented) (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13183263#comment-13183263 ] 

Herve Nicol commented on CASSANDRA-3712:
----------------------------------------

I restarted my nodes, but it didn't fix this.
                
> 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
>
> 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

        

[jira] [Updated] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Yuki Morishita (Updated) (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Yuki Morishita updated CASSANDRA-3712:
--------------------------------------

    Attachment: 0002-Acquire-lock-when-updating-index.patch
                0001-Add-flush-and-cleanup-race-test.patch

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

        

[jira] [Updated] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Yuki Morishita (Updated) (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Yuki Morishita updated CASSANDRA-3712:
--------------------------------------

    Attachment:     (was: 0002-Acquire-lock-when-updating-index.patch)
    
> 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
>          Components: Core
>         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
>             Fix For: 1.0.8
>
>         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

        

[jira] [Commented] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Yuki Morishita (Commented) (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13205631#comment-13205631 ] 

Yuki Morishita commented on CASSANDRA-3712:
-------------------------------------------

bq. I can't get the new test to fail after a dozen tries. If there isn't a way to make it more robust (say, with explicit sleeps) maybe we should just leave that out.

In my env, it fails 1/3 or 1/4 try. I cannot think of better test program, so you can leave it out.

bq. Currently the switch locking is done by the callers of the SIM methods, i.e., Table.apply and Table.indexRow. Locking at the column level is not sufficient there, but doing it in both places is redundant. So maybe the right place to lock here would be in the doCleanupCompaction method.

You are right. Previous patch acquires lock too often. I placed lock/unlock inside doCleanupCompaction in newer patch.
In order to do that, I have to expose Table.switchlock to public, but I don't know if that is the right way.
                
> 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
>          Components: Core
>         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
>             Fix For: 1.0.8
>
>         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

        

[jira] [Assigned] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Yuki Morishita (Assigned) (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Yuki Morishita reassigned CASSANDRA-3712:
-----------------------------------------

    Assignee: Yuki Morishita
    
> 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
>
> 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

        

[jira] [Updated] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Jonathan Ellis (Updated) (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jonathan Ellis updated CASSANDRA-3712:
--------------------------------------

             Reviewer: jbellis
          Component/s: Core
    Affects Version/s:     (was: 1.0.6)
        Fix Version/s: 1.0.8
    
> 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
>          Components: Core
>         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
>             Fix For: 1.0.8
>
>         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

        

[jira] [Commented] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Herve Nicol (Commented) (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13184198#comment-13184198 ] 

Herve Nicol commented on CASSANDRA-3712:
----------------------------------------

Thanks, that fixed cleanup.
                
> 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
>
> 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

        

[jira] [Commented] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Jonathan Ellis (Commented) (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13182916#comment-13182916 ] 

Jonathan Ellis commented on CASSANDRA-3712:
-------------------------------------------

We'll look into the root cause, but in the meantime, restarting the node should fix this.
                
> 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
>
> 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

        

[jira] [Commented] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Jonathan Ellis (Commented) (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13183399#comment-13183399 ] 

Jonathan Ellis commented on CASSANDRA-3712:
-------------------------------------------

Then you'll probably need to drop your indexes, then rebuild after the cleanup.
                
> 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
>
> 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

        

[jira] [Updated] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Yuki Morishita (Updated) (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Yuki Morishita updated CASSANDRA-3712:
--------------------------------------

    Attachment: 0002-Acquire-lock-when-updating-index.patch
    
> 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
>          Components: Core
>         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
>             Fix For: 1.0.8
>
>         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

        

[jira] [Updated] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Jonathan Ellis (Updated) (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jonathan Ellis updated CASSANDRA-3712:
--------------------------------------

    Attachment: 3712-v3.txt

The new patch acquires the switchlock for the entire cleanup, so no flushes can happen.  For large sstables this could cause a problem.  How about attached v3, is that sufficient for it to be safe?
                
> 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
>          Components: Core
>         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
>             Fix For: 1.0.8
>
>         Attachments: 0001-Add-flush-and-cleanup-race-test.patch, 0002-Acquire-lock-when-updating-index.patch, 3712-v3.txt
>
>
> 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

        

[jira] [Commented] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Yuki Morishita (Commented) (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13207021#comment-13207021 ] 

Yuki Morishita commented on CASSANDRA-3712:
-------------------------------------------

I ran my unit test enough and I see no error.
+1
                
> 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
>          Components: Core
>         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
>             Fix For: 1.0.8
>
>         Attachments: 0001-Add-flush-and-cleanup-race-test.patch, 0002-Acquire-lock-when-updating-index.patch, 3712-v3.txt
>
>
> 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

        

[jira] [Commented] (CASSANDRA-3712) Can't cleanup after I moved a token.

Posted by "Jonathan Ellis (Commented) (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-3712?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13204121#comment-13204121 ] 

Jonathan Ellis commented on CASSANDRA-3712:
-------------------------------------------

A couple comments:

- I can't get the new test to fail after a dozen tries. If there isn't a way to make it more robust (say, with explicit sleeps) maybe we should just leave that out.
- Currently the switch locking is done by the callers of the SIM methods, i.e., Table.apply and Table.indexRow. Locking at the column level is not sufficient there, but doing it in both places is redundant. So maybe the right place to lock here would be in the doCleanupCompaction method.
                
> 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
>          Components: Core
>         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
>             Fix For: 1.0.8
>
>         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