You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by ak...@apache.org on 2017/06/12 15:33:35 UTC
[21/62] [abbrv] ignite git commit: ignite-5125 Do not limit number of
hanging objects dumps, instead increase time between dumps.
ignite-5125 Do not limit number of hanging objects dumps, instead increase time between dumps.
Project: http://git-wip-us.apache.org/repos/asf/ignite/repo
Commit: http://git-wip-us.apache.org/repos/asf/ignite/commit/808ad9fe
Tree: http://git-wip-us.apache.org/repos/asf/ignite/tree/808ad9fe
Diff: http://git-wip-us.apache.org/repos/asf/ignite/diff/808ad9fe
Branch: refs/heads/ignite-5239
Commit: 808ad9fe4b339dbe86ae96c1915c5aa5ea0521c7
Parents: ec5c3a2
Author: Evgeny Stanilovskiy <es...@gridgain.com>
Authored: Tue Jun 6 17:58:44 2017 +0300
Committer: sboikov <sb...@gridgain.com>
Committed: Tue Jun 6 17:58:44 2017 +0300
----------------------------------------------------------------------
.../apache/ignite/IgniteSystemProperties.java | 3 +
.../GridCachePartitionExchangeManager.java | 129 ++++++++++---------
.../dht/GridDhtPartitionTopologyImpl.java | 6 +-
.../GridDhtPartitionsExchangeFuture.java | 56 +++++---
4 files changed, 117 insertions(+), 77 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/ignite/blob/808ad9fe/modules/core/src/main/java/org/apache/ignite/IgniteSystemProperties.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/IgniteSystemProperties.java b/modules/core/src/main/java/org/apache/ignite/IgniteSystemProperties.java
index ea4b690..84f3732 100644
--- a/modules/core/src/main/java/org/apache/ignite/IgniteSystemProperties.java
+++ b/modules/core/src/main/java/org/apache/ignite/IgniteSystemProperties.java
@@ -451,6 +451,9 @@ public final class IgniteSystemProperties {
/** Cache operations that take more time than value of this property will be output to log. Set to {@code 0} to disable. */
public static final String IGNITE_LONG_OPERATIONS_DUMP_TIMEOUT = "IGNITE_LONG_OPERATIONS_DUMP_TIMEOUT";
+ /** Upper time limit between long running/hanging operations debug dumps. */
+ public static final String IGNITE_LONG_OPERATIONS_DUMP_TIMEOUT_LIMIT = "IGNITE_LONG_OPERATIONS_DUMP_TIMEOUT_LIMIT";
+
/** JDBC driver cursor remove delay. */
public static final String IGNITE_JDBC_DRIVER_CURSOR_REMOVE_DELAY = "IGNITE_JDBC_DRIVER_CURSOR_RMV_DELAY";
http://git-wip-us.apache.org/repos/asf/ignite/blob/808ad9fe/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCachePartitionExchangeManager.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCachePartitionExchangeManager.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCachePartitionExchangeManager.java
index 2d1aa05..2be4d0f 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCachePartitionExchangeManager.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCachePartitionExchangeManager.java
@@ -110,6 +110,7 @@ import static org.apache.ignite.events.EventType.EVT_NODE_LEFT;
import static org.apache.ignite.internal.GridTopic.TOPIC_CACHE;
import static org.apache.ignite.internal.events.DiscoveryCustomEvent.EVT_DISCOVERY_CUSTOM_EVT;
import static org.apache.ignite.internal.managers.communication.GridIoPolicy.SYSTEM_POOL;
+import static org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.*;
import static org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPreloader.DFLT_PRELOAD_RESEND_TIMEOUT;
/**
@@ -175,7 +176,10 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
private volatile IgniteCheckedException stopErr;
/** */
- private int longRunningOpsDumpCnt;
+ private long nextLongRunningOpsDumpTime;
+
+ /** */
+ private int longRunningOpsDumpStep;
/** */
private DateFormat dateFormat = new SimpleDateFormat("HH:mm:ss.SSS");
@@ -1405,84 +1409,83 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
/**
* @param timeout Operation timeout.
+ * @return {@code True} if found long running operations.
*/
- public void dumpLongRunningOperations(long timeout) {
- try {
- GridDhtPartitionsExchangeFuture lastFut = lastInitializedFut;
+ private boolean dumpLongRunningOperations0(long timeout) {
+ long curTime = U.currentTimeMillis();
- // If exchange is in progress it will dump all hanging operations if any.
- if (lastFut != null && !lastFut.isDone())
- return;
-
- long curTime = U.currentTimeMillis();
+ boolean found = false;
- boolean found = false;
+ IgniteTxManager tm = cctx.tm();
- IgniteTxManager tm = cctx.tm();
+ GridCacheMvccManager mvcc = cctx.mvcc();
- if (tm != null) {
- for (IgniteInternalTx tx : tm.activeTransactions()) {
- if (curTime - tx.startTime() > timeout) {
- found = true;
+ if (tm != null) {
+ for (IgniteInternalTx tx : tm.activeTransactions()) {
+ if (curTime - tx.startTime() > timeout) {
+ found = true;
- if (longRunningOpsDumpCnt < GridDhtPartitionsExchangeFuture.DUMP_PENDING_OBJECTS_THRESHOLD) {
- U.warn(log, "Found long running transaction [startTime=" + formatTime(tx.startTime()) +
- ", curTime=" + formatTime(curTime) + ", tx=" + tx + ']');
- }
- else
- break;
- }
+ U.warn(log, "Found long running transaction [startTime=" + formatTime(tx.startTime()) +
+ ", curTime=" + formatTime(curTime) + ", tx=" + tx + ']');
}
}
+ }
- GridCacheMvccManager mvcc = cctx.mvcc();
-
- if (mvcc != null) {
- for (GridCacheFuture<?> fut : mvcc.activeFutures()) {
- if (curTime - fut.startTime() > timeout) {
- found = true;
+ if (mvcc != null) {
+ for (GridCacheFuture<?> fut : mvcc.activeFutures()) {
+ if (curTime - fut.startTime() > timeout) {
+ found = true;
- if (longRunningOpsDumpCnt < GridDhtPartitionsExchangeFuture.DUMP_PENDING_OBJECTS_THRESHOLD) {
- U.warn(log, "Found long running cache future [startTime=" + formatTime(fut.startTime()) +
- ", curTime=" + formatTime(curTime) + ", fut=" + fut + ']');
- }
- else
- break;
- }
+ U.warn(log, "Found long running cache future [startTime=" + formatTime(fut.startTime()) +
+ ", curTime=" + formatTime(curTime) + ", fut=" + fut + ']');
}
+ }
- for (GridCacheFuture<?> fut : mvcc.atomicFutures()) {
- if (curTime - fut.startTime() > timeout) {
- found = true;
+ for (GridCacheFuture<?> fut : mvcc.atomicFutures()) {
+ if (curTime - fut.startTime() > timeout) {
+ found = true;
- if (longRunningOpsDumpCnt < GridDhtPartitionsExchangeFuture.DUMP_PENDING_OBJECTS_THRESHOLD) {
- U.warn(log, "Found long running cache future [startTime=" + formatTime(fut.startTime()) +
- ", curTime=" + formatTime(curTime) + ", fut=" + fut + ']');
- }
- else
- break;
- }
+ U.warn(log, "Found long running cache future [startTime=" + formatTime(fut.startTime()) +
+ ", curTime=" + formatTime(curTime) + ", fut=" + fut + ']');
}
}
+ }
- if (found) {
- if (longRunningOpsDumpCnt < GridDhtPartitionsExchangeFuture.DUMP_PENDING_OBJECTS_THRESHOLD) {
- longRunningOpsDumpCnt++;
+ return found;
+ }
- if (IgniteSystemProperties.getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false)) {
- U.warn(log, "Found long running cache operations, dump threads.");
+ /**
+ * @param timeout Operation timeout.
+ */
+ public void dumpLongRunningOperations(long timeout) {
+ try {
+ GridDhtPartitionsExchangeFuture lastFut = lastInitializedFut;
- U.dumpThreads(log);
- }
+ // If exchange is in progress it will dump all hanging operations if any.
+ if (lastFut != null && !lastFut.isDone())
+ return;
- U.warn(log, "Found long running cache operations, dump IO statistics.");
+ if (U.currentTimeMillis() < nextLongRunningOpsDumpTime)
+ return;
- // Dump IO manager statistics.
- cctx.gridIO().dumpStats();
+ if (dumpLongRunningOperations0(timeout)) {
+ nextLongRunningOpsDumpTime = U.currentTimeMillis() + nextDumpTimeout(longRunningOpsDumpStep++, timeout);
+
+ if (IgniteSystemProperties.getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false)) {
+ U.warn(log, "Found long running cache operations, dump threads.");
+
+ U.dumpThreads(log);
}
+
+ U.warn(log, "Found long running cache operations, dump IO statistics.");
+
+ // Dump IO manager statistics.
+ cctx.gridIO().dumpStats();
+ }
+ else {
+ nextLongRunningOpsDumpTime = 0;
+ longRunningOpsDumpStep = 0;
}
- else
- longRunningOpsDumpCnt = 0;
}
catch (Exception e) {
U.error(log, "Failed to dump debug information: " + e, e);
@@ -1774,11 +1777,15 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
exchFut.init();
- int dumpedObjects = 0;
+ int dumpCnt = 0;
+
+ final long futTimeout = 2 * cctx.gridConfig().getNetworkTimeout();
+
+ long nextDumpTime = 0;
while (true) {
try {
- exchFut.get(2 * cctx.gridConfig().getNetworkTimeout(), TimeUnit.MILLISECONDS);
+ exchFut.get(futTimeout, TimeUnit.MILLISECONDS);
break;
}
@@ -1788,7 +1795,7 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
", node=" + cctx.localNodeId() + "]. " +
"Dumping pending objects that might be the cause: ");
- if (dumpedObjects < GridDhtPartitionsExchangeFuture.DUMP_PENDING_OBJECTS_THRESHOLD) {
+ if (nextDumpTime <= U.currentTimeMillis()) {
try {
dumpDebugInfo(exchFut.topologyVersion());
}
@@ -1799,7 +1806,7 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
if (IgniteSystemProperties.getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false))
U.dumpThreads(log);
- dumpedObjects++;
+ nextDumpTime = U.currentTimeMillis() + nextDumpTimeout(dumpCnt++, futTimeout);
}
}
catch (Exception e) {
http://git-wip-us.apache.org/repos/asf/ignite/blob/808ad9fe/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtPartitionTopologyImpl.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtPartitionTopologyImpl.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtPartitionTopologyImpl.java
index 248d44e..89554f3 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtPartitionTopologyImpl.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtPartitionTopologyImpl.java
@@ -80,6 +80,10 @@ public class GridDhtPartitionTopologyImpl implements GridDhtPartitionTopology {
private static final boolean FULL_MAP_DEBUG = false;
/** */
+ private static final int DUMP_PENDING_OBJECTS_THRESHOLD =
+ IgniteSystemProperties.getInteger(IgniteSystemProperties.IGNITE_DUMP_PENDING_OBJECTS_THRESHOLD, 10);
+
+ /** */
private static final Long ZERO = 0L;
/** */
@@ -234,7 +238,7 @@ public class GridDhtPartitionTopologyImpl implements GridDhtPartitionTopology {
break;
}
catch (IgniteFutureTimeoutCheckedException ignored) {
- if (dumpCnt++ < GridDhtPartitionsExchangeFuture.DUMP_PENDING_OBJECTS_THRESHOLD) {
+ if (dumpCnt++ < DUMP_PENDING_OBJECTS_THRESHOLD) {
U.warn(log, "Failed to wait for partition eviction [" +
"topVer=" + topVer +
", group=" + grp.cacheOrGroupName() +
http://git-wip-us.apache.org/repos/asf/ignite/blob/808ad9fe/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionsExchangeFuture.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionsExchangeFuture.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionsExchangeFuture.java
index 0c5cdd9..26406c6 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionsExchangeFuture.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionsExchangeFuture.java
@@ -35,7 +35,6 @@ import java.util.concurrent.atomic.AtomicReference;
import java.util.concurrent.locks.ReadWriteLock;
import org.apache.ignite.IgniteCheckedException;
import org.apache.ignite.IgniteLogger;
-import org.apache.ignite.IgniteSystemProperties;
import org.apache.ignite.cache.PartitionLossPolicy;
import org.apache.ignite.cluster.ClusterNode;
import org.apache.ignite.events.CacheEvent;
@@ -90,7 +89,10 @@ import org.apache.ignite.lang.IgniteRunnable;
import org.jetbrains.annotations.Nullable;
import org.jsr166.ConcurrentHashMap8;
+import static org.apache.ignite.IgniteSystemProperties.IGNITE_LONG_OPERATIONS_DUMP_TIMEOUT_LIMIT;
import static org.apache.ignite.IgniteSystemProperties.IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT;
+import static org.apache.ignite.IgniteSystemProperties.getBoolean;
+import static org.apache.ignite.IgniteSystemProperties.getLong;
import static org.apache.ignite.cache.PartitionLossPolicy.READ_ONLY_ALL;
import static org.apache.ignite.cache.PartitionLossPolicy.READ_ONLY_SAFE;
import static org.apache.ignite.cache.PartitionLossPolicy.READ_WRITE_ALL;
@@ -107,10 +109,6 @@ import static org.apache.ignite.internal.managers.communication.GridIoPolicy.SYS
@SuppressWarnings({"TypeMayBeWeakened", "unchecked"})
public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityTopologyVersion>
implements Comparable<GridDhtPartitionsExchangeFuture>, GridDhtTopologyFuture, CachePartitionExchangeWorkerTask {
- /** */
- public static final int DUMP_PENDING_OBJECTS_THRESHOLD =
- IgniteSystemProperties.getInteger(IgniteSystemProperties.IGNITE_DUMP_PENDING_OBJECTS_THRESHOLD, 10);
-
/** Dummy flag. */
private final boolean dummy;
@@ -880,20 +878,24 @@ public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityT
if (log.isDebugEnabled())
log.debug("Before waiting for partition release future: " + this);
- int dumpedObjects = 0;
+ int dumpCnt = 0;
+
+ long nextDumpTime = 0;
+
+ long futTimeout = 2 * cctx.gridConfig().getNetworkTimeout();
while (true) {
try {
- partReleaseFut.get(2 * cctx.gridConfig().getNetworkTimeout(), TimeUnit.MILLISECONDS);
+ partReleaseFut.get(futTimeout, TimeUnit.MILLISECONDS);
break;
}
catch (IgniteFutureTimeoutCheckedException ignored) {
// Print pending transactions and locks that might have led to hang.
- if (dumpedObjects < DUMP_PENDING_OBJECTS_THRESHOLD) {
+ if (nextDumpTime <= U.currentTimeMillis()) {
dumpPendingObjects();
- dumpedObjects++;
+ nextDumpTime = U.currentTimeMillis() + nextDumpTimeout(dumpCnt++, futTimeout);
}
}
}
@@ -903,16 +905,17 @@ public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityT
IgniteInternalFuture<?> locksFut = cctx.mvcc().finishLocks(exchId.topologyVersion());
- dumpedObjects = 0;
+ nextDumpTime = 0;
+ dumpCnt = 0;
while (true) {
try {
- locksFut.get(2 * cctx.gridConfig().getNetworkTimeout(), TimeUnit.MILLISECONDS);
+ locksFut.get(futTimeout, TimeUnit.MILLISECONDS);
break;
}
catch (IgniteFutureTimeoutCheckedException ignored) {
- if (dumpedObjects < DUMP_PENDING_OBJECTS_THRESHOLD) {
+ if (nextDumpTime <= U.currentTimeMillis()) {
U.warn(log, "Failed to wait for locks release future. " +
"Dumping pending objects that might be the cause: " + cctx.localNodeId());
@@ -930,9 +933,9 @@ public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityT
for (Map.Entry<IgniteTxKey, Collection<GridCacheMvccCandidate>> e : locks.entrySet())
U.warn(log, "Awaited locked entry [key=" + e.getKey() + ", mvcc=" + e.getValue() + ']');
- dumpedObjects++;
+ nextDumpTime = U.currentTimeMillis() + nextDumpTimeout(dumpCnt++, futTimeout);
- if (IgniteSystemProperties.getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false))
+ if (getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false))
U.dumpThreads(log);
}
}
@@ -1026,7 +1029,7 @@ public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityT
U.error(log, "Failed to dump debug information: " + e, e);
}
- if (IgniteSystemProperties.getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false))
+ if (getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false))
U.dumpThreads(log);
}
@@ -2195,4 +2198,27 @@ public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityT
return S.toString(CounterWithNodes.class, this);
}
}
+
+ /**
+ * @param step Exponent coefficient.
+ * @param timeout Base timeout.
+ * @return Time to wait before next debug dump.
+ */
+ public static long nextDumpTimeout(int step, long timeout) {
+ long limit = getLong(IGNITE_LONG_OPERATIONS_DUMP_TIMEOUT_LIMIT, 30 * 60_000);
+
+ if (limit <= 0)
+ limit = 30 * 60_000;
+
+ assert step >= 0 : step;
+
+ long dumpFactor = Math.round(Math.pow(2, step));
+
+ long nextTimeout = timeout * dumpFactor;
+
+ if (nextTimeout <= 0)
+ return limit;
+
+ return nextTimeout <= limit ? nextTimeout : limit;
+ }
}