HDFS-7978. Add LOG.isDebugEnabled() guard for some LOG.debug(..). Contributed by Walter Su.

This commit is contained in:
Andrew Wang 2015-04-01 12:53:25 -07:00
parent a3a96a07fa
commit ed72daa5df
12 changed files with 78 additions and 43 deletions

View File

@ -373,6 +373,9 @@ Release 2.8.0 - UNRELEASED
HDFS-8009. Signal congestion on the DataNode. (wheat9) HDFS-8009. Signal congestion on the DataNode. (wheat9)
HDFS-7978. Add LOG.isDebugEnabled() guard for some LOG.debug(..).
(Walter Su via wang)
OPTIMIZATIONS OPTIMIZATIONS
BUG FIXES BUG FIXES

View File

@ -369,9 +369,9 @@ private BlockReader getLegacyBlockReaderLocal() throws IOException {
return null; return null;
} }
if (clientContext.getDisableLegacyBlockReaderLocal()) { if (clientContext.getDisableLegacyBlockReaderLocal()) {
PerformanceAdvisory.LOG.debug(this + ": can't construct " + PerformanceAdvisory.LOG.debug("{}: can't construct " +
"BlockReaderLocalLegacy because " + "BlockReaderLocalLegacy because " +
"disableLegacyBlockReaderLocal is set."); "disableLegacyBlockReaderLocal is set.", this);
return null; return null;
} }
IOException ioe = null; IOException ioe = null;
@ -410,8 +410,8 @@ private BlockReader getBlockReaderLocal() throws InvalidToken {
getPathInfo(inetSocketAddress, conf); getPathInfo(inetSocketAddress, conf);
} }
if (!pathInfo.getPathState().getUsableForShortCircuit()) { if (!pathInfo.getPathState().getUsableForShortCircuit()) {
PerformanceAdvisory.LOG.debug(this + ": " + pathInfo + " is not " + PerformanceAdvisory.LOG.debug("{}: {} is not usable for short circuit; " +
"usable for short circuit; giving up on BlockReaderLocal."); "giving up on BlockReaderLocal.", this, pathInfo);
return null; return null;
} }
ShortCircuitCache cache = clientContext.getShortCircuitCache(); ShortCircuitCache cache = clientContext.getShortCircuitCache();
@ -426,11 +426,9 @@ private BlockReader getBlockReaderLocal() throws InvalidToken {
throw exc; throw exc;
} }
if (info.getReplica() == null) { if (info.getReplica() == null) {
if (LOG.isTraceEnabled()) { PerformanceAdvisory.LOG.debug("{}: failed to get " +
PerformanceAdvisory.LOG.debug(this + ": failed to get " + "ShortCircuitReplica. Cannot construct " +
"ShortCircuitReplica. Cannot construct " + "BlockReaderLocal via {}", this, pathInfo.getPath());
"BlockReaderLocal via " + pathInfo.getPath());
}
return null; return null;
} }
return new BlockReaderLocal.Builder(conf). return new BlockReaderLocal.Builder(conf).
@ -610,9 +608,9 @@ private BlockReader getRemoteBlockReaderFromDomain() throws IOException {
getPathInfo(inetSocketAddress, conf); getPathInfo(inetSocketAddress, conf);
} }
if (!pathInfo.getPathState().getUsableForDataTransfer()) { if (!pathInfo.getPathState().getUsableForDataTransfer()) {
PerformanceAdvisory.LOG.debug(this + ": not trying to create a " + PerformanceAdvisory.LOG.debug("{}: not trying to create a " +
"remote block reader because the UNIX domain socket at " + "remote block reader because the UNIX domain socket at {}" +
pathInfo + " is not usable."); " is not usable.", this, pathInfo);
return null; return null;
} }
if (LOG.isTraceEnabled()) { if (LOG.isTraceEnabled()) {

View File

@ -319,12 +319,16 @@ public static void cloneDelegationTokenForLogicalUri(
buildTokenServicePrefixForLogicalUri(HdfsConstants.HDFS_URI_SCHEME) buildTokenServicePrefixForLogicalUri(HdfsConstants.HDFS_URI_SCHEME)
+ "//" + specificToken.getService()); + "//" + specificToken.getService());
ugi.addToken(alias, specificToken); ugi.addToken(alias, specificToken);
LOG.debug("Mapped HA service delegation token for logical URI " + if (LOG.isDebugEnabled()) {
haUri + " to namenode " + singleNNAddr); LOG.debug("Mapped HA service delegation token for logical URI " +
haUri + " to namenode " + singleNNAddr);
}
} }
} else { } else {
LOG.debug("No HA service delegation token found for logical URI " + if (LOG.isDebugEnabled()) {
haUri); LOG.debug("No HA service delegation token found for logical URI " +
haUri);
}
} }
} }

View File

@ -580,9 +580,11 @@ DatanodeCommand cacheReport() throws IOException {
long createCost = createTime - startTime; long createCost = createTime - startTime;
long sendCost = sendTime - createTime; long sendCost = sendTime - createTime;
dn.getMetrics().addCacheReport(sendCost); dn.getMetrics().addCacheReport(sendCost);
LOG.debug("CacheReport of " + blockIds.size() if (LOG.isDebugEnabled()) {
+ " block(s) took " + createCost + " msec to generate and " LOG.debug("CacheReport of " + blockIds.size()
+ sendCost + " msecs for RPC and NN processing"); + " block(s) took " + createCost + " msec to generate and "
+ sendCost + " msecs for RPC and NN processing");
}
} }
return cmd; return cmd;
} }

View File

@ -319,9 +319,11 @@ synchronized void uncacheBlock(String bpid, long blockId) {
mappableBlockMap.put(key, mappableBlockMap.put(key,
new Value(prevValue.mappableBlock, State.UNCACHING)); new Value(prevValue.mappableBlock, State.UNCACHING));
if (deferred) { if (deferred) {
LOG.debug("{} is anchored, and can't be uncached now. Scheduling it " + if (LOG.isDebugEnabled()) {
"for uncaching in {} ", LOG.debug("{} is anchored, and can't be uncached now. Scheduling it " +
key, DurationFormatUtils.formatDurationHMS(revocationPollingMs)); "for uncaching in {} ",
key, DurationFormatUtils.formatDurationHMS(revocationPollingMs));
}
deferredUncachingExecutor.schedule( deferredUncachingExecutor.schedule(
new UncachingTask(key, revocationMs), new UncachingTask(key, revocationMs),
revocationPollingMs, TimeUnit.MILLISECONDS); revocationPollingMs, TimeUnit.MILLISECONDS);

View File

@ -320,9 +320,11 @@ synchronized public void selectInputStreams(
Collection<EditLogInputStream> streams, long fromTxId, Collection<EditLogInputStream> streams, long fromTxId,
boolean inProgressOk) throws IOException { boolean inProgressOk) throws IOException {
List<EditLogFile> elfs = matchEditLogs(sd.getCurrentDir()); List<EditLogFile> elfs = matchEditLogs(sd.getCurrentDir());
LOG.debug(this + ": selecting input streams starting at " + fromTxId + if (LOG.isDebugEnabled()) {
(inProgressOk ? " (inProgress ok) " : " (excluding inProgress) ") + LOG.debug(this + ": selecting input streams starting at " + fromTxId +
"from among " + elfs.size() + " candidate file(s)"); (inProgressOk ? " (inProgress ok) " : " (excluding inProgress) ") +
"from among " + elfs.size() + " candidate file(s)");
}
addStreamsToCollectionFromFiles(elfs, streams, fromTxId, inProgressOk); addStreamsToCollectionFromFiles(elfs, streams, fromTxId, inProgressOk);
} }
@ -331,8 +333,10 @@ static void addStreamsToCollectionFromFiles(Collection<EditLogFile> elfs,
for (EditLogFile elf : elfs) { for (EditLogFile elf : elfs) {
if (elf.isInProgress()) { if (elf.isInProgress()) {
if (!inProgressOk) { if (!inProgressOk) {
LOG.debug("passing over " + elf + " because it is in progress " + if (LOG.isDebugEnabled()) {
"and we are ignoring in-progress logs."); LOG.debug("passing over " + elf + " because it is in progress " +
"and we are ignoring in-progress logs.");
}
continue; continue;
} }
try { try {
@ -345,9 +349,11 @@ static void addStreamsToCollectionFromFiles(Collection<EditLogFile> elfs,
} }
if (elf.lastTxId < fromTxId) { if (elf.lastTxId < fromTxId) {
assert elf.lastTxId != HdfsConstants.INVALID_TXID; assert elf.lastTxId != HdfsConstants.INVALID_TXID;
LOG.debug("passing over " + elf + " because it ends at " + if (LOG.isDebugEnabled()) {
elf.lastTxId + ", but we only care about transactions " + LOG.debug("passing over " + elf + " because it ends at " +
"as new as " + fromTxId); elf.lastTxId + ", but we only care about transactions " +
"as new as " + fromTxId);
}
continue; continue;
} }
EditLogFileInputStream elfis = new EditLogFileInputStream(elf.getFile(), EditLogFileInputStream elfis = new EditLogFileInputStream(elf.getFile(),

View File

@ -1534,7 +1534,9 @@ public static void initializeGenericKeys(Configuration conf,
URI defaultUri = URI.create(HdfsConstants.HDFS_URI_SCHEME + "://" URI defaultUri = URI.create(HdfsConstants.HDFS_URI_SCHEME + "://"
+ conf.get(DFS_NAMENODE_RPC_ADDRESS_KEY)); + conf.get(DFS_NAMENODE_RPC_ADDRESS_KEY));
conf.set(FS_DEFAULT_NAME_KEY, defaultUri.toString()); conf.set(FS_DEFAULT_NAME_KEY, defaultUri.toString());
LOG.debug("Setting " + FS_DEFAULT_NAME_KEY + " to " + defaultUri.toString()); if (LOG.isDebugEnabled()) {
LOG.debug("Setting " + FS_DEFAULT_NAME_KEY + " to " + defaultUri.toString());
}
} }
} }

View File

@ -446,7 +446,9 @@ void unref(ShortCircuitReplica replica) {
purgeReason = "purging replica because it is stale."; purgeReason = "purging replica because it is stale.";
} }
if (purgeReason != null) { if (purgeReason != null) {
LOG.debug(this + ": " + purgeReason); if (LOG.isDebugEnabled()) {
LOG.debug(this + ": " + purgeReason);
}
purge(replica); purge(replica);
} }
} }

View File

@ -147,8 +147,10 @@ public int compare(FsImageProto.FileSummary.Section s1,
summary.getCodec(), new BufferedInputStream(new LimitInputStream( summary.getCodec(), new BufferedInputStream(new LimitInputStream(
fin, s.getLength()))); fin, s.getLength())));
LOG.debug("Loading section " + s.getName() + " length: " + s.getLength if (LOG.isDebugEnabled()) {
()); LOG.debug("Loading section " + s.getName() + " length: " + s.getLength
());
}
switch (FSImageFormatProtobuf.SectionName.fromString(s.getName())) { switch (FSImageFormatProtobuf.SectionName.fromString(s.getName())) {
case STRING_TABLE: case STRING_TABLE:
stringTable = loadStringTable(is); stringTable = loadStringTable(is);

View File

@ -126,8 +126,10 @@ public LightWeightHashSet(int initCapacity, float maxLoadFactor,
this.shrinkThreshold = (int) (capacity * minLoadFactor); this.shrinkThreshold = (int) (capacity * minLoadFactor);
entries = new LinkedElement[capacity]; entries = new LinkedElement[capacity];
LOG.debug("initial capacity=" + initialCapacity + ", max load factor= " if (LOG.isDebugEnabled()) {
+ maxLoadFactor + ", min load factor= " + minLoadFactor); LOG.debug("initial capacity=" + initialCapacity + ", max load factor= "
+ maxLoadFactor + ", min load factor= " + minLoadFactor);
}
} }
public LightWeightHashSet() { public LightWeightHashSet() {

View File

@ -136,7 +136,9 @@ synchronized void ensureTokenInitialized() throws IOException {
if (token != null) { if (token != null) {
fs.setDelegationToken(token); fs.setDelegationToken(token);
addRenewAction(fs); addRenewAction(fs);
LOG.debug("Created new DT for " + token.getService()); if(LOG.isDebugEnabled()) {
LOG.debug("Created new DT for " + token.getService());
}
} }
hasInitedToken = true; hasInitedToken = true;
} }
@ -149,7 +151,9 @@ public synchronized void reset() {
synchronized void initDelegationToken(UserGroupInformation ugi) { synchronized void initDelegationToken(UserGroupInformation ugi) {
Token<?> token = selectDelegationToken(ugi); Token<?> token = selectDelegationToken(ugi);
if (token != null) { if (token != null) {
LOG.debug("Found existing DT for " + token.getService()); if(LOG.isDebugEnabled()) {
LOG.debug("Found existing DT for " + token.getService());
}
fs.setDelegationToken(token); fs.setDelegationToken(token);
hasInitedToken = true; hasInitedToken = true;
} }

View File

@ -224,12 +224,16 @@ protected synchronized Token<?> getDelegationToken() throws IOException {
// refetch tokens. even if ugi has credentials, don't attempt // refetch tokens. even if ugi has credentials, don't attempt
// to get another token to match hdfs/rpc behavior // to get another token to match hdfs/rpc behavior
if (token != null) { if (token != null) {
LOG.debug("Using UGI token: " + token); if(LOG.isDebugEnabled()) {
LOG.debug("Using UGI token: " + token);
}
canRefreshDelegationToken = false; canRefreshDelegationToken = false;
} else { } else {
token = getDelegationToken(null); token = getDelegationToken(null);
if (token != null) { if (token != null) {
LOG.debug("Fetched new token: " + token); if(LOG.isDebugEnabled()) {
LOG.debug("Fetched new token: " + token);
}
} else { // security is disabled } else { // security is disabled
canRefreshDelegationToken = false; canRefreshDelegationToken = false;
} }
@ -244,7 +248,9 @@ synchronized boolean replaceExpiredDelegationToken() throws IOException {
boolean replaced = false; boolean replaced = false;
if (canRefreshDelegationToken) { if (canRefreshDelegationToken) {
Token<?> token = getDelegationToken(null); Token<?> token = getDelegationToken(null);
LOG.debug("Replaced expired token: " + token); if(LOG.isDebugEnabled()) {
LOG.debug("Replaced expired token: " + token);
}
setDelegationToken(token); setDelegationToken(token);
replaced = (token != null); replaced = (token != null);
} }
@ -1188,7 +1194,9 @@ public synchronized void close() throws IOException {
cancelDelegationToken(delegationToken); cancelDelegationToken(delegationToken);
} }
} catch (IOException ioe) { } catch (IOException ioe) {
LOG.debug("Token cancel failed: "+ioe); if (LOG.isDebugEnabled()) {
LOG.debug("Token cancel failed: " + ioe);
}
} finally { } finally {
super.close(); super.close();
} }