add debug log to dual read caches (#952)

* add debug log to dual read caches

* simplify the entry log code, also add info log about executor shutdown

* move private helper method to a proper place

CHANGELOG.md

@@ -14,6 +14,9 @@ and what APIs have changed, if applicable.
 
 ## [Unreleased]
 
+## [29.48.5] - 2023-12-12
+- add debug log to dual read caches
+
 ## [29.48.4] - 2023-12-06
 - correct where to increment the clusterNotFound count and adjust quarantine log level
 
@@ -5575,7 +5578,8 @@ patch operations can re-use these classes for generating patch messages.
 
 ## [0.14.1]
 
-[Unreleased]: https://github.com/linkedin/rest.li/compare/v29.48.4...master
+[Unreleased]: https://github.com/linkedin/rest.li/compare/v29.48.5...master
+[29.48.5]: https://github.com/linkedin/rest.li/compare/v29.48.4...v29.48.5
 [29.48.4]: https://github.com/linkedin/rest.li/compare/v29.48.3...v29.48.4
 [29.48.3]: https://github.com/linkedin/rest.li/compare/v29.48.2...v29.48.3
 [29.48.2]: https://github.com/linkedin/rest.li/compare/v29.48.1...v29.48.2

d2/src/main/java/com/linkedin/d2/balancer/dualread/DualReadLoadBalancerMonitor.java

@@ -71,29 +71,36 @@ public void reportData(String propertyName, T property, String propertyVersion,
     Cache<String, CacheEntry<T>> cacheToAdd = fromNewLb ? _newLbPropertyCache : _oldLbPropertyCache;
     Cache<String, CacheEntry<T>> cacheToCompare = fromNewLb ? _oldLbPropertyCache : _newLbPropertyCache;
 
-    CacheEntry<T> entry = cacheToCompare.getIfPresent(propertyName);
+    CacheEntry<T> entryToCompare = cacheToCompare.getIfPresent(propertyName);
+    CacheEntry<T> newEntry = new CacheEntry<>(propertyVersion, getTimestamp(), property);
+    String entriesLogMsg = getEntriesMessage(fromNewLb, entryToCompare, newEntry);
 
-    if (entry != null && Objects.equals(entry._version, propertyVersion))
+    if (entryToCompare != null && Objects.equals(entryToCompare._version, propertyVersion))
     {
-      CacheEntry<T> newEntry = new CacheEntry<>(propertyVersion, getTimestamp(), property);
-      if (!isEqual(entry, newEntry))
+      if (!isEqual(entryToCompare, newEntry))
       {
-        _rateLimitedLogger.warn("Received mismatched properties from dual read. Old LB: {}, New LB: {}",
-            fromNewLb ? entry : newEntry, fromNewLb ? newEntry : entry);
         incrementEntryOutOfSyncCount(); // increment the out-of-sync count for the entry received later
+        _rateLimitedLogger.warn("Received mismatched properties from dual read. {}", entriesLogMsg);
       }
       else
       { // entries are in-sync, decrement the out-of-sync count for the entry received earlier
         decrementEntryOutOfSyncCount();
+        _rateLimitedLogger.debug("Matched properties from dual read. {}", entriesLogMsg);
       }
       cacheToCompare.invalidate(propertyName);
     }
     else
     {
-      cacheToAdd.put(propertyName, new CacheEntry<>(propertyVersion, getTimestamp(), property));
+      cacheToAdd.put(propertyName, newEntry);
       // if version is different, entries of both the old version and the new version will increment the out-of-sync count
       incrementEntryOutOfSyncCount();
+      _rateLimitedLogger.debug("Added new entry to dual read cache for {} LB.",
+          fromNewLb ? "New" : "Old");
     }
+    entryToCompare = cacheToCompare.getIfPresent(propertyName);
+    newEntry = cacheToAdd.getIfPresent(propertyName);
+    entriesLogMsg = getEntriesMessage(fromNewLb, entryToCompare, newEntry);
+    _rateLimitedLogger.debug("Current entries on dual read caches: {}", entriesLogMsg);
   }
 
   abstract void incrementEntryOutOfSyncCount();
@@ -121,6 +128,12 @@ private Cache<String, CacheEntry<T>> buildCache()
         .build();
   }
 
+  private String getEntriesMessage(boolean fromNewLb, CacheEntry<T> oldE, CacheEntry<T> newE)
+  {
+    return String.format("Old LB: {}, New LB: {}.",
+        fromNewLb? oldE : newE, fromNewLb? newE : oldE);
+  }
+
   private String getTimestamp() {
     return ZonedDateTime.ofInstant(Instant.ofEpochMilli(_clock.currentTimeMillis()), ZoneId.systemDefault())
         .format(_format);

d2/src/main/java/com/linkedin/d2/balancer/dualread/DualReadStateManager.java

@@ -183,6 +183,12 @@ private void reportUriPropertiesData(String propertyName, UriProperties property
    */
   public void checkAndSwitchMode(String d2ServiceName)
   {
+    if (_executorService.isShutdown())
+    {
+      LOG.info("Dual read mode executor is shut down already. Skipping getting the latest dual read mode.");
+      return;
+    }
+
     _executorService.execute(() ->
     {
       boolean shouldCheck = _rateLimiter.tryAcquire();

gradle.properties

@@ -1,4 +1,4 @@
-version=29.48.4
+version=29.48.5
 group=com.linkedin.pegasus
 org.gradle.configureondemand=true
 org.gradle.parallel=true