Details
-
Bug
-
Status: Resolved
-
Urgent
-
Resolution: Duplicate
-
None
-
Critical
Description
Reported by cscotta on Twitter. Here is a log fragment showing the 2110 sstable pulled into two compactions:
INFO [CompactionExecutor:41495] 2013-02-14 14:19:26,621 CompactionTask.java (line 118) Compacting [SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2110-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-1711-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2068-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-1391-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2115-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2052-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2089-Data.db')]
INFO [OptionalTasks:1] 2013-02-14 14:20:28,978 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399218463 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:20:28,979 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@347404907(60626496/399218463 serialized/live bytes, 2165232 ops)
INFO [FlushWriter:1590] 2013-02-14 14:20:28,980 Memtable.java (line 447) Writing Memtable-Metrics@347404907(60626496/399218463 serialized/live bytes, 2165232 ops)
INFO [FlushWriter:1590] 2013-02-14 14:20:30,606 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2117-Data.db (21066414 bytes) for commitlog position ReplayPosition(segmentId=1360737579813, position=4969777)
INFO [OptionalTasks:1] 2013-02-14 14:21:51,046 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399221413 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:21:51,046 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@663159049(60626944/399221413 serialized/live bytes, 2165248 ops)
INFO [FlushWriter:1591] 2013-02-14 14:21:51,047 Memtable.java (line 447) Writing Memtable-Metrics@663159049(60626944/399221413 serialized/live bytes, 2165248 ops)
INFO [FlushWriter:1591] 2013-02-14 14:21:52,692 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2118-Data.db (21071657 bytes) for commitlog position ReplayPosition(segmentId=1360737579815, position=14067099)
INFO [OptionalTasks:1] 2013-02-14 14:23:13,059 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399214407 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:23:13,060 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@480704694(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1592] 2013-02-14 14:23:13,061 Memtable.java (line 447) Writing Memtable-Metrics@480704694(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1592] 2013-02-14 14:23:14,677 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2119-Data.db (21074605 bytes) for commitlog position ReplayPosition(segmentId=1360737579817, position=23128798)
INFO [OptionalTasks:1] 2013-02-14 14:24:35,073 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399214407 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:24:35,073 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@2075924408(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1593] 2013-02-14 14:24:35,074 Memtable.java (line 447) Writing Memtable-Metrics@2075924408(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1593] 2013-02-14 14:24:36,683 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2120-Data.db (21044055 bytes) for commitlog position ReplayPosition(segmentId=1360737579819, position=32199135)
INFO [CompactionExecutor:41571] 2013-02-14 14:24:36,684 CompactionTask.java (line 118) Compacting [SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2120-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2119-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2117-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2118-Data.db')]
INFO [CompactionExecutor:41571] 2013-02-14 14:25:12,234 CompactionTask.java (line 273) Compacted 4 sstables to [/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2121,]. 84,256,731 bytes to 84,334,086 (~100% of original) in 35,549ms = 2.262434MB/s. 14,432 total rows, 14,432 unique. Row merge counts were {1:14432, 2:0, 3:0, 4:0, }
INFO [OptionalTasks:1] 2013-02-14 14:25:57,115 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399232107 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:25:57,117 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@258318328(60628568/399232107 serialized/live bytes, 2165306 ops)
INFO [FlushWriter:1594] 2013-02-14 14:25:57,118 Memtable.java (line 447) Writing Memtable-Metrics@258318328(60628568/399232107 serialized/live bytes, 2165306 ops)
INFO [FlushWriter:1594] 2013-02-14 14:25:58,705 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2122-Data.db (21059731 bytes) for commitlog position ReplayPosition(segmentId=1360737579822, position=7758494)
INFO [OptionalTasks:1] 2013-02-14 14:27:19,129 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399218832 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:27:19,130 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@2026189692(60626552/399218832 serialized/live bytes, 2165234 ops)
INFO [FlushWriter:1595] 2013-02-14 14:27:19,131 Memtable.java (line 447) Writing Memtable-Metrics@2026189692(60626552/399218832 serialized/live bytes, 2165234 ops)
INFO [FlushWriter:1595] 2013-02-14 14:27:20,726 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2123-Data.db (21081156 bytes) for commitlog position ReplayPosition(segmentId=1360737579824, position=16830476)
INFO [OptionalTasks:1] 2013-02-14 14:28:41,143 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399214407 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:28:41,143 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@835031438(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1596] 2013-02-14 14:28:41,144 Memtable.java (line 447) Writing Memtable-Metrics@835031438(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1596] 2013-02-14 14:28:42,775 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2124-Data.db (21050393 bytes) for commitlog position ReplayPosition(segmentId=1360737579826, position=25891158)
INFO [OptionalTasks:1] 2013-02-14 14:30:03,156 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399214407 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:30:03,157 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@1604541794(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1597] 2013-02-14 14:30:03,158 Memtable.java (line 447) Writing Memtable-Metrics@1604541794(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1597] 2013-02-14 14:30:04,869 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2125-Data.db (21050877 bytes) for commitlog position ReplayPosition(segmentId=1360737579829, position=1405790)
INFO [CompactionExecutor:41657] 2013-02-14 14:30:04,870 CompactionTask.java (line 118) Compacting [SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2123-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2122-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2125-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2124-Data.db')]
INFO [CompactionExecutor:41657] 2013-02-14 14:30:40,416 CompactionTask.java (line 273) Compacted 4 sstables to [/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2126,]. 84,242,157 bytes to 84,305,839 (~100% of original) in 35,545ms = 2.261930MB/s. 14,432 total rows, 14,432 unique. Row merge counts were {1:14432, 2:0, 3:0, 4:0, }
INFO [OptionalTasks:1] 2013-02-14 14:31:25,169 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399240957 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:31:25,171 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@960476318(60629912/399240957 serialized/live bytes, 2165354 ops)
INFO [FlushWriter:1598] 2013-02-14 14:31:25,172 Memtable.java (line 447) Writing Memtable-Metrics@960476318(60629912/399240957 serialized/live bytes, 2165354 ops)
INFO [FlushWriter:1598] 2013-02-14 14:31:26,783 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2127-Data.db (21084189 bytes) for commitlog position ReplayPosition(segmentId=1360737579831, position=10480922)
INFO [OptionalTasks:1] 2013-02-14 14:32:47,183 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399238376 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:32:47,184 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@852152579(60629520/399238376 serialized/live bytes, 2165340 ops)
INFO [FlushWriter:1599] 2013-02-14 14:32:47,185 Memtable.java (line 447) Writing Memtable-Metrics@852152579(60629520/399238376 serialized/live bytes, 2165340 ops)
INFO [FlushWriter:1599] 2013-02-14 14:32:48,794 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2128-Data.db (21052579 bytes) for commitlog position ReplayPosition(segmentId=1360737579833, position=19561582)
INFO [OptionalTasks:1] 2013-02-14 14:34:09,197 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399229710 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:34:09,197 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@600711801(60628204/399229710 serialized/live bytes, 2165293 ops)
INFO [FlushWriter:1600] 2013-02-14 14:34:09,198 Memtable.java (line 447) Writing Memtable-Metrics@600711801(60628204/399229710 serialized/live bytes, 2165293 ops)
INFO [FlushWriter:1600] 2013-02-14 14:34:10,818 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2129-Data.db (21067262 bytes) for commitlog position ReplayPosition(segmentId=1360737579835, position=28636059)
INFO [OptionalTasks:1] 2013-02-14 14:35:31,238 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399221598 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:35:31,239 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@2104370804(60626972/399221598 serialized/live bytes, 2165249 ops)
INFO [FlushWriter:1601] 2013-02-14 14:35:31,240 Memtable.java (line 447) Writing Memtable-Metrics@2104370804(60626972/399221598 serialized/live bytes, 2165249 ops)
INFO [FlushWriter:1601] 2013-02-14 14:35:32,844 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2130-Data.db (21078893 bytes) for commitlog position ReplayPosition(segmentId=1360737579838, position=4177813)
INFO [CompactionExecutor:41742] 2013-02-14 14:35:32,845 CompactionTask.java (line 118) Compacting [SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2128-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2129-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2130-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2127-Data.db')]
INFO [CompactionExecutor:41742] 2013-02-14 14:36:08,384 CompactionTask.java (line 273) Compacted 4 sstables to [/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2131,]. 84,282,923 bytes to 84,299,440 (~100% of original) in 35,538ms = 2.262204MB/s. 14,432 total rows, 14,432 unique. Row merge counts were {1:14432, 2:0, 3:0, 4:0, }
INFO [CompactionExecutor:41767] 2013-02-14 14:36:08,385 CompactionTask.java (line 118) Compacting [SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2126-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2131-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2115-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2121-Data.db')]
INFO [OptionalTasks:1] 2013-02-14 14:36:53,252 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399229895 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:36:53,253 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@562526332(60628232/399229895 serialized/live bytes, 2165294 ops)
INFO [FlushWriter:1602] 2013-02-14 14:36:53,254 Memtable.java (line 447) Writing Memtable-Metrics@562526332(60628232/399229895 serialized/live bytes, 2165294 ops)
INFO [FlushWriter:1602] 2013-02-14 14:36:55,065 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2133-Data.db (21065439 bytes) for commitlog position ReplayPosition(segmentId=1360737579840, position=13247694)
INFO [OptionalTasks:1] 2013-02-14 14:38:15,266 MeteredFlusher.java (line 58) flushing high-traffic column family CFS(Keyspace='jetpack', ColumnFamily='Metrics') (estimated 399214407 bytes)
INFO [OptionalTasks:1] 2013-02-14 14:38:15,267 ColumnFamilyStore.java (line 640) Enqueuing flush of Memtable-Metrics@1048911247(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1603] 2013-02-14 14:38:15,268 Memtable.java (line 447) Writing Memtable-Metrics@1048911247(60625880/399214407 serialized/live bytes, 2165210 ops)
INFO [FlushWriter:1603] 2013-02-14 14:38:16,899 Memtable.java (line 481) Completed flushing /home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2134-Data.db (21065175 bytes) for commitlog position ReplayPosition(segmentId=1360737579842, position=22318066)
INFO [CompactionExecutor:41767] 2013-02-14 14:38:32,197 CompactionTask.java (line 273) Compacted 4 sstables to [/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2132,]. 337,297,607 bytes to 337,468,452 (~100% of original) in 143,810ms = 2.237918MB/s. 57,728 total rows, 57,728 unique. Row merge counts were {1:57728, 2:0, 3:0, 4:0, }
INFO [CompactionExecutor:41811] 2013-02-14 14:38:32,197 CompactionTask.java (line 118) Compacting [SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2110-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2132-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2068-Data.db'), SSTableReader(path='/home/cscotta/jetpack/cassandra/data/jetpack/Metrics/jetpack-Metrics-ib-2089-Data.db')]
ERROR [CompactionExecutor:41495] 2013-02-14 14:38:35,720 CassandraDaemon.java (line 133) Exception in thread Thread[CompactionExecutor:41495,1,RMI Runtime]
java.lang.AssertionError: Memory was freed
at org.apache.cassandra.io.util.Memory.checkPosition(Memory.java:146)
at org.apache.cassandra.io.util.Memory.getLong(Memory.java:116)
at org.apache.cassandra.io.compress.CompressionMetadata.chunkFor(CompressionMetadata.java:176)
at org.apache.cassandra.io.compress.CompressedRandomAccessReader.reBuffer(CompressedRandomAccessReader.java:88)
at org.apache.cassandra.io.util.RandomAccessReader.read(RandomAccessReader.java:327)
at java.io.RandomAccessFile.readInt(RandomAccessFile.java:755)
at java.io.RandomAccessFile.readLong(RandomAccessFile.java:792)
at org.apache.cassandra.utils.BytesReadTracker.readLong(BytesReadTracker.java:114)
at org.apache.cassandra.db.ColumnSerializer.deserializeColumnBody(ColumnSerializer.java:101)
at org.apache.cassandra.db.OnDiskAtom$Serializer.deserializeFromSSTable(OnDiskAtom.java:92)
at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumnsFromSSTable(ColumnFamilySerializer.java:149)
at org.apache.cassandra.io.sstable.SSTableIdentityIterator.getColumnFamilyWithColumns(SSTableIdentityIterator.java:235)
at org.apache.cassandra.db.compaction.PrecompactedRow.merge(PrecompactedRow.java:109)
at org.apache.cassandra.db.compaction.PrecompactedRow.<init>(PrecompactedRow.java:93)
at org.apache.cassandra.db.compaction.CompactionController.getCompactedRow(CompactionController.java:162)
at org.apache.cassandra.db.compaction.CompactionIterable$Reducer.getReduced(CompactionIterable.java:76)
at org.apache.cassandra.db.compaction.CompactionIterable$Reducer.getReduced(CompactionIterable.java:57)
at org.apache.cassandra.utils.MergeIterator$ManyToOne.consume(MergeIterator.java:114)
at org.apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.java:97)
at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143)
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
at org.apache.cassandra.db.compaction.CompactionTask.runWith(CompactionTask.java:158)
at org.apache.cassandra.io.util.DiskAwareRunnable.runMayThrow(DiskAwareRunnable.java:48)
at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28)
at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:71)
at org.apache.cassandra.db.compaction.CompactionManager$6.runMayThrow(CompactionManager.java:342)
at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)