You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by sb...@apache.org on 2017/08/01 15:09:09 UTC

ignite git commit: debug

Repository: ignite
Updated Branches:
  refs/heads/ignite-5578-debug [created] 3ec06329d


debug


Project: http://git-wip-us.apache.org/repos/asf/ignite/repo
Commit: http://git-wip-us.apache.org/repos/asf/ignite/commit/3ec06329
Tree: http://git-wip-us.apache.org/repos/asf/ignite/tree/3ec06329
Diff: http://git-wip-us.apache.org/repos/asf/ignite/diff/3ec06329

Branch: refs/heads/ignite-5578-debug
Commit: 3ec06329d88f1c3eef491fd886b378082a4628df
Parents: d6b2420
Author: sboikov <sb...@gridgain.com>
Authored: Tue Aug 1 17:38:51 2017 +0300
Committer: sboikov <sb...@gridgain.com>
Committed: Tue Aug 1 17:43:41 2017 +0300

----------------------------------------------------------------------
 .../java/org/apache/ignite/TestDebugLog.java    | 52 ++++++++++++++++++++
 .../affinity/GridAffinityAssignmentCache.java   | 11 +++++
 .../processors/cache/GridCacheMapEntry.java     |  7 +++
 .../distributed/dht/GridDhtLocalPartition.java  |  4 ++
 .../dht/GridDhtPartitionTopologyImpl.java       | 13 +++++
 .../distributed/dht/GridDhtTxPrepareFuture.java |  3 ++
 .../dht/preloader/GridDhtPartitionDemander.java |  4 ++
 .../dht/preloader/GridDhtPreloader.java         |  4 ++
 .../near/GridNearOptimisticTxPrepareFuture.java |  3 ++
 ...ePrimaryNodeFailureRecoveryAbstractTest.java | 19 +++++--
 10 files changed, 117 insertions(+), 3 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/TestDebugLog.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/TestDebugLog.java b/modules/core/src/main/java/org/apache/ignite/TestDebugLog.java
index 94c5eb2..7cde562 100644
--- a/modules/core/src/main/java/org/apache/ignite/TestDebugLog.java
+++ b/modules/core/src/main/java/org/apache/ignite/TestDebugLog.java
@@ -161,6 +161,58 @@ public class TestDebugLog {
         }
     }
 
+    public static void printKeyAndPartMessages(boolean file, Object key, Integer part) {
+        List<Object> msgs0;
+
+        synchronized (msgs) {
+            msgs0 = new ArrayList<>(msgs);
+
+            msgs.clear();
+        }
+
+        if (file) {
+            try {
+                FileOutputStream out = new FileOutputStream("test_debug.log");
+
+                PrintWriter w = new PrintWriter(out);
+
+                for (Object msg : msgs0) {
+                    if (msg instanceof PartMessage) {
+                        if (((PartMessage) msg).p != part)
+                            continue;
+                    }
+                    if (msg instanceof EntryMessage) {
+                        if (!((EntryMessage) msg).key.equals(key))
+                            continue;
+                    }
+
+                    w.println(msg.toString());
+                }
+
+                w.close();
+
+                out.close();
+            }
+            catch (IOException e) {
+                e.printStackTrace();
+            }
+        }
+        else {
+            for (Object msg : msgs0) {
+                if (msg instanceof PartMessage) {
+                    if (((PartMessage) msg).p != part)
+                        continue;
+                }
+                if (msg instanceof EntryMessage) {
+                    if (!((EntryMessage) msg).key.equals(key))
+                        continue;
+                }
+
+                System.out.println(msg.toString());
+            }
+        }
+    }
+
     public static void printKeyMessages(boolean file, Object key) {
         List<Object> msgs0;
 

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/internal/processors/affinity/GridAffinityAssignmentCache.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/affinity/GridAffinityAssignmentCache.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/affinity/GridAffinityAssignmentCache.java
index c60a690..377161d 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/affinity/GridAffinityAssignmentCache.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/affinity/GridAffinityAssignmentCache.java
@@ -32,6 +32,7 @@ import java.util.concurrent.atomic.AtomicReference;
 import org.apache.ignite.IgniteCheckedException;
 import org.apache.ignite.IgniteException;
 import org.apache.ignite.IgniteLogger;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cache.affinity.AffinityCentralizedFunction;
 import org.apache.ignite.cache.affinity.AffinityFunction;
 import org.apache.ignite.cluster.ClusterNode;
@@ -201,6 +202,11 @@ public class GridAffinityAssignmentCache {
             }
         }
 
+        if ("default".equals(cacheOrGrpName)) {
+            for (int p = 0; p < affAssignment.size(); p++)
+                TestDebugLog.addPartMessage(p, U.nodeIds(assignment.get(p)), "aff new init " + topVer);
+        }
+
         onHistoryAdded(assignment);
     }
 
@@ -293,6 +299,11 @@ public class GridAffinityAssignmentCache {
             assignment = aff.assignPartitions(new GridAffinityFunctionContextImpl(sorted, prevAssignment, discoEvt,
                 topVer, backups));
 
+        if ("default".equals(cacheOrGrpName)) {
+            for (int p = 0; p < assignment.size(); p++)
+                TestDebugLog.addPartMessage(p, U.nodeIds(assignment.get(p)), "aff new calc " + topVer);
+        }
+
         assert assignment != null;
 
         idealAssignment = assignment;

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheMapEntry.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheMapEntry.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheMapEntry.java
index 2a6a109..2ca5a08 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheMapEntry.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheMapEntry.java
@@ -32,6 +32,7 @@ import org.apache.ignite.IgniteCache;
 import org.apache.ignite.IgniteCheckedException;
 import org.apache.ignite.IgniteException;
 import org.apache.ignite.IgniteLogger;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cache.eviction.EvictableEntry;
 import org.apache.ignite.internal.pagemem.wal.StorageException;
 import org.apache.ignite.internal.pagemem.wal.record.DataEntry;
@@ -883,6 +884,8 @@ public abstract class GridCacheMapEntry extends GridMetadataAwareAdapter impleme
     ) throws IgniteCheckedException, GridCacheEntryRemovedException {
         CacheObject old;
 
+        TestDebugLog.addEntryMessage(key.value(null, false), val.value(cctx.cacheObjectContext(), false), "innerSet");
+
         boolean valid = valid(tx != null ? tx.topologyVersion() : topVer);
 
         // Lock should be held by now.
@@ -2523,6 +2526,8 @@ public abstract class GridCacheMapEntry extends GridMetadataAwareAdapter impleme
     ) throws IgniteCheckedException, GridCacheEntryRemovedException {
         ensureFreeSpace();
 
+        TestDebugLog.addEntryMessage(key.value(null, false), val.value(cctx.cacheObjectContext(), false), "initialVal");
+
         synchronized (this) {
             checkObsolete();
 
@@ -3218,6 +3223,8 @@ public abstract class GridCacheMapEntry extends GridMetadataAwareAdapter impleme
     protected void removeValue() throws IgniteCheckedException {
         assert Thread.holdsLock(this);
 
+        TestDebugLog.addEntryMessage(key.value(null, false), val != null ? val.value(cctx.cacheObjectContext(), false) : null, "remove value");
+
         cctx.offheap().remove(cctx, key, partition(), localPartition());
     }
 

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtLocalPartition.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtLocalPartition.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtLocalPartition.java
index b739bdd..aa00be9 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtLocalPartition.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtLocalPartition.java
@@ -31,6 +31,7 @@ import java.util.concurrent.locks.ReentrantLock;
 import org.apache.ignite.IgniteCheckedException;
 import org.apache.ignite.IgniteException;
 import org.apache.ignite.IgniteLogger;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cluster.ClusterNode;
 import org.apache.ignite.internal.IgniteInternalFuture;
 import org.apache.ignite.internal.NodeStoppingException;
@@ -558,6 +559,9 @@ public class GridDhtLocalPartition extends GridCacheConcurrentMapImpl implements
                 boolean update = this.state.compareAndSet(state, setPartState(state, toState));
 
                 if (update)
+                    if (grp.cacheOrGroupName().equals("default"))
+                        TestDebugLog.addPartMessage(id, toState, "set state");
+
                     try {
                         ctx.wal().log(new PartitionMetaStateRecord(grp.groupId(), id, toState, updateCounter()));
                     }

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/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 5af4fef..222ab91 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
@@ -32,6 +32,7 @@ import java.util.concurrent.atomic.AtomicReferenceArray;
 import org.apache.ignite.IgniteCheckedException;
 import org.apache.ignite.IgniteException;
 import org.apache.ignite.IgniteLogger;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cache.PartitionLossPolicy;
 import org.apache.ignite.cluster.ClusterNode;
 import org.apache.ignite.events.DiscoveryEvent;
@@ -350,6 +351,9 @@ public class GridDhtPartitionTopologyImpl implements GridDhtPartitionTopology {
 
                             boolean owned = locPart.own();
 
+                            if (grp.cacheOrGroupName().equals("default"))
+                                TestDebugLog.addPartMessage(p, "own start", "owned");
+
                             assert owned : "Failed to own partition for oldest node [grp=" + grp.cacheOrGroupName() +
                                 ", part=" + locPart + ']';
 
@@ -619,6 +623,9 @@ public class GridDhtPartitionTopologyImpl implements GridDhtPartitionTopology {
                                 assert owned : "Failed to own partition [grp=" + grp.cacheOrGroupName() + ", locPart=" +
                                     locPart + ']';
 
+                                if (grp.cacheOrGroupName().equals("default"))
+                                    TestDebugLog.addPartMessage(p, "own after", "owned");
+
                                 updateSeq = updateLocal(p, locPart.state(), updateSeq, topVer);
 
                                 changed = true;
@@ -1737,6 +1744,9 @@ public class GridDhtPartitionTopologyImpl implements GridDhtPartitionTopology {
                     GridDhtLocalPartition locPart = localPartition(part, resTopVer, false);
 
                     if (locPart != null) {
+                        if (grp.cacheOrGroupName().equals("default"))
+                            TestDebugLog.addPartMessage(locPart.id(), "detect loss", "owned");
+
                         boolean marked = plc == PartitionLossPolicy.IGNORE ? locPart.own() : locPart.markLost();
 
                         if (marked)
@@ -1794,6 +1804,9 @@ public class GridDhtPartitionTopologyImpl implements GridDhtPartitionTopology {
                     if (locPart != null && locPart.state() == LOST) {
                         boolean marked = locPart.own();
 
+                        if (grp.cacheOrGroupName().equals("default"))
+                            TestDebugLog.addPartMessage(locPart.id(), "reset lost", "owned");
+
                         if (marked)
                             updateLocal(locPart.id(), locPart.state(), updSeq, resTopVer);
                     }

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtTxPrepareFuture.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtTxPrepareFuture.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtTxPrepareFuture.java
index a31c540..576d2bc 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtTxPrepareFuture.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/GridDhtTxPrepareFuture.java
@@ -35,6 +35,7 @@ import javax.cache.processor.EntryProcessor;
 import org.apache.ignite.IgniteCheckedException;
 import org.apache.ignite.IgniteInterruptedException;
 import org.apache.ignite.IgniteLogger;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cluster.ClusterNode;
 import org.apache.ignite.internal.IgniteDiagnosticAware;
 import org.apache.ignite.internal.IgniteDiagnosticPrepareContext;
@@ -1512,6 +1513,8 @@ public final class GridDhtTxPrepareFuture extends GridCacheCompoundFuture<Ignite
 
                 assert dhtNodes.size() > 0 && dhtNodes.get(0).id().equals(cctx.localNodeId()) : dhtNodes;
 
+                TestDebugLog.addEntryMessage(cached.key().value(null, false), U.nodeIds(dhtNodes), "dht mapped");
+
                 if (log.isDebugEnabled())
                     log.debug("Mapping entry to DHT nodes [nodes=" + U.toShortString(dhtNodes) +
                         ", entry=" + entry + ']');

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionDemander.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionDemander.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionDemander.java
index 248b739..697a9dd 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionDemander.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPartitionDemander.java
@@ -30,6 +30,7 @@ import java.util.UUID;
 import java.util.concurrent.atomic.AtomicReference;
 import org.apache.ignite.IgniteCheckedException;
 import org.apache.ignite.IgniteLogger;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cache.CacheRebalanceMode;
 import org.apache.ignite.cluster.ClusterNode;
 import org.apache.ignite.configuration.CacheConfiguration;
@@ -683,6 +684,9 @@ public class GridDhtPartitionDemander {
                                 if (supply.isClean(p))
                                     part.updateCounter(supply.last().get(p));
 
+                                if (grp.cacheOrGroupName().equals("default"))
+                                    TestDebugLog.addPartMessage(p, "last supply", "owned");
+
                                 top.own(part);
 
                                 fut.partitionDone(id, p);

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPreloader.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPreloader.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPreloader.java
index 11d9c77..94afad3 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPreloader.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/preloader/GridDhtPreloader.java
@@ -28,6 +28,7 @@ import java.util.concurrent.atomic.AtomicInteger;
 import java.util.concurrent.locks.ReadWriteLock;
 import java.util.concurrent.locks.ReentrantReadWriteLock;
 import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cluster.ClusterNode;
 import org.apache.ignite.internal.IgniteFutureTimeoutCheckedException;
 import org.apache.ignite.internal.IgniteInternalFuture;
@@ -291,6 +292,9 @@ public class GridDhtPreloader extends GridCachePreloaderAdapter {
                     if (picked.isEmpty()) {
                         top.own(part);
 
+                        if (grp.cacheOrGroupName().equals("default"))
+                            TestDebugLog.addPartMessage(p, "no picked", "owned");
+
                         if (grp.eventRecordable(EVT_CACHE_REBALANCE_PART_DATA_LOST)) {
                             grp.addRebalanceEvent(p,
                                 EVT_CACHE_REBALANCE_PART_DATA_LOST,

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearOptimisticTxPrepareFuture.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearOptimisticTxPrepareFuture.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearOptimisticTxPrepareFuture.java
index 2c23a7a..0f59bcd 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearOptimisticTxPrepareFuture.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearOptimisticTxPrepareFuture.java
@@ -28,6 +28,7 @@ import java.util.Set;
 import java.util.UUID;
 import java.util.concurrent.atomic.AtomicIntegerFieldUpdater;
 import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cluster.ClusterNode;
 import org.apache.ignite.cluster.ClusterTopologyException;
 import org.apache.ignite.internal.IgniteInternalFuture;
@@ -656,6 +657,8 @@ public class GridNearOptimisticTxPrepareFuture extends GridNearOptimisticTxPrepa
             return null;
         }
 
+        TestDebugLog.addEntryMessage(entry.key().value(null, false), U.nodeIds(nodes), "near mapped");
+
         txMapping.addMapping(nodes);
 
         ClusterNode primary = F.first(nodes);

http://git-wip-us.apache.org/repos/asf/ignite/blob/3ec06329/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/distributed/dht/IgniteCachePrimaryNodeFailureRecoveryAbstractTest.java
----------------------------------------------------------------------
diff --git a/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/distributed/dht/IgniteCachePrimaryNodeFailureRecoveryAbstractTest.java b/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/distributed/dht/IgniteCachePrimaryNodeFailureRecoveryAbstractTest.java
index 0d0cda4..7391978 100644
--- a/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/distributed/dht/IgniteCachePrimaryNodeFailureRecoveryAbstractTest.java
+++ b/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/distributed/dht/IgniteCachePrimaryNodeFailureRecoveryAbstractTest.java
@@ -27,6 +27,7 @@ import org.apache.ignite.IgniteException;
 import org.apache.ignite.IgniteIllegalStateException;
 import org.apache.ignite.IgniteLogger;
 import org.apache.ignite.IgniteTransactions;
+import org.apache.ignite.TestDebugLog;
 import org.apache.ignite.cache.CacheAtomicityMode;
 import org.apache.ignite.cache.CacheMode;
 import org.apache.ignite.cache.affinity.Affinity;
@@ -413,6 +414,8 @@ public abstract class IgniteCachePrimaryNodeFailureRecoveryAbstractTest extends
 
         checkKey(key1, rollback ? null : key1Nodes);
         checkKey(key2, rollback ? null : key2Nodes);
+
+        TestDebugLog.clear();
     }
 
     /**
@@ -443,8 +446,6 @@ public abstract class IgniteCachePrimaryNodeFailureRecoveryAbstractTest extends
                     found = true;
 
                     ignite.cache(DEFAULT_CACHE_NAME);
-
-                    assertEquals("Unexpected value for: " + ignite.name(), key, key);
                 }
                 catch (IgniteIllegalStateException ignore) {
                     // No-op.
@@ -456,7 +457,19 @@ public abstract class IgniteCachePrimaryNodeFailureRecoveryAbstractTest extends
             for (Ignite ignite : G.allGrids()) {
                 IgniteCache<Integer, Integer> cache = ignite.cache(DEFAULT_CACHE_NAME);
 
-                assertEquals("Unexpected value for: " + ignite.name(), key, cache.get(key));
+                TestDebugLog.addEntryMessage(key, ignite.name(), "start get");
+
+                Object v = cache.get(key);
+
+                if (!key.equals(v)) {
+                    TestDebugLog.addEntryMessage(key, v, "invalid value " + ignite.name());
+
+                    TestDebugLog.printKeyAndPartMessages(false, key, ignite.affinity(DEFAULT_CACHE_NAME).partition(key));
+
+                    System.exit(1);
+                }
+
+                //assertEquals("Unexpected value for: " + ignite.name(), key, cache.get(key));
             }
         }
     }