IGNITE-20912 Fixed ConflictResolver debug logging (#282)

apache · Aug 9, 2024 · 2e49deb · 2e49deb
1 parent c1aae7f
commit 2e49deb
Show file tree

Hide file tree

Showing 5 changed files with 89 additions and 98 deletions.
diff --git a/...c/main/java/org/apache/ignite/cdc/conflictresolve/CacheConflictResolutionManagerImpl.java b/...c/main/java/org/apache/ignite/cdc/conflictresolve/CacheConflictResolutionManagerImpl.java
@@ -80,14 +80,6 @@ public CacheConflictResolutionManagerImpl(
 
         if (resolver != null)
             rslvr = resolver;
-        else if (conflictResolverLog.isDebugEnabled()) {
-            rslvr = new DebugCacheVersionConflictResolverImpl(
-                clusterId,
-                conflictResolveField,
-                conflictResolverLog,
-                mreg
-            );
-        }
         else {
             rslvr = new CacheVersionConflictResolverImpl(
                 clusterId,

diff --git a/...src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java b/...src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java
@@ -119,6 +119,9 @@ public CacheVersionConflictResolverImpl(
 
         boolean useNew = isUseNew(ctx, oldEntry, newEntry);
 
+        if (log.isDebugEnabled())
+            debugResolve(ctx, useNew, oldEntry, newEntry);
+
         if (useNew) {
             res.useNew();
             acceptedCnt.increment();
@@ -195,6 +198,45 @@ protected Comparable value(Object val) {
             : U.field(val, conflictResolveField);
     }
 
+    /** */
+    private <K, V> void debugResolve(
+        CacheObjectValueContext ctx,
+        boolean useNew,
+        GridCacheVersionedEntryEx<K, V> oldEntry,
+        GridCacheVersionedEntryEx<K, V> newEntry
+    ) {
+        Object oldVal = conflictResolveFieldEnabled ? oldEntry.value(ctx) : null;
+        Object newVal = conflictResolveFieldEnabled ? newEntry.value(ctx) : null;
+
+        if (oldVal != null)
+            oldVal = debugValue(oldVal);
+
+        if (newVal != null)
+            newVal = debugValue(newVal);
+
+        log.debug("isUseNew[" +
+            "start=" + oldEntry.isStartVersion() +
+            ", oldVer=" + oldEntry.version() +
+            ", newVer=" + newEntry.version() +
+            ", oldExpire=[" + oldEntry.ttl() + "," + oldEntry.expireTime() + ']' +
+            ", newExpire=[" + newEntry.ttl() + "," + newEntry.expireTime() + ']' +
+            ", old=" + oldVal +
+            ", new=" + newVal +
+            ", res=" + useNew + ']');
+    }
+
+    /** @return Conflict resolve field value, or specified {@code val} if the field not found. */
+    private Object debugValue(Object val) {
+        try {
+            return value(val);
+        }
+        catch (Exception e) {
+            log.debug("Can't resolve field value [field=" + conflictResolveField + ", val=" + val + ']');
+
+            return val;
+        }
+    }
+
     /** {@inheritDoc} */
     @Override public String toString() {
         return S.toString(CacheVersionConflictResolverImpl.class, this);

diff --git a/...ain/java/org/apache/ignite/cdc/conflictresolve/DebugCacheVersionConflictResolverImpl.java b/...ain/java/org/apache/ignite/cdc/conflictresolve/DebugCacheVersionConflictResolverImpl.java
diff --git a/modules/cdc-ext/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsTest.java b/modules/cdc-ext/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsTest.java
@@ -30,6 +30,7 @@
 import org.apache.ignite.cache.CacheAtomicityMode;
 import org.apache.ignite.cache.CacheEntry;
 import org.apache.ignite.cache.CacheEntryVersion;
+import org.apache.ignite.cdc.conflictresolve.CacheVersionConflictResolverImpl;
 import org.apache.ignite.cdc.conflictresolve.CacheVersionConflictResolverPluginProvider;
 import org.apache.ignite.configuration.CacheConfiguration;
 import org.apache.ignite.configuration.IgniteConfiguration;
@@ -43,7 +44,11 @@
 import org.apache.ignite.internal.processors.cache.version.GridCacheVersion;
 import org.apache.ignite.internal.processors.metric.MetricRegistryImpl;
 import org.apache.ignite.internal.processors.metric.impl.LongAdderMetric;
+import org.apache.ignite.testframework.ListeningTestLogger;
+import org.apache.ignite.testframework.LogListener;
 import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest;
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.core.config.Configurator;
 import org.junit.Test;
 import org.junit.runner.RunWith;
 import org.junit.runners.Parameterized;
@@ -101,6 +106,9 @@ public static Collection<?> parameters() {
     /** */
     private IgniteEx ign;
 
+    /** Listening test logger. */
+    private final ListeningTestLogger listeningLog = new ListeningTestLogger(log);
+
     /** {@inheritDoc} */
     @Override protected IgniteConfiguration getConfiguration(String igniteInstanceName) throws Exception {
         CacheVersionConflictResolverPluginProvider<?> pluginCfg = new CacheVersionConflictResolverPluginProvider<>();
@@ -109,7 +117,9 @@ public static Collection<?> parameters() {
         pluginCfg.setCaches(new HashSet<>(Collections.singleton(DEFAULT_CACHE_NAME)));
         pluginCfg.setConflictResolveField(conflictResolveField());
 
-        return super.getConfiguration(igniteInstanceName).setPluginProviders(pluginCfg);
+        return super.getConfiguration(igniteInstanceName)
+            .setPluginProviders(pluginCfg)
+            .setGridLogger(listeningLog);
     }
 
     /** {@inheritDoc} */
@@ -270,6 +280,35 @@ public void testMetrics() throws Exception {
         checkMetrics(1, 1);
     }
 
+    /** Test switching debug log level for ConflictResolver during runtime */
+    @Test
+    public void testResolveDebug() throws Exception {
+        String key = key("UpdateClusterUpdateReorder", otherClusterId);
+
+        LogListener lsnr = LogListener.matches("isUseNew").build();
+
+        listeningLog.registerListener(lsnr);
+
+        Configurator.setLevel(CacheVersionConflictResolverImpl.class.getName(), Level.DEBUG);
+
+        try {
+            putConflict(key, 1, true);
+
+            putConflict(key, 1, false);
+
+            assertTrue(lsnr.check());
+        }
+        finally {
+            Configurator.setLevel(CacheVersionConflictResolverImpl.class.getName(), Level.INFO);
+        }
+
+        lsnr.reset();
+
+        putConflict(key, 1, false);
+
+        assertFalse(lsnr.check());
+    }
+
     /** */
     private void put(String key) {
         ConflictResolvableTestData newVal = ConflictResolvableTestData.create();

diff --git a/...xt/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsWithCustomResolverTest.java b/...xt/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsWithCustomResolverTest.java
@@ -58,6 +58,13 @@ public class CacheConflictOperationsWithCustomResolverTest extends CacheConflict
         GridTestUtils.assertThrows(log, super::testMetrics, AssertionError.class, "");
     }
 
+    /** {@inheritDoc} */
+    @Test
+    @Override public void testResolveDebug() throws Exception {
+        // LWW strategy resolves conflicts in unexpected way at versioned resolve test.
+        GridTestUtils.assertThrows(log, super::testResolveDebug, AssertionError.class, "");
+    }
+
     /**
      *
      */