ignite-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From ag...@apache.org
Subject [05/24] ignite git commit: IGNITE-4513 Improve debug logging.
Date Thu, 09 Feb 2017 17:43:05 GMT
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/master
Commit: 496fb173d55a8ea0702fcb70a4e807f61d8fc53e
Parents: 1665a61
Author: nikolay_tikhonov <ntikhonov@gridgain.com>
Authored: Mon Jan 16 13:19:51 2017 +0300
Committer: nikolay_tikhonov <ntikhonov@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"/>


Mime
View raw message