This is an automated email from the ASF dual-hosted git repository.
fangmin pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/zookeeper.git
The following commit(s) were added to refs/heads/master by this push:
new d84b7a6 ZOOKEEPER-3339: Improve Debug and Trace Log Statements
d84b7a6 is described below
commit d84b7a682eb4601005db9fac886079b1a9a4d4b0
Author: Beluga Behr <dam6923@gmail.com>
AuthorDate: Fri Aug 2 23:42:39 2019 -0700
ZOOKEEPER-3339: Improve Debug and Trace Log Statements
Author: Beluga Behr <dam6923@gmail.com>
Reviewers: andor@apache.org, nkalmar@apache.org, maoling@apache.org, fangmin@apache.org
Closes #878 from belugabehr/ZOOKEEPER-3339
---
.../zookeeper/recipes/lock/ProtocolSupport.java | 6 +--
.../apache/zookeeper/recipes/lock/WriteLock.java | 15 ++-----
.../zookeeper/recipes/queue/DistributedQueue.java | 3 +-
.../main/java/org/apache/zookeeper/ClientCnxn.java | 6 +--
.../org/apache/zookeeper/ClientCnxnSocketNIO.java | 29 +++---------
.../src/main/java/org/apache/zookeeper/Login.java | 4 +-
.../org/apache/zookeeper/SaslServerPrincipal.java | 4 +-
.../src/main/java/org/apache/zookeeper/ZKUtil.java | 6 +--
.../main/java/org/apache/zookeeper/ZooKeeper.java | 8 +---
.../java/org/apache/zookeeper/ZooKeeperMain.java | 2 +-
.../zookeeper/client/ZooKeeperSaslClient.java | 28 ++++++------
.../apache/zookeeper/common/FileChangeWatcher.java | 15 +++----
.../org/apache/zookeeper/common/NettyUtils.java | 6 +--
.../java/org/apache/zookeeper/server/DataTree.java | 16 +++----
.../zookeeper/server/FinalRequestProcessor.java | 9 ++--
.../org/apache/zookeeper/server/NIOServerCnxn.java | 51 +++++++++-------------
.../zookeeper/server/NIOServerCnxnFactory.java | 9 ++--
.../apache/zookeeper/server/NettyServerCnxn.java | 24 ++++------
.../zookeeper/server/NettyServerCnxnFactory.java | 40 ++++++-----------
.../zookeeper/server/SessionTrackerImpl.java | 12 +++--
.../apache/zookeeper/server/ZooKeeperServer.java | 48 ++++++++++----------
.../server/auth/KeyAuthenticationProvider.java | 4 +-
.../server/auth/SaslServerCallbackHandler.java | 2 +-
.../zookeeper/server/persistence/FileTxnLog.java | 6 +--
.../zookeeper/server/quorum/CommitProcessor.java | 8 +---
.../server/quorum/FastLeaderElection.java | 21 ++++-----
.../org/apache/zookeeper/server/quorum/Leader.java | 14 ++----
.../zookeeper/server/quorum/LearnerHandler.java | 31 +++++++------
.../zookeeper/server/quorum/QuorumCnxManager.java | 30 ++++++-------
.../apache/zookeeper/server/quorum/QuorumPeer.java | 7 +--
.../server/quorum/auth/SaslQuorumAuthLearner.java | 4 +-
.../server/quorum/flexible/QuorumHierarchical.java | 10 ++---
.../org/apache/zookeeper/util/SecurityUtils.java | 9 ++--
33 files changed, 207 insertions(+), 280 deletions(-)
diff --git a/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/ProtocolSupport.java b/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/ProtocolSupport.java
index 4efdb85..a4cd989 100644
--- a/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/ProtocolSupport.java
+++ b/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/ProtocolSupport.java
@@ -126,8 +126,8 @@ class ProtocolSupport {
if (exception == null) {
exception = e;
}
- LOG.debug("Attempt " + i + " failed with connection loss so " +
- "attempting to reconnect: " + e, e);
+ LOG.debug("Attempt {} failed with connection loss so " +
+ "attempting to reconnect", i, e);
retryDelay(i);
}
}
@@ -186,7 +186,7 @@ class ProtocolSupport {
try {
Thread.sleep(attemptCount * retryDelay);
} catch (InterruptedException e) {
- LOG.debug("Failed to sleep: " + e, e);
+ LOG.debug("Failed to sleep", e);
}
}
}
diff --git a/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/WriteLock.java b/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/WriteLock.java
index 09587ed..693d1e8 100644
--- a/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/WriteLock.java
+++ b/zookeeper-recipes/zookeeper-recipes-lock/src/main/java/org/apache/zookeeper/recipes/lock/WriteLock.java
@@ -151,8 +151,7 @@ public class WriteLock extends ProtocolSupport {
private class LockWatcher implements Watcher {
public void process(WatchedEvent event) {
// lets either become the leader or watch the new/updated node
- LOG.debug("Watcher fired on path: " + event.getPath() + " state: " +
- event.getState() + " type " + event.getType());
+ LOG.debug("Watcher fired: {}", event);
try {
lock();
} catch (Exception e) {
@@ -181,9 +180,7 @@ public class WriteLock extends ProtocolSupport {
for (String name : names) {
if (name.startsWith(prefix)) {
id = name;
- if (LOG.isDebugEnabled()) {
- LOG.debug("Found id created last time: " + id);
- }
+ LOG.debug("Found id created last time: {}", id);
break;
}
}
@@ -191,9 +188,7 @@ public class WriteLock extends ProtocolSupport {
id = zookeeper.create(dir + "/" + prefix, data,
getAcl(), EPHEMERAL_SEQUENTIAL);
- if (LOG.isDebugEnabled()) {
- LOG.debug("Created id: " + id);
- }
+ LOG.debug("Created id: {}", id);
}
}
@@ -232,9 +227,7 @@ public class WriteLock extends ProtocolSupport {
if (!lessThanMe.isEmpty()) {
ZNodeName lastChildName = lessThanMe.last();
lastChildId = lastChildName.getName();
- if (LOG.isDebugEnabled()) {
- LOG.debug("watching less than me node: " + lastChildId);
- }
+ LOG.debug("watching less than me node: {}", lastChildId);
Stat stat = zookeeper.exists(lastChildId, new LockWatcher());
if (stat != null) {
return Boolean.FALSE;
diff --git a/zookeeper-recipes/zookeeper-recipes-queue/src/main/java/org/apache/zookeeper/recipes/queue/DistributedQueue.java b/zookeeper-recipes/zookeeper-recipes-queue/src/main/java/org/apache/zookeeper/recipes/queue/DistributedQueue.java
index ca01541..ae11cc8 100644
--- a/zookeeper-recipes/zookeeper-recipes-queue/src/main/java/org/apache/zookeeper/recipes/queue/DistributedQueue.java
+++ b/zookeeper-recipes/zookeeper-recipes-queue/src/main/java/org/apache/zookeeper/recipes/queue/DistributedQueue.java
@@ -218,8 +218,7 @@ public class DistributedQueue {
}
public void process(WatchedEvent event){
- LOG.debug("Watcher fired on path: " + event.getPath() + " state: " +
- event.getState() + " type " + event.getType());
+ LOG.debug("Watcher fired: {}", event);
latch.countDown();
}
public void await() throws InterruptedException {
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxn.java b/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxn.java
index 4125f24..5148dab 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxn.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxn.java
@@ -1050,10 +1050,8 @@ public class ClientCnxn {
outgoingQueue.addFirst(new Packet(null, null, conReq,
null, null, readOnly));
clientCnxnSocket.connectionPrimed();
- if (LOG.isDebugEnabled()) {
- LOG.debug("Session establishment request sent on "
- + clientCnxnSocket.getRemoteSocketAddress());
- }
+ LOG.debug("Session establishment request sent on {}",
+ clientCnxnSocket.getRemoteSocketAddress());
}
private List<String> prependChroot(List<String> paths) {
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNIO.java b/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNIO.java
index bda31ba..0ce64ab 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNIO.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNIO.java
@@ -196,39 +196,28 @@ public class ClientCnxnSocketNIO extends ClientCnxnSocket {
try {
sock.socket().shutdownInput();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Ignoring exception during shutdown input", e);
- }
+ LOG.debug("Ignoring exception during shutdown input", e);
}
try {
sock.socket().shutdownOutput();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Ignoring exception during shutdown output",
- e);
- }
+ LOG.debug("Ignoring exception during shutdown output", e);
}
try {
sock.socket().close();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Ignoring exception during socket close", e);
- }
+ LOG.debug("Ignoring exception during socket close", e);
}
try {
sock.close();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Ignoring exception during channel close", e);
- }
+ LOG.debug("Ignoring exception during channel close", e);
}
}
try {
Thread.sleep(100);
} catch (InterruptedException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("SendThread interrupted during sleep, ignoring");
- }
+ LOG.debug("SendThread interrupted during sleep, ignoring");
}
sockKey = null;
}
@@ -236,13 +225,9 @@ public class ClientCnxnSocketNIO extends ClientCnxnSocket {
@Override
void close() {
try {
- if (LOG.isTraceEnabled()) {
- LOG.trace("Doing client selector close");
- }
+ LOG.trace("Doing client selector close");
selector.close();
- if (LOG.isTraceEnabled()) {
- LOG.trace("Closed client selector");
- }
+ LOG.trace("Closed client selector");
} catch (IOException e) {
LOG.warn("Ignoring exception during selector close", e);
}
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java b/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java
index d97d6c1..5806fcb 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java
@@ -335,8 +335,8 @@ public class Login {
for(KerberosTicket ticket: tickets) {
KerberosPrincipal server = ticket.getServer();
if (server.getName().equals("krbtgt/" + server.getRealm() + "@" + server.getRealm())) {
- LOG.debug("Client principal is \"" + ticket.getClient().getName() + "\".");
- LOG.debug("Server principal is \"" + ticket.getServer().getName() + "\".");
+ LOG.debug("Client principal is \"{}\".", ticket.getClient().getName());
+ LOG.debug("Server principal is \"{}\".", ticket.getServer().getName());
return ticket;
}
}
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/SaslServerPrincipal.java b/zookeeper-server/src/main/java/org/apache/zookeeper/SaslServerPrincipal.java
index 2694f77..403bf07 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/SaslServerPrincipal.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/SaslServerPrincipal.java
@@ -71,9 +71,7 @@ public class SaslServerPrincipal {
if (!canonicalHostName.equals(ia.getHostAddress())) {
hostName = canonicalHostName;
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("Canonicalized address to {}", hostName);
- }
+ LOG.debug("Canonicalized address to {}", hostName);
}
String serverPrincipal = principalUserName + "/" + hostName;
return serverPrincipal;
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/ZKUtil.java b/zookeeper-server/src/main/java/org/apache/zookeeper/ZKUtil.java
index 8f758c9..b1bad3f 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/ZKUtil.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/ZKUtil.java
@@ -53,8 +53,7 @@ public class ZKUtil {
PathUtils.validatePath(pathRoot);
List<String> tree = listSubTreeBFS(zk, pathRoot);
- LOG.debug("Deleting {}",tree);
- LOG.debug("Deleting {} subnodes ",tree.size());
+ LOG.debug("Deleting tree: {}", tree);
return deleteInBatch(zk, tree, batchSize);
}
@@ -125,8 +124,7 @@ public class ZKUtil {
PathUtils.validatePath(pathRoot);
List<String> tree = listSubTreeBFS(zk, pathRoot);
- LOG.debug("Deleting {}",tree);
- LOG.debug("Deleting {} subnodes ",tree.size());
+ LOG.debug("Deleting tree: {}", tree);
for (int i = tree.size() - 1; i >= 0 ; --i) {
//Delete the leaves first and eventually get rid of the root
zk.delete(tree.get(i), -1, cb, ctx); //Delete all versions of the node with -1.
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeper.java b/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeper.java
index 6f78925..ab45061 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeper.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeper.java
@@ -1406,9 +1406,7 @@ public class ZooKeeper implements AutoCloseable {
*/
public synchronized void close() throws InterruptedException {
if (!cnxn.getState().isAlive()) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Close called on already closed client");
- }
+ LOG.debug("Close called on already closed client");
return;
}
@@ -1419,9 +1417,7 @@ public class ZooKeeper implements AutoCloseable {
try {
cnxn.close();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Ignoring unexpected exception during close", e);
- }
+ LOG.debug("Ignoring unexpected exception during close", e);
}
LOG.info("Session: 0x" + Long.toHexString(getSessionId()) + " closed");
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeperMain.java b/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeperMain.java
index 8b0caf9..ea7b21c 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeperMain.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/ZooKeeperMain.java
@@ -405,7 +405,7 @@ public class ZooKeeperMain {
}
boolean watch = false;
- LOG.debug("Processing " + cmd);
+ LOG.debug("Processing {}", cmd);
if (cmd.equals("quit")) {
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/client/ZooKeeperSaslClient.java b/zookeeper-server/src/main/java/org/apache/zookeeper/client/ZooKeeperSaslClient.java
index 34f6656..b8c2aaa 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/client/ZooKeeperSaslClient.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/client/ZooKeeperSaslClient.java
@@ -225,11 +225,15 @@ public class ZooKeeperSaslClient {
}
byte[] usedata = data;
if (data != null) {
- LOG.debug("ServerSaslResponseCallback(): saslToken server response: (length="+usedata.length+")");
+ LOG.debug(
+ "ServerSaslResponseCallback(): saslToken server response: (length={})",
+ usedata.length);
}
else {
usedata = new byte[0];
- LOG.debug("ServerSaslResponseCallback(): using empty data[] as server response (length="+usedata.length+")");
+ LOG.debug(
+ "ServerSaslResponseCallback(): using empty data[] as server response (length={})",
+ usedata.length);
}
client.respondToServer(usedata, (ClientCnxn)ctx);
}
@@ -241,9 +245,7 @@ public class ZooKeeperSaslClient {
if (!initializedLogin) {
synchronized (this) {
if (login == null) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("JAAS loginContext is: " + loginContext);
- }
+ LOG.debug("JAAS loginContext is: {}", loginContext);
// note that the login object is static: it's shared amongst all zookeeper-related connections.
// in order to ensure the login is initialized only once, it must be synchronized the code snippet.
login = new Login(loginContext, new SaslClientCallbackHandler(null, "Client"), clientConfig);
@@ -319,7 +321,7 @@ public class ZooKeeperSaslClient {
final byte[] retval =
Subject.doAs(subject, new PrivilegedExceptionAction<byte[]>() {
public byte[] run() throws SaslException {
- LOG.debug("saslClient.evaluateChallenge(len="+saslToken.length+")");
+ LOG.debug("saslClient.evaluateChallenge(len={})", saslToken.length);
return saslClient.evaluateChallenge(saslToken);
}
});
@@ -352,9 +354,7 @@ public class ZooKeeperSaslClient {
private void sendSaslPacket(byte[] saslToken, ClientCnxn cnxn)
throws SaslException{
- if (LOG.isDebugEnabled()) {
- LOG.debug("ClientCnxn:sendSaslPacket:length="+saslToken.length);
- }
+ LOG.debug("ClientCnxn:sendSaslPacket:length={}", saslToken.length);
GetSASLRequest request = new GetSASLRequest();
request.setToken(saslToken);
@@ -370,9 +370,8 @@ public class ZooKeeperSaslClient {
}
private void sendSaslPacket(ClientCnxn cnxn) throws SaslException {
- if (LOG.isDebugEnabled()) {
- LOG.debug("ClientCnxn:sendSaslPacket:length="+saslToken.length);
- }
+ LOG.debug("ClientCnxn:sendSaslPacket:length={}", saslToken.length);
+
GetSASLRequest request = new GetSASLRequest();
request.setToken(createSaslToken());
SetSASLResponse response = new SetSASLResponse();
@@ -456,9 +455,8 @@ public class ZooKeeperSaslClient {
} catch (SecurityException e) {
// Thrown if the caller does not have permission to retrieve the Configuration.
// In this case, simply returning false is correct.
- if (LOG.isDebugEnabled()) {
- LOG.debug("Could not retrieve login configuration: " + e);
- }
+ LOG.debug("Could not retrieve login configuration", e);
+
return false;
}
}
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/common/FileChangeWatcher.java b/zookeeper-server/src/main/java/org/apache/zookeeper/common/FileChangeWatcher.java
index 8b49be9..4e7fba3 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/common/FileChangeWatcher.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/common/FileChangeWatcher.java
@@ -69,9 +69,9 @@ public final class FileChangeWatcher {
public FileChangeWatcher(Path dirPath, Consumer<WatchEvent<?>> callback) throws IOException {
FileSystem fs = dirPath.getFileSystem();
WatchService watchService = fs.newWatchService();
- if (LOG.isDebugEnabled()) {
- LOG.debug("Registering with watch service: " + dirPath);
- }
+
+ LOG.debug("Registering with watch service: {}", dirPath);
+
dirPath.register(
watchService,
new WatchEvent.Kind<?>[]{
@@ -223,15 +223,12 @@ public final class FileChangeWatcher {
try {
key = watchService.take();
} catch (InterruptedException|ClosedWatchServiceException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug(getName() + " was interrupted and is shutting down ...");
- }
+ LOG.debug("{} was interrupted and is shutting down...", getName());
break;
}
for (WatchEvent<?> event : key.pollEvents()) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Got file changed event: " + event.kind() + " with context: " + event.context());
- }
+ LOG.debug("Got file changed event: {} with context: {}", event.kind(),
+ event.context());
try {
callback.accept(event);
} catch (Throwable e) {
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/common/NettyUtils.java b/zookeeper-server/src/main/java/org/apache/zookeeper/common/NettyUtils.java
index 283ea87..d55281f 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/common/NettyUtils.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/common/NettyUtils.java
@@ -151,10 +151,8 @@ public class NettyUtils {
validInetAddresses.add(inetAddress);
}
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("Detected {} local network addresses", validInetAddresses.size());
- LOG.debug("Resolved local addresses are: {}", Arrays.toString(validInetAddresses.toArray()));
- }
+ LOG.debug("Detected {} local network addresses: {}",
+ validInetAddresses.size(), validInetAddresses);
return validInetAddresses.size() > 0 ? validInetAddresses.size() : DEFAULT_INET_ADDRESS_COUNT;
} catch (SocketException ex) {
LOG.warn("Failed to list all network interfaces, assuming 1", ex);
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/DataTree.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/DataTree.java
index 1c7f4dc..d2371ff 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/DataTree.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/DataTree.java
@@ -1033,14 +1033,10 @@ public class DataTree {
break;
}
} catch (KeeperException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Failed: " + header + ":" + txn, e);
- }
+ LOG.debug("Failed: {}:{}", header, txn, e);
rc.err = e.code().intValue();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Failed: " + header + ":" + txn, e);
- }
+ LOG.debug("Failed: {}:{}", header, txn, e);
}
/*
@@ -1059,8 +1055,8 @@ public class DataTree {
*/
if (header.getType() == OpCode.create &&
rc.err == Code.NODEEXISTS.intValue()) {
- LOG.debug("Adjusting parent cversion for Txn: " + header.getType() +
- " path:" + rc.path + " err: " + rc.err);
+ LOG.debug("Adjusting parent cversion for Txn: {} path: {} err: {}",
+ header.getType(), rc.path, rc.err);
int lastSlash = rc.path.lastIndexOf('/');
String parentName = rc.path.substring(0, lastSlash);
CreateTxn cTxn = (CreateTxn)txn;
@@ -1073,8 +1069,8 @@ public class DataTree {
rc.err = e.code().intValue();
}
} else if (rc.err != Code.OK.intValue()) {
- LOG.debug("Ignoring processTxn failure hdr: " + header.getType() +
- " : error: " + rc.err);
+ LOG.debug("Ignoring processTxn failure hdr: {} : error: {}",
+ header.getType(), rc.err);
}
/*
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/FinalRequestProcessor.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/FinalRequestProcessor.java
index 962a267..528c4ba 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/FinalRequestProcessor.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/FinalRequestProcessor.java
@@ -105,9 +105,8 @@ public class FinalRequestProcessor implements RequestProcessor {
}
public void processRequest(Request request) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Processing request:: " + request);
- }
+ LOG.debug("Processing request:: {}", request);
+
// request.addRQRec(">final");
long traceMask = ZooTrace.CLIENT_REQUEST_TRACE_MASK;
if (request.type == OpCode.ping) {
@@ -213,9 +212,7 @@ public class FinalRequestProcessor implements RequestProcessor {
throw ke;
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("{}",request);
- }
+ LOG.debug("{}",request);
if (request.isStale()) {
ServerMetrics.getMetrics().STALE_REPLIES.add(1);
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxn.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxn.java
index d94d407..10424ae 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxn.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxn.java
@@ -135,10 +135,9 @@ public class NIOServerCnxn extends ServerCnxn {
* asynchronous writes.
*/
public void sendBuffer(ByteBuffer... buffers) {
- if (LOG.isTraceEnabled()) {
- LOG.trace("Add a buffer to outgoingBuffers, sk " + sk
- + " is valid: " + sk.isValid());
- }
+ LOG.trace("Add a buffer to outgoingBuffers, sk {} is valid: {}", sk,
+ sk.isValid());
+
synchronized (outgoingBuffers) {
for (ByteBuffer buffer : buffers) {
outgoingBuffers.add(buffer);
@@ -363,9 +362,9 @@ public class NIOServerCnxn extends ServerCnxn {
} catch (CancelledKeyException e) {
LOG.warn("CancelledKeyException causing close of session 0x"
+ Long.toHexString(sessionId));
- if (LOG.isDebugEnabled()) {
- LOG.debug("CancelledKeyException stack trace", e);
- }
+
+ LOG.debug("CancelledKeyException stack trace", e);
+
close(DisconnectReason.CANCELLED_KEY_EXCEPTION);
} catch (CloseRequestException e) {
// expecting close to log session closure
@@ -385,9 +384,8 @@ public class NIOServerCnxn extends ServerCnxn {
} catch (IOException e) {
LOG.warn("Exception causing close of session 0x"
+ Long.toHexString(sessionId) + ": " + e.getMessage());
- if (LOG.isDebugEnabled()) {
- LOG.debug("IOException stack trace", e);
- }
+
+ LOG.debug("IOException stack trace", e);
close(DisconnectReason.IO_EXCEPTION);
}
}
@@ -613,9 +611,7 @@ public class NIOServerCnxn extends ServerCnxn {
// need to cancel this selection key from the selector
sk.cancel();
} catch (Exception e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("ignoring exception during selectionkey cancel", e);
- }
+ LOG.debug("ignoring exception during selectionkey cancel", e);
}
}
@@ -630,11 +626,14 @@ public class NIOServerCnxn extends ServerCnxn {
return;
}
- LOG.debug("Closed socket connection for client "
- + sock.socket().getRemoteSocketAddress()
- + (sessionId != 0 ?
- " which had sessionid 0x" + Long.toHexString(sessionId) :
- " (no session established for client)"));
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Closed socket connection for client "
+ + sock.socket().getRemoteSocketAddress()
+ + (sessionId != 0 ?
+ " which had sessionid 0x" + Long.toHexString(sessionId) :
+ " (no session established for client)"));
+ }
+
closeSock(sock);
}
@@ -656,31 +655,23 @@ public class NIOServerCnxn extends ServerCnxn {
sock.socket().shutdownOutput();
} catch (IOException e) {
// This is a relatively common exception that we can't avoid
- if (LOG.isDebugEnabled()) {
- LOG.debug("ignoring exception during output shutdown", e);
- }
+ LOG.debug("ignoring exception during output shutdown", e);
}
try {
sock.socket().shutdownInput();
} catch (IOException e) {
// This is a relatively common exception that we can't avoid
- if (LOG.isDebugEnabled()) {
- LOG.debug("ignoring exception during input shutdown", e);
- }
+ LOG.debug("ignoring exception during input shutdown", e);
}
try {
sock.socket().close();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("ignoring exception during socket close", e);
- }
+ LOG.debug("ignoring exception during socket close", e);
}
try {
sock.close();
} catch (IOException e) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("ignoring exception during socketchannel close", e);
- }
+ LOG.debug("ignoring exception during socketchannel close", e);
}
}
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxnFactory.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxnFactory.java
index 67d799b..f76279f 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxnFactory.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NIOServerCnxnFactory.java
@@ -151,9 +151,7 @@ public class NIOServerCnxnFactory extends ServerCnxnFactory {
try {
key.cancel();
} catch (Exception ex) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("ignoring exception during selectionkey cancel", ex);
- }
+ LOG.debug("ignoring exception during selectionkey cancel", ex);
}
}
}
@@ -293,8 +291,9 @@ public class NIOServerCnxnFactory extends ServerCnxnFactory {
+ " - max is " + maxClientCnxns );
}
- LOG.debug("Accepted socket connection from "
- + sc.socket().getRemoteSocketAddress());
+ LOG.debug("Accepted socket connection from {}",
+ sc.socket().getRemoteSocketAddress());
+
sc.configureBlocking(false);
// Round-robin assign this connection to a selector thread
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxn.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxn.java
index 33161e4..245b55d 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxn.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxn.java
@@ -371,9 +371,8 @@ public class NettyServerCnxn extends ServerCnxn {
// Have to check !closingChannel, because an error in
// receiveMessage() could have led to close() being called.
if (!closingChannel && buf.isReadable()) {
- if (LOG.isTraceEnabled()) {
- LOG.trace("Before copy {}", buf);
- }
+ LOG.trace("Before copy {}", buf);
+
if (queuedBuffer == null) {
queuedBuffer = channel.alloc().compositeBuffer();
}
@@ -488,10 +487,8 @@ public class NettyServerCnxn extends ServerCnxn {
// we could implement zero-copy queueing.
zks.processPacket(this, bb);
} else {
- if (LOG.isDebugEnabled()) {
- LOG.debug("got conn req request from {}",
- getRemoteSocketAddress());
- }
+ LOG.debug("got conn req request from {}",
+ getRemoteSocketAddress());
zks.processConnectRequest(this, bb);
initialized = true;
}
@@ -548,9 +545,8 @@ public class NettyServerCnxn extends ServerCnxn {
} catch(ClientCnxnLimitException e) {
// Common case exception, print at debug level
ServerMetrics.getMetrics().CONNECTION_REJECTED.add(1);
- if (LOG.isDebugEnabled()) {
- LOG.debug("Closing connection to " + getRemoteSocketAddress(), e);
- }
+
+ LOG.debug("Closing connection to " + getRemoteSocketAddress(), e);
close(DisconnectReason.CLIENT_RATE_LIMIT);
}
}
@@ -573,9 +569,7 @@ public class NettyServerCnxn extends ServerCnxn {
@Override
public void disableRecv(boolean waitDisableRecv) {
if (throttled.compareAndSet(false, true)) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Throttling - disabling recv {}", this);
- }
+ LOG.debug("Throttling - disabling recv {}", this);
channel.pipeline().fireUserEventTriggered(ReadEvent.DISABLE);
}
}
@@ -583,9 +577,7 @@ public class NettyServerCnxn extends ServerCnxn {
@Override
public void enableRecv() {
if (throttled.compareAndSet(true, false)) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Sending unthrottle event {}", this);
- }
+ LOG.debug("Sending unthrottle event {}", this);
channel.pipeline().fireUserEventTriggered(ReadEvent.ENABLE);
}
}
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxnFactory.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxnFactory.java
index e3ae959..8928c53 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxnFactory.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/NettyServerCnxnFactory.java
@@ -232,9 +232,7 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
LOG.warn("Exception caught", cause);
NettyServerCnxn cnxn = ctx.channel().attr(CONNECTION_ATTRIBUTE).getAndSet(null);
if (cnxn != null) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Closing {}", cnxn);
- }
+ LOG.debug("Closing {}", cnxn);
cnxn.close(ServerCnxn.DisconnectReason.CHANNEL_CLOSED_EXCEPTION);
}
}
@@ -256,9 +254,7 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
// trigger a read if we have consumed all
// backlog
ctx.read();
- if (LOG.isDebugEnabled()) {
- LOG.debug("Issued a read after queuedBuffer drained");
- }
+ LOG.debug("Issued a read after queuedBuffer drained");
}
}
}
@@ -277,13 +273,9 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
@Override
public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception {
try {
- if (LOG.isTraceEnabled()) {
- LOG.trace("message received called {}", msg);
- }
+ LOG.trace("message received called {}", msg);
try {
- if (LOG.isDebugEnabled()) {
- LOG.debug("New message {} from {}", msg, ctx.channel());
- }
+ LOG.debug("New message {} from {}", msg, ctx.channel());
NettyServerCnxn cnxn = ctx.channel().attr(CONNECTION_ATTRIBUTE).get();
if (cnxn == null) {
LOG.error("channelRead() on a closed or closing NettyServerCnxn");
@@ -306,10 +298,8 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
if (cnxn != null && cnxn.getQueuedReadableBytes() == 0 &&
cnxn.readIssuedAfterReadComplete == 0) {
ctx.read();
- if (LOG.isDebugEnabled()) {
- LOG.debug("Issued a read since we don't have " +
- "anything to consume after channelReadComplete");
- }
+ LOG.debug("Issued a read since we do not have " +
+ "anything to consume after channelReadComplete");
}
}
@@ -320,7 +310,7 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
// Note: this listener is only added when LOG.isTraceEnabled() is true,
// so it should not do any work other than trace logging.
private final GenericFutureListener<Future<Void>> onWriteCompletedTracer = (f) -> {
- LOG.trace("write {}", f.isSuccess() ? "complete" : "failed");
+ LOG.trace("write success: {}", f.isSuccess());
};
@Override
@@ -534,9 +524,8 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
@Override
public void closeAll(ServerCnxn.DisconnectReason reason) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("closeAll()");
- }
+ LOG.debug("closeAll()");
+
// clear all the connections on which we are selecting
int length = cnxns.size();
for (ServerCnxn cnxn : cnxns) {
@@ -548,10 +537,9 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
+ Long.toHexString(cnxn.getSessionId()), e);
}
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("allChannels size:" + allChannels.size() + " cnxns size:"
- + length);
- }
+
+ LOG.debug("allChannels size: {} cnxns size: {}", allChannels.size(),
+ length);
}
@Override
@@ -656,7 +644,7 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
// Port changes after bind() if the original port was 0, update
// localAddress to get the real port.
localAddress = (InetSocketAddress) parentChannel.localAddress();
- LOG.info("bound to port " + getLocalPort());
+ LOG.info("bound to port {}", getLocalPort());
}
public void reconfigure(InetSocketAddress addr) {
@@ -667,7 +655,7 @@ public class NettyServerCnxnFactory extends ServerCnxnFactory {
// Port changes after bind() if the original port was 0, update
// localAddress to get the real port.
localAddress = (InetSocketAddress) parentChannel.localAddress();
- LOG.info("bound to port " + getLocalPort());
+ LOG.info("bound to port {}", getLocalPort());
} catch (Exception e) {
LOG.error("Error while reconfiguring", e);
} finally {
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/SessionTrackerImpl.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/SessionTrackerImpl.java
index a984f20..28b0948 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/SessionTrackerImpl.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/SessionTrackerImpl.java
@@ -221,7 +221,9 @@ public class SessionTrackerImpl extends ZooKeeperCriticalThread implements
}
synchronized public void removeSession(long sessionId) {
- LOG.debug("Removing session 0x" + Long.toHexString(sessionId));
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Removing session 0x{}", Long.toHexString(sessionId));
+ }
SessionImpl s = sessionsById.remove(sessionId);
sessionsWithTimeout.remove(sessionId);
if (LOG.isTraceEnabled()) {
@@ -267,7 +269,9 @@ public class SessionTrackerImpl extends ZooKeeperCriticalThread implements
session = existedSession;
} else {
added = true;
- LOG.debug("Adding session 0x" + Long.toHexString(id));
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Adding session 0x{}", Long.toHexString(id));
+ }
}
if (LOG.isTraceEnabled()) {
@@ -293,7 +297,9 @@ public class SessionTrackerImpl extends ZooKeeperCriticalThread implements
throws KeeperException.SessionExpiredException,
KeeperException.SessionMovedException,
KeeperException.UnknownSessionException {
- LOG.debug("Checking session 0x" + Long.toHexString(sessionId));
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Checking session 0x" + Long.toHexString(sessionId));
+ }
SessionImpl session = sessionsById.get(sessionId);
if (session == null) {
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java
index e580ab5..fd24873 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java
@@ -938,11 +938,13 @@ public class ZooKeeperServer implements SessionExpirer, ServerStats.Provider {
cnxn.sendBuffer(bb);
if (valid) {
- LOG.debug("Established session 0x"
- + Long.toHexString(cnxn.getSessionId())
- + " with negotiated timeout " + cnxn.getSessionTimeout()
- + " for client "
- + cnxn.getRemoteSocketAddress());
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Established session 0x"
+ + Long.toHexString(cnxn.getSessionId())
+ + " with negotiated timeout " + cnxn.getSessionTimeout()
+ + " for client "
+ + cnxn.getRemoteSocketAddress());
+ }
cnxn.enableRecv();
} else {
@@ -1291,20 +1293,24 @@ public class ZooKeeperServer implements SessionExpirer, ServerStats.Provider {
long sessionId = connReq.getSessionId();
if (sessionId == 0) {
long id = createSession(cnxn, passwd, sessionTimeout);
- LOG.debug("Client attempting to establish new session:" +
- " session = 0x{}, zxid = 0x{}, timeout = {}, address = {}",
- Long.toHexString(id),
- Long.toHexString(connReq.getLastZxidSeen()),
- connReq.getTimeOut(),
- cnxn.getRemoteSocketAddress());
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Client attempting to establish new session:" +
+ " session = 0x{}, zxid = 0x{}, timeout = {}, address = {}",
+ Long.toHexString(id),
+ Long.toHexString(connReq.getLastZxidSeen()),
+ connReq.getTimeOut(),
+ cnxn.getRemoteSocketAddress());
+ }
} else {
long clientSessionId = connReq.getSessionId();
- LOG.debug("Client attempting to renew session:" +
- " session = 0x{}, zxid = 0x{}, timeout = {}, address = {}",
- Long.toHexString(clientSessionId),
- Long.toHexString(connReq.getLastZxidSeen()),
- connReq.getTimeOut(),
- cnxn.getRemoteSocketAddress());
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Client attempting to renew session:" +
+ " session = 0x{}, zxid = 0x{}, timeout = {}, address = {}",
+ Long.toHexString(clientSessionId),
+ Long.toHexString(connReq.getLastZxidSeen()),
+ connReq.getTimeOut(),
+ cnxn.getRemoteSocketAddress());
+ }
if (serverCnxnFactory != null) {
serverCnxnFactory.closeSession(sessionId, ServerCnxn.DisconnectReason.CLIENT_RECONNECT);
}
@@ -1392,9 +1398,7 @@ public class ZooKeeperServer implements SessionExpirer, ServerStats.Provider {
}
}
if (authReturn == KeeperException.Code.OK) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Authentication succeeded for scheme: " + scheme);
- }
+ LOG.debug("Authentication succeeded for scheme: {}", scheme);
LOG.info("auth success " + cnxn.getRemoteSocketAddress());
ReplyHeader rh = new ReplyHeader(h.getXid(), 0,
KeeperException.Code.OK.intValue());
@@ -1460,7 +1464,7 @@ public class ZooKeeperServer implements SessionExpirer, ServerStats.Provider {
GetSASLRequest clientTokenRecord = new GetSASLRequest();
ByteBufferInputStream.byteBuffer2Record(incomingBuffer,clientTokenRecord);
byte[] clientToken = clientTokenRecord.getToken();
- LOG.debug("Size of client SASL token: " + clientToken.length);
+ LOG.debug("Size of client SASL token: {}", clientToken.length);
byte[] responseToken = null;
try {
ZooKeeperSaslServer saslServer = cnxn.zooKeeperSaslServer;
@@ -1506,7 +1510,7 @@ public class ZooKeeperServer implements SessionExpirer, ServerStats.Provider {
LOG.error("cnxn.saslServer is null: cnxn object did not initialize its saslServer properly.");
}
if (responseToken != null) {
- LOG.debug("Size of server SASL response: " + responseToken.length);
+ LOG.debug("Size of server SASL response: {}", responseToken.length);
}
ReplyHeader replyHeader = new ReplyHeader(requestHeader.getXid(), 0, Code.OK.intValue());
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/KeyAuthenticationProvider.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/KeyAuthenticationProvider.java
index 90cfe92..0b53bba 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/KeyAuthenticationProvider.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/KeyAuthenticationProvider.java
@@ -108,7 +108,9 @@ public class KeyAuthenticationProvider extends ServerAuthenticationProvider {
// empty key
keyStr = authStr;
}
- LOG.debug("KeyAuthenticationProvider handleAuthentication ("+keyStr+", "+authStr+") -> FAIL.\n");
+ LOG.debug(
+ "KeyAuthenticationProvider handleAuthentication ({}, {}) -> FAIL.\n",
+ keyStr, authStr);
return KeeperException.Code.AUTHFAILED;
}
}
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/SaslServerCallbackHandler.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/SaslServerCallbackHandler.java
index 9f53a4d..f3d767b 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/SaslServerCallbackHandler.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/auth/SaslServerCallbackHandler.java
@@ -109,7 +109,7 @@ public class SaslServerCallbackHandler implements CallbackHandler {
}
private void handleRealmCallback(RealmCallback rc) {
- LOG.debug("client supplied realm: " + rc.getDefaultText());
+ LOG.debug("client supplied realm: {}", rc.getDefaultText());
rc.setText(rc.getDefaultText());
}
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnLog.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnLog.java
index ec3113b..41f293b 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnLog.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnLog.java
@@ -723,10 +723,10 @@ public class FileTxnLog implements TxnLog {
protected InputArchive createInputArchive(File logFile) throws IOException {
if(inputStream==null){
inputStream= new PositionInputStream(new BufferedInputStream(new FileInputStream(logFile)));
- LOG.debug("Created new input stream " + logFile);
+ LOG.debug("Created new input stream: {}", logFile);
ia = BinaryInputArchive.getArchive(inputStream);
inStreamCreated(ia,inputStream);
- LOG.debug("Created new input archive " + logFile);
+ LOG.debug("Created new input archive: {}", logFile);
}
return ia;
}
@@ -764,7 +764,7 @@ public class FileTxnLog implements TxnLog {
hdr = new TxnHeader();
record = SerializeUtils.deserializeTxn(bytes, hdr);
} catch (EOFException e) {
- LOG.debug("EOF exception " + e);
+ LOG.debug("EOF exception", e);
inputStream.close();
inputStream = null;
ia = null;
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/CommitProcessor.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/CommitProcessor.java
index 77635c9..22b8956 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/CommitProcessor.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/CommitProcessor.java
@@ -602,9 +602,7 @@ public class CommitProcessor extends ZooKeeperCriticalThread implements
if (stopped || request == null) {
return;
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("Committing request:: " + request);
- }
+ LOG.debug("Committing request:: {}", request);
request.commitRecvTime = Time.currentElapsedTime();
ServerMetrics.getMetrics().COMMITS_QUEUED.add(1);
committedRequests.add(request);
@@ -616,9 +614,7 @@ public class CommitProcessor extends ZooKeeperCriticalThread implements
if (stopped) {
return;
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("Processing request:: " + request);
- }
+ LOG.debug("Processing request:: {}", request);
request.commitProcQueueStartTime = Time.currentElapsedTime();
queuedRequests.add(request);
// If the request will block, add it to the queue of blocking requests
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java
index 42fed41..dbc1425 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java
@@ -356,10 +356,7 @@ public class FastLeaderElection implements Election {
sendqueue.offer(notmsg);
} else {
// Receive new message
- if (LOG.isDebugEnabled()) {
- LOG.debug("Receive new notification message. My id = "
- + self.getId());
- }
+ LOG.debug("Receive new notification message. My id = {}", self.getId());
// State of peer that sent this message
QuorumPeer.ServerState ackstate = QuorumPeer.ServerState.LOOKING;
@@ -726,8 +723,12 @@ public class FastLeaderElection implements Election {
*
*/
protected boolean totalOrderPredicate(long newId, long newZxid, long newEpoch, long curId, long curZxid, long curEpoch) {
- LOG.debug("id: " + newId + ", proposed id: " + curId + ", zxid: 0x" +
- Long.toHexString(newZxid) + ", proposed zxid: 0x" + Long.toHexString(curZxid));
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("id: " + newId + ", proposed id: " + curId + ", zxid: 0x"
+ + Long.toHexString(newZxid) + ", proposed zxid: 0x"
+ + Long.toHexString(curZxid));
+ }
+
if(self.getQuorumVerifier().getWeight(newId) == 0){
return false;
}
@@ -836,11 +837,11 @@ public class FastLeaderElection implements Election {
*/
private ServerState learningState(){
if(self.getLearnerType() == LearnerType.PARTICIPANT){
- LOG.debug("I'm a participant: " + self.getId());
+ LOG.debug("I am a participant: {}", self.getId());
return ServerState.FOLLOWING;
}
else{
- LOG.debug("I'm an observer: " + self.getId());
+ LOG.debug("I am an observer: {}", self.getId());
return ServerState.OBSERVING;
}
}
@@ -975,7 +976,7 @@ public class FastLeaderElection implements Election {
break;
}
if (n.zxid == -1) {
- LOG.debug("Ignoring notification from member with -1 zxid" + n.sid);
+ LOG.debug("Ignoring notification from member with -1 zxid {}", n.sid);
break;
}
// If notification > current, replace and send messages out
@@ -1045,7 +1046,7 @@ public class FastLeaderElection implements Election {
}
break;
case OBSERVING:
- LOG.debug("Notification from observer: " + n.sid);
+ LOG.debug("Notification from observer: {}", n.sid);
break;
case FOLLOWING:
case LEADING:
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Leader.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Leader.java
index 8d90996..f9be136 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Leader.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Leader.java
@@ -856,7 +856,7 @@ public class Leader extends LearnerMaster {
if (p.request == null) {
LOG.warn("Going to commmit null: " + p);
} else if (p.request.getHdr().getType() == OpCode.reconfig) {
- LOG.debug("Committing a reconfiguration! " + outstandingProposals.size());
+ LOG.debug("Committing a reconfiguration! {}", outstandingProposals.size());
//if this server is voter in new config with the same quorum address,
//then it will remain the leader
@@ -927,9 +927,7 @@ public class Leader extends LearnerMaster {
if (outstandingProposals.size() == 0) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("outstanding is 0");
- }
+ LOG.debug("outstanding is 0");
return;
}
if (lastCommitted >= zxid) {
@@ -952,10 +950,6 @@ public class Leader extends LearnerMaster {
}
p.addAck(sid);
- /*if (LOG.isDebugEnabled()) {
- LOG.debug("Count for zxid: 0x{} is {}",
- Long.toHexString(zxid), p.ackSet.size());
- }*/
boolean hasCommitted = tryToCommit(p, zxid, followerAddr);
@@ -1183,9 +1177,7 @@ public class Leader extends LearnerMaster {
p.addQuorumVerifier(self.getLastSeenQuorumVerifier());
}
- if (LOG.isDebugEnabled()) {
- LOG.debug("Proposing:: " + request);
- }
+ LOG.debug("Proposing:: {}", request);
lastProposed = p.packet.getZxid();
outstandingProposals.put(lastProposed, p);
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/LearnerHandler.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/LearnerHandler.java
index e59ac6b..81ca163 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/LearnerHandler.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/LearnerHandler.java
@@ -575,7 +575,7 @@ public class LearnerHandler extends ZooKeeperThread {
ServerMetrics.getMetrics().DIFF_COUNT.add(1);
}
- LOG.debug("Sending NEWLEADER message to " + sid);
+ LOG.debug("Sending NEWLEADER message to {}", sid);
// the version of this quorumVerifier will be set by leader.lead() in case
// the leader is just being established. waitForEpochAck makes sure that readyToStart is true if
// we got here, so the version was set
@@ -606,9 +606,8 @@ public class LearnerHandler extends ZooKeeperThread {
return;
}
- if(LOG.isDebugEnabled()){
- LOG.debug("Received NEWLEADER-ACK message from " + sid);
- }
+ LOG.debug("Received NEWLEADER-ACK message from {}", sid);
+
learnerMaster.waitForNewLeaderAck(getSid(), qp.getZxid());
syncLimitCheck.start();
@@ -628,7 +627,7 @@ public class LearnerHandler extends ZooKeeperThread {
// so we need to mark when the peer can actually start
// using the data
//
- LOG.debug("Sending UPTODATE message to " + sid);
+ LOG.debug("Sending UPTODATE message to {}", sid);
queuedPackets.add(new QuorumPacket(Leader.UPTODATE, -1, null, null));
while (true) {
@@ -654,9 +653,7 @@ public class LearnerHandler extends ZooKeeperThread {
switch (qp.getType()) {
case Leader.ACK:
if (this.learnerType == LearnerType.OBSERVER) {
- if (LOG.isDebugEnabled()) {
- LOG.debug("Received ACK from Observer " + this.sid);
- }
+ LOG.debug("Received ACK from Observer {}", this.sid);
}
syncLimitCheck.updateAck(qp.getZxid());
learnerMaster.processAck(this.sid, qp.getZxid(), sock.getLocalSocketAddress());
@@ -843,9 +840,11 @@ public class LearnerHandler extends ZooKeeperThread {
needSnap = false;
} else if (peerLastZxid > maxCommittedLog && !isPeerNewEpochZxid) {
// Newer than committedLog, send trunc and done
- LOG.debug("Sending TRUNC to follower zxidToSend=0x" +
- Long.toHexString(maxCommittedLog) +
- " for peer sid:" + getSid());
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Sending TRUNC to follower zxidToSend=0x" +
+ Long.toHexString(maxCommittedLog) +
+ " for peer sid:" + getSid());
+ }
queueOpPacket(Leader.TRUNC, maxCommittedLog);
currentZxid = maxCommittedLog;
needOpPacket = false;
@@ -882,8 +881,10 @@ public class LearnerHandler extends ZooKeeperThread {
queuedPackets.clear();
needOpPacket = true;
} else {
- LOG.debug("Queueing committedLog 0x{}",
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Queueing committedLog 0x{}",
Long.toHexString(currentZxid));
+ }
Iterator<Proposal> committedLogItr =
db.getCommittedLog().iterator();
currentZxid = queueCommittedProposals(committedLogItr,
@@ -909,8 +910,10 @@ public class LearnerHandler extends ZooKeeperThread {
if (needSnap) {
currentZxid = db.getDataTreeLastProcessedZxid();
}
- LOG.debug("Start forwarding 0x" + Long.toHexString(currentZxid) +
- " for peer sid: " + getSid());
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Start forwarding 0x" + Long.toHexString(currentZxid) +
+ " for peer sid: " + getSid());
+ }
leaderLastZxid = learnerMaster.startForwarding(this, currentZxid);
} finally {
rl.unlock();
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumCnxManager.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumCnxManager.java
index d97da2a..3b6133a 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumCnxManager.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumCnxManager.java
@@ -329,7 +329,7 @@ public class QuorumCnxManager {
* @param sid
*/
public void testInitiateConnection(long sid) throws Exception {
- LOG.debug("Opening channel to server " + sid);
+ LOG.debug("Opening channel to server {}", sid);
Socket sock = new Socket();
setSockOpts(sock);
sock.connect(self.getVotingView().get(sid).electionAddr, cnxTO);
@@ -637,13 +637,13 @@ public class QuorumCnxManager {
*/
synchronized boolean connectOne(long sid, InetSocketAddress electionAddr){
if (senderWorkerMap.get(sid) != null) {
- LOG.debug("There is a connection already for server " + sid);
+ LOG.debug("There is a connection already for server {}", sid);
return true;
}
Socket sock = null;
try {
- LOG.debug("Opening channel to server " + sid);
+ LOG.debug("Opening channel to server {}", sid);
if (self.isSslQuorum()) {
sock = self.getX509Util().createSSLSocket();
} else {
@@ -657,7 +657,7 @@ public class QuorumCnxManager {
LOG.info("SSL handshake complete with {} - {} - {}", sslSock.getRemoteSocketAddress(), sslSock.getSession().getProtocol(), sslSock.getSession().getCipherSuite());
}
- LOG.debug("Connected to server " + sid);
+ LOG.debug("Connected to server {}", sid);
// Sends connection request asynchronously if the quorum
// sasl authentication is enabled. This is required because
// sasl server authentication process may take few seconds to
@@ -698,7 +698,7 @@ public class QuorumCnxManager {
*/
synchronized void connectOne(long sid){
if (senderWorkerMap.get(sid) != null) {
- LOG.debug("There is a connection already for server " + sid);
+ LOG.debug("There is a connection already for server {}", sid);
return;
}
synchronized (self.QV_LOCK) {
@@ -749,7 +749,7 @@ public class QuorumCnxManager {
*/
boolean haveDelivered() {
for (ArrayBlockingQueue<ByteBuffer> queue : queueSendMap.values()) {
- LOG.debug("Queue size: " + queue.size());
+ LOG.debug("Queue size: {}", queue.size());
if (queue.size() == 0) {
return true;
}
@@ -787,7 +787,7 @@ public class QuorumCnxManager {
*/
public void softHalt() {
for (SendWorker sw : senderWorkerMap.values()) {
- LOG.debug("Halting sender: " + sw);
+ LOG.debug("Halting sender: {}", sw);
sw.finish();
}
}
@@ -961,9 +961,9 @@ public class QuorumCnxManager {
*/
void halt(){
try{
- LOG.debug("Trying to close listener: " + ss);
+ LOG.debug("Trying to close listener: {}", ss);
if(ss != null) {
- LOG.debug("Closing listener: "
+ LOG.debug("Closing listener: {}",
+ QuorumCnxManager.this.mySid);
ss.close();
}
@@ -1006,7 +1006,7 @@ public class QuorumCnxManager {
closeSocket(sock);
running = false;
}
- LOG.debug("Address of remote peer: " + this.sid);
+ LOG.debug("Address of remote peer: {}", this.sid);
}
synchronized void setRecv(RecvWorker recvWorker) {
@@ -1023,7 +1023,7 @@ public class QuorumCnxManager {
}
synchronized boolean finish() {
- LOG.debug("Calling finish for " + sid);
+ LOG.debug("Calling finish for {}", sid);
if(!running){
/*
@@ -1040,7 +1040,7 @@ public class QuorumCnxManager {
recvWorker.finish();
}
- LOG.debug("Removing entry from senderWorkerMap sid=" + sid);
+ LOG.debug("Removing entry from senderWorkerMap sid={}", sid);
senderWorkerMap.remove(sid, this);
threadCnt.decrementAndGet();
@@ -1082,7 +1082,7 @@ public class QuorumCnxManager {
if (bq == null || isSendQueueEmpty(bq)) {
ByteBuffer b = lastMessageSent.get(sid);
if (b != null) {
- LOG.debug("Attempting to send lastMessage to sid=" + sid);
+ LOG.debug("Attempting to send lastMessage to sid={}", sid);
send(b);
}
}
@@ -1230,7 +1230,7 @@ public class QuorumCnxManager {
} catch (NoSuchElementException ne) {
// element could be removed by poll()
LOG.debug("Trying to remove from an empty " +
- "Queue. Ignoring exception " + ne);
+ "Queue. Ignoring exception.", ne);
}
}
try {
@@ -1292,7 +1292,7 @@ public class QuorumCnxManager {
} catch (NoSuchElementException ne) {
// element could be removed by poll()
LOG.debug("Trying to remove from an empty " +
- "recvQueue. Ignoring exception " + ne);
+ "recvQueue. Ignoring exception.", ne);
}
}
try {
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java
index ce794d1..2e202d0 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java
@@ -1434,7 +1434,7 @@ public class QuorumPeer extends ZooKeeperThread implements QuorumStats.Provider
LOG.debug("PeerState set to OBSERVER");
} else { // currently shouldn't happen since there are only 2 learner types
setPeerState(ServerState.LOOKING);
- LOG.debug("Shouldn't be here");
+ LOG.debug("Should not be here");
}
reconfigFlag = false;
}
@@ -1771,8 +1771,9 @@ public class QuorumPeer extends ZooKeeperThread implements QuorumStats.Provider
if ((quorumVerifier != null) && (quorumVerifier.getVersion() >= qv.getVersion())) {
// this is normal. For example - server found out about new config through FastLeaderElection gossiping
// and then got the same config in UPTODATE message so its already known
- LOG.debug(getId() + " setQuorumVerifier called with known or old config " + qv.getVersion() +
- ". Current version: " + quorumVerifier.getVersion());
+ LOG.debug("{} setQuorumVerifier called with known or old config {}."
+ + " Current version: {}", getId(), qv.getVersion(),
+ quorumVerifier.getVersion());
return quorumVerifier;
}
QuorumVerifier prevQV = quorumVerifier;
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/auth/SaslQuorumAuthLearner.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/auth/SaslQuorumAuthLearner.java
index 31f4f55..96e2e92 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/auth/SaslQuorumAuthLearner.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/auth/SaslQuorumAuthLearner.java
@@ -191,8 +191,8 @@ public class SaslQuorumAuthLearner implements QuorumAuthLearner {
final byte[] retval = Subject.doAs(login.getSubject(),
new PrivilegedExceptionAction<byte[]>() {
public byte[] run() throws SaslException {
- LOG.debug("saslClient.evaluateChallenge(len="
- + saslToken.length + ")");
+ LOG.debug("saslClient.evaluateChallenge(len={})",
+ saslToken.length);
return saslClient.evaluateChallenge(saslToken);
}
});
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/flexible/QuorumHierarchical.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/flexible/QuorumHierarchical.java
index 9abeca8..237f174 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/flexible/QuorumHierarchical.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/flexible/QuorumHierarchical.java
@@ -310,10 +310,10 @@ public class QuorumHierarchical implements QuorumVerifier {
* Do not consider groups with weight zero
*/
for(long weight: groupWeight.values()){
- LOG.debug("Group weight: " + weight);
+ LOG.debug("Group weight: {}", weight);
if(weight == ((long) 0)){
numGroups--;
- LOG.debug("One zero-weight group: " + 1 + ", " + numGroups);
+ LOG.debug("One zero-weight group: 1, {}", numGroups);
}
}
}
@@ -327,9 +327,9 @@ public class QuorumHierarchical implements QuorumVerifier {
/*
* Adds up weights per group
*/
- if(set.size() == 0) return false;
- else LOG.debug("Set size: " + set.size());
-
+ LOG.debug("Set size: {}", set.size());
+ if (set.size() == 0) return false;
+
for(long sid : set){
Long gid = serverGroup.get(sid);
if (gid == null) continue;
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/util/SecurityUtils.java b/zookeeper-server/src/main/java/org/apache/zookeeper/util/SecurityUtils.java
index 67484e4..7f658ab 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/util/SecurityUtils.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/util/SecurityUtils.java
@@ -124,7 +124,7 @@ public final class SecurityUtils {
LOG.info("{} will use GSSAPI as SASL mechanism.", entity);
String[] mechs = { "GSSAPI" };
LOG.debug("creating sasl client: {}={};service={};serviceHostname={}",
- new Object[] { entity, clientPrincipalName, serviceName, serviceHostname });
+ entity, clientPrincipalName, serviceName, serviceHostname);
SaslClient saslClient = Sasl.createSaslClient(
mechs, clientPrincipalName, serviceName,
serviceHostname, null,
@@ -188,10 +188,9 @@ public final class SecurityUtils {
// subject is non-null, it can be assumed to be GSSAPI.
final String mech = "GSSAPI";
- LOG.debug("serviceHostname is '" + serviceHostname + "'");
- LOG.debug("servicePrincipalName is '" + servicePrincipalName
- + "'");
- LOG.debug("SASL mechanism(mech) is '" + mech + "'");
+ LOG.debug("serviceHostname is '{}'", serviceHostname);
+ LOG.debug("servicePrincipalName is '{}'", servicePrincipalName);
+ LOG.debug("SASL mechanism(mech) is '{}'", mech);
boolean usingNativeJgss = Boolean
.getBoolean("sun.security.jgss.native");
|