Repository: incubator-ignite Updated Branches: refs/heads/ignite-157-debug 7eaf87561 -> f3286d18d
# ignite-157-debug Project: http://git-wip-us.apache.org/repos/asf/incubator-ignite/repo Commit: http://git-wip-us.apache.org/repos/asf/incubator-ignite/commit/f3286d18 Tree: http://git-wip-us.apache.org/repos/asf/incubator-ignite/tree/f3286d18 Diff: http://git-wip-us.apache.org/repos/asf/incubator-ignite/diff/f3286d18 Branch: refs/heads/ignite-157-debug Commit: f3286d18de3333c8515f819f5da040d3f3855634 Parents: 7eaf875 Author: sboikov <sboi...@gridgain.com> Authored: Tue Apr 28 10:08:06 2015 +0300 Committer: sboikov <sboi...@gridgain.com> Committed: Tue Apr 28 10:08:06 2015 +0300 ---------------------------------------------------------------------- .../processors/cache/GridCacheIoManager.java | 3 +++ .../GridDhtPartitionsExchangeFuture.java | 6 +++++ .../cache/transactions/IgniteTxAdapter.java | 9 +++++++ .../cache/transactions/IgniteTxManager.java | 16 ++++++++++++ .../GridCacheAbstractFailoverSelfTest.java | 27 ++++++++++++++++++-- 5 files changed, 59 insertions(+), 2 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/incubator-ignite/blob/f3286d18/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheIoManager.java ---------------------------------------------------------------------- diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheIoManager.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheIoManager.java index b8668e6..9f046e6 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheIoManager.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheIoManager.java @@ -226,6 +226,9 @@ public class GridCacheIoManager extends GridCacheSharedManagerAdapter { unmarshall(nodeId, cacheMsg); + if (!cacheMsg.partitionExchangeMessage()) + TestDebugLog.addMessage("Message: " + cacheMsg); + if (cacheMsg.allowForStartup()) processMessage(nodeId, cacheMsg, c); else { http://git-wip-us.apache.org/repos/asf/incubator-ignite/blob/f3286d18/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 45d332c..e6d9d54 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 @@ -705,6 +705,12 @@ public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityT for (GridCacheFuture<?> fut : cctx.mvcc().atomicFutures()) U.warn(log, ">>> " + fut); + + TestDebugLog.addMessage("Release timeout"); + + TestDebugLog.printMessages(false); + + System.exit(1); } /** http://git-wip-us.apache.org/repos/asf/incubator-ignite/blob/f3286d18/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxAdapter.java ---------------------------------------------------------------------- diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxAdapter.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxAdapter.java index 1c02356..371ea83 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxAdapter.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxAdapter.java @@ -280,6 +280,8 @@ public abstract class IgniteTxAdapter extends GridMetadataAwareAdapter threadId = Thread.currentThread().getId(); log = U.logger(cctx.kernalContext(), logRef, this); + + TestDebugLog.addMessage("Created1 " + this.getClass().getSimpleName()); } /** @@ -332,6 +334,8 @@ public abstract class IgniteTxAdapter extends GridMetadataAwareAdapter loc = false; log = U.logger(cctx.kernalContext(), logRef, this); + + TestDebugLog.addMessage("Created2 " + this.getClass().getSimpleName()); } /** {@inheritDoc} */ @@ -1102,6 +1106,8 @@ public abstract class IgniteTxAdapter extends GridMetadataAwareAdapter if (log.isDebugEnabled()) log.debug("Changed transaction state [prev=" + prev + ", new=" + this.state + ", tx=" + this + ']'); + TestDebugLog.addMessage("Changed transaction state [prev=" + prev + ", new=" + this.state + ", tx=" + this + ']'); + // Notify of state change. signalAll(); } @@ -1109,6 +1115,9 @@ public abstract class IgniteTxAdapter extends GridMetadataAwareAdapter if (log.isDebugEnabled()) log.debug("Invalid transaction state transition [invalid=" + state + ", cur=" + this.state + ", tx=" + this + ']'); + + TestDebugLog.addMessage("Invalid transaction state transition [invalid=" + state + ", cur=" + this.state + + ", tx=" + this + ']'); } } finally { http://git-wip-us.apache.org/repos/asf/incubator-ignite/blob/f3286d18/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxManager.java ---------------------------------------------------------------------- diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxManager.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxManager.java index c494602..cc70c38 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxManager.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxManager.java @@ -177,6 +177,8 @@ public class IgniteTxManager extends GridCacheSharedManagerAdapter { private boolean salvageTx(IgniteInternalTx tx, boolean warn, IgniteInternalTx.FinalizationStatus status) { assert tx != null; + TestDebugLog.addMessage("Salvage tx"); + TransactionState state = tx.state(); if (state == ACTIVE || state == PREPARING || state == PREPARED) { @@ -1788,6 +1790,8 @@ public class IgniteTxManager extends GridCacheSharedManagerAdapter { IgniteInternalFuture<IgniteInternalTx> prepFut = tx.currentPrepareFuture(); if (prepFut != null && !prepFut.isDone()) { + log.info("Wait prepare txsPreparedOrCommitted " + tx); + if (log.isDebugEnabled()) log.debug("Transaction is preparing (will wait): " + tx); @@ -2050,6 +2054,8 @@ public class IgniteTxManager extends GridCacheSharedManagerAdapter { } try { + TestDebugLog.addMessage("Node failure timeout"); + if (log.isDebugEnabled()) log.debug("Processing node failed event [locNodeId=" + cctx.localNodeId() + ", failedNodeId=" + evtNodeId + ']'); @@ -2068,6 +2074,8 @@ public class IgniteTxManager extends GridCacheSharedManagerAdapter { IgniteInternalFuture<IgniteInternalTx> prepFut = tx.currentPrepareFuture(); if (prepFut != null) { + log.info("Wait when prepared node timeout " + tx); + prepFut.listen(new CI1<IgniteInternalFuture<IgniteInternalTx>>() { @Override public void apply(IgniteInternalFuture<IgniteInternalTx> fut) { if (tx.state() == PREPARED) @@ -2078,16 +2086,22 @@ public class IgniteTxManager extends GridCacheSharedManagerAdapter { }); } else { + log.info("Try rollback " + tx); + // If we could not mark tx as rollback, it means that transaction is being committed. if (tx.setRollbackOnly()) tx.rollbackAsync(); } } } + else + TestDebugLog.addMessage("Skip tx " + tx); } } } finally { + TestDebugLog.addMessage("Node failure timeout done"); + cctx.kernalContext().gateway().readUnlock(); } } @@ -2103,6 +2117,8 @@ public class IgniteTxManager extends GridCacheSharedManagerAdapter { assert !F.isEmpty(tx.transactionNodes()) : tx; assert tx.nearXidVersion() != null : tx; + log.info("Commit if prepared " + tx); + GridCacheOptimisticCheckPreparedTxFuture fut = new GridCacheOptimisticCheckPreparedTxFuture<>( cctx, tx, http://git-wip-us.apache.org/repos/asf/incubator-ignite/blob/f3286d18/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/GridCacheAbstractFailoverSelfTest.java ---------------------------------------------------------------------- diff --git a/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/GridCacheAbstractFailoverSelfTest.java b/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/GridCacheAbstractFailoverSelfTest.java index 0a0baf5..7e05388 100644 --- a/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/GridCacheAbstractFailoverSelfTest.java +++ b/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/GridCacheAbstractFailoverSelfTest.java @@ -87,6 +87,7 @@ public abstract class GridCacheAbstractFailoverSelfTest extends GridCacheAbstrac /** {@inheritDoc} */ @Override protected void beforeTestsStarted() throws Exception { // No-op + System.setProperty(IgniteSystemProperties.IGNITE_NO_SHUTDOWN_HOOK, "true"); } /** {@inheritDoc} */ @@ -104,6 +105,8 @@ public abstract class GridCacheAbstractFailoverSelfTest extends GridCacheAbstrac /** {@inheritDoc} */ @Override protected void afterTest() throws Exception { stopAllGrids(); + + TestDebugLog.clear(); } /** @@ -185,8 +188,12 @@ public abstract class GridCacheAbstractFailoverSelfTest extends GridCacheAbstrac info("Topology change " + i); try { + TestDebugLog.addMessage("Start node " + name); + final Ignite g = startGrid(name); + TestDebugLog.addMessage("Started node " + name + " " + g.cluster().localNode().id()); + IgniteCache<String, Object> cache = g.<String, Object>cache(null).withAsync(); for (int k = half; k < ENTRY_CNT; k++) { @@ -198,6 +205,8 @@ public abstract class GridCacheAbstractFailoverSelfTest extends GridCacheAbstrac } } finally { + TestDebugLog.addMessage("Stop node " + name + " " + G.ignite(name).cluster().localNode().id()); + G.stop(name, false); } } @@ -272,14 +281,21 @@ public abstract class GridCacheAbstractFailoverSelfTest extends GridCacheAbstrac try { info("Putting values to cache [0," + cnt + ')'); + TestDebugLog.addMessage("Putting values to cache [0," + cnt + ')'); + CU.inTx(ignite, cache, concurrency, isolation, new CIX1<IgniteCache<String, Integer>>() { - @Override public void applyx(IgniteCache<String, Integer> cache) { + @Override + public void applyx(IgniteCache<String, Integer> cache) { for (int i = 0; i < cnt; i++) cache.put("key" + i, i); } }); + + TestDebugLog.addMessage("Put done"); } catch (Exception e) { + TestDebugLog.addMessage("Put error: " + e); + // It is ok to fail with topology exception. if (!X.hasCause(e, ClusterTopologyCheckedException.class)) throw e; @@ -317,14 +333,21 @@ public abstract class GridCacheAbstractFailoverSelfTest extends GridCacheAbstrac try { info("Removing values form cache [0," + cnt + ')'); + TestDebugLog.addMessage("Removing values form cache [0," + cnt + ')'); + CU.inTx(ignite, cache, concurrency, isolation, new CIX1<IgniteCache<String, Integer>>() { - @Override public void applyx(IgniteCache<String, Integer> cache) { + @Override + public void applyx(IgniteCache<String, Integer> cache) { for (int i = 0; i < cnt; i++) cache.remove("key" + i); } }); + + TestDebugLog.addMessage("Removing done"); } catch (Exception e) { + TestDebugLog.addMessage("Removing error: " + e); + // It is ok to fail with topology exception. if (!X.hasCause(e, ClusterTopologyCheckedException.class)) throw e;
