IGNITE-9859 Add debug logging on refreshPartitions cause - Fixes #5801.
authorMax Shonichev <mshonich@yandex.ru>
Tue, 25 Dec 2018 11:01:50 +0000 (14:01 +0300)
committerDmitriy Govorukhin <dmitriy.govorukhin@gmail.com>
Fri, 11 Jan 2019 13:38:30 +0000 (16:38 +0300)
Signed-off-by: Dmitriy Govorukhin <dmitriy.govorukhin@gmail.com>
modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCachePartitionExchangeManager.java
modules/core/src/main/java/org/apache/ignite/internal/processors/cache/WalStateManager.java
modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionsExchangeFuture.java

index d2304d4..525c41a 100644 (file)
@@ -44,6 +44,7 @@ import java.util.concurrent.atomic.AtomicReference;
 import java.util.concurrent.locks.ReadWriteLock;
 import java.util.concurrent.locks.ReentrantReadWriteLock;
 import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.IgniteLogger;
 import org.apache.ignite.IgniteSystemProperties;
 import org.apache.ignite.cache.affinity.AffinityFunction;
 import org.apache.ignite.cluster.ClusterNode;
@@ -1104,6 +1105,9 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
     public void refreshPartitions(@NotNull Collection<CacheGroupContext> grps) {
         // TODO https://issues.apache.org/jira/browse/IGNITE-6857
         if (cctx.snapshot().snapshotOperationInProgress()) {
+            if (log.isDebugEnabled())
+                log.debug("Schedule resend parititions due to snapshot in progress");
+
             scheduleResendPartitions();
 
             return;
@@ -1709,8 +1713,12 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
                     }
                 }
 
-                if (!cctx.kernalContext().clientNode() && updated)
+                if (!cctx.kernalContext().clientNode() && updated) {
+                    if (log.isDebugEnabled())
+                        log.debug("Refresh partitions due to topology update");
+
                     refreshPartitions();
+                }
 
                 boolean hasMovingParts = false;
 
@@ -2973,8 +2981,12 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
                                 changed |= grp.topology().afterExchange(exchFut);
                             }
 
-                            if (!cctx.kernalContext().clientNode() && changed && !hasPendingServerExchange())
+                            if (!cctx.kernalContext().clientNode() && changed && !hasPendingServerExchange()) {
+                                if (log.isDebugEnabled())
+                                    log.debug("Refresh partitions due to mapping was changed");
+
                                 refreshPartitions();
+                            }
                         }
 
                         // Schedule rebalance if force rebalance or force reassign occurs.
@@ -3137,12 +3149,22 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
         /** Timeout ID. */
         private final IgniteUuid timeoutId = IgniteUuid.randomUuid();
 
+        /** Logger. */
+        protected final IgniteLogger log;
+
         /** Timeout start time. */
         private final long createTime = U.currentTimeMillis();
 
         /** Started flag. */
         private AtomicBoolean started = new AtomicBoolean();
 
+        /**
+         *
+         */
+        private ResendTimeoutObject() {
+            this.log = cctx.logger(getClass());
+        }
+
         /** {@inheritDoc} */
         @Override public IgniteUuid timeoutId() {
             return timeoutId;
@@ -3161,8 +3183,12 @@ public class GridCachePartitionExchangeManager<K, V> extends GridCacheSharedMana
                         return;
 
                     try {
-                        if (started.compareAndSet(false, true))
+                        if (started.compareAndSet(false, true)) {
+                            if (log.isDebugEnabled())
+                                log.debug("Refresh partitions due to scheduled timeout");
+
                             refreshPartitions();
+                        }
                     }
                     finally {
                         busyLock.readLock().unlock();
index 83c548e..9d962db 100644 (file)
@@ -514,6 +514,9 @@ public class WalStateManager extends GridCacheSharedManagerAdapter {
 
                     }
 
+                    if (log.isDebugEnabled())
+                        log.debug("Refresh partitions due to rebalance finished");
+
                     cctx.exchange().refreshPartitions();
                 }
             });
index b53fe99..bce239c 100644 (file)
@@ -2118,8 +2118,13 @@ public class GridDhtPartitionsExchangeFuture extends GridDhtTopologyFutureAdapte
 
                 }
 
-                if (!grpToRefresh.isEmpty())
+                if (!grpToRefresh.isEmpty()){
+                    if (log.isDebugEnabled())
+                        log.debug("Refresh partitions due to partitions initialized when affinity ready [" +
+                            grpToRefresh.stream().map(CacheGroupContext::name).collect(Collectors.toList()) + ']');
+
                     cctx.exchange().refreshPartitions(grpToRefresh);
+                }
             }
 
             for (GridCacheContext cacheCtx : cctx.cacheContexts()) {