You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@helix.apache.org by xy...@apache.org on 2023/05/12 17:27:44 UTC
[helix] branch master updated: code clean up - debug log format (#2470)
This is an automated email from the ASF dual-hosted git repository.
xyuanlu pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/helix.git
The following commit(s) were added to refs/heads/master by this push:
new 46e363d89 code clean up - debug log format (#2470)
46e363d89 is described below
commit 46e363d89a1dcb2df3b3024dfd441bd5b99732cf
Author: xyuanlu <xy...@gmail.com>
AuthorDate: Fri May 12 10:27:38 2023 -0700
code clean up - debug log format (#2470)
---
.../org/apache/helix/agent/AgentStateModel.java | 6 ++----
.../helix/common/ClusterEventBlockingQueue.java | 6 ++----
.../helix/common/caches/AbstractDataCache.java | 7 +++----
.../helix/common/caches/BasicClusterDataCache.java | 8 +++-----
.../controller/rebalancer/AutoRebalancer.java | 14 ++++++--------
.../controller/rebalancer/CustomRebalancer.java | 6 ++----
.../rebalancer/DelayedAutoRebalancer.java | 22 +++++++++-------------
.../rebalancer/util/DelayedRebalanceUtil.java | 15 ++++-----------
.../apache/helix/manager/zk/CallbackHandler.java | 10 ----------
.../apache/helix/manager/zk/HelixGroupCommit.java | 8 ++------
.../helix/manager/zk/ZkCacheEventThread.java | 10 +++-------
.../apache/helix/spectator/RoutingDataCache.java | 14 +++++++-------
.../helix/zookeeper/zkclient/ZkEventThread.java | 8 ++------
.../zkclient/callback/ZkAsyncCallbacks.java | 6 +++---
14 files changed, 48 insertions(+), 92 deletions(-)
diff --git a/helix-agent/src/main/java/org/apache/helix/agent/AgentStateModel.java b/helix-agent/src/main/java/org/apache/helix/agent/AgentStateModel.java
index ca17ac96e..1d0e5500a 100644
--- a/helix-agent/src/main/java/org/apache/helix/agent/AgentStateModel.java
+++ b/helix-agent/src/main/java/org/apache/helix/agent/AgentStateModel.java
@@ -147,10 +147,8 @@ public class AgentStateModel extends StateModel {
// System.out.println("command: " + cmd + ", exitValue: " + exitValue
// + " output:\n" + externalCmd.getStringOutput());
- if (_logger.isDebugEnabled()) {
- _logger.debug("command: " + cmd + ", exitValue: " + exitValue + " output:\n"
- + externalCmd.getStringOutput());
- }
+ _logger.debug("command: {}, exitValue: {} output: {}\n", cmd, exitValue,
+ externalCmd.getStringOutput());
// monitor pid if pidFile exists
if (pidFile == null) {
diff --git a/helix-core/src/main/java/org/apache/helix/common/ClusterEventBlockingQueue.java b/helix-core/src/main/java/org/apache/helix/common/ClusterEventBlockingQueue.java
index 2c6cf913c..95b26760a 100644
--- a/helix-core/src/main/java/org/apache/helix/common/ClusterEventBlockingQueue.java
+++ b/helix-core/src/main/java/org/apache/helix/common/ClusterEventBlockingQueue.java
@@ -59,10 +59,8 @@ public class ClusterEventBlockingQueue {
*/
public void put(ClusterEvent event) {
_eventQueue.put(event.getEventType(), event);
- if (LOG.isDebugEnabled()) {
- LOG.debug("Putting event " + event.getEventType());
- LOG.debug("Event queue size: " + _eventQueue.size());
- }
+ LOG.debug("Putting event {}", event.getEventType());
+ LOG.debug("Event queue size: {}", _eventQueue.size());
}
/**
diff --git a/helix-core/src/main/java/org/apache/helix/common/caches/AbstractDataCache.java b/helix-core/src/main/java/org/apache/helix/common/caches/AbstractDataCache.java
index 9dbabc3d5..c7943ab8b 100644
--- a/helix-core/src/main/java/org/apache/helix/common/caches/AbstractDataCache.java
+++ b/helix-core/src/main/java/org/apache/helix/common/caches/AbstractDataCache.java
@@ -96,10 +96,9 @@ public abstract class AbstractDataCache<T extends HelixProperty> {
}
}
- LogUtil.logInfo(LOG, genEventInfo(), String.format("%s properties refreshed from ZK.", reloadKeys.size()));
- if (LOG.isDebugEnabled()) {
- LOG.debug("refreshed keys: " + reloadKeys);
- }
+ LogUtil.logInfo(LOG, genEventInfo(),
+ String.format("%s properties refreshed from ZK.", reloadKeys.size()));
+ LOG.debug("refreshed keys: {}", reloadKeys);
return refreshedPropertyMap;
}
diff --git a/helix-core/src/main/java/org/apache/helix/common/caches/BasicClusterDataCache.java b/helix-core/src/main/java/org/apache/helix/common/caches/BasicClusterDataCache.java
index 4d3ce7278..f57bfd93f 100644
--- a/helix-core/src/main/java/org/apache/helix/common/caches/BasicClusterDataCache.java
+++ b/helix-core/src/main/java/org/apache/helix/common/caches/BasicClusterDataCache.java
@@ -135,11 +135,9 @@ public class BasicClusterDataCache implements ControlContextProvider {
"END: BasicClusterDataCache.refresh() for cluster " + _clusterName + ", took " + (endTime
- startTime) + " ms");
- if (LOG.isDebugEnabled()) {
- LOG.debug("LiveInstances: {}", _liveInstancePropertyCache.getPropertyMap());
- LOG.debug("ExternalViews: {}", _externalViewCache.getExternalViewMap().keySet());
- LOG.debug("InstanceConfigs: {}", _instanceConfigPropertyCache.getPropertyMap());
- }
+ LOG.debug("LiveInstances: {}", _liveInstancePropertyCache.getPropertyMap());
+ LOG.debug("ExternalViews: {}", _externalViewCache.getExternalViewMap().keySet());
+ LOG.debug("InstanceConfigs: {}", _instanceConfigPropertyCache.getPropertyMap());
}
/**
diff --git a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/AutoRebalancer.java b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/AutoRebalancer.java
index e5226a766..78bbbba28 100644
--- a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/AutoRebalancer.java
+++ b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/AutoRebalancer.java
@@ -129,14 +129,12 @@ public class AutoRebalancer extends AbstractRebalancer<ResourceControllerDataPro
ZNRecord newMapping = _rebalanceStrategy
.computePartitionAssignment(allNodes, liveNodes, currentMapping, clusterData);
- if (LOG.isDebugEnabled()) {
- LOG.debug("currentMapping: " + currentMapping);
- LOG.debug("stateCountMap: " + stateCountMap);
- LOG.debug("liveNodes: " + liveNodes);
- LOG.debug("allNodes: " + allNodes);
- LOG.debug("maxPartition: " + maxPartition);
- LOG.debug("newMapping: " + newMapping);
- }
+ LOG.debug("currentMapping: {}", currentMapping);
+ LOG.debug("stateCountMap: {}", stateCountMap);
+ LOG.debug("liveNodes: {}", liveNodes);
+ LOG.debug("allNodes: {}", allNodes);
+ LOG.debug("maxPartition: {}", maxPartition);
+ LOG.debug("newMapping: {}", newMapping);
IdealState newIdealState = new IdealState(resourceName);
newIdealState.getRecord().setSimpleFields(currentIdealState.getRecord().getSimpleFields());
diff --git a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/CustomRebalancer.java b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/CustomRebalancer.java
index 0dc38cdbf..7ed2e70b0 100644
--- a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/CustomRebalancer.java
+++ b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/CustomRebalancer.java
@@ -84,10 +84,8 @@ public class CustomRebalancer extends AbstractRebalancer<ResourceControllerDataP
}
cache.setCachedResourceAssignment(resource.getResourceName(), partitionMapping);
- if (LOG.isDebugEnabled()) {
- LOG.debug(String.format("Processing resource: %s", resource.getResourceName()));
- LOG.debug(String.format("Final Mapping of resource : %s", partitionMapping.toString()));
- }
+ LOG.debug("Processing resource: {}", resource.getResourceName());
+ LOG.debug("Final Mapping of resource : {}", partitionMapping.toString());
return partitionMapping;
}
diff --git a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/DelayedAutoRebalancer.java b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/DelayedAutoRebalancer.java
index bdb8ab63c..89f0a76b1 100644
--- a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/DelayedAutoRebalancer.java
+++ b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/DelayedAutoRebalancer.java
@@ -60,9 +60,7 @@ public class DelayedAutoRebalancer extends AbstractRebalancer<ResourceController
IdealState cachedIdealState = getCachedIdealState(resourceName, clusterData);
if (cachedIdealState != null) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Use cached IdealState for " + resourceName);
- }
+ LOG.debug("Use cached IdealState for {}", resourceName);
return cachedIdealState;
}
@@ -181,16 +179,14 @@ public class DelayedAutoRebalancer extends AbstractRebalancer<ResourceController
finalMapping.getListFields().putAll(userDefinedPreferenceList);
- if (LOG.isDebugEnabled()) {
- LOG.debug("currentMapping: " + currentMapping);
- LOG.debug("stateCountMap: " + stateCountMap);
- LOG.debug("liveEnabledNodes: " + liveEnabledNodes);
- LOG.debug("activeNodes: " + activeNodes);
- LOG.debug("allNodes: " + allNodes);
- LOG.debug("maxPartition: " + maxPartition);
- LOG.debug("newIdealMapping: " + newIdealMapping);
- LOG.debug("finalMapping: " + finalMapping);
- }
+ LOG.debug("currentMapping: {}", currentMapping);
+ LOG.debug("stateCountMap: {}", stateCountMap);
+ LOG.debug("liveEnabledNodes: {}", liveEnabledNodes);
+ LOG.debug("activeNodes: {}", activeNodes);
+ LOG.debug("allNodes: {}", allNodes);
+ LOG.debug("maxPartition: {}", maxPartition);
+ LOG.debug("newIdealMapping: {}", newIdealMapping);
+ LOG.debug("finalMapping: {}", finalMapping);
IdealState idealState = generateNewIdealState(resourceName, currentIdealState, finalMapping);
clusterData.setCachedIdealMapping(resourceName, idealState.getRecord());
diff --git a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/util/DelayedRebalanceUtil.java b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/util/DelayedRebalanceUtil.java
index 61985223c..ee8804749 100644
--- a/helix-core/src/main/java/org/apache/helix/controller/rebalancer/util/DelayedRebalanceUtil.java
+++ b/helix-core/src/main/java/org/apache/helix/controller/rebalancer/util/DelayedRebalanceUtil.java
@@ -26,8 +26,8 @@ import java.util.HashSet;
import java.util.List;
import java.util.Map;
import java.util.Set;
-
import java.util.stream.Collectors;
+
import org.apache.helix.HelixManager;
import org.apache.helix.controller.dataproviders.ResourceControllerDataProvider;
import org.apache.helix.controller.rebalancer.waged.model.AssignableReplica;
@@ -269,20 +269,13 @@ public class DelayedRebalanceUtil {
if (nextRebalanceTime == Long.MAX_VALUE) {
long startTime = REBALANCE_SCHEDULER.removeScheduledRebalance(resourceName);
- if (LOG.isDebugEnabled()) {
- LOG.debug(String
- .format("Remove exist rebalance timer for resource %s at %d\n", resourceName,
- startTime));
- }
+ LOG.debug("Remove exist rebalance timer for resource {} at {}", resourceName, startTime);
} else {
long currentScheduledTime = REBALANCE_SCHEDULER.getRebalanceTime(resourceName);
if (currentScheduledTime < 0 || currentScheduledTime > nextRebalanceTime) {
REBALANCE_SCHEDULER.scheduleRebalance(manager, resourceName, nextRebalanceTime);
- if (LOG.isDebugEnabled()) {
- LOG.debug(String
- .format("Set next rebalance time for resource %s at time %d\n", resourceName,
- nextRebalanceTime));
- }
+ LOG.debug("Set next rebalance time for resource {} at time {}", resourceName,
+ nextRebalanceTime);
}
}
}
diff --git a/helix-core/src/main/java/org/apache/helix/manager/zk/CallbackHandler.java b/helix-core/src/main/java/org/apache/helix/manager/zk/CallbackHandler.java
index 902c89d4d..34029f15d 100644
--- a/helix-core/src/main/java/org/apache/helix/manager/zk/CallbackHandler.java
+++ b/helix-core/src/main/java/org/apache/helix/manager/zk/CallbackHandler.java
@@ -492,10 +492,8 @@ public class CallbackHandler implements IZkChildListener, IZkDataListener {
private List<String> subscribeChildChange(String path, NotificationContext.Type callbackType) {
if (callbackType == NotificationContext.Type.INIT
|| callbackType == NotificationContext.Type.CALLBACK) {
- if (logger.isDebugEnabled()) {
logger.debug("CallbackHandler {}, {} subscribes child-change. path: {} , listener: {}",
_uid, _manager.getInstanceName(), path, _listener );
- }
// In the lifecycle of CallbackHandler, INIT is the first stage of registration of watch.
// For some usage case such as current state, the path can be created later. Thus we would
// install watch anyway event the path is not yet created.
@@ -530,10 +528,8 @@ public class CallbackHandler implements IZkChildListener, IZkDataListener {
private void subscribeDataChange(String path, NotificationContext.Type callbackType) {
if (callbackType == NotificationContext.Type.INIT
|| callbackType == NotificationContext.Type.CALLBACK) {
- if (logger.isDebugEnabled()) {
logger.debug("CallbackHandler {}, {} subscribe data-change. path: {}, listener: {}",
_uid, _manager.getInstanceName(), path, _listener);
- }
boolean subStatus = _zkClient.subscribeDataChanges(path, this, callbackType != Type.INIT);
logger.debug("CallbackHandler {} subscribe data path {} result {}", _uid, path, subStatus);
if (!subStatus) {
@@ -664,9 +660,7 @@ public class CallbackHandler implements IZkChildListener, IZkDataListener {
@Override
public void handleDataChange(String dataPath, Object data) {
- if (logger.isDebugEnabled()) {
logger.debug("Data change callbackhandler {}: paths changed: {}", _uid, dataPath);
- }
try {
updateNotificationTime(System.nanoTime());
@@ -687,9 +681,7 @@ public class CallbackHandler implements IZkChildListener, IZkDataListener {
@Override
public void handleDataDeleted(String dataPath) {
- if (logger.isDebugEnabled()) {
logger.debug("Data change callbackhandler {}: path deleted: {}", _uid, dataPath);
- }
try {
updateNotificationTime(System.nanoTime());
@@ -714,10 +706,8 @@ public class CallbackHandler implements IZkChildListener, IZkDataListener {
@Override
public void handleChildChange(String parentPath, List<String> currentChilds) {
- if (logger.isDebugEnabled()) {
logger.debug("Data change callback: child changed, path: {} , current child count: {}",
parentPath, currentChilds == null ? 0 : currentChilds.size());
- }
try {
updateNotificationTime(System.nanoTime());
diff --git a/helix-core/src/main/java/org/apache/helix/manager/zk/HelixGroupCommit.java b/helix-core/src/main/java/org/apache/helix/manager/zk/HelixGroupCommit.java
index bf140cefa..fc185a67f 100644
--- a/helix-core/src/main/java/org/apache/helix/manager/zk/HelixGroupCommit.java
+++ b/helix-core/src/main/java/org/apache/helix/manager/zk/HelixGroupCommit.java
@@ -111,9 +111,7 @@ public class HelixGroupCommit<T> {
continue;
}
merged = ent._updater.update(merged);
- if (LOG.isDebugEnabled()) {
- LOG.debug("After merging processed entry. path: " + mergedKey + ", value: " + merged);
- }
+ LOG.debug("After merging processed entry. path: {}, value: {}", mergedKey, merged);
}
// iterate over queue._pending for newly coming requests
@@ -125,9 +123,7 @@ public class HelixGroupCommit<T> {
}
processed.add(ent);
merged = ent._updater.update(merged);
- if (LOG.isDebugEnabled()) {
- LOG.debug("After merging pending entry. path: " + mergedKey + ", value: " + merged);
- }
+ LOG.debug("After merging processed entry. path: {}, value: {}", mergedKey, merged);
it.remove();
}
diff --git a/helix-core/src/main/java/org/apache/helix/manager/zk/ZkCacheEventThread.java b/helix-core/src/main/java/org/apache/helix/manager/zk/ZkCacheEventThread.java
index 0cb15ae76..a0c4d6079 100644
--- a/helix-core/src/main/java/org/apache/helix/manager/zk/ZkCacheEventThread.java
+++ b/helix-core/src/main/java/org/apache/helix/manager/zk/ZkCacheEventThread.java
@@ -62,9 +62,7 @@ public class ZkCacheEventThread extends Thread {
while (!isInterrupted()) {
ZkCacheEvent zkEvent = _events.take();
int eventId = _eventId.incrementAndGet();
- if (LOG.isDebugEnabled()) {
- LOG.debug("Delivering event #" + eventId + " " + zkEvent);
- }
+ LOG.debug("Delivering event # {} {}", eventId, zkEvent);
try {
zkEvent.run();
} catch (InterruptedException e) {
@@ -74,11 +72,9 @@ public class ZkCacheEventThread extends Thread {
} catch (ThreadDeath death) {
throw death;
} catch (Throwable e) {
- LOG.error("Error handling event " + zkEvent, e);
- }
- if (LOG.isDebugEnabled()) {
- LOG.debug("Delivering event #" + eventId + " done");
+ LOG.error("Error handling event {} ", zkEvent, e);
}
+ LOG.debug("Delivering event # {} done", eventId);
}
} catch (InterruptedException e) {
LOG.info("Terminate ZkClient event thread.");
diff --git a/helix-core/src/main/java/org/apache/helix/spectator/RoutingDataCache.java b/helix-core/src/main/java/org/apache/helix/spectator/RoutingDataCache.java
index 8b1619339..727bd8df9 100644
--- a/helix-core/src/main/java/org/apache/helix/spectator/RoutingDataCache.java
+++ b/helix-core/src/main/java/org/apache/helix/spectator/RoutingDataCache.java
@@ -19,12 +19,12 @@ package org.apache.helix.spectator;
* under the License.
*/
-import com.google.common.collect.ImmutableMap;
import java.util.Collections;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
+import com.google.common.collect.ImmutableMap;
import org.apache.helix.HelixConstants;
import org.apache.helix.HelixDataAccessor;
import org.apache.helix.HelixException;
@@ -139,13 +139,13 @@ class RoutingDataCache extends BasicClusterDataCache {
LOG.info("END: RoutingDataCache.refresh() for cluster " + _clusterName + ", took " + (endTime
- startTime) + " ms");
+ LOG.debug("CurrentStates: {}", _currentStateCache);
+ LOG.debug("TargetExternalViews: {}", _targetExternalViewCache.getExternalViewMap());
if (LOG.isDebugEnabled()) {
- LOG.debug("CurrentStates: " + _currentStateCache);
- LOG.debug("TargetExternalViews: " + _targetExternalViewCache.getExternalViewMap());
- for (String customizedStateType : _sourceDataTypeMap.getOrDefault(PropertyType.CUSTOMIZEDVIEW,
- Collections.emptyList())) {
- LOG.debug("CustomizedViews customizedStateType: " + customizedStateType + " "
- + _customizedViewCaches.get(customizedStateType).getCustomizedViewMap());
+ for (String customizedStateType : _sourceDataTypeMap
+ .getOrDefault(PropertyType.CUSTOMIZEDVIEW, Collections.emptyList())) {
+ LOG.debug("CustomizedViews customizedStateType: {} {}", customizedStateType,
+ _customizedViewCaches.get(customizedStateType).getCustomizedViewMap());
}
}
}
diff --git a/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/ZkEventThread.java b/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/ZkEventThread.java
index 5abb50614..56eda657c 100644
--- a/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/ZkEventThread.java
+++ b/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/ZkEventThread.java
@@ -92,9 +92,7 @@ public class ZkEventThread extends Thread {
while (!isInterrupted()) {
ZkEvent zkEvent = _events.take();
int eventId = _eventId.incrementAndGet();
- if (LOG.isDebugEnabled()) {
- LOG.debug("Delivering event #" + eventId + " " + zkEvent);
- }
+ LOG.debug("Delivering event # {} {}", eventId, zkEvent);
try {
zkEvent.run();
_totalEventCountHandled ++;
@@ -105,9 +103,7 @@ public class ZkEventThread extends Thread {
} catch (Throwable e) {
LOG.error("Error handling event " + zkEvent, e);
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("Delivering event #" + eventId + " done");
- }
+ LOG.debug("Delivering event # {} done", eventId);
}
} catch (InterruptedException e) {
LOG.info("Terminate ZkClient event thread.");
diff --git a/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/callback/ZkAsyncCallbacks.java b/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/callback/ZkAsyncCallbacks.java
index 72e2b95b7..ab38b4ed6 100644
--- a/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/callback/ZkAsyncCallbacks.java
+++ b/zookeeper-api/src/main/java/org/apache/helix/zookeeper/zkclient/callback/ZkAsyncCallbacks.java
@@ -184,13 +184,13 @@ public class ZkAsyncCallbacks {
int _rc = KeeperException.Code.APIERROR.intValue();
public void callback(int rc, String path, Object ctx) {
- if (rc != 0 && LOG.isDebugEnabled()) {
- LOG.debug(this + ", rc:" + Code.get(rc) + ", path: " + path);
+ if (rc != 0) {
+ LOG.debug(" {}, rc:{}, path {}", this, Code.get(rc), path);
}
if (ctx != null && ctx instanceof ZkAsyncCallMonitorContext) {
ZkAsyncCallMonitorContext monitor = (ZkAsyncCallMonitorContext) ctx;
- if(rc == 0) {
+ if (rc == 0) {
monitor.recordAccess(path);
} else {
recordFailure(rc, path, monitor);