You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@accumulo.apache.org by ct...@apache.org on 2022/04/11 21:18:54 UTC
[accumulo] branch main updated: Add details to ZooKeeper watcher logs (#2615)
This is an automated email from the ASF dual-hosted git repository.
ctubbsii pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/accumulo.git
The following commit(s) were added to refs/heads/main by this push:
new a76401788a Add details to ZooKeeper watcher logs (#2615)
a76401788a is described below
commit a76401788a5b0fdeb38cb4e29abdbfbb11a27faf
Author: Christopher Tubbs <ct...@apache.org>
AuthorDate: Mon Apr 11 17:18:50 2022 -0400
Add details to ZooKeeper watcher logs (#2615)
Add more details to the log messages produced while processing ZooKeeper
WatchedEvents. Also, try to standardize some messages by adding the
event at the end, after whatever core message is conveyed. Most of the
time, we won't see these messages, but it definitely helps to have
greater insight into what event triggered the situation, rather than
picking out and printing only certain details from the WatchedEvent.
---
.../accumulo/fate/zookeeper/ServiceLock.java | 31 +++++++++++-----------
.../apache/accumulo/fate/zookeeper/ZooCache.java | 12 ++++-----
.../apache/accumulo/fate/zookeeper/ZooSession.java | 2 +-
.../delegation/ZooAuthenticationKeyWatcher.java | 24 ++++++++---------
.../accumulo/server/tables/TableManager.java | 4 +--
.../server/zookeeper/DistributedWorkQueue.java | 11 ++++----
6 files changed, 42 insertions(+), 42 deletions(-)
diff --git a/core/src/main/java/org/apache/accumulo/fate/zookeeper/ServiceLock.java b/core/src/main/java/org/apache/accumulo/fate/zookeeper/ServiceLock.java
index 40ed6f6d5c..7aaafef712 100644
--- a/core/src/main/java/org/apache/accumulo/fate/zookeeper/ServiceLock.java
+++ b/core/src/main/java/org/apache/accumulo/fate/zookeeper/ServiceLock.java
@@ -311,22 +311,19 @@ public class ServiceLock implements Watcher {
@Override
public void process(WatchedEvent event) {
if (LOG.isTraceEnabled()) {
- LOG.trace("[{}] Processing event:", vmLockPrefix);
- LOG.trace("- type {}", event.getType());
- LOG.trace("- path {}", event.getPath());
- LOG.trace("- state {}", event.getState());
+ LOG.trace("[{}] Processing {}", vmLockPrefix, event);
}
boolean renew = true;
if (event.getType() == EventType.NodeDeleted && event.getPath().equals(nodeToWatch)) {
- LOG.debug("[{}] Detected deletion of prior node {}, attempting to acquire lock",
- vmLockPrefix, nodeToWatch);
+ LOG.debug("[{}] Detected deletion of prior node {}, attempting to acquire lock; {}",
+ vmLockPrefix, nodeToWatch, event);
synchronized (ServiceLock.this) {
try {
if (createdNodeName != null) {
determineLockOwnership(createdEphemeralNode, lw);
} else if (LOG.isDebugEnabled()) {
- LOG.debug("[{}] While waiting for another lock {}, {} was deleted", vmLockPrefix,
- nodeToWatch, createdEphemeralNode);
+ LOG.debug("[{}] While waiting for another lock {}, {} was deleted; {}",
+ vmLockPrefix, nodeToWatch, createdEphemeralNode, event);
}
} catch (Exception e) {
if (lockNodeName == null) {
@@ -342,8 +339,9 @@ public class ServiceLock implements Watcher {
|| event.getState() == KeeperState.Disconnected) {
synchronized (ServiceLock.this) {
if (lockNodeName == null) {
- LOG.info("Zookeeper Session expired / disconnected");
- lw.failedToAcquireLock(new Exception("Zookeeper Session expired / disconnected"));
+ LOG.info("Zookeeper Session expired / disconnected; {}", event);
+ lw.failedToAcquireLock(
+ new Exception("Zookeeper Session expired / disconnected; " + event));
}
}
renew = false;
@@ -361,7 +359,8 @@ public class ServiceLock implements Watcher {
LOG.debug("[{}] Renewed watch on prior node {}", vmLockPrefix, nodeToWatch);
}
} catch (KeeperException | InterruptedException e) {
- lw.failedToAcquireLock(new Exception("Failed to renew watch on other manager node"));
+ lw.failedToAcquireLock(
+ new Exception("Failed to renew watch on other manager node", e));
}
}
}
@@ -466,16 +465,16 @@ public class ServiceLock implements Watcher {
synchronized (ServiceLock.this) {
if (lockNodeName != null && event.getType() == EventType.NodeDeleted
&& event.getPath().equals(path + "/" + lockNodeName)) {
- LOG.debug("[{}] {} was deleted", vmLockPrefix, lockNodeName);
+ LOG.debug("[{}] {} was deleted; {}", vmLockPrefix, lockNodeName, event);
lostLock(LockLossReason.LOCK_DELETED);
} else if (createdNodeName != null && event.getType() == EventType.NodeDeleted
&& event.getPath().equals(path + "/" + createdNodeName)) {
- LOG.debug("[{}] {} was deleted", vmLockPrefix, createdNodeName);
+ LOG.debug("[{}] {} was deleted; {}", vmLockPrefix, createdNodeName, event);
failedToAcquireLock();
} else if (event.getState() != KeeperState.Disconnected
&& event.getState() != KeeperState.Expired
&& (lockNodeName != null || createdNodeName != null)) {
- LOG.debug("Unexpected event watching lock node {} {}", event, pathForWatcher);
+ LOG.debug("Unexpected event watching lock node {}; {}", pathForWatcher, event);
try {
Stat stat2 = zooKeeper.exists(pathForWatcher, this);
if (stat2 == null) {
@@ -491,7 +490,7 @@ public class ServiceLock implements Watcher {
}
} catch (Exception e) {
lockWatcher.unableToMonitorLockNode(e);
- LOG.error("Failed to stat lock node: {} ", pathForWatcher, e);
+ LOG.error("Failed to stat lock node: {}; {}", pathForWatcher, event, e);
}
}
@@ -603,7 +602,7 @@ public class ServiceLock implements Watcher {
@Override
public synchronized void process(WatchedEvent event) {
if (LOG.isDebugEnabled()) {
- LOG.debug("event {} {} {}", event.getPath(), event.getType(), event.getState());
+ LOG.debug("{}", event);
}
watchingParent = false;
diff --git a/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooCache.java b/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooCache.java
index ace2b02905..4fc17feb33 100644
--- a/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooCache.java
+++ b/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooCache.java
@@ -171,26 +171,26 @@ public class ZooCache {
// These are ignored, because they are generated by SingletonManager closing
// ZooKeepers for ZooSession, and SingletonManager is already responsible for clearing
// caches via the registered ZooCacheFactory singleton
- log.trace("Zoo keeper connection closed, ignoring");
+ log.trace("ZooKeeper connection closed, ignoring; {}", event);
break;
case Disconnected:
- log.trace("Zoo keeper connection disconnected, clearing cache");
+ log.trace("ZooKeeper connection disconnected, clearing cache; {}", event);
clear();
break;
case SyncConnected:
- log.trace("Zoo keeper connection established, ignoring");
+ log.trace("ZooKeeper connection established, ignoring; {}", event);
break;
case Expired:
- log.trace("Zoo keeper connection expired, clearing cache");
+ log.trace("ZooKeeper connection expired, clearing cache; {}", event);
clear();
break;
default:
- log.warn("Unhandled: {}", event);
+ log.warn("Unhandled {}", event);
break;
}
break;
default:
- log.warn("Unhandled: {}", event);
+ log.warn("Unhandled {}", event);
break;
}
diff --git a/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooSession.java b/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooSession.java
index 76f608ab5c..c6dea78771 100644
--- a/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooSession.java
+++ b/core/src/main/java/org/apache/accumulo/fate/zookeeper/ZooSession.java
@@ -95,7 +95,7 @@ public class ZooSession {
@Override
public void process(WatchedEvent event) {
if (event.getState() == KeeperState.Expired) {
- log.debug("Session expired, state of current session : {}", event.getState());
+ log.debug("Session expired; {}", event);
}
}
diff --git a/server/base/src/main/java/org/apache/accumulo/server/security/delegation/ZooAuthenticationKeyWatcher.java b/server/base/src/main/java/org/apache/accumulo/server/security/delegation/ZooAuthenticationKeyWatcher.java
index 1cf140e2db..4e911ff03e 100644
--- a/server/base/src/main/java/org/apache/accumulo/server/security/delegation/ZooAuthenticationKeyWatcher.java
+++ b/server/base/src/main/java/org/apache/accumulo/server/security/delegation/ZooAuthenticationKeyWatcher.java
@@ -59,19 +59,19 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
case Disconnected: // Intentional fall through of case
case Expired: // ZooReader is handling the Expiration of the original ZooKeeper object for
// us
- log.debug("ZooKeeper connection disconnected, clearing secret manager");
+ log.debug("ZooKeeper connection disconnected, clearing secret manager; {}", event);
secretManager.removeAllKeys();
break;
case SyncConnected:
- log.debug("ZooKeeper reconnected, updating secret manager");
+ log.debug("ZooKeeper reconnected, updating secret manager; {}", event);
try {
updateAuthKeys();
} catch (KeeperException | InterruptedException e) {
- log.error("Failed to update secret manager after ZooKeeper reconnect");
+ log.error("Failed to update secret manager after ZooKeeper reconnect; {}", event, e);
}
break;
default:
- log.warn("Unhandled: {}", event);
+ log.warn("Unhandled {}", event);
}
// Nothing more to do for EventType.None
@@ -84,7 +84,7 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
}
if (!path.startsWith(baseNode)) {
- log.info("Ignoring event for path: {}", path);
+ log.info("Ignoring event for path {}; {}", path, event);
return;
}
@@ -95,7 +95,7 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
processChildNode(event);
}
} catch (KeeperException | InterruptedException e) {
- log.error("Failed to communicate with ZooKeeper", e);
+ log.error("Failed to communicate with ZooKeeper processing {}", event, e);
}
}
@@ -123,7 +123,7 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
// The data on the parent changed. We aren't storing anything there so it's a noop
break;
default:
- log.warn("Unsupported event type: {}", event.getType());
+ log.warn("Unsupported {}", event);
break;
}
}
@@ -167,7 +167,7 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
case NodeDeleted:
// Key expired
if (path == null) {
- log.error("Got null path for NodeDeleted event");
+ log.error("Got null path for {}", event);
return;
}
@@ -181,7 +181,7 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
case NodeCreated:
// New key created
if (path == null) {
- log.error("Got null path for NodeCreated event");
+ log.error("Got null path for {}", event);
return;
}
// Get the data and reset the watcher
@@ -192,7 +192,7 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
case NodeDataChanged:
// Key changed, could happen on restart after not running Accumulo.
if (path == null) {
- log.error("Got null path for NodeDataChanged event");
+ log.error("Got null path for {}", event);
return;
}
// Get the data and reset the watcher
@@ -202,10 +202,10 @@ public class ZooAuthenticationKeyWatcher implements Watcher {
break;
case NodeChildrenChanged:
// no children for the children..
- log.warn("Unexpected NodeChildrenChanged event for authentication key node {}", path);
+ log.warn("Unexpected event for authentication key node {}; {}", path, event);
break;
default:
- log.warn("Unsupported event type: {}", event.getType());
+ log.warn("Unsupported {}", event);
break;
}
}
diff --git a/server/base/src/main/java/org/apache/accumulo/server/tables/TableManager.java b/server/base/src/main/java/org/apache/accumulo/server/tables/TableManager.java
index 76c4a6a8eb..25f95ac3fb 100644
--- a/server/base/src/main/java/org/apache/accumulo/server/tables/TableManager.java
+++ b/server/base/src/main/java/org/apache/accumulo/server/tables/TableManager.java
@@ -258,7 +258,7 @@ public class TableManager {
if (zPath != null && zPath.equals(tablesPrefix)) {
updateTableStateCache();
} else {
- log.warn("Unexpected path {}", zPath);
+ log.warn("Unexpected path {} in {}", zPath, event);
}
break;
case NodeCreated:
@@ -281,7 +281,7 @@ public class TableManager {
case None:
switch (event.getState()) {
case Expired:
- log.trace("Session expired {}", event);
+ log.trace("Session expired; {}", event);
synchronized (observers) {
for (TableObserver to : observers)
to.sessionExpired();
diff --git a/server/base/src/main/java/org/apache/accumulo/server/zookeeper/DistributedWorkQueue.java b/server/base/src/main/java/org/apache/accumulo/server/zookeeper/DistributedWorkQueue.java
index cbbf81b22c..23a9c6a341 100644
--- a/server/base/src/main/java/org/apache/accumulo/server/zookeeper/DistributedWorkQueue.java
+++ b/server/base/src/main/java/org/apache/accumulo/server/zookeeper/DistributedWorkQueue.java
@@ -201,15 +201,16 @@ public class DistributedWorkQueue {
try {
lookForWork(processor, zoo.getChildren(path, this));
} catch (KeeperException e) {
- log.error("Failed to look for work", e);
+ log.error("Failed to look for work at path {}; {}", path, event, e);
} catch (InterruptedException e) {
- log.info("Interrupted looking for work", e);
+ log.info("Interrupted looking for work at path {}; {}", path, event, e);
}
else
- log.info("Unexpected path for NodeChildrenChanged event {}", event.getPath());
+ log.info("Unexpected path for NodeChildrenChanged event watching path {}; {}", path,
+ event);
break;
default:
- log.info("Got unexpected zookeeper event: {} for {}", event.getType(), path);
+ log.info("Unexpected event watching path {}; {}", path, event);
break;
}
}
@@ -270,7 +271,7 @@ public class DistributedWorkQueue {
}
break;
default:
- log.info("Got unexpected zookeeper event: {} for {}", event.getType(), path);
+ log.info("Got unexpected zookeeper event for path {}: {}", path, event);
break;
}
}