You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Sean Thornton (JIRA)" <ji...@apache.org> on 2015/08/11 16:47:46 UTC

[jira] [Commented] (CASSANDRA-9882) DTCS (maybe other strategies) can block flushing when there are lots of sstables

    [ https://issues.apache.org/jira/browse/CASSANDRA-9882?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14681893#comment-14681893 ] 

Sean Thornton commented on CASSANDRA-9882:
------------------------------------------

Also have seen this behavior under LCS.  Again with a cluster that had 150-200K sstables.  First thread below executed for a very, very long time and held onto a lock that blocked flushes and compactions (and some jmx methods).  Glanced at the code and saw some nested loops each going through all sstables but didn't look deeper than that.

Cut down stack -
{quote}
"CompactionExecutor:12" daemon prio=10 tid=0x00002ad7735244a0 nid=0x81f6 runnable [0x00002ad7beb60000]
   java.lang.Thread.State: RUNNABLE
	at org.apache.cassandra.dht.Bounds.intersects(Bounds.java:67)
	at org.apache.cassandra.db.compaction.LeveledManifest.overlapping(LeveledManifest.java:459)
	at org.apache.cassandra.db.compaction.LeveledManifest.overlapping(LeveledManifest.java:445)
	at org.apache.cassandra.db.compaction.LeveledManifest.getCandidatesFor(LeveledManifest.java:520)
	at org.apache.cassandra.db.compaction.LeveledManifest.getCompactionCandidates(LeveledManifest.java:307)
	- locked <0x00000006b02c9a30> (a org.apache.cassandra.db.compaction.LeveledManifest)
	at org.apache.cassandra.db.compaction.LeveledCompactionStrategy.getMaximalTask(LeveledCompactionStrategy.java:121)
	at org.apache.cassandra.db.compaction.LeveledCompactionStrategy.getNextBackgroundTask(LeveledCompactionStrategy.java:113)
	- locked <0x00000006b0315410> (a org.apache.cassandra.db.compaction.LeveledCompactionStrategy)
	at org.apache.cassandra.db.compaction.CompactionManager$BackgroundCompactionTask.run(CompactionManager.java:192)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x0000000739a196c0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"FlushWriter:26" daemon prio=10 tid=0x00002ad697d84210 nid=0x941f waiting for monitor entry [0x00002ad7bfb5f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.apache.cassandra.db.compaction.LeveledManifest.add(LeveledManifest.java:118)
	- waiting to lock <0x00000006b02c9a30> (a org.apache.cassandra.db.compaction.LeveledManifest)
	at org.apache.cassandra.db.compaction.LeveledCompactionStrategy.handleNotification(LeveledCompactionStrategy.java:181)
	at org.apache.cassandra.db.DataTracker.notifyAdded(DataTracker.java:461)
	at org.apache.cassandra.db.DataTracker.replaceFlushed(DataTracker.java:179)
	at org.apache.cassandra.db.compaction.AbstractCompactionStrategy.replaceFlushed(AbstractCompactionStrategy.java:231)
	at org.apache.cassandra.db.ColumnFamilyStore.replaceFlushed(ColumnFamilyStore.java:1151)
	at org.apache.cassandra.db.Memtable$FlushRunnable.runMayThrow(Memtable.java:346)
	at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x00000006c8c12568> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"CompactionExecutor:15" daemon prio=10 tid=0x00002ad697eb9640 nid=0x81fa waiting for monitor entry [0x00002ad7bea5c000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.apache.cassandra.db.compaction.LeveledManifest.replace(LeveledManifest.java:128)
	- waiting to lock <0x00000006b02c9a30> (a org.apache.cassandra.db.compaction.LeveledManifest)
	at org.apache.cassandra.db.compaction.LeveledCompactionStrategy.handleNotification(LeveledCompactionStrategy.java:186)
	at org.apache.cassandra.db.DataTracker.notifySSTablesChanged(DataTracker.java:454)
	at org.apache.cassandra.db.DataTracker.replaceCompactedSSTables(DataTracker.java:267)
	at org.apache.cassandra.db.ColumnFamilyStore.replaceCompactedSSTables(ColumnFamilyStore.java:1146)
	at org.apache.cassandra.db.compaction.CompactionTask.replaceCompactedSSTables(CompactionTask.java:330)
	at org.apache.cassandra.db.compaction.CompactionTask.runMayThrow(CompactionTask.java:254)
	at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28)
	at org.apache.cassandra.db.compaction.CompactionTask.executeInternal(CompactionTask.java:60)
	at org.apache.cassandra.db.compaction.AbstractCompactionTask.execute(AbstractCompactionTask.java:59)
	at org.apache.cassandra.db.compaction.CompactionManager$BackgroundCompactionTask.run(CompactionManager.java:198)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x00000007399e4110> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"CompactionExecutor:11" daemon prio=10 tid=0x00002ad773523ed0 nid=0x81f5 waiting on condition [0x00002ad7beba1000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007976adaf0> (a java.util.concurrent.FutureTask)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
	at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:425)
	at java.util.concurrent.FutureTask.get(FutureTask.java:187)
	at org.apache.cassandra.utils.FBUtilities.waitOnFuture(FBUtilities.java:409)
	at org.apache.cassandra.db.SystemKeyspace.forceBlockingFlush(SystemKeyspace.java:459)
	at org.apache.cassandra.db.SystemKeyspace.finishCompaction(SystemKeyspace.java:205)
	at org.apache.cassandra.db.compaction.CompactionTask.runMayThrow(CompactionTask.java:237)
	at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28)
	at org.apache.cassandra.db.compaction.CompactionTask.executeInternal(CompactionTask.java:60)
	at org.apache.cassandra.db.compaction.AbstractCompactionTask.execute(AbstractCompactionTask.java:59)
	at org.apache.cassandra.db.compaction.CompactionManager$BackgroundCompactionTask.run(CompactionManager.java:198)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x00000007399c4a60> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"RMI TCP Connection(130)-10.129.124.20" daemon prio=10 tid=0x00002ad5d8598750 nid=0xc054 waiting for monitor entry [0x00002ad7bdce5000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.apache.cassandra.db.compaction.LeveledManifest.getEstimatedTasks(LeveledManifest.java:620)
	- waiting to lock <0x00000006b02c9a30> (a org.apache.cassandra.db.compaction.LeveledManifest)
	at org.apache.cassandra.db.compaction.LeveledCompactionStrategy.getEstimatedRemainingTasks(LeveledCompactionStrategy.java:173)
	at org.apache.cassandra.metrics.CompactionMetrics$1.value(CompactionMetrics.java:64)
	at org.apache.cassandra.metrics.CompactionMetrics$1.value(CompactionMetrics.java:57)
  ....
{quote}

> DTCS (maybe other strategies) can block flushing when there are lots of sstables
> --------------------------------------------------------------------------------
>
>                 Key: CASSANDRA-9882
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-9882
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core
>            Reporter: Jeremiah Jordan
>            Assignee: Marcus Eriksson
>              Labels: dtcs
>             Fix For: 2.1.x, 2.2.x
>
>
> MemtableFlushWriter tasks can get blocked by Compaction getNextBackgroundTask.  This is in a wonky cluster with 200k sstables in the CF, but seems bad for flushing to be blocked by getNextBackgroundTask when we are trying to make these new "smart" strategies that may take some time to calculate what to do.
> {noformat}
> "MemtableFlushWriter:21" daemon prio=10 tid=0x00007ff7ad965000 nid=0x6693 waiting for monitor entry [0x00007ff78a667000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
> 	at org.apache.cassandra.db.compaction.WrappingCompactionStrategy.handleNotification(WrappingCompactionStrategy.java:237)
> 	- waiting to lock <0x00000006fcdbbf60> (a org.apache.cassandra.db.compaction.WrappingCompactionStrategy)
> 	at org.apache.cassandra.db.DataTracker.notifyAdded(DataTracker.java:518)
> 	at org.apache.cassandra.db.DataTracker.replaceFlushed(DataTracker.java:178)
> 	at org.apache.cassandra.db.compaction.AbstractCompactionStrategy.replaceFlushed(AbstractCompactionStrategy.java:234)
> 	at org.apache.cassandra.db.ColumnFamilyStore.replaceFlushed(ColumnFamilyStore.java:1475)
> 	at org.apache.cassandra.db.Memtable$FlushRunnable.runMayThrow(Memtable.java:336)
> 	at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28)
> 	at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:297)
> 	at org.apache.cassandra.db.ColumnFamilyStore$Flush.run(ColumnFamilyStore.java:1127)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> 	at java.lang.Thread.run(Thread.java:745)
>    Locked ownable synchronizers:
> 	- <0x0000000743b3ac38> (a java.util.concurrent.ThreadPoolExecutor$Worker)
> "MemtableFlushWriter:19" daemon prio=10 tid=0x00007ff7ac57a000 nid=0x649b waiting for monitor entry [0x00007ff78b8ee000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
> 	at org.apache.cassandra.db.compaction.WrappingCompactionStrategy.handleNotification(WrappingCompactionStrategy.java:237)
> 	- waiting to lock <0x00000006fcdbbf60> (a org.apache.cassandra.db.compaction.WrappingCompactionStrategy)
> 	at org.apache.cassandra.db.DataTracker.notifyAdded(DataTracker.java:518)
> 	at org.apache.cassandra.db.DataTracker.replaceFlushed(DataTracker.java:178)
> 	at org.apache.cassandra.db.compaction.AbstractCompactionStrategy.replaceFlushed(AbstractCompactionStrategy.java:234)
> 	at org.apache.cassandra.db.ColumnFamilyStore.replaceFlushed(ColumnFamilyStore.java:1475)
> 	at org.apache.cassandra.db.Memtable$FlushRunnable.runMayThrow(Memtable.java:336)
> 	at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28)
> 	at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:297)
> 	at org.apache.cassandra.db.ColumnFamilyStore$Flush.run(ColumnFamilyStore.java:1127)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> 	at java.lang.Thread.run(Thread.java:745)
> "CompactionExecutor:14" daemon prio=10 tid=0x00007ff7ad359800 nid=0x4d59 runnable [0x00007fecce3ea000]
>    java.lang.Thread.State: RUNNABLE
> 	at org.apache.cassandra.io.sstable.SSTableReader.equals(SSTableReader.java:628)
> 	at com.google.common.collect.ImmutableSet.construct(ImmutableSet.java:206)
> 	at com.google.common.collect.ImmutableSet.construct(ImmutableSet.java:220)
> 	at com.google.common.collect.ImmutableSet.access$000(ImmutableSet.java:74)
> 	at com.google.common.collect.ImmutableSet$Builder.build(ImmutableSet.java:531)
> 	at com.google.common.collect.Sets$1.immutableCopy(Sets.java:606)
> 	at org.apache.cassandra.db.ColumnFamilyStore.getOverlappingSSTables(ColumnFamilyStore.java:1352)
> 	at org.apache.cassandra.db.compaction.DateTieredCompactionStrategy.getNextBackgroundSSTables(DateTieredCompactionStrategy.java:88)
> 	at org.apache.cassandra.db.compaction.DateTieredCompactionStrategy.getNextBackgroundTask(DateTieredCompactionStrategy.java:65)
> 	- locked <0x00000006fcdbbf00> (a org.apache.cassandra.db.compaction.DateTieredCompactionStrategy)
> 	at org.apache.cassandra.db.compaction.WrappingCompactionStrategy.getNextBackgroundTask(WrappingCompactionStrategy.java:72)
> 	- locked <0x00000006fcdbbf60> (a org.apache.cassandra.db.compaction.WrappingCompactionStrategy)
> 	at org.apache.cassandra.db.compaction.CompactionManager$BackgroundCompactionTask.run(CompactionManager.java:238)
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> 	at java.lang.Thread.run(Thread.java:745)
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)