You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by vo...@apache.org on 2017/02/13 11:29:45 UTC
[05/40] ignite git commit: IGNITE-4513 Improve debug logging.
IGNITE-4513 Improve debug logging.
Project: http://git-wip-us.apache.org/repos/asf/ignite/repo
Commit: http://git-wip-us.apache.org/repos/asf/ignite/commit/496fb173
Tree: http://git-wip-us.apache.org/repos/asf/ignite/tree/496fb173
Diff: http://git-wip-us.apache.org/repos/asf/ignite/diff/496fb173
Branch: refs/heads/ignite-2.0
Commit: 496fb173d55a8ea0702fcb70a4e807f61d8fc53e
Parents: 1665a61
Author: nikolay_tikhonov <nt...@gridgain.com>
Authored: Mon Jan 16 13:19:51 2017 +0300
Committer: nikolay_tikhonov <nt...@gridgain.com>
Committed: Mon Jan 16 13:19:51 2017 +0300
----------------------------------------------------------------------
.../processors/cache/GridCacheUtils.java | 3 +
.../continuous/CacheContinuousQueryHandler.java | 81 +++++++++++++++++---
modules/core/src/test/config/log4j-test.xml | 6 ++
3 files changed, 79 insertions(+), 11 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/ignite/blob/496fb173/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheUtils.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheUtils.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheUtils.java
index d32f4c1..8ee77e3 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheUtils.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheUtils.java
@@ -123,6 +123,9 @@ public class GridCacheUtils {
public static final String MARSH_CACHE_NAME = "ignite-marshaller-sys-cache";
/** */
+ public static final String CONTINUOUS_QRY_LOG_CATEGORY = "org.apache.ignite.continuous.query";
+
+ /** */
public static final String CACHE_MSG_LOG_CATEGORY = "org.apache.ignite.cache.msg";
/** */
http://git-wip-us.apache.org/repos/asf/ignite/blob/496fb173/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/query/continuous/CacheContinuousQueryHandler.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/query/continuous/CacheContinuousQueryHandler.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/query/continuous/CacheContinuousQueryHandler.java
index 10784fc..83edab4 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/query/continuous/CacheContinuousQueryHandler.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/query/continuous/CacheContinuousQueryHandler.java
@@ -352,7 +352,7 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
assert !skipPrimaryCheck || loc;
- log = ctx.log(CacheContinuousQueryHandler.class);
+ log = ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY);
CacheContinuousQueryListener<K, V> lsnr = new CacheContinuousQueryListener<K, V>() {
@Override public void onExecution() {
@@ -384,7 +384,10 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
final boolean recordIgniteEvt,
GridDhtAtomicAbstractUpdateFuture fut) {
if (ignoreExpired && evt.getEventType() == EventType.EXPIRED)
- return ;
+ return;
+
+ if (log.isDebugEnabled())
+ log.debug("Entry updated on affinity node [evt=" + evt + ", primary=" + primary + ']');
final GridCacheContext<K, V> cctx = cacheContext(ctx);
@@ -407,6 +410,10 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
else {
final boolean notify = filter(evt, primary);
+ if (log.isDebugEnabled())
+ log.debug("Filter invoked for event [evt=" + evt + ", primary=" + primary
+ + ", notify=" + notify + ']');
+
if (primary || skipPrimaryCheck) {
if (fut == null)
onEntryUpdate(evt, notify, loc, recordIgniteEvt);
@@ -474,7 +481,8 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
backupQueue0.clear();
}
catch (IgniteCheckedException e) {
- U.error(ctx.log(getClass()), "Failed to send backup event notification to node: " + nodeId, e);
+ U.error(ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY),
+ "Failed to send backup event notification to node: " + nodeId, e);
}
}
@@ -653,7 +661,7 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
final GridCacheContext cctx = cacheContext(ctx);
if (cctx == null) {
- IgniteLogger log = ctx.log(CacheContinuousQueryHandler.class);
+ IgniteLogger log = ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY);
if (log.isDebugEnabled())
log.debug("Failed to notify callback, cache is not found: " + cacheId);
@@ -689,7 +697,7 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
if (ignoreClsNotFound)
assert internal;
else
- U.error(ctx.log(getClass()), "Failed to unmarshal entry.", ex);
+ U.error(ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY), "Failed to unmarshal entry.", ex);
}
}
@@ -799,8 +807,12 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
CacheContinuousQueryEntry e = handleEntry(entry);
- if (e != null)
+ if (e != null) {
+ if (log.isDebugEnabled())
+ log.debug("Send the following event to listener: " + e);
+
ctx.continuous().addNotification(nodeId, routineId, entry, topic, sync, true);
+ }
}
}
catch (ClusterTopologyCheckedException ex) {
@@ -809,7 +821,7 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
"[node=" + nodeId + ", err=" + ex + ']');
}
catch (IgniteCheckedException ex) {
- U.error(ctx.log(getClass()), "Failed to send event notification to node: " + nodeId, ex);
+ U.error(ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY), "Failed to send event notification to node: " + nodeId, ex);
}
if (recordIgniteEvt && notify) {
@@ -875,7 +887,7 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
partCntr = initUpdCntrs.get(partId);
}
- rec = new PartitionRecovery(ctx.log(getClass()), initTopVer0, partCntr);
+ rec = new PartitionRecovery(ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY), initTopVer0, partCntr);
PartitionRecovery oldRec = rcvs.putIfAbsent(partId, rec);
@@ -984,12 +996,27 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
List<CacheEntryEvent<? extends K, ? extends V>> entries;
synchronized (pendingEvts) {
+ if (log.isDebugEnabled()) {
+ log.debug("Handling event [lastFiredEvt=" + lastFiredEvt +
+ ", curTop=" + curTop +
+ ", entUpdCnt=" + entry.updateCounter() +
+ ", partId=" + entry.partition() +
+ ", pendingEvts=" + pendingEvts + ']');
+ }
+
// Received first event.
if (curTop == AffinityTopologyVersion.NONE) {
lastFiredEvt = entry.updateCounter();
curTop = entry.topologyVersion();
+ if (log.isDebugEnabled()) {
+ log.debug("First event [lastFiredEvt=" + lastFiredEvt +
+ ", curTop=" + curTop +
+ ", entUpdCnt=" + entry.updateCounter() +
+ ", partId=" + entry.partition() + ']');
+ }
+
return !entry.isFiltered() ?
F.<CacheEntryEvent<? extends K, ? extends V>>
asList(new CacheContinuousQueryEvent<K, V>(cache, cctx, entry)) :
@@ -1014,6 +1041,13 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
if (!entry.isFiltered())
entries.add(new CacheContinuousQueryEvent<K, V>(cache, cctx, entry));
+ if (log.isDebugEnabled())
+ log.debug("Partition was lost [lastFiredEvt=" + lastFiredEvt +
+ ", curTop=" + curTop +
+ ", entUpdCnt=" + entry.updateCounter() +
+ ", partId=" + entry.partition() +
+ ", pendingEvts=" + pendingEvts + ']');
+
return entries;
}
@@ -1039,8 +1073,16 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
return Collections.emptyList();
}
- if (pendingEvts.isEmpty())
+ if (pendingEvts.isEmpty()) {
+ if (log.isDebugEnabled()) {
+ log.debug("Nothing sent to listener [lastFiredEvt=" + lastFiredEvt +
+ ", curTop=" + curTop +
+ ", entUpdCnt=" + entry.updateCounter() +
+ ", partId=" + entry.partition() + ']');
+ }
+
return Collections.emptyList();
+ }
Iterator<Map.Entry<Long, CacheContinuousQueryEntry>> iter = pendingEvts.entrySet().iterator();
@@ -1057,6 +1099,14 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
iter.remove();
}
+
+ if (log.isDebugEnabled()) {
+ log.debug("Pending events reached max of buffer size [lastFiredEvt=" + lastFiredEvt +
+ ", curTop=" + curTop +
+ ", entUpdCnt=" + entry.updateCounter() +
+ ", partId=" + entry.partition() +
+ ", pendingEvts=" + pendingEvts + ']');
+ }
}
else {
// Elements are consistently.
@@ -1077,6 +1127,15 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
}
}
+ if (log.isDebugEnabled()) {
+ log.debug("Will send to listener the following events [entries=" + entries +
+ ", lastFiredEvt=" + lastFiredEvt +
+ ", curTop=" + curTop +
+ ", entUpdCnt=" + entry.updateCounter() +
+ ", partId=" + entry.partition() +
+ ", pendingEvts=" + pendingEvts + ']');
+ }
+
return entries;
}
}
@@ -1254,14 +1313,14 @@ public class CacheContinuousQueryHandler<K, V> implements GridContinuousHandler
cctx.io().send(node, msg, GridIoPolicy.SYSTEM_POOL);
}
catch (ClusterTopologyCheckedException e) {
- IgniteLogger log = ctx.log(getClass());
+ IgniteLogger log = ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY);
if (log.isDebugEnabled())
log.debug("Failed to send acknowledge message, node left " +
"[msg=" + msg + ", node=" + node + ']');
}
catch (IgniteCheckedException e) {
- IgniteLogger log = ctx.log(getClass());
+ IgniteLogger log = ctx.log(CU.CONTINUOUS_QRY_LOG_CATEGORY);
U.error(log, "Failed to send acknowledge message " +
"[msg=" + msg + ", node=" + node + ']', e);
http://git-wip-us.apache.org/repos/asf/ignite/blob/496fb173/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 276de8c..638b260 100644
--- a/modules/core/src/test/config/log4j-test.xml
+++ b/modules/core/src/test/config/log4j-test.xml
@@ -102,6 +102,12 @@
</category>
-->
+ <!--
+ <category name="org.apache.ignite.continuous.query">
+ <level value="DEBUG"/>
+ </category>
+ -->
+
<!-- Disable all open source debugging. -->
<category name="org">
<level value="INFO"/>