You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by ag...@apache.org on 2016/07/06 18:23:28 UTC
[29/50] [abbrv] ignite git commit: ignite-3336 Added properties
IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT,
IGNITE_LONG_OPERATIONS_DUMP_TIMEOUT. Refactored cache message logging. (cherry
picked from commit 8ed13e8)
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicCache.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicCache.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicCache.java
index 9291153..561c6c6 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicCache.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicCache.java
@@ -37,6 +37,7 @@ import javax.cache.processor.EntryProcessor;
import javax.cache.processor.EntryProcessorResult;
import org.apache.ignite.IgniteCheckedException;
import org.apache.ignite.IgniteException;
+import org.apache.ignite.IgniteLogger;
import org.apache.ignite.cluster.ClusterNode;
import org.apache.ignite.internal.IgniteInternalFuture;
import org.apache.ignite.internal.NodeStoppingException;
@@ -148,6 +149,9 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
/** */
private GridNearAtomicCache<K, V> near;
+ /** Logger. */
+ private IgniteLogger msgLog;
+
/**
* Empty constructor required by {@link Externalizable}.
*/
@@ -160,6 +164,8 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
*/
public GridDhtAtomicCache(GridCacheContext<K, V> ctx) {
super(ctx);
+
+ msgLog = ctx.shared().atomicMessageLogger();
}
/**
@@ -168,6 +174,8 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
*/
public GridDhtAtomicCache(GridCacheContext<K, V> ctx, GridCacheConcurrentMap map) {
super(ctx, map);
+
+ msgLog = ctx.shared().atomicMessageLogger();
}
/** {@inheritDoc} */
@@ -1581,7 +1589,8 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
ClusterNode node = ctx.discovery().node(nodeId);
if (node == null) {
- U.warn(log, "Node originated update request left grid: " + nodeId);
+ U.warn(msgLog, "Skip near update request, node originated update request left [" +
+ "futId=" + req.futureVersion() + ", node=" + nodeId + ']');
return;
}
@@ -1596,14 +1605,15 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
if (hasNear)
res.nearVersion(ver);
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Assigned update version [futId=" + req.futureVersion() +
+ ", writeVer=" + ver + ']');
+ }
}
assert ver != null : "Got null version for update request: " + req;
- if (log.isDebugEnabled())
- log.debug("Using cache version for update request on primary node [ver=" + ver +
- ", req=" + req + ']');
-
boolean sndPrevVal = !top.rebalanceFinished(req.topologyVersion());
dhtFut = createDhtFuture(ver, req, res, completionCb, false);
@@ -2020,8 +2030,8 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
old,
req.keepBinary()),
ctx.unwrapBinaryIfNeeded(
- updated,
- req.keepBinary(),
+ updated,
+ req.keepBinary(),
false));
if (val == null)
@@ -2929,8 +2939,11 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
* @param req Near atomic update request.
*/
private void processNearAtomicUpdateRequest(UUID nodeId, GridNearAtomicUpdateRequest req) {
- if (log.isDebugEnabled())
- log.debug("Processing near atomic update request [nodeId=" + nodeId + ", req=" + req + ']');
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Received near atomic update request [futId=" + req.futureVersion() +
+ ", writeVer=" + req.updateVersion() +
+ ", node=" + nodeId + ']');
+ }
req.nodeId(ctx.localNodeId());
@@ -2943,8 +2956,8 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
*/
@SuppressWarnings("unchecked")
private void processNearAtomicUpdateResponse(UUID nodeId, GridNearAtomicUpdateResponse res) {
- if (log.isDebugEnabled())
- log.debug("Processing near atomic update response [nodeId=" + nodeId + ", res=" + res + ']');
+ if (msgLog.isDebugEnabled())
+ msgLog.debug("Received near atomic update response [futId" + res.futureVersion() + ", node=" + nodeId + ']');
res.nodeId(ctx.localNodeId());
@@ -2958,8 +2971,8 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
((GridNearAtomicUpdateFuture)fut).onResult(nodeId, res, false);
}
else
- U.warn(log, "Failed to find near update future for update response (will ignore) " +
- "[nodeId=" + nodeId + ", res=" + res + ']');
+ U.warn(msgLog, "Failed to find near update future for update response (will ignore) " +
+ "[futId" + res.futureVersion() + ", node=" + nodeId + ", res=" + res + ']');
}
/**
@@ -2967,8 +2980,10 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
* @param req Dht atomic update request.
*/
private void processDhtAtomicUpdateRequest(UUID nodeId, GridDhtAtomicUpdateRequest req) {
- if (log.isDebugEnabled())
- log.debug("Processing dht atomic update request [nodeId=" + nodeId + ", req=" + req + ']');
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Received DHT atomic update request [futId=" + req.futureVersion() +
+ ", writeVer=" + req.writeVersion() + ", node=" + nodeId + ']');
+ }
GridCacheVersion ver = req.writeVersion();
@@ -3066,20 +3081,31 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
((GridNearAtomicCache<K, V>)near()).processDhtAtomicUpdateRequest(nodeId, req, res);
try {
- if (res.failedKeys() != null || res.nearEvicted() != null || req.writeSynchronizationMode() == FULL_SYNC)
+ if (res.failedKeys() != null || res.nearEvicted() != null || req.writeSynchronizationMode() == FULL_SYNC) {
ctx.io().send(nodeId, res, ctx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Sent DHT atomic update response [futId=" + req.futureVersion() +
+ ", writeVer=" + req.writeVersion() + ", node=" + nodeId + ']');
+ }
+ }
else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Will send deferred DHT atomic update response [futId=" + req.futureVersion() +
+ ", writeVer=" + req.writeVersion() + ", node=" + nodeId + ']');
+ }
+
// No failed keys and sync mode is not FULL_SYNC, thus sending deferred response.
sendDeferredUpdateResponse(nodeId, req.futureVersion());
}
}
catch (ClusterTopologyCheckedException ignored) {
- U.warn(log, "Failed to send DHT atomic update response to node because it left grid: " +
- req.nodeId());
+ U.warn(msgLog, "Failed to send DHT atomic update response, node left [futId=" + req.futureVersion() +
+ ", node=" + req.nodeId() + ']');
}
catch (IgniteCheckedException e) {
- U.error(log, "Failed to send DHT atomic update response (did node leave grid?) [nodeId=" + nodeId +
- ", req=" + req + ']', e);
+ U.error(msgLog, "Failed to send DHT atomic update response [futId=" + req.futureVersion() +
+ ", node=" + nodeId + ", res=" + res + ']', e);
}
}
@@ -3118,16 +3144,20 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
*/
@SuppressWarnings("unchecked")
private void processDhtAtomicUpdateResponse(UUID nodeId, GridDhtAtomicUpdateResponse res) {
- if (log.isDebugEnabled())
- log.debug("Processing dht atomic update response [nodeId=" + nodeId + ", res=" + res + ']');
-
GridDhtAtomicUpdateFuture updateFut = (GridDhtAtomicUpdateFuture)ctx.mvcc().atomicFuture(res.futureVersion());
- if (updateFut != null)
+ if (updateFut != null) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Received DHT atomic update response [futId=" + res.futureVersion() +
+ ", writeVer=" + updateFut.writeVersion() + ", node=" + nodeId + ']');
+ }
+
updateFut.onResult(nodeId, res);
- else
- U.warn(log, "Failed to find DHT update future for update response [nodeId=" + nodeId +
- ", res=" + res + ']');
+ }
+ else {
+ U.warn(msgLog, "Failed to find DHT update future for update response [futId=" + res.futureVersion() +
+ ", node=" + nodeId + ", res=" + res + ']');
+ }
}
/**
@@ -3136,17 +3166,21 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
*/
@SuppressWarnings("unchecked")
private void processDhtAtomicDeferredUpdateResponse(UUID nodeId, GridDhtAtomicDeferredUpdateResponse res) {
- if (log.isDebugEnabled())
- log.debug("Processing deferred dht atomic update response [nodeId=" + nodeId + ", res=" + res + ']');
-
for (GridCacheVersion ver : res.futureVersions()) {
GridDhtAtomicUpdateFuture updateFut = (GridDhtAtomicUpdateFuture)ctx.mvcc().atomicFuture(ver);
- if (updateFut != null)
+ if (updateFut != null) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Received DHT atomic deferred update response [futId=" + ver +
+ ", writeVer=" + res + ", node=" + nodeId + ']');
+ }
+
updateFut.onResult(nodeId);
- else
- U.warn(log, "Failed to find DHT update future for deferred update response [nodeId=" +
- nodeId + ", ver=" + ver + ", res=" + res + ']');
+ }
+ else {
+ U.warn(msgLog, "Failed to find DHT update future for deferred update response [futId=" + ver +
+ ", nodeId=" + nodeId + ", res=" + res + ']');
+ }
}
}
@@ -3157,14 +3191,19 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
private void sendNearUpdateReply(UUID nodeId, GridNearAtomicUpdateResponse res) {
try {
ctx.io().send(nodeId, res, ctx.ioPolicy());
+
+ if (msgLog.isDebugEnabled())
+ msgLog.debug("Sent near update response [futId=" + res.futureVersion() + ", node=" + nodeId + ']');
}
catch (ClusterTopologyCheckedException ignored) {
- U.warn(log, "Failed to send near update reply to node because it left grid: " +
- nodeId);
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Failed to send near update response [futId=" + res.futureVersion() +
+ ", node=" + nodeId + ']');
+ }
}
catch (IgniteCheckedException e) {
- U.error(log, "Failed to send near update reply (did node leave grid?) [nodeId=" + nodeId +
- ", res=" + res + ']', e);
+ U.error(msgLog, "Failed to send near update response [futId=" + res.futureVersion() +
+ ", node=" + nodeId + ", res=" + res + ']', e);
}
}
@@ -3434,24 +3473,31 @@ public class GridDhtAtomicCache<K, V> extends GridDhtCacheAdapter<K, V> {
try {
ctx.io().send(nodeId, msg, ctx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Sent deferred DHT update response [futIds=" + msg.futureVersions() +
+ ", node=" + nodeId + ']');
+ }
}
finally {
ctx.kernalContext().gateway().readUnlock();
}
}
catch (IllegalStateException ignored) {
- if (log.isDebugEnabled())
- log.debug("Failed to send deferred dht update response to remote node (grid is stopping) " +
- "[nodeId=" + nodeId + ", msg=" + msg + ']');
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Failed to send deferred DHT update response, node is stopping [" +
+ "futIds=" + msg.futureVersions() + ", node=" + nodeId + ']');
+ }
}
catch (ClusterTopologyCheckedException ignored) {
- if (log.isDebugEnabled())
- log.debug("Failed to send deferred dht update response to remote node (did node leave grid?) " +
- "[nodeId=" + nodeId + ", msg=" + msg + ']');
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Failed to send deferred DHT update response, node left [" +
+ "futIds=" + msg.futureVersions() + ", node=" + nodeId + ']');
+ }
}
catch (IgniteCheckedException e) {
- U.error(log, "Failed to send deferred dht update response to remote node [nodeId="
- + nodeId + ", msg=" + msg + ']', e);
+ U.error(log, "Failed to send deferred DHT update response to remote node [" +
+ "futIds=" + msg.futureVersions() + ", node=" + nodeId + ']', e);
}
pendingResponses.remove(nodeId, this);
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicDeferredUpdateResponse.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicDeferredUpdateResponse.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicDeferredUpdateResponse.java
index 3a7bf1c..923b220 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicDeferredUpdateResponse.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicDeferredUpdateResponse.java
@@ -20,9 +20,11 @@ package org.apache.ignite.internal.processors.cache.distributed.dht.atomic;
import java.io.Externalizable;
import java.nio.ByteBuffer;
import java.util.Collection;
+import org.apache.ignite.IgniteLogger;
import org.apache.ignite.internal.GridDirectCollection;
import org.apache.ignite.internal.processors.cache.GridCacheDeployable;
import org.apache.ignite.internal.processors.cache.GridCacheMessage;
+import org.apache.ignite.internal.processors.cache.GridCacheSharedContext;
import org.apache.ignite.internal.processors.cache.version.GridCacheVersion;
import org.apache.ignite.internal.util.typedef.F;
import org.apache.ignite.plugin.extensions.communication.MessageCollectionItemType;
@@ -83,6 +85,11 @@ public class GridDhtAtomicDeferredUpdateResponse extends GridCacheMessage implem
}
/** {@inheritDoc} */
+ @Override public IgniteLogger messageLogger(GridCacheSharedContext ctx) {
+ return ctx.atomicMessageLogger();
+ }
+
+ /** {@inheritDoc} */
@Override public boolean writeTo(ByteBuffer buf, MessageWriter writer) {
writer.setBuffer(buf);
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateFuture.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateFuture.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateFuture.java
index 570f043..4e59d11 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateFuture.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateFuture.java
@@ -64,7 +64,10 @@ public class GridDhtAtomicUpdateFuture extends GridFutureAdapter<Void>
private static final AtomicReference<IgniteLogger> logRef = new AtomicReference<>();
/** Logger. */
- protected static IgniteLogger log;
+ private static IgniteLogger log;
+
+ /** Logger. */
+ private static IgniteLogger msgLog;
/** Cache context. */
private final GridCacheContext cctx;
@@ -116,8 +119,7 @@ public class GridDhtAtomicUpdateFuture extends GridFutureAdapter<Void>
*/
public GridDhtAtomicUpdateFuture(
GridCacheContext cctx,
- CI2<GridNearAtomicUpdateRequest,
- GridNearAtomicUpdateResponse> completionCb,
+ CI2<GridNearAtomicUpdateRequest, GridNearAtomicUpdateResponse> completionCb,
GridCacheVersion writeVer,
GridNearAtomicUpdateRequest updateReq,
GridNearAtomicUpdateResponse updateRes
@@ -130,8 +132,10 @@ public class GridDhtAtomicUpdateFuture extends GridFutureAdapter<Void>
this.completionCb = completionCb;
this.updateRes = updateRes;
- if (log == null)
+ if (log == null) {
+ msgLog = cctx.shared().atomicMessageLogger();
log = U.logger(cctx.kernalContext(), logRef, GridDhtAtomicUpdateFuture.class);
+ }
keys = new ArrayList<>(updateReq.keys().size());
mappings = U.newHashMap(updateReq.keys().size());
@@ -139,6 +143,13 @@ public class GridDhtAtomicUpdateFuture extends GridFutureAdapter<Void>
waitForExchange = !(updateReq.topologyLocked() || (updateReq.fastMap() && !updateReq.clientRequest()));
}
+ /**
+ * @return Write version.
+ */
+ GridCacheVersion writeVersion() {
+ return writeVer;
+ }
+
/** {@inheritDoc} */
@Override public IgniteUuid futureId() {
return futVer.asGridUuid();
@@ -151,10 +162,14 @@ public class GridDhtAtomicUpdateFuture extends GridFutureAdapter<Void>
/** {@inheritDoc} */
@Override public boolean onNodeLeft(UUID nodeId) {
- if (log.isDebugEnabled())
- log.debug("Processing node leave event [fut=" + this + ", nodeId=" + nodeId + ']');
+ boolean res = registerResponse(nodeId);
+
+ if (res && msgLog.isDebugEnabled()) {
+ msgLog.debug("DTH update fut, node left [futId=" + futVer + ", writeVer=" + writeVer +
+ ", node=" + nodeId + ']');
+ }
- return registerResponse(nodeId);
+ return res;
}
/**
@@ -385,20 +400,24 @@ public class GridDhtAtomicUpdateFuture extends GridFutureAdapter<Void>
if (!mappings.isEmpty()) {
for (GridDhtAtomicUpdateRequest req : mappings.values()) {
try {
- if (log.isDebugEnabled())
- log.debug("Sending DHT atomic update request [nodeId=" + req.nodeId() + ", req=" + req + ']');
-
cctx.io().send(req.nodeId(), req, cctx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("DTH update fut, sent request [futId=" + futVer +
+ ", writeVer=" + writeVer + ", node=" + req.nodeId() + ']');
+ }
}
catch (ClusterTopologyCheckedException ignored) {
- U.warn(log, "Failed to send update request to backup node because it left grid: " +
- req.nodeId());
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("DTH update fut, failed to send request, node left [futId=" + futVer +
+ ", writeVer=" + writeVer + ", node=" + req.nodeId() + ']');
+ }
registerResponse(req.nodeId());
}
catch (IgniteCheckedException e) {
- U.error(log, "Failed to send update request to backup node (did node leave the grid?): "
- + req.nodeId(), e);
+ U.error(msgLog, "Failed to send request [futId=" + futVer +
+ ", writeVer=" + writeVer + ", node=" + req.nodeId() + ']');
registerResponse(req.nodeId());
}
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateRequest.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateRequest.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateRequest.java
index b1a94de..55f7560 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateRequest.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateRequest.java
@@ -25,6 +25,7 @@ import java.util.List;
import java.util.UUID;
import javax.cache.processor.EntryProcessor;
import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.IgniteLogger;
import org.apache.ignite.cache.CacheWriteSynchronizationMode;
import org.apache.ignite.internal.GridDirectCollection;
import org.apache.ignite.internal.GridDirectTransient;
@@ -715,6 +716,11 @@ public class GridDhtAtomicUpdateRequest extends GridCacheMessage implements Grid
}
/** {@inheritDoc} */
+ @Override public IgniteLogger messageLogger(GridCacheSharedContext ctx) {
+ return ctx.atomicMessageLogger();
+ }
+
+ /** {@inheritDoc} */
@Override public boolean writeTo(ByteBuffer buf, MessageWriter writer) {
writer.setBuffer(buf);
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateResponse.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateResponse.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateResponse.java
index 383e515..1334819 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateResponse.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridDhtAtomicUpdateResponse.java
@@ -23,6 +23,7 @@ import java.util.ArrayList;
import java.util.Collection;
import java.util.List;
import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.IgniteLogger;
import org.apache.ignite.internal.GridDirectCollection;
import org.apache.ignite.internal.GridDirectTransient;
import org.apache.ignite.internal.processors.cache.GridCacheContext;
@@ -190,6 +191,11 @@ public class GridDhtAtomicUpdateResponse extends GridCacheMessage implements Gri
}
/** {@inheritDoc} */
+ @Override public IgniteLogger messageLogger(GridCacheSharedContext ctx) {
+ return ctx.atomicMessageLogger();
+ }
+
+ /** {@inheritDoc} */
@Override public boolean writeTo(ByteBuffer buf, MessageWriter writer) {
writer.setBuffer(buf);
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateRequest.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateRequest.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateRequest.java
index e847c7c..eb9be4d 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateRequest.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateRequest.java
@@ -26,6 +26,7 @@ import java.util.UUID;
import javax.cache.expiry.ExpiryPolicy;
import javax.cache.processor.EntryProcessor;
import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.IgniteLogger;
import org.apache.ignite.cache.CacheWriteSynchronizationMode;
import org.apache.ignite.internal.GridDirectCollection;
import org.apache.ignite.internal.GridDirectTransient;
@@ -674,6 +675,11 @@ public class GridNearAtomicUpdateRequest extends GridCacheMessage implements Gri
}
/** {@inheritDoc} */
+ @Override public IgniteLogger messageLogger(GridCacheSharedContext ctx) {
+ return ctx.atomicMessageLogger();
+ }
+
+ /** {@inheritDoc} */
@Override public boolean writeTo(ByteBuffer buf, MessageWriter writer) {
writer.setBuffer(buf);
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateResponse.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateResponse.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateResponse.java
index f47bb75..ff4008e 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateResponse.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/atomic/GridNearAtomicUpdateResponse.java
@@ -25,6 +25,7 @@ import java.util.List;
import java.util.UUID;
import java.util.concurrent.ConcurrentLinkedQueue;
import org.apache.ignite.IgniteCheckedException;
+import org.apache.ignite.IgniteLogger;
import org.apache.ignite.internal.GridDirectCollection;
import org.apache.ignite.internal.GridDirectTransient;
import org.apache.ignite.internal.processors.cache.CacheObject;
@@ -435,6 +436,11 @@ public class GridNearAtomicUpdateResponse extends GridCacheMessage implements Gr
}
/** {@inheritDoc} */
+ @Override public IgniteLogger messageLogger(GridCacheSharedContext ctx) {
+ return ctx.atomicMessageLogger();
+ }
+
+ /** {@inheritDoc} */
@Override public boolean writeTo(ByteBuffer buf, MessageWriter writer) {
writer.setBuffer(buf);
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedCache.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedCache.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedCache.java
index 3376510..176a90f 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedCache.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedCache.java
@@ -1079,6 +1079,9 @@ public class GridDhtColocatedCache<K, V> extends GridDhtTransactionalCacheAdapte
* @param res Response.
*/
private void processLockResponse(UUID nodeId, GridNearLockResponse res) {
+ if (txLockMsgLog.isDebugEnabled())
+ txLockMsgLog.debug("Received near lock response [txId=" + res.version() + ", node=" + nodeId + ']');
+
assert nodeId != null;
assert res != null;
@@ -1087,6 +1090,13 @@ public class GridDhtColocatedCache<K, V> extends GridDhtTransactionalCacheAdapte
if (fut != null)
fut.onResult(nodeId, res);
+ else {
+ if (txLockMsgLog.isDebugEnabled()) {
+ txLockMsgLog.debug("Received near lock response for unknown future [txId=" + res.version() +
+ ", node=" + nodeId +
+ ", res=" + res + ']');
+ }
+ }
}
/** {@inheritDoc} */
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedLockFuture.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedLockFuture.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedLockFuture.java
index 3b8b9b8..f77efee 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedLockFuture.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/dht/colocated/GridDhtColocatedLockFuture.java
@@ -93,6 +93,9 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
/** Logger. */
private static IgniteLogger log;
+ /** Logger. */
+ private static IgniteLogger msgLog;
+
/** Cache registry. */
@GridToStringExclude
private final GridCacheContext<?, ?> cctx;
@@ -199,8 +202,10 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
futId = IgniteUuid.randomUuid();
- if (log == null)
+ if (log == null) {
+ msgLog = cctx.shared().txLockMessageLogger();
log = U.logger(cctx.kernalContext(), logRef, GridDhtColocatedLockFuture.class);
+ }
if (timeout > 0) {
timeoutObj = new LockTimeoutObject();
@@ -390,10 +395,6 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
MiniFuture f = (MiniFuture)fut;
if (f.node().id().equals(nodeId)) {
- if (log.isDebugEnabled())
- log.debug("Found mini-future for left node [nodeId=" + nodeId + ", mini=" + f + ", fut=" +
- this + ']');
-
f.onResult(newTopologyException(null, nodeId));
found = true;
@@ -414,33 +415,29 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
*/
void onResult(UUID nodeId, GridNearLockResponse res) {
if (!isDone()) {
- if (log.isDebugEnabled())
- log.debug("Received lock response from node [nodeId=" + nodeId + ", res=" + res + ", fut=" +
- this + ']');
-
MiniFuture mini = miniFuture(res.miniId());
if (mini != null) {
assert mini.node().id().equals(nodeId);
- if (log.isDebugEnabled())
- log.debug("Found mini future for response [mini=" + mini + ", res=" + res + ']');
-
mini.onResult(res);
- if (log.isDebugEnabled())
- log.debug("Future after processed lock response [fut=" + this + ", mini=" + mini +
- ", res=" + res + ']');
-
return;
}
- U.warn(log, "Failed to find mini future for response (perhaps due to stale message) [res=" + res +
+ U.warn(msgLog, "Collocated lock fut, failed to find mini future [txId=" + lockVer +
+ ", inTx=" + inTx() +
+ ", node=" + nodeId +
+ ", res=" + res +
", fut=" + this + ']');
}
- else if (log.isDebugEnabled())
- log.debug("Ignoring lock response from node (future is done) [nodeId=" + nodeId + ", res=" + res +
- ", fut=" + this + ']');
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Collocated lock fut, response for finished future [txId=" + lockVer +
+ ", inTx=" + inTx() +
+ ", node=" + nodeId + ']');
+ }
+ }
}
/**
@@ -1046,10 +1043,13 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
if (txSync == null || txSync.isDone()) {
try {
- if (log.isDebugEnabled())
- log.debug("Sending near lock request [node=" + node.id() + ", req=" + req + ']');
-
cctx.io().send(node, req, cctx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Collocated lock fut, sent request [txId=" + lockVer +
+ ", inTx=" + inTx() +
+ ", node=" + node.id() + ']');
+ }
}
catch (ClusterTopologyCheckedException ex) {
assert fut != null;
@@ -1061,10 +1061,13 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
txSync.listen(new CI1<IgniteInternalFuture<?>>() {
@Override public void apply(IgniteInternalFuture<?> t) {
try {
- if (log.isDebugEnabled())
- log.debug("Sending near lock request [node=" + node.id() + ", req=" + req + ']');
-
cctx.io().send(node, req, cctx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Collocated lock fut, sent request [txId=" + lockVer +
+ ", inTx=" + inTx() +
+ ", node=" + node.id() + ']');
+ }
}
catch (ClusterTopologyCheckedException ex) {
assert fut != null;
@@ -1072,6 +1075,13 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
fut.onResult(ex);
}
catch (IgniteCheckedException e) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Collocated lock fut, failed to send request [txId=" + lockVer +
+ ", inTx=" + inTx() +
+ ", node=" + node.id() +
+ ", err=" + e + ']');
+ }
+
onError(e);
}
}
@@ -1404,6 +1414,12 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
* @param e Node left exception.
*/
void onResult(ClusterTopologyCheckedException e) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Collocated lock fut, mini future node left [txId=" + lockVer +
+ ", inTx=" + inTx() +
+ ", nodeId=" + node.id() + ']');
+ }
+
if (isDone())
return;
@@ -1414,9 +1430,6 @@ public final class GridDhtColocatedLockFuture extends GridCompoundIdentityFuture
rcvRes = true;
}
- if (log.isDebugEnabled())
- log.debug("Remote node left grid while sending or waiting for reply (will fail): " + this);
-
if (tx != null)
tx.removeMapping(node.id());
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/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 bea1957..80b3768 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
@@ -807,6 +807,9 @@ public class GridDhtPartitionsExchangeFuture extends GridFutureAdapter<AffinityT
U.warn(log, "Awaited locked entry [key=" + e.getKey() + ", mvcc=" + e.getValue() + ']');
dumpedObjects++;
+
+ if (IgniteSystemProperties.getBoolean(IGNITE_THREAD_DUMP_ON_EXCHANGE_TIMEOUT, false))
+ U.dumpThreads(log);
}
}
}
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/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 5d3f604..1ea99c4 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
@@ -162,6 +162,22 @@ public class GridNearOptimisticTxPrepareFuture extends GridNearOptimisticTxPrepa
mini.onResult(nodeId, res);
}
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near optimistic prepare fut, failed to find mini future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
+ }
+ }
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near optimistic prepare fut, response for finished future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
}
}
@@ -483,6 +499,11 @@ public class GridNearOptimisticTxPrepareFuture extends GridNearOptimisticTxPrepa
else {
try {
cctx.io().send(n, req, tx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near optimistic prepare fut, sent request [txId=" + tx.nearXidVersion() +
+ ", node=" + n.id() + ']');
+ }
}
catch (ClusterTopologyCheckedException e) {
e.retryReadyFuture(cctx.nextAffinityReadyFuture(tx.topologyVersion()));
@@ -490,6 +511,12 @@ public class GridNearOptimisticTxPrepareFuture extends GridNearOptimisticTxPrepa
fut.onNodeLeft(e, false);
}
catch (IgniteCheckedException e) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near optimistic prepare fut, failed to sent request [txId=" + tx.nearXidVersion() +
+ ", node=" + n.id() +
+ ", err=" + e + ']');
+ }
+
fut.onResult(e);
}
}
@@ -696,8 +723,14 @@ public class GridNearOptimisticTxPrepareFuture extends GridNearOptimisticTxPrepa
/**
* @param e Node failure.
+ * @param discoThread {@code True} if executed from discovery thread.
*/
void onNodeLeft(ClusterTopologyCheckedException e, boolean discoThread) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near optimistic prepare fut, mini future node left [txId=" + parent.tx.nearXidVersion() +
+ ", node=" + m.node().id() + ']');
+ }
+
if (isDone())
return;
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearPessimisticTxPrepareFuture.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearPessimisticTxPrepareFuture.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearPessimisticTxPrepareFuture.java
index 9adf580..5d347d7 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearPessimisticTxPrepareFuture.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearPessimisticTxPrepareFuture.java
@@ -102,11 +102,24 @@ public class GridNearPessimisticTxPrepareFuture extends GridNearTxPrepareFutureA
if (f != null) {
assert f.node().id().equals(nodeId);
- if (log.isDebugEnabled())
- log.debug("Remote node left grid while sending or waiting for reply (will not retry): " + f);
-
f.onResult(res);
}
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near pessimistic prepare, failed to find mini future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
+ }
+ }
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near pessimistic prepare, response for finished future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
}
}
@@ -260,6 +273,11 @@ public class GridNearPessimisticTxPrepareFuture extends GridNearTxPrepareFutureA
else {
try {
cctx.io().send(node, req, tx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near pessimistic prepare, sent request [txId=" + tx.nearXidVersion() +
+ ", node=" + node.id() + ']');
+ }
}
catch (ClusterTopologyCheckedException e) {
e.retryReadyFuture(cctx.nextAffinityReadyFuture(topVer));
@@ -267,6 +285,11 @@ public class GridNearPessimisticTxPrepareFuture extends GridNearTxPrepareFutureA
fut.onNodeLeft(e);
}
catch (IgniteCheckedException e) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near pessimistic prepare, failed send request [txId=" + tx.nearXidVersion() +
+ ", node=" + node.id() + ", err=" + e + ']');
+ }
+
fut.onError(e);
}
}
@@ -365,6 +388,11 @@ public class GridNearPessimisticTxPrepareFuture extends GridNearTxPrepareFutureA
* @param e Error.
*/
void onNodeLeft(ClusterTopologyCheckedException e) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near pessimistic prepare, mini future node left [txId=" + tx.nearXidVersion() +
+ ", nodeId=" + m.node().id() + ']');
+ }
+
if (tx.onePhaseCommit()) {
tx.markForBackupCheck();
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxFinishFuture.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxFinishFuture.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxFinishFuture.java
index fe6290d..39f3ff3 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxFinishFuture.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxFinishFuture.java
@@ -84,6 +84,9 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
/** Logger. */
private static IgniteLogger log;
+ /** Logger. */
+ protected static IgniteLogger msgLog;
+
/** Context. */
private GridCacheSharedContext<K, V> cctx;
@@ -124,9 +127,6 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
futId = IgniteUuid.randomUuid();
- if (log == null)
- log = U.logger(cctx.kernalContext(), logRef, GridNearTxFinishFuture.class);
-
CacheWriteSynchronizationMode syncMode;
if (tx.explicitLock())
@@ -135,6 +135,11 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
syncMode = tx.syncMode();
tx.syncMode(syncMode);
+
+ if (log == null) {
+ msgLog = cctx.txFinishMessageLogger();
+ log = U.logger(cctx.kernalContext(), logRef, GridNearTxFinishFuture.class);
+ }
}
/** {@inheritDoc} */
@@ -162,6 +167,13 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
return found;
}
+ /**
+ * @return Transaction.
+ */
+ public GridNearTxLocal tx() {
+ return tx;
+ }
+
/** {@inheritDoc} */
@Override public boolean trackable() {
return trackable;
@@ -203,6 +215,22 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
if (finishFut != null)
finishFut.onNearFinishResponse(res);
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, failed to find mini future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
+ }
+ }
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, response for finished future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
}
}
@@ -211,12 +239,16 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
* @param res Result.
*/
public void onResult(UUID nodeId, GridDhtTxFinishResponse res) {
- if (!isDone())
+ if (!isDone()) {
+ boolean found = false;
+
for (IgniteInternalFuture<IgniteInternalTx> fut : futures()) {
if (fut.getClass() == CheckBackupMiniFuture.class) {
CheckBackupMiniFuture f = (CheckBackupMiniFuture)fut;
if (f.futureId().equals(res.miniId())) {
+ found = true;
+
assert f.node().id().equals(nodeId);
f.onDhtFinishResponse(res);
@@ -229,6 +261,22 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
f.onDhtFinishResponse(nodeId, false);
}
}
+
+ if (!found && msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, failed to find mini future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
+ }
+ else {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, response for finished future [txId=" + tx.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res +
+ ", fut=" + this + ']');
+ }
+ }
}
/** {@inheritDoc} */
@@ -458,8 +506,15 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
finishReq.syncCommit(true);
try {
- if (FINISH_NEAR_ONE_PHASE_SINCE.compareTo(backup.version()) <= 0)
+ if (FINISH_NEAR_ONE_PHASE_SINCE.compareTo(backup.version()) <= 0) {
cctx.io().send(backup, finishReq, tx.ioPolicy());
+
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, sent check committed request [" +
+ "txId=" + tx.nearXidVersion() +
+ ", node=" + backup.id() + ']');
+ }
+ }
else {
mini.onDone(new IgniteTxHeuristicCheckedException("Failed to check for tx commit on " +
"the backup node (node has an old Ignite version) [rmtNodeId=" + backup.id() +
@@ -470,6 +525,13 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
mini.onNodeLeft(backupId, false);
}
catch (IgniteCheckedException e) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, failed to send check committed request [" +
+ "txId=" + tx.nearXidVersion() +
+ ", node=" + backup.id() +
+ ", err=" + e + ']');
+ }
+
mini.onDone(e);
}
}
@@ -607,6 +669,12 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
try {
cctx.io().send(n, req, tx.ioPolicy());
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, sent request [" +
+ "txId=" + tx.nearXidVersion() +
+ ", node=" + n.id() + ']');
+ }
+
boolean wait;
if (syncMode == PRIMARY_SYNC)
@@ -625,6 +693,13 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
fut.onNodeLeft(n.id(), false);
}
catch (IgniteCheckedException e) {
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, failed to send request [" +
+ "txId=" + tx.nearXidVersion() +
+ ", node=" + n.id() +
+ ", err=" + e + ']');
+ }
+
// Fail the whole thing.
fut.onDone(e);
}
@@ -770,8 +845,10 @@ public final class GridNearTxFinishFuture<K, V> extends GridCompoundIdentityFutu
/** {@inheritDoc} */
boolean onNodeLeft(UUID nodeId, boolean discoThread) {
if (nodeId.equals(m.node().id())) {
- if (log.isDebugEnabled())
- log.debug("Remote node left grid while sending or waiting for reply: " + this);
+ if (msgLog.isDebugEnabled()) {
+ msgLog.debug("Near finish fut, mini future node left [txId=" + tx.nearXidVersion() +
+ ", node=" + m.node().id() + ']');
+ }
if (tx.syncMode() == FULL_SYNC) {
Map<UUID, Collection<UUID>> txNodes = tx.transactionNodes();
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxPrepareFutureAdapter.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxPrepareFutureAdapter.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxPrepareFutureAdapter.java
index fd959b4..3260d39 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxPrepareFutureAdapter.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/distributed/near/GridNearTxPrepareFutureAdapter.java
@@ -74,6 +74,9 @@ public abstract class GridNearTxPrepareFutureAdapter extends
/** Logger. */
protected static IgniteLogger log;
+ /** Logger. */
+ protected static IgniteLogger msgLog;
+
/** Context. */
protected GridCacheSharedContext<?, ?> cctx;
@@ -110,8 +113,10 @@ public abstract class GridNearTxPrepareFutureAdapter extends
futId = IgniteUuid.randomUuid();
- if (log == null)
+ if (log == null) {
+ msgLog = cctx.txFinishMessageLogger();
log = U.logger(cctx.kernalContext(), logRef, GridNearTxPrepareFutureAdapter.class);
+ }
}
/** {@inheritDoc} */
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxHandler.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxHandler.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxHandler.java
index 7039399..ba30e10 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxHandler.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxHandler.java
@@ -95,6 +95,15 @@ public class IgniteTxHandler {
/** Logger. */
private IgniteLogger log;
+ /** */
+ private final IgniteLogger txPrepareMsgLog;
+
+ /** */
+ private final IgniteLogger txFinishMsgLog;
+
+ /** */
+ private final IgniteLogger txRecoveryMsgLog;
+
/** Shared cache context. */
private GridCacheSharedContext<?, ?> ctx;
@@ -105,6 +114,11 @@ public class IgniteTxHandler {
*/
public IgniteInternalFuture<?> processNearTxPrepareRequest(final UUID nearNodeId,
final GridNearTxPrepareRequest req) {
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Received near prepare request [txId=" + req.version() +
+ ", node=" + nearNodeId + ']');
+ }
+
return prepareTx(nearNodeId, null, req);
}
@@ -116,6 +130,10 @@ public class IgniteTxHandler {
log = ctx.logger(IgniteTxHandler.class);
+ txRecoveryMsgLog = ctx.logger(CU.TX_MSG_RECOVERY_LOG_CATEGORY);
+ txPrepareMsgLog = ctx.logger(CU.TX_MSG_PREPARE_LOG_CATEGORY);
+ txFinishMsgLog = ctx.logger(CU.TX_MSG_FINISH_LOG_CATEGORY);
+
ctx.io().addHandler(0, GridNearTxPrepareRequest.class, new CI2<UUID, GridCacheMessage>() {
@Override public void apply(UUID nodeId, GridCacheMessage msg) {
processNearTxPrepareRequest(nodeId, (GridNearTxPrepareRequest)msg);
@@ -268,8 +286,11 @@ public class IgniteTxHandler {
ClusterNode nearNode = ctx.node(nearNodeId);
if (nearNode == null) {
- if (log.isDebugEnabled())
- log.debug("Received transaction request from node that left grid (will ignore): " + nearNodeId);
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Received near prepare from node that left grid (will ignore) [" +
+ "txId=" + req.version() +
+ ", node=" + nearNodeId + ']');
+ }
return null;
}
@@ -319,9 +340,11 @@ public class IgniteTxHandler {
try {
if (top != null && needRemap(req.topologyVersion(), top.topologyVersion(), req)) {
- if (log.isDebugEnabled()) {
- log.debug("Client topology version mismatch, need remap transaction [" +
- "reqTopVer=" + req.topologyVersion() +
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Topology version mismatch for near prepare, need remap transaction [" +
+ "txId=" + req.version() +
+ ", node=" + nearNodeId +
+ ", reqTopVer=" + req.topologyVersion() +
", locTopVer=" + top.topologyVersion() +
", req=" + req + ']');
}
@@ -339,15 +362,24 @@ public class IgniteTxHandler {
try {
ctx.io().send(nearNode, res, req.policy());
+
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Sent remap response for near prepare [txId=" + req.version() +
+ ", node=" + nearNodeId + ']');
+ }
}
catch (ClusterTopologyCheckedException ignored) {
- if (log.isDebugEnabled())
- log.debug("Failed to send client tx remap response, client node failed " +
- "[node=" + nearNode + ", req=" + req + ']');
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Failed to send remap response for near prepare, node failed [" +
+ "txId=" + req.version() +
+ ", node=" + nearNodeId + ']');
+ }
}
catch (IgniteCheckedException e) {
- U.error(log, "Failed to send client tx remap response " +
- "[node=" + nearNode + ", req=" + req + ']', e);
+ U.error(txPrepareMsgLog, "Failed to send remap response for near prepare " +
+ "[txId=" + req.version() +
+ ", node=" + nearNodeId +
+ ", req=" + req + ']', e);
}
return new GridFinishedFuture<>(res);
@@ -494,11 +526,16 @@ public class IgniteTxHandler {
* @param res Response.
*/
private void processNearTxPrepareResponse(UUID nodeId, GridNearTxPrepareResponse res) {
+ if (txPrepareMsgLog.isDebugEnabled())
+ txPrepareMsgLog.debug("Received near prepare response [txId=" + res.version() + ", node=" + nodeId + ']');
+
GridNearTxPrepareFutureAdapter fut = (GridNearTxPrepareFutureAdapter)ctx.mvcc()
.<IgniteInternalTx>mvccFuture(res.version(), res.futureId());
if (fut == null) {
- U.warn(log, "Failed to find future for prepare response [sender=" + nodeId + ", res=" + res + ']');
+ U.warn(log, "Failed to find future for near prepare response [txId=" + res.version() +
+ ", node=" + nodeId +
+ ", res=" + res + ']');
return;
}
@@ -511,13 +548,19 @@ public class IgniteTxHandler {
* @param res Response.
*/
private void processNearTxFinishResponse(UUID nodeId, GridNearTxFinishResponse res) {
+ if (txFinishMsgLog.isDebugEnabled())
+ txFinishMsgLog.debug("Received near finish response [txId=" + res.xid() + ", node=" + nodeId + ']');
+
ctx.tm().onFinishedRemote(nodeId, res.threadId());
GridNearTxFinishFuture fut = (GridNearTxFinishFuture)ctx.mvcc().<IgniteInternalTx>future(res.futureId());
if (fut == null) {
- if (log.isDebugEnabled())
- log.debug("Failed to find future for finish response [sender=" + nodeId + ", res=" + res + ']');
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Failed to find future for near finish response [txId=" + res.xid() +
+ ", node=" + nodeId +
+ ", res=" + res + ']');
+ }
return;
}
@@ -533,11 +576,17 @@ public class IgniteTxHandler {
GridDhtTxPrepareFuture fut = (GridDhtTxPrepareFuture)ctx.mvcc().mvccFuture(res.version(), res.futureId());
if (fut == null) {
- if (log.isDebugEnabled())
- log.debug("Received response for unknown future (will ignore): " + res);
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Failed to find future for dht prepare response [txId=null" +
+ ", dhtTxId=" + res.version() +
+ ", node=" + nodeId +
+ ", res=" + res + ']');
+ }
return;
}
+ else if (txPrepareMsgLog.isDebugEnabled())
+ txPrepareMsgLog.debug("Received dht prepare response [txId=" + fut.tx().nearXidVersion() + ", node=" + nodeId + ']');
fut.onResult(nodeId, res);
}
@@ -554,11 +603,20 @@ public class IgniteTxHandler {
GridNearTxFinishFuture fut = (GridNearTxFinishFuture)ctx.mvcc().<IgniteInternalTx>future(res.futureId());
if (fut == null) {
- if (log.isDebugEnabled())
- log.debug("Received response for unknown future (will ignore): " + res);
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Failed to find future for dht finish check committed response [txId=null" +
+ ", dhtTxId=" + res.xid() +
+ ", node=" + nodeId +
+ ", res=" + res + ']');
+ }
return;
}
+ else if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Received dht finish check committed response [txId=" + fut.tx().nearXidVersion() +
+ ", dhtTxId=" + res.xid() +
+ ", node=" + nodeId + ']');
+ }
fut.onResult(nodeId, res);
}
@@ -566,11 +624,21 @@ public class IgniteTxHandler {
GridDhtTxFinishFuture fut = (GridDhtTxFinishFuture)ctx.mvcc().<IgniteInternalTx>future(res.futureId());
if (fut == null) {
- if (log.isDebugEnabled())
- log.debug("Received response for unknown future (will ignore): " + res);
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Failed to find future for dht finish response [txId=null" +
+ ", dhtTxId=" + res.xid() +
+ ", node=" + nodeId +
+ ", res=" + res);
+ }
return;
}
+ else if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Received dht finish response [txId=" + fut.tx().nearXidVersion() +
+ ", dhtTxId=" + res.xid() +
+ ", node=" + nodeId + ']');
+ }
+
fut.onResult(nodeId, res);
}
@@ -583,6 +651,9 @@ public class IgniteTxHandler {
*/
@Nullable public IgniteInternalFuture<IgniteInternalTx> processNearTxFinishRequest(UUID nodeId,
GridNearTxFinishRequest req) {
+ if (txFinishMsgLog.isDebugEnabled())
+ txFinishMsgLog.debug("Received near finish request [txId=" + req.version() + ", node=" + nodeId + ']');
+
return finish(nodeId, null, req);
}
@@ -660,9 +731,11 @@ public class IgniteTxHandler {
if (tx == null && !req.explicitLock()) {
assert locTx == null : "DHT local tx should never be lost for near local tx: " + locTx;
- U.warn(log, "Received finish request for completed transaction (the message may be too late " +
- "and transaction could have been DGCed by now) [commit=" + req.commit() +
- ", xid=" + req.version() + ']');
+ U.warn(txFinishMsgLog, "Received finish request for completed transaction (the message may be too late) [" +
+ "txId=" + req.version() +
+ ", dhtTxId=" + dhtVer +
+ ", node=" + nodeId +
+ ", commit=" + req.commit() + ']');
// Always send finish response.
GridCacheMessage res = new GridNearTxFinishResponse(req.version(), req.threadId(), req.futureId(),
@@ -670,17 +743,31 @@ public class IgniteTxHandler {
try {
ctx.io().send(nodeId, res, req.policy());
+
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Sent near finish response for completed tx [txId=" + req.version() +
+ ", dhtTxId=" + dhtVer +
+ ", node=" + nodeId + ']');
+ }
}
catch (Throwable e) {
// Double-check.
if (ctx.discovery().node(nodeId) == null) {
- if (log.isDebugEnabled())
- log.debug("Node left while sending finish response [nodeId=" + nodeId + ", res=" + res +
- ']');
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Failed to send near finish response for completed tx, node failed [" +
+ "txId=" + req.version() +
+ ", dhtTxId=" + dhtVer +
+ ", node=" + nodeId + ']');
+ }
+ }
+ else {
+ U.error(txFinishMsgLog, "Failed to send near finish response for completed tx, node failed [" +
+ "txId=" + req.version() +
+ ", dhtTxId=" + dhtVer +
+ ", node=" + nodeId +
+ ", req=" + req +
+ ", res=" + res + ']', e);
}
- else
- U.error(log, "Failed to send finish response to node [nodeId=" + nodeId + ", " +
- "res=" + res + ']', e);
if (e instanceof Error)
throw (Error)e;
@@ -794,15 +881,17 @@ public class IgniteTxHandler {
* @param req Request.
*/
protected final void processDhtTxPrepareRequest(UUID nodeId, GridDhtTxPrepareRequest req) {
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Received dht prepare request [txId=" + req.nearXidVersion() +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId + ']');
+ }
+
assert nodeId != null;
assert req != null;
assert req.transactionNodes() != null;
- if (log.isDebugEnabled())
- log.debug("Processing dht tx prepare request [locNodeId=" + ctx.localNodeId() +
- ", nodeId=" + nodeId + ", req=" + req + ']');
-
GridDhtTxRemote dhtTx = null;
GridNearTxRemote nearTx = null;
@@ -862,16 +951,28 @@ public class IgniteTxHandler {
try {
// Reply back to sender.
ctx.io().send(nodeId, res, req.policy());
+
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Sent dht prepare response [txId=" + req.nearXidVersion() +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId + ']');
+ }
}
catch (IgniteCheckedException e) {
if (e instanceof ClusterTopologyCheckedException) {
- if (log.isDebugEnabled())
- log.debug("Failed to send tx response to remote node (node left grid) [node=" + nodeId +
- ", xid=" + req.version());
+ if (txPrepareMsgLog.isDebugEnabled()) {
+ txPrepareMsgLog.debug("Failed to send dht prepare response, node left [txId=" + req.nearXidVersion() +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId + ']');
+ }
+ }
+ else {
+ U.warn(log, "Failed to send tx response to remote node (will rollback transaction) [" +
+ "txId=" + req.nearXidVersion() +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId +
+ ", err=" + e.getMessage() + ']');
}
- else
- U.warn(log, "Failed to send tx response to remote node (will rollback transaction) [node=" + nodeId +
- ", xid=" + req.version() + ", err=" + e.getMessage() + ']');
if (nearTx != null)
nearTx.rollback();
@@ -890,20 +991,17 @@ public class IgniteTxHandler {
assert nodeId != null;
assert req != null;
- if (log.isDebugEnabled())
- log.debug("Processing dht tx finish request [nodeId=" + nodeId + ", req=" + req + ']');
-
if (req.checkCommitted()) {
boolean committed = req.waitRemoteTransactions() || !ctx.tm().addRolledbackTx(null, req.version());
if (!committed || !req.syncCommit())
- sendReply(nodeId, req, committed);
+ sendReply(nodeId, req, committed, null);
else {
IgniteInternalFuture<?> fut = ctx.tm().remoteTxFinishFuture(req.version());
fut.listen(new CI1<IgniteInternalFuture<?>>() {
@Override public void apply(IgniteInternalFuture<?> fut) {
- sendReply(nodeId, req, true);
+ sendReply(nodeId, req, true, null);
}
});
}
@@ -911,9 +1009,18 @@ public class IgniteTxHandler {
return;
}
- GridDhtTxRemote dhtTx = ctx.tm().tx(req.version());
+ final GridDhtTxRemote dhtTx = ctx.tm().tx(req.version());
GridNearTxRemote nearTx = ctx.tm().nearTx(req.version());
+ final GridCacheVersion nearTxId =
+ (dhtTx != null ? dhtTx.nearXidVersion() : (nearTx != null ? nearTx.nearXidVersion() : null));
+
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Received dht finish request [txId=" + nearTxId +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId + ']');
+ }
+
// Safety - local transaction will finish explicitly.
if (nearTx != null && nearTx.local())
nearTx = null;
@@ -929,7 +1036,7 @@ public class IgniteTxHandler {
IgniteInternalFuture<IgniteInternalTx> dhtFin = dhtTx == null ?
null : dhtTx.done() ? null : dhtTx.finishFuture();
- IgniteInternalFuture<IgniteInternalTx> nearFin = nearTx == null ?
+ final IgniteInternalFuture<IgniteInternalTx> nearFin = nearTx == null ?
null : nearTx.done() ? null : nearTx.finishFuture();
if (dhtFin != null && nearFin != null) {
@@ -948,15 +1055,15 @@ public class IgniteTxHandler {
if (completeFut != null) {
completeFut.listen(new CI1<IgniteInternalFuture<IgniteInternalTx>>() {
@Override public void apply(IgniteInternalFuture<IgniteInternalTx> igniteTxIgniteFuture) {
- sendReply(nodeId, req, true);
+ sendReply(nodeId, req, true, nearTxId);
}
});
}
else
- sendReply(nodeId, req, true);
+ sendReply(nodeId, req, true, nearTxId);
}
else
- sendReply(nodeId, req, true);
+ sendReply(nodeId, req, true, null);
}
/**
@@ -1073,8 +1180,9 @@ public class IgniteTxHandler {
* @param nodeId Node id that originated finish request.
* @param req Request.
* @param committed {@code True} if transaction committed on this node.
+ * @param nearTxId Near tx version.
*/
- protected void sendReply(UUID nodeId, GridDhtTxFinishRequest req, boolean committed) {
+ protected void sendReply(UUID nodeId, GridDhtTxFinishRequest req, boolean committed, GridCacheVersion nearTxId) {
if (req.replyRequired() || req.checkCommitted()) {
GridDhtTxFinishResponse res = new GridDhtTxFinishResponse(req.version(), req.futureId(), req.miniId());
@@ -1092,20 +1200,41 @@ public class IgniteTxHandler {
try {
ctx.io().send(nodeId, res, req.policy());
+
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Sent dht tx finish response [txId=" + nearTxId +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId +
+ ", checkCommitted=" + req.checkCommitted() + ']');
+ }
}
catch (Throwable e) {
// Double-check.
if (ctx.discovery().node(nodeId) == null) {
- if (log.isDebugEnabled())
- log.debug("Node left while sending finish response [nodeId=" + nodeId + ", res=" + res + ']');
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Node left while send dht tx finish response [txId=" + nearTxId +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId + ']');
+ }
+ }
+ else {
+ U.error(log, "Failed to send finish response to node [txId=" + nearTxId +
+ ", dhtTxId=" + req.version() +
+ ", nodeId=" + nodeId +
+ ", res=" + res + ']', e);
}
- else
- U.error(log, "Failed to send finish response to node [nodeId=" + nodeId + ", res=" + res + ']', e);
if (e instanceof Error)
throw (Error)e;
}
}
+ else {
+ if (txFinishMsgLog.isDebugEnabled()) {
+ txFinishMsgLog.debug("Skip send dht tx finish response [txId=" + nearTxId +
+ ", dhtTxId=" + req.version() +
+ ", node=" + nodeId + ']');
+ }
+ }
}
/**
@@ -1363,8 +1492,10 @@ public class IgniteTxHandler {
protected void processCheckPreparedTxRequest(final UUID nodeId,
final GridCacheTxRecoveryRequest req)
{
- if (log.isDebugEnabled())
- log.debug("Processing check prepared transaction requests [nodeId=" + nodeId + ", req=" + req + ']');
+ if (txRecoveryMsgLog.isDebugEnabled()) {
+ txRecoveryMsgLog.debug("Received tx recovery request [txId=" + req.nearXidVersion() +
+ ", node=" + nodeId + ']');
+ }
IgniteInternalFuture<Boolean> fut = req.nearTxCheck() ? ctx.tm().txCommitted(req.nearXidVersion()) :
ctx.tm().txsPreparedOrCommitted(req.nearXidVersion(), req.transactions());
@@ -1411,23 +1542,32 @@ public class IgniteTxHandler {
private void sendCheckPreparedResponse(UUID nodeId,
GridCacheTxRecoveryRequest req,
boolean prepared) {
- GridCacheTxRecoveryResponse res =
- new GridCacheTxRecoveryResponse(req.version(), req.futureId(), req.miniId(), prepared,
- req.deployInfo() != null);
+ GridCacheTxRecoveryResponse res = new GridCacheTxRecoveryResponse(req.version(),
+ req.futureId(),
+ req.miniId(),
+ prepared,
+ req.deployInfo() != null);
try {
- if (log.isDebugEnabled())
- log.debug("Sending check prepared transaction response [nodeId=" + nodeId + ", res=" + res + ']');
-
ctx.io().send(nodeId, res, req.system() ? UTILITY_CACHE_POOL : SYSTEM_POOL);
+
+ if (txRecoveryMsgLog.isDebugEnabled()) {
+ txRecoveryMsgLog.debug("Sent tx recovery response [txId=" + req.nearXidVersion() +
+ ", node=" + nodeId + ", res=" + res + ']');
+ }
}
catch (ClusterTopologyCheckedException ignored) {
- if (log.isDebugEnabled())
- log.debug("Failed to send check prepared transaction response (did node leave grid?) [nodeId=" +
- nodeId + ", res=" + res + ']');
+ if (txRecoveryMsgLog.isDebugEnabled())
+ txRecoveryMsgLog.debug("Failed to send tx recovery response, node failed [" +
+ ", txId=" + req.nearXidVersion() +
+ ", node=" + nodeId +
+ ", res=" + res + ']');
}
catch (IgniteCheckedException e) {
- U.error(log, "Failed to send response to node [nodeId=" + nodeId + ", res=" + res + ']', e);
+ U.error(txRecoveryMsgLog, "Failed to send tx recovery response [txId=" + req.nearXidVersion() +
+ ", node=" + nodeId +
+ ", req=" + req +
+ ", res=" + res + ']', e);
}
}
@@ -1436,14 +1576,19 @@ public class IgniteTxHandler {
* @param res Response.
*/
protected void processCheckPreparedTxResponse(UUID nodeId, GridCacheTxRecoveryResponse res) {
- if (log.isDebugEnabled())
- log.debug("Processing check prepared transaction response [nodeId=" + nodeId + ", res=" + res + ']');
+ if (txRecoveryMsgLog.isDebugEnabled()) {
+ txRecoveryMsgLog.debug("Received tx recovery response [txId=" + res.version() +
+ ", node=" + nodeId +
+ ", res=" + res + ']');
+ }
GridCacheTxRecoveryFuture fut = (GridCacheTxRecoveryFuture)ctx.mvcc().future(res.futureId());
if (fut == null) {
- if (log.isDebugEnabled())
- log.debug("Received response for unknown future (will ignore): " + res);
+ if (txRecoveryMsgLog.isDebugEnabled()) {
+ txRecoveryMsgLog.debug("Failed to find future for tx recovery response [txId=" + res.version() +
+ ", node=" + nodeId + ", res=" + res + ']');
+ }
return;
}
http://git-wip-us.apache.org/repos/asf/ignite/blob/ad76dda5/modules/core/src/test/config/log4j-test.xml
----------------------------------------------------------------------
diff --git a/modules/core/src/test/config/log4j-test.xml b/modules/core/src/test/config/log4j-test.xml
index 29ae7b6..276de8c 100644
--- a/modules/core/src/test/config/log4j-test.xml
+++ b/modules/core/src/test/config/log4j-test.xml
@@ -96,6 +96,12 @@
</category>
-->
+ <!--
+ <category name="org.apache.ignite.cache.msg">
+ <level value="DEBUG"/>
+ </category>
+ -->
+
<!-- Disable all open source debugging. -->
<category name="org">
<level value="INFO"/>