From 5aadf0cc4b1ecac0d3d73882cff2a5d87e889c7e Mon Sep 17 00:00:00 2001 From: Ilya Shishkov Date: Fri, 21 Nov 2025 17:05:12 +0300 Subject: [PATCH 1/3] IGNITE-27122 Enhance ConflictResolver logging --- .../CacheVersionConflictResolverImpl.java | 69 ++++++++++++---- .../cdc/CacheConflictOperationsTest.java | 81 +++++++++++++++++-- ...flictOperationsWithCustomResolverTest.java | 26 +++++- 3 files changed, 153 insertions(+), 23 deletions(-) diff --git a/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java b/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java index 1e275a7be..f2bd3dfc5 100644 --- a/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java +++ b/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java @@ -17,6 +17,8 @@ package org.apache.ignite.cdc.conflictresolve; +import java.util.Objects; +import org.apache.ignite.IgniteCommonsSystemProperties; import org.apache.ignite.IgniteLogger; import org.apache.ignite.binary.BinaryObject; import org.apache.ignite.internal.processors.cache.CacheObjectValueContext; @@ -113,7 +115,6 @@ public CacheVersionConflictResolverImpl( * @param Key type. * @return {@code True} is should use new entry. */ - @SuppressWarnings({"unchecked", "rawtypes"}) protected boolean isUseNew( CacheObjectValueContext ctx, GridCacheVersionedEntryEx oldEntry, @@ -147,28 +148,57 @@ protected boolean isUseNew( return value(oldVal).compareTo(value(newVal)) < 0; } catch (Exception e) { - log.error( - "Error while resolving replication conflict. [field=" + conflictResolveField + ", key=" + newEntry.key() + ']', - e - ); + log.error("Error during field-based conflicts resolving " + + "[key=" + safeKeyToString(newEntry) + + ", field=" + conflictResolveField + ']', + e); } } + else { + log.warning( + "Field-based conflicts resolving is enabled, but at least one of entries has null value " + + "[key=" + safeKeyToString(newEntry) + + ", oldValIsNull=" + (oldVal == null) + + ", newValIsNull=" + (newVal == null) + ']'); + } } + else + log.warning("Field-based conflicts resolving is not enabled: key=" + safeKeyToString(newEntry)); log.error("Conflict can't be resolved, " + (newEntry.value(ctx) == null ? "remove" : "update") + " ignored " + - "[key=" + newEntry.key() + ", fromCluster=" + newEntry.dataCenterId() + ", toCluster=" + oldEntry.dataCenterId() + ']'); + "[key=" + safeKeyToString(newEntry) + + ", fromCluster=" + newEntry.dataCenterId() + + ", toCluster=" + oldEntry.dataCenterId() + ']'); // Ignoring update. return false; } /** @return Conflict resolve field value. */ - protected Comparable value(Object val) { + protected Comparable value(Object val) { return (val instanceof BinaryObject) ? ((BinaryObject)val).field(conflictResolveField) : U.field(val, conflictResolveField); } + /** @return Sensitive-safe string representation of an entry key. */ + private static String safeKeyToString(GridCacheVersionedEntryEx entry) { + return safeToString(entry.key()); + } + + /** + * @param obj Object. + * + * @return Sensitive-safe string representation of an object. + * @see IgniteCommonsSystemProperties#IGNITE_TO_STRING_INCLUDE_SENSITIVE + */ + private static String safeToString(Object obj) { + if (obj instanceof BinaryObject) + return Objects.toString(obj); + + return S.includeSensitive() ? Objects.toString(obj) : "[sensitiveKeyHash=" + Objects.hashCode(obj) + ']'; + } + /** */ private void debugResolve( CacheObjectValueContext ctx, @@ -179,32 +209,39 @@ private void debugResolve( Object oldVal = conflictResolveFieldEnabled ? oldEntry.value(ctx) : null; Object newVal = conflictResolveFieldEnabled ? newEntry.value(ctx) : null; + String keyStr = safeKeyToString(newEntry); + if (oldVal != null) - oldVal = debugValue(oldVal); + oldVal = debugValue(keyStr, oldVal); if (newVal != null) - newVal = debugValue(newVal); + newVal = debugValue(keyStr, newVal); - log.debug("isUseNew[" + - "start=" + oldEntry.isStartVersion() + + log.debug("isUseNew [" + + "key=" + keyStr + + ", start=" + oldEntry.isStartVersion() + ", oldVer=" + oldEntry.version() + ", newVer=" + newEntry.version() + ", oldExpire=[" + oldEntry.ttl() + "," + oldEntry.expireTime() + ']' + ", newExpire=[" + newEntry.ttl() + "," + newEntry.expireTime() + ']' + - ", old=" + oldVal + - ", new=" + newVal + + ", oldFieldVal=" + oldVal + + ", newFieldVal=" + newVal + ", res=" + useNew + ']'); } /** @return Conflict resolve field value, or specified {@code val} if the field not found. */ - private Object debugValue(Object val) { + private Object debugValue(String keyStr, Object val) { try { return value(val); } catch (Exception e) { - log.debug("Can't resolve field value [field=" + conflictResolveField + ", val=" + val + ']'); + log.error("Can't resolve field value " + + "[key=" + keyStr + + ", field=" + conflictResolveField + + ", val=" + safeToString(val) + ']', + e); - return val; + return null; } } 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 index 86ef675fb..c7a633d3e 100644 --- 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 @@ -26,6 +26,7 @@ import java.util.Map; import org.apache.ignite.IgniteCache; import org.apache.ignite.IgniteCheckedException; +import org.apache.ignite.IgniteSystemProperties; import org.apache.ignite.binary.BinaryObject; import org.apache.ignite.cache.CacheAtomicityMode; import org.apache.ignite.cache.CacheEntry; @@ -44,9 +45,11 @@ import org.apache.ignite.internal.processors.cache.version.GridCacheVersion; import org.apache.ignite.testframework.ListeningTestLogger; import org.apache.ignite.testframework.LogListener; +import org.apache.ignite.testframework.junits.WithSystemProperty; 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.Assume; import org.junit.Test; import org.junit.runner.RunWith; import org.junit.runners.Parameterized; @@ -134,6 +137,8 @@ public static Collection parameters() { cachex = client.cachex(DEFAULT_CACHE_NAME); } + + listeningLog.clearListeners(); } /** {@inheritDoc} */ @@ -259,21 +264,39 @@ public void testUpdatesConflict() throws Exception { putConflict(key, 5, conflictResolveField() != null); } - /** Test switching debug log level for ConflictResolver during runtime */ + /** Test switching debug log level for ConflictResolver during runtime. */ @Test + @WithSystemProperty(key = IgniteSystemProperties.IGNITE_TO_STRING_INCLUDE_SENSITIVE, value = "true") public void testResolveDebug() throws Exception { + testResolveDebug(true); + } + + /** + * Test switching debug log level for ConflictResolver during runtime. + * Sensitive data should be hidden. + */ + @Test + @WithSystemProperty(key = IgniteSystemProperties.IGNITE_TO_STRING_INCLUDE_SENSITIVE, value = "false") + public void testResolveDebugExcludeSensitive() throws Exception { + testResolveDebug(false); + } + + /** */ + private void testResolveDebug(boolean includeSensitive) throws IgniteCheckedException { String key = key("UpdateClusterUpdateReorder", otherClusterId); - LogListener lsnr = LogListener.matches("isUseNew").build(); + String expKeyStr = includeSensitive ? key : "[sensitiveKeyHash=" + key.hashCode() + "]"; + + LogListener lsnr = LogListener.matches("isUseNew [key=" + expKeyStr).build(); listeningLog.registerListener(lsnr); Configurator.setLevel(CacheVersionConflictResolverImpl.class.getName(), Level.DEBUG); try { - putConflict(key, 1, true); + assertFalse(lsnr.check()); - putConflict(key, 1, false); + put(key); assertTrue(lsnr.check()); } @@ -283,11 +306,59 @@ public void testResolveDebug() throws Exception { lsnr.reset(); - putConflict(key, 1, false); + put(key); assertFalse(lsnr.check()); } + /** Test log of resolving error. */ + @Test + @WithSystemProperty(key = IgniteSystemProperties.IGNITE_TO_STRING_INCLUDE_SENSITIVE, value = "true") + public void testResolveError() throws Exception { + testResolveError("TestErrorLoggingINCLUDE", true); + } + + /** Test log of resolving error with hidden sensitive data. */ + @Test + @WithSystemProperty(key = IgniteSystemProperties.IGNITE_TO_STRING_INCLUDE_SENSITIVE, value = "false") + public void testResolveErrorExcludeSensitive() throws Exception { + testResolveError("TestErrorLoggingEXCLUDE", false); + } + + /** */ + private void testResolveError(String keyVal, boolean includeSensitive) throws IgniteCheckedException { + Assume.assumeTrue("Should not run with enabled field", conflictResolveField() == null); + + String key = key(keyVal, otherClusterId); + + String expKeyStr = includeSensitive ? key : "[sensitiveKeyHash=" + key.hashCode() + "]"; + + LogListener warnLsnr = LogListener.matches("Field-based conflicts resolving is not enabled: key=" + + expKeyStr).build(); + + LogListener errLsnr = LogListener.matches("Conflict can't be resolved, update ignored " + + "[key=" + expKeyStr + ", fromCluster=" + otherClusterId + ", toCluster=" + SECOND_CLUSTER_ID + "]").build(); + + listeningLog.registerListener(warnLsnr); + listeningLog.registerListener(errLsnr); + + Configurator.setLevel(CacheVersionConflictResolverImpl.class.getName(), Level.DEBUG); + + try { + put(key); + assertFalse(warnLsnr.check()); + assertFalse(errLsnr.check()); + + putConflict(key, 1, false); + + assertTrue(warnLsnr.check()); + assertTrue(errLsnr.check()); + } + finally { + Configurator.setLevel(CacheVersionConflictResolverImpl.class.getName(), Level.INFO); + } + } + /** */ private void put(String key) { ConflictResolvableTestData newVal = ConflictResolvableTestData.create(); diff --git a/modules/cdc-ext/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsWithCustomResolverTest.java b/modules/cdc-ext/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsWithCustomResolverTest.java index 24bd8489d..b7844336d 100644 --- a/modules/cdc-ext/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsWithCustomResolverTest.java +++ b/modules/cdc-ext/src/test/java/org/apache/ignite/cdc/CacheConflictOperationsWithCustomResolverTest.java @@ -24,6 +24,7 @@ import org.apache.ignite.internal.processors.cache.version.GridCacheVersionConflictContext; import org.apache.ignite.internal.processors.cache.version.GridCacheVersionedEntryEx; import org.apache.ignite.testframework.GridTestUtils; +import org.junit.Ignore; import org.junit.Test; /** Cache conflict operations test with a custom resolver. */ @@ -53,9 +54,30 @@ public class CacheConflictOperationsWithCustomResolverTest extends CacheConflict /** {@inheritDoc} */ @Test + @Ignore("LwwConflictResolver does not have logging.") @Override public void testResolveDebug() throws Exception { - // LWW strategy resolves conflicts in unexpected way at versioned resolve test. - GridTestUtils.assertThrows(log, super::testResolveDebug, AssertionError.class, ""); + // No-op. + } + + /** {@inheritDoc} */ + @Test + @Ignore("LwwConflictResolver does not have logging.") + @Override public void testResolveDebugExcludeSensitive() throws Exception { + // No-op. + } + + /** {@inheritDoc} */ + @Test + @Ignore("LwwConflictResolver does not have logging.") + @Override public void testResolveError() throws Exception { + // No-op. + } + + /** {@inheritDoc} */ + @Test + @Ignore("LwwConflictResolver does not have logging.") + @Override public void testResolveErrorExcludeSensitive() throws Exception { + // No-op. } /** From 4c7f30b1358d91e5c893e84bdef72eb28ea9cfd9 Mon Sep 17 00:00:00 2001 From: Ilya Shishkov Date: Wed, 17 Dec 2025 15:10:05 +0300 Subject: [PATCH 2/3] Fix to string --- .../cdc/conflictresolve/CacheVersionConflictResolverImpl.java | 2 +- .../org/apache/ignite/cdc/CacheConflictOperationsTest.java | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java b/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java index f2bd3dfc5..e7ab81420 100644 --- a/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java +++ b/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java @@ -196,7 +196,7 @@ private static String safeToString(Object obj) { if (obj instanceof BinaryObject) return Objects.toString(obj); - return S.includeSensitive() ? Objects.toString(obj) : "[sensitiveKeyHash=" + Objects.hashCode(obj) + ']'; + return S.includeSensitive() ? Objects.toString(obj) : "[sensitiveDataHash=" + Objects.hashCode(obj) + ']'; } /** */ 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 index c7a633d3e..15f4f0f28 100644 --- 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 @@ -285,7 +285,7 @@ public void testResolveDebugExcludeSensitive() throws Exception { private void testResolveDebug(boolean includeSensitive) throws IgniteCheckedException { String key = key("UpdateClusterUpdateReorder", otherClusterId); - String expKeyStr = includeSensitive ? key : "[sensitiveKeyHash=" + key.hashCode() + "]"; + String expKeyStr = includeSensitive ? key : "[sensitiveDataHash=" + key.hashCode() + "]"; LogListener lsnr = LogListener.matches("isUseNew [key=" + expKeyStr).build(); @@ -331,7 +331,7 @@ private void testResolveError(String keyVal, boolean includeSensitive) throws Ig String key = key(keyVal, otherClusterId); - String expKeyStr = includeSensitive ? key : "[sensitiveKeyHash=" + key.hashCode() + "]"; + String expKeyStr = includeSensitive ? key : "[sensitiveDataHash=" + key.hashCode() + "]"; LogListener warnLsnr = LogListener.matches("Field-based conflicts resolving is not enabled: key=" + expKeyStr).build(); From 0f463a299358cf9cd46b113afa544930ca451605 Mon Sep 17 00:00:00 2001 From: Ilya Shishkov Date: Wed, 17 Dec 2025 15:44:29 +0300 Subject: [PATCH 3/3] Fix to string for field values. --- .../CacheVersionConflictResolverImpl.java | 2 +- .../cdc/CacheConflictOperationsTest.java | 24 ++++++++++++++++++- 2 files changed, 24 insertions(+), 2 deletions(-) diff --git a/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java b/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java index e7ab81420..365c49101 100644 --- a/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java +++ b/modules/cdc-ext/src/main/java/org/apache/ignite/cdc/conflictresolve/CacheVersionConflictResolverImpl.java @@ -232,7 +232,7 @@ private void debugResolve( /** @return Conflict resolve field value, or specified {@code val} if the field not found. */ private Object debugValue(String keyStr, Object val) { try { - return value(val); + return safeToString(value(val)); } catch (Exception e) { log.error("Can't resolve field value " + 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 index 15f4f0f28..88c7ea784 100644 --- 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 @@ -24,6 +24,7 @@ import java.util.HashSet; import java.util.List; import java.util.Map; +import java.util.Objects; import org.apache.ignite.IgniteCache; import org.apache.ignite.IgniteCheckedException; import org.apache.ignite.IgniteSystemProperties; @@ -288,27 +289,48 @@ private void testResolveDebug(boolean includeSensitive) throws IgniteCheckedExce String expKeyStr = includeSensitive ? key : "[sensitiveDataHash=" + key.hashCode() + "]"; LogListener lsnr = LogListener.matches("isUseNew [key=" + expKeyStr).build(); - listeningLog.registerListener(lsnr); + LogListener resolveFieldLsnr = LogListener.matches(newValueString(includeSensitive)).build(); + listeningLog.registerListener(resolveFieldLsnr); + Configurator.setLevel(CacheVersionConflictResolverImpl.class.getName(), Level.DEBUG); try { assertFalse(lsnr.check()); + assertFalse(resolveFieldLsnr.check()); put(key); assertTrue(lsnr.check()); + assertTrue(resolveFieldLsnr.check()); } finally { Configurator.setLevel(CacheVersionConflictResolverImpl.class.getName(), Level.INFO); } lsnr.reset(); + resolveFieldLsnr.reset(); put(key); assertFalse(lsnr.check()); + assertFalse(resolveFieldLsnr.check()); + } + + /** Gets expected conflict resolvable field output in log. */ + private String newValueString(boolean includeSensitive) { + String newValExpStr = null; + + if (conflictResolveField() != null) { + // Incremented in ConflictResolvableTestData#create during put. + long expReqId = ConflictResolvableTestData.REQUEST_ID.get() + 1; + + newValExpStr = includeSensitive ? String.valueOf(expReqId) : "[sensitiveDataHash=" + + Objects.hashCode(expReqId); + } + + return "newFieldVal=" + newValExpStr; } /** Test log of resolving error. */