Repository: hadoop Updated Branches: refs/heads/branch-2 5ffb26c2a -> 818915aab
HDFS-10872. Add MutableRate metrics for FSNamesystemLock operations. Contributed by Erik Krogen. Project: http://git-wip-us.apache.org/repos/asf/hadoop/repo Commit: http://git-wip-us.apache.org/repos/asf/hadoop/commit/818915aa Tree: http://git-wip-us.apache.org/repos/asf/hadoop/tree/818915aa Diff: http://git-wip-us.apache.org/repos/asf/hadoop/diff/818915aa Branch: refs/heads/branch-2 Commit: 818915aabb22653e212f4646b1b3cd0673330328 Parents: 5ffb26c Author: Zhe Zhang <[email protected]> Authored: Mon Nov 14 16:33:15 2016 -0800 Committer: Zhe Zhang <[email protected]> Committed: Mon Nov 14 16:33:15 2016 -0800 ---------------------------------------------------------------------- .../hadoop/metrics2/lib/MetricsRegistry.java | 8 + .../metrics2/lib/MutableMetricsFactory.java | 4 +- .../org/apache/hadoop/hdfs/DFSConfigKeys.java | 4 + .../hdfs/server/namenode/CacheManager.java | 2 +- .../hdfs/server/namenode/Checkpointer.java | 2 +- .../ContentSummaryComputationContext.java | 2 +- .../hdfs/server/namenode/FSEditLogLoader.java | 4 +- .../hdfs/server/namenode/FSNamesystem.java | 429 +++++++++++-------- .../hdfs/server/namenode/FSNamesystemLock.java | 59 ++- .../hdfs/server/namenode/LeaseManager.java | 2 +- .../hdfs/server/namenode/NamenodeFsck.java | 2 +- .../src/main/resources/hdfs-default.xml | 8 + .../server/namenode/TestFSNamesystemLock.java | 59 ++- 13 files changed, 383 insertions(+), 202 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MetricsRegistry.java ---------------------------------------------------------------------- diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MetricsRegistry.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MetricsRegistry.java index 6e7e5ab..1ef74f4 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MetricsRegistry.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MetricsRegistry.java @@ -281,6 +281,14 @@ public class MetricsRegistry { return ret; } + public synchronized MutableRatesWithAggregation newRatesWithAggregation( + String name) { + checkMetricName(name); + MutableRatesWithAggregation rates = new MutableRatesWithAggregation(); + metricsMap.put(name, rates); + return rates; + } + synchronized void add(String name, MutableMetric metric) { checkMetricName(name); metricsMap.put(name, metric); http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MutableMetricsFactory.java ---------------------------------------------------------------------- diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MutableMetricsFactory.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MutableMetricsFactory.java index ac05132..4712ccf 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MutableMetricsFactory.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/metrics2/lib/MutableMetricsFactory.java @@ -68,9 +68,7 @@ public class MutableMetricsFactory { return new MutableRates(registry); } if (cls == MutableRatesWithAggregation.class) { - MutableRatesWithAggregation rates = new MutableRatesWithAggregation(); - registry.add(info.name(), rates); - return rates; + return registry.newRatesWithAggregation(info.name()); } if (cls == MutableStat.class) { return registry.newStat(info.name(), info.description(), http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/DFSConfigKeys.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/DFSConfigKeys.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/DFSConfigKeys.java index 7048621..c1e6de6 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/DFSConfigKeys.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/DFSConfigKeys.java @@ -391,6 +391,10 @@ public class DFSConfigKeys extends CommonConfigurationKeys { public static final long DFS_NAMENODE_MAX_LOCK_HOLD_TO_RELEASE_LEASE_MS_DEFAULT = 25; + public static final String DFS_NAMENODE_LOCK_DETAILED_METRICS_KEY = + "dfs.namenode.lock.detailed-metrics.enabled"; + public static final boolean DFS_NAMENODE_LOCK_DETAILED_METRICS_DEFAULT = + false; // Threshold for how long namenode locks must be held for the // event to be logged public static final String DFS_NAMENODE_WRITE_LOCK_REPORTING_THRESHOLD_MS_KEY = http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/CacheManager.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/CacheManager.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/CacheManager.java index fa8f011..515a363 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/CacheManager.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/CacheManager.java @@ -959,7 +959,7 @@ public final class CacheManager { processCacheReportImpl(datanode, blockIds); } finally { endTime = Time.monotonicNow(); - namesystem.writeUnlock(); + namesystem.writeUnlock("processCacheReport"); } // Log the block report processing stats from Namenode perspective http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/Checkpointer.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/Checkpointer.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/Checkpointer.java index a782049..9ff40cc 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/Checkpointer.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/Checkpointer.java @@ -264,7 +264,7 @@ class Checkpointer extends Daemon { bnStorage.writeAll(); } } finally { - backupNode.namesystem.writeUnlock(); + backupNode.namesystem.writeUnlock("doCheckpoint"); } if(cpCmd.needToReturnImage()) { http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ContentSummaryComputationContext.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ContentSummaryComputationContext.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ContentSummaryComputationContext.java index 4208b53..53fa552 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ContentSummaryComputationContext.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ContentSummaryComputationContext.java @@ -115,7 +115,7 @@ public class ContentSummaryComputationContext { // unlock dir.readUnlock(); - fsn.readUnlock(); + fsn.readUnlock("contentSummary"); try { Thread.sleep(sleepMilliSec, sleepNanoSec); http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java index 2946e8f..4ac90e1 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java @@ -151,7 +151,7 @@ public class FSEditLogLoader { return numEdits; } finally { edits.close(); - fsNamesys.writeUnlock(); + fsNamesys.writeUnlock("loadFSEdits"); prog.endStep(Phase.LOADING_EDITS, step); } } @@ -288,7 +288,7 @@ public class FSEditLogLoader { in.close(); } fsDir.writeUnlock(); - fsNamesys.writeUnlock(); + fsNamesys.writeUnlock("loadEditRecords"); if (LOG.isTraceEnabled()) { LOG.trace("replaying edit log finished"); http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java index 6b364d1..7ea8218 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java @@ -272,6 +272,8 @@ import org.apache.hadoop.ipc.StandbyException; import org.apache.hadoop.metrics2.annotation.Metric; import org.apache.hadoop.metrics2.annotation.Metrics; import org.apache.hadoop.metrics2.lib.DefaultMetricsSystem; +import org.apache.hadoop.metrics2.lib.MetricsRegistry; +import org.apache.hadoop.metrics2.lib.MutableRatesWithAggregation; import org.apache.hadoop.metrics2.util.MBeans; import org.apache.hadoop.net.Node; import org.apache.hadoop.security.AccessControlException; @@ -315,6 +317,9 @@ import com.google.common.util.concurrent.ThreadFactoryBuilder; public class FSNamesystem implements Namesystem, FSNamesystemMBean, NameNodeMXBean { public static final Log LOG = LogFactory.getLog(FSNamesystem.class); + private final MetricsRegistry registry = new MetricsRegistry("FSNamesystem"); + @Metric final MutableRatesWithAggregation detailedLockHoldTimeMetrics = + registry.newRatesWithAggregation("detailedLockHoldTimeMetrics"); boolean isAuditEnabled() { return (!isDefaultAuditLogger || auditLog.isInfoEnabled()) @@ -545,7 +550,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, dir.markNameCacheInitialized(); cond.signalAll(); } finally { - writeUnlock(); + writeUnlock("setImageLoaded"); } } @@ -696,7 +701,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, LOG.info("Enabling async auditlog"); enableAsyncAuditLog(); } - fsLock = new FSNamesystemLock(conf); + fsLock = new FSNamesystemLock(conf, detailedLockHoldTimeMetrics); cond = fsLock.newWriteLockCondition(); cpLock = new ReentrantLock(); @@ -1035,7 +1040,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, if (!success) { fsImage.close(); } - writeUnlock(); + writeUnlock("loadFSImage"); } imageLoadComplete(); } @@ -1087,7 +1092,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, completeBlocksTotal); blockManager.activate(conf, completeBlocksTotal); } finally { - writeUnlock(); + writeUnlock("startCommonServices"); } registerMXBean(); @@ -1111,7 +1116,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, try { if (blockManager != null) blockManager.close(); } finally { - writeUnlock(); + writeUnlock("stopCommonServices"); } RetryCache.clear(retryCache); } @@ -1206,7 +1211,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } finally { startingActiveService = false; blockManager.checkSafeMode(); - writeUnlock(); + writeUnlock("startActiveServices"); } } @@ -1269,7 +1274,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, blockManager.setInitializedReplQueues(false); } } finally { - writeUnlock(); + writeUnlock("stopActiveServices"); } } @@ -1500,6 +1505,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, public void readUnlock() { this.fsLock.readUnlock(); } + public void readUnlock(String opName) { + this.fsLock.readUnlock(opName); + } @Override public void writeLock() { this.fsLock.writeLock(); @@ -1512,6 +1520,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, public void writeUnlock() { this.fsLock.writeUnlock(); } + public void writeUnlock(String opName) { + this.fsLock.writeUnlock(opName); + } @Override public boolean hasWriteLock() { return this.fsLock.isWriteLockedByCurrentThread(); @@ -1550,7 +1561,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, try { return unprotectedGetNamespaceInfo(); } finally { - readUnlock(); + readUnlock("getNamespaceInfo"); } } @@ -1628,7 +1639,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkOperation(OperationCategory.READ); return getBlockManager().getBlocksWithLocations(datanode, size); } finally { - readUnlock(); + readUnlock("getBlocks"); } } @@ -1648,7 +1659,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, out.flush(); out.close(); } finally { - writeUnlock(); + writeUnlock("metaSave"); } } @@ -1685,6 +1696,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, * @throws IOException */ void setPermission(String src, FsPermission permission) throws IOException { + final String operationName = "setPermission"; HdfsFileStatus auditStat; checkOperation(OperationCategory.WRITE); writeLock(); @@ -1693,13 +1705,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot set permission for " + src); auditStat = FSDirAttrOp.setPermission(dir, src, permission); } catch (AccessControlException e) { - logAuditEvent(false, "setPermission", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "setPermission", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } /** @@ -1708,6 +1720,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ void setOwner(String src, String username, String group) throws IOException { + final String operationName = "setOwner"; HdfsFileStatus auditStat; checkOperation(OperationCategory.WRITE); writeLock(); @@ -1716,13 +1729,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot set owner for " + src); auditStat = FSDirAttrOp.setOwner(dir, src, username, group); } catch (AccessControlException e) { - logAuditEvent(false, "setOwner", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "setOwner", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } /** @@ -1731,6 +1744,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ LocatedBlocks getBlockLocations(String clientMachine, String srcArg, long offset, long length) throws IOException { + final String operationName = "open"; checkOperation(OperationCategory.READ); GetBlockLocationsResult res = null; FSPermissionChecker pc = getPermissionChecker(); @@ -1755,13 +1769,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } } } catch (AccessControlException e) { - logAuditEvent(false, "open", srcArg); + logAuditEvent(false, operationName, srcArg); throw e; } finally { - readUnlock(); + readUnlock(operationName); } - logAuditEvent(true, "open", srcArg); + logAuditEvent(true, operationName, srcArg); if (!isInSafeMode() && res.updateAccessTime()) { String src = srcArg; @@ -1802,7 +1816,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } catch (Throwable e) { LOG.warn("Failed to update the access time of " + src, e); } finally { - writeUnlock(); + writeUnlock(operationName); } } @@ -1834,6 +1848,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ void concat(String target, String [] srcs, boolean logRetryCache) throws IOException { + final String operationName = "concat"; HdfsFileStatus stat = null; boolean success = false; writeLock(); @@ -1843,11 +1858,12 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, stat = FSDirConcatOp.concat(dir, target, srcs, logRetryCache); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); if (success) { getEditLog().logSync(); } - logAuditEvent(success, "concat", Arrays.toString(srcs), target, stat); + logAuditEvent(success, operationName, Arrays.toString(srcs), + target, stat); } } @@ -1857,6 +1873,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, * written to the edits log but is not flushed. */ void setTimes(String src, long mtime, long atime) throws IOException { + final String operationName = "setTimes"; HdfsFileStatus auditStat; checkOperation(OperationCategory.WRITE); writeLock(); @@ -1865,13 +1882,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot set times " + src); auditStat = FSDirAttrOp.setTimes(dir, src, mtime, atime); } catch (AccessControlException e) { - logAuditEvent(false, "setTimes", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "setTimes", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } /** @@ -1881,6 +1898,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, void createSymlink(String target, String link, PermissionStatus dirPerms, boolean createParent, boolean logRetryCache) throws IOException { + final String operationName = "createSymlink"; if (!FileSystem.areSymlinksEnabled()) { throw new UnsupportedOperationException("Symlinks not supported"); } @@ -1893,13 +1911,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, auditStat = FSDirSymlinkOp.createSymlinkInt(this, target, link, dirPerms, createParent, logRetryCache); } catch (AccessControlException e) { - logAuditEvent(false, "createSymlink", link, target, null); + logAuditEvent(false, operationName, link, target, null); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "createSymlink", link, target, auditStat); + logAuditEvent(true, operationName, link, target, auditStat); } /** @@ -1917,6 +1935,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ boolean setReplication(final String src, final short replication) throws IOException { + final String operationName = "setReplication"; boolean success = false; checkOperation(OperationCategory.WRITE); writeLock(); @@ -1925,14 +1944,14 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot set replication for " + src); success = FSDirAttrOp.setReplication(dir, blockManager, src, replication); } catch (AccessControlException e) { - logAuditEvent(false, "setReplication", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } if (success) { getEditLog().logSync(); - logAuditEvent(true, "setReplication", src); + logAuditEvent(true, operationName, src); } return success; } @@ -1950,6 +1969,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, String clientMachine, long mtime) throws IOException, UnresolvedLinkException { + String operationName = "truncate"; requireEffectiveLayoutVersionForFeature(Feature.TRUNCATE); final FSDirTruncateOp.TruncateResult r; try { @@ -1969,16 +1989,16 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, r = FSDirTruncateOp.truncate(this, src, newLength, clientName, clientMachine, mtime, toRemoveBlocks, pc); } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); if (!toRemoveBlocks.getToDeleteList().isEmpty()) { removeBlocks(toRemoveBlocks); toRemoveBlocks.clear(); } - logAuditEvent(true, "truncate", src, null, r.getFileStatus()); + logAuditEvent(true, operationName, src, null, r.getFileStatus()); } catch (AccessControlException e) { - logAuditEvent(false, "truncate", src); + logAuditEvent(false, operationName, src); throw e; } return r.getResult(); @@ -1991,6 +2011,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, * @param policyName storage policy name */ void setStoragePolicy(String src, String policyName) throws IOException { + final String operationName = "setStoragePolicy"; HdfsFileStatus auditStat; checkOperation(OperationCategory.WRITE); writeLock(); @@ -2000,13 +2021,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, auditStat = FSDirAttrOp.setStoragePolicy(dir, blockManager, src, policyName); } catch (AccessControlException e) { - logAuditEvent(false, "setStoragePolicy", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "setStoragePolicy", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } /** @@ -2015,6 +2036,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, * @param src file/directory path */ void unsetStoragePolicy(String src) throws IOException { + final String operationName = "unsetStoragePolicy"; HdfsFileStatus auditStat; checkOperation(OperationCategory.WRITE); writeLock(); @@ -2023,13 +2045,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot unset storage policy for " + src); auditStat = FSDirAttrOp.unsetStoragePolicy(dir, blockManager, src); } catch (AccessControlException e) { - logAuditEvent(false, "unsetStoragePolicy", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "unsetStoragePolicy", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } /** * Get the storage policy for a file or a directory. @@ -2045,7 +2067,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkOperation(OperationCategory.READ); return FSDirAttrOp.getStoragePolicy(dir, blockManager, src); } finally { - readUnlock(); + readUnlock("getStoragePolicy"); } } @@ -2059,7 +2081,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkOperation(OperationCategory.READ); return FSDirAttrOp.getStoragePolicies(blockManager); } finally { - readUnlock(); + readUnlock("getStoragePolicies"); } } @@ -2070,7 +2092,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkOperation(OperationCategory.READ); return FSDirAttrOp.getPreferredBlockSize(dir, src); } finally { - readUnlock(); + readUnlock("getPreferredBlockSize"); } } @@ -2218,7 +2240,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, dir.writeUnlock(); } } finally { - writeUnlock(); + writeUnlock("create"); // There might be transactions logged while trying to recover the lease. // They need to be sync'ed even when an exception was thrown. if (!skipSync) { @@ -2270,7 +2292,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, skipSync = true; throw se; } finally { - writeUnlock(); + writeUnlock("recoverLease"); // There might be transactions logged while trying to recover the lease. // They need to be sync'ed even when an exception was thrown. if (!skipSync) { @@ -2376,6 +2398,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, LastBlockWithStatus appendFile(String srcArg, String holder, String clientMachine, EnumSet<CreateFlag> flag, boolean logRetryCache) throws IOException { + final String operationName = "append"; boolean newBlock = flag.contains(CreateFlag.NEW_BLOCK); if (newBlock) { requireEffectiveLayoutVersionForFeature(Feature.APPEND_NEW_BLOCK); @@ -2405,17 +2428,17 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, skipSync = true; throw se; } finally { - writeUnlock(); + writeUnlock(operationName); // There might be transactions logged while trying to recover the lease // They need to be sync'ed even when an exception was thrown. if (!skipSync) { getEditLog().logSync(); } } - logAuditEvent(true, "append", srcArg); + logAuditEvent(true, operationName, srcArg); return lbs; } catch (AccessControlException e) { - logAuditEvent(false, "append", srcArg); + logAuditEvent(false, operationName, srcArg); throw e; } } @@ -2443,6 +2466,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, String src, long fileId, String clientName, ExtendedBlock previous, DatanodeInfo[] excludedNodes, String[] favoredNodes, EnumSet<AddBlockFlag> flags) throws IOException { + final String operationName = "getAdditionalBlock"; NameNode.stateChangeLog.debug("BLOCK* getAdditionalBlock: {} inodeId {}" + " for {}", src, fileId, clientName); @@ -2456,7 +2480,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, r = FSDirWriteFileOp.validateAddBlock(this, pc, src, fileId, clientName, previous, onRetryBlock); } finally { - readUnlock(); + readUnlock(operationName); } if (r == null) { @@ -2476,7 +2500,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, lb = FSDirWriteFileOp.storeAllocatedBlock( this, src, fileId, clientName, previous, targets); } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); return lb; @@ -2520,7 +2544,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, "src=%s, fileId=%d, blk=%s, clientName=%s, clientMachine=%s", src, fileId, blk, clientName, clientMachine)); } finally { - readUnlock(); + readUnlock("getAdditionalDatanode"); } if (clientnode == null) { @@ -2554,7 +2578,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, NameNode.stateChangeLog.debug("BLOCK* NameSystem.abandonBlock: {} is" + " removed from pendingCreates", b); } finally { - writeUnlock(); + writeUnlock("abandonBlock"); } getEditLog().logSync(); } @@ -2618,7 +2642,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, success = FSDirWriteFileOp.completeFile(this, pc, src, holder, last, fileId); } finally { - writeUnlock(); + writeUnlock("completeFile"); } getEditLog().logSync(); return success; @@ -2681,6 +2705,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, @Deprecated boolean renameTo(String src, String dst, boolean logRetryCache) throws IOException { + final String operationName = "rename"; FSDirRenameOp.RenameResult ret = null; writeLock(); try { @@ -2688,22 +2713,23 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot rename " + src); ret = FSDirRenameOp.renameToInt(dir, src, dst, logRetryCache); } catch (AccessControlException e) { - logAuditEvent(false, "rename", src, dst, null); + logAuditEvent(false, operationName, src, dst, null); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } boolean success = ret.success; if (success) { getEditLog().logSync(); } - logAuditEvent(success, "rename", src, dst, ret.auditStat); + logAuditEvent(success, operationName, src, dst, ret.auditStat); return success; } void renameTo(final String src, final String dst, boolean logRetryCache, Options.Rename... options) throws IOException { + final String operationName = "rename"; FSDirRenameOp.RenameResult res = null; writeLock(); try { @@ -2711,11 +2737,11 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot rename " + src); res = FSDirRenameOp.renameToInt(dir, src, dst, logRetryCache, options); } catch (AccessControlException e) { - logAuditEvent(false, "rename (options=" + Arrays.toString(options) + - ")", src, dst, null); + logAuditEvent(false, operationName + " (options=" + + Arrays.toString(options) + ")", src, dst, null); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); @@ -2726,8 +2752,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, collectedBlocks.clear(); } - logAuditEvent(true, "rename (options=" + Arrays.toString(options) + - ")", src, dst, res.auditStat); + logAuditEvent(true, operationName + " (options=" + + Arrays.toString(options) + ")", src, dst, res.auditStat); } /** @@ -2738,6 +2764,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ boolean delete(String src, boolean recursive, boolean logRetryCache) throws IOException { + final String operationName = "delete"; BlocksMapUpdateInfo toRemovedBlocks = null; writeLock(); boolean ret = false; @@ -2748,16 +2775,16 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, this, src, recursive, logRetryCache); ret = toRemovedBlocks != null; } catch (AccessControlException e) { - logAuditEvent(false, "delete", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); if (toRemovedBlocks != null) { removeBlocks(toRemovedBlocks); // Incremental deletion of blocks } - logAuditEvent(true, "delete", src); + logAuditEvent(true, operationName, src); return ret; } @@ -2785,7 +2812,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, blockManager.removeBlock(iter.next()); } } finally { - writeUnlock(); + writeUnlock("removeBlocks"); } } } @@ -2836,6 +2863,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ HdfsFileStatus getFileInfo(final String src, boolean resolveLink) throws IOException { + final String operationName = "getfileinfo"; checkOperation(OperationCategory.READ); HdfsFileStatus stat = null; readLock(); @@ -2843,12 +2871,12 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkOperation(OperationCategory.READ); stat = FSDirStatAndListingOp.getFileInfo(dir, src, resolveLink); } catch (AccessControlException e) { - logAuditEvent(false, "getfileinfo", src); + logAuditEvent(false, operationName, src); throw e; } finally { - readUnlock(); + readUnlock(operationName); } - logAuditEvent(true, "getfileinfo", src); + logAuditEvent(true, operationName, src); return stat; } @@ -2856,16 +2884,17 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, * Returns true if the file is closed */ boolean isFileClosed(final String src) throws IOException { + final String operationName = "isFileClosed"; checkOperation(OperationCategory.READ); readLock(); try { checkOperation(OperationCategory.READ); return FSDirStatAndListingOp.isFileClosed(dir, src); } catch (AccessControlException e) { - logAuditEvent(false, "isFileClosed", src); + logAuditEvent(false, operationName, src); throw e; } finally { - readUnlock(); + readUnlock(operationName); } } @@ -2874,6 +2903,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ boolean mkdirs(String src, PermissionStatus permissions, boolean createParent) throws IOException { + final String operationName = "mkdirs"; HdfsFileStatus auditStat = null; checkOperation(OperationCategory.WRITE); writeLock(); @@ -2882,13 +2912,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot create directory " + src); auditStat = FSDirMkdirOp.mkdirs(this, src, permissions, createParent); } catch (AccessControlException e) { - logAuditEvent(false, "mkdirs", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "mkdirs", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); return true; } @@ -2908,6 +2938,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ ContentSummary getContentSummary(final String src) throws IOException { checkOperation(OperationCategory.READ); + final String operationName = "contentSummary"; readLock(); boolean success = true; try { @@ -2917,8 +2948,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, success = false; throw ace; } finally { - readUnlock(); - logAuditEvent(success, "contentSummary", src); + readUnlock(operationName); + logAuditEvent(success, operationName, src); } } @@ -2938,6 +2969,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ QuotaUsage getQuotaUsage(final String src) throws IOException { checkOperation(OperationCategory.READ); + final String operationName = "quotaUsage"; readLock(); boolean success = true; try { @@ -2947,8 +2979,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, success = false; throw ace; } finally { - readUnlock(); - logAuditEvent(success, "quotaUsage", src); + readUnlock(operationName); + logAuditEvent(success, operationName, src); } } @@ -2965,6 +2997,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, requireEffectiveLayoutVersionForFeature(Feature.QUOTA_BY_STORAGE_TYPE); } checkOperation(OperationCategory.WRITE); + final String operationName = "setQuota"; writeLock(); boolean success = false; try { @@ -2973,11 +3006,11 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, FSDirAttrOp.setQuota(dir, src, nsQuota, ssQuota, type); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); if (success) { getEditLog().logSync(); } - logAuditEvent(success, "setQuota", src); + logAuditEvent(success, operationName, src); } } @@ -3009,7 +3042,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } FSDirWriteFileOp.persistBlocks(dir, src, pendingFile, false); } finally { - writeUnlock(); + writeUnlock("fsync"); } getEditLog().logSync(); } @@ -3442,7 +3475,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, FSDirWriteFileOp.persistBlocks(dir, src, iFile, false); } } finally { - writeUnlock(); + writeUnlock("commitBlockSynchronization"); } getEditLog().logSync(); if (closeFile) { @@ -3486,7 +3519,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot renew lease for " + holder); leaseManager.renewLease(holder); } finally { - readUnlock(); + readUnlock("renewLease"); } } @@ -3506,18 +3539,19 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, boolean needLocation) throws IOException { checkOperation(OperationCategory.READ); + final String operationName = "listStatus"; DirectoryListing dl = null; readLock(); try { checkOperation(NameNode.OperationCategory.READ); dl = getListingInt(dir, src, startAfter, needLocation); } catch (AccessControlException e) { - logAuditEvent(false, "listStatus", src); + logAuditEvent(false, operationName, src); throw e; } finally { - readUnlock(); + readUnlock(operationName); } - logAuditEvent(true, "listStatus", src); + logAuditEvent(true, operationName, src); return dl; } @@ -3554,7 +3588,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, try { blockManager.registerDatanode(nodeReg); } finally { - writeUnlock(); + writeUnlock("registerDatanode"); } } @@ -3604,7 +3638,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, return new HeartbeatResponse(cmds, haState, rollingUpgradeInfo, blockReportLeaseId); } finally { - readUnlock(); + readUnlock("handleHeartbeat"); } } @@ -3798,7 +3832,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } } } finally { - writeUnlock(); + writeUnlock("clearCorruptLazyPersistFiles"); } if (changed) { getEditLog().logSync(); @@ -4004,7 +4038,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, return getBlockManager().getDatanodeManager().getDatanodeListForReport( type).size(); } finally { - readUnlock(); + readUnlock("getNumberOfDatanodes"); } } @@ -4025,7 +4059,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } return arr; } finally { - readUnlock(); + readUnlock("datanodeReport"); } } @@ -4048,7 +4082,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } return reports; } finally { - readUnlock(); + readUnlock("getDatanodeStorageReport"); } } @@ -4075,7 +4109,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } getFSImage().saveNamespace(this); } finally { - readUnlock(); + readUnlock("saveNamespace"); cpUnlock(); } LOG.info("New namespace image has been created"); @@ -4105,7 +4139,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, return val; } finally { - writeUnlock(); + writeUnlock("restoreFailedStorage"); cpUnlock(); } } @@ -4123,7 +4157,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkOperation(OperationCategory.UNCHECKED); getFSImage().finalizeUpgrade(this.isHaEnabled() && inActiveState()); } finally { - writeUnlock(); + writeUnlock("finalizeUpgrade"); cpUnlock(); } } @@ -4199,7 +4233,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, numUCBlocks = leaseManager.getNumUnderConstructionBlocks(); return getBlocksTotal() - numUCBlocks; } finally { - readUnlock(); + readUnlock("getCompleteBlocksTotal"); } } @@ -4238,7 +4272,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, NameNode.stateChangeLog.info("STATE* Safe mode is ON.\n" + getSafeModeTip()); } finally { - writeUnlock(); + writeUnlock("enterSafeMode"); } } @@ -4258,7 +4292,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, startSecretManagerIfNecessary(); } } finally { - writeUnlock(); + writeUnlock("leaveSafeMode"); } } @@ -4303,7 +4337,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } return getFSImage().rollEditLog(getEffectiveLayoutVersion()); } finally { - writeUnlock(); + writeUnlock("rollEditLog"); } } @@ -4321,7 +4355,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, getEditLog().logSync(); return cmd; } finally { - writeUnlock(); + writeUnlock("startCheckpoint"); } } @@ -4332,7 +4366,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, try { blockManager.processIncrementalBlockReport(nodeID, srdb); } finally { - writeUnlock(); + writeUnlock("processIncrementalBlockReport"); } } @@ -4346,7 +4380,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, LOG.info("End checkpoint for " + registration.getAddress()); getFSImage().endCheckpoint(sig); } finally { - readUnlock(); + readUnlock("endCheckpoint"); } } @@ -4739,7 +4773,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } } } finally { - writeUnlock(); + writeUnlock("reportBadBlocks"); } } @@ -4771,7 +4805,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, locatedBlock = new LocatedBlock(block, new DatanodeInfo[0]); blockManager.setBlockToken(locatedBlock, BlockTokenIdentifier.AccessMode.WRITE); } finally { - writeUnlock(); + writeUnlock("bumpBlockGenerationStamp"); } // Ensure we record the new generation stamp getEditLog().logSync(); @@ -4806,7 +4840,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, updatePipelineInternal(clientName, oldBlock, newBlock, newNodes, newStorageIDs, logRetryCache); } finally { - writeUnlock(); + writeUnlock("updatePipeline"); } getEditLog().logSync(); LOG.info("updatePipeline(" + oldBlock.getLocalBlock() + " => " @@ -4874,7 +4908,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, bnReg, nnReg); } } finally { - writeUnlock(); + writeUnlock("registerBackupNode"); } } @@ -4899,7 +4933,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, " node namespaceID = " + registration.getNamespaceID()); getEditLog().releaseBackupStream(registration); } finally { - writeUnlock(); + writeUnlock("releaseBackupNode"); } } @@ -4984,7 +5018,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } return corruptFiles; } finally { - readUnlock(); + readUnlock("listCorruptFileBlocks"); } } @@ -5068,7 +5102,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, long expiryTime = dtSecretManager.getTokenExpiryTime(dtId); getEditLog().logGetDelegationToken(dtId, expiryTime); } finally { - writeUnlock(); + writeUnlock("getDelegationToken"); } getEditLog().logSync(); return token; @@ -5102,7 +5136,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, id.readFields(in); getEditLog().logRenewDelegationToken(id, expiryTime); } finally { - writeUnlock(); + writeUnlock("renewDelegationToken"); } getEditLog().logSync(); return expiryTime; @@ -5126,7 +5160,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, .cancelToken(token, canceller); getEditLog().logCancelDelegationToken(id); } finally { - writeUnlock(); + writeUnlock("cancelDelegationToken"); } getEditLog().logSync(); } @@ -5777,6 +5811,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, /** Allow snapshot on a directory. */ void allowSnapshot(String path) throws IOException { checkOperation(OperationCategory.WRITE); + final String operationName = "allowSnapshot"; boolean success = false; writeLock(); try { @@ -5786,15 +5821,16 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, FSDirSnapshotOp.allowSnapshot(dir, snapshotManager, path); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(success, "allowSnapshot", path, null, null); + logAuditEvent(success, operationName, path, null, null); } /** Disallow snapshot on a directory. */ void disallowSnapshot(String path) throws IOException { checkOperation(OperationCategory.WRITE); + final String operationName = "disallowSnapshot"; boolean success = false; writeLock(); try { @@ -5804,10 +5840,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, FSDirSnapshotOp.disallowSnapshot(dir, snapshotManager, path); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(success, "disallowSnapshot", path, null, null); + logAuditEvent(success, operationName, path, null, null); } /** @@ -5817,6 +5853,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ String createSnapshot(String snapshotRoot, String snapshotName, boolean logRetryCache) throws IOException { + final String operationName = "createSnapshot"; String snapshotPath = null; writeLock(); try { @@ -5825,10 +5862,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, snapshotPath = FSDirSnapshotOp.createSnapshot(dir, snapshotManager, snapshotRoot, snapshotName, logRetryCache); } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(snapshotPath != null, "createSnapshot", snapshotRoot, + logAuditEvent(snapshotPath != null, operationName, snapshotRoot, snapshotPath, null); return snapshotPath; } @@ -5844,6 +5881,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, void renameSnapshot( String path, String snapshotOldName, String snapshotNewName, boolean logRetryCache) throws IOException { + final String operationName = "renameSnapshot"; boolean success = false; writeLock(); try { @@ -5853,12 +5891,12 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, snapshotOldName, snapshotNewName, logRetryCache); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); String oldSnapshotRoot = Snapshot.getSnapshotPath(path, snapshotOldName); String newSnapshotRoot = Snapshot.getSnapshotPath(path, snapshotNewName); - logAuditEvent(success, "renameSnapshot", oldSnapshotRoot, + logAuditEvent(success, operationName, oldSnapshotRoot, newSnapshotRoot, null); } @@ -5871,6 +5909,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ public SnapshottableDirectoryStatus[] getSnapshottableDirListing() throws IOException { + final String operationName = "listSnapshottableDirectory"; SnapshottableDirectoryStatus[] status = null; checkOperation(OperationCategory.READ); boolean success = false; @@ -5880,9 +5919,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, status = FSDirSnapshotOp.getSnapshottableDirListing(dir, snapshotManager); success = true; } finally { - readUnlock(); + readUnlock(operationName); } - logAuditEvent(success, "listSnapshottableDirectory", null, null, null); + logAuditEvent(success, operationName, null, null, null); return status; } @@ -5903,6 +5942,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ SnapshotDiffReport getSnapshotDiffReport(String path, String fromSnapshot, String toSnapshot) throws IOException { + final String operationName = "computeSnapshotDiff"; SnapshotDiffReport diffs = null; checkOperation(OperationCategory.READ); readLock(); @@ -5911,13 +5951,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, diffs = FSDirSnapshotOp.getSnapshotDiffReport(dir, snapshotManager, path, fromSnapshot, toSnapshot); } finally { - readUnlock(); + readUnlock(operationName); } String fromSnapshotRoot = (fromSnapshot == null || fromSnapshot.isEmpty()) ? path : Snapshot.getSnapshotPath(path, fromSnapshot); String toSnapshotRoot = (toSnapshot == null || toSnapshot.isEmpty()) ? path : Snapshot.getSnapshotPath(path, toSnapshot); - logAuditEvent(diffs != null, "computeSnapshotDiff", fromSnapshotRoot, + logAuditEvent(diffs != null, operationName, fromSnapshotRoot, toSnapshotRoot, null); return diffs; } @@ -5931,6 +5971,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ void deleteSnapshot(String snapshotRoot, String snapshotName, boolean logRetryCache) throws IOException { + final String operationName = "deleteSnapshot"; boolean success = false; writeLock(); BlocksMapUpdateInfo blocksToBeDeleted = null; @@ -5942,7 +5983,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, snapshotRoot, snapshotName, logRetryCache); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); @@ -5953,7 +5994,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } String rootPath = Snapshot.getSnapshotPath(snapshotRoot, snapshotName); - logAuditEvent(success, "deleteSnapshot", rootPath, null, null); + logAuditEvent(success, operationName, rootPath, null, null); } /** @@ -5979,11 +6020,12 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, rollingUpgradeInfo.setCreatedRollbackImages(hasRollbackImage); return rollingUpgradeInfo; } finally { - readUnlock(); + readUnlock("queryRollingUpgrade"); } } RollingUpgradeInfo startRollingUpgrade() throws IOException { + final String operationName = "startRollingUpgrade"; checkSuperuserPrivilege(); checkOperation(OperationCategory.WRITE); writeLock(); @@ -6006,12 +6048,12 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, getFSImage().rollEditLog(getEffectiveLayoutVersion()); } } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); if (auditLog.isInfoEnabled() && isExternalInvocation()) { - logAuditEvent(true, "startRollingUpgrade", null, null, null); + logAuditEvent(true, operationName, null, null, null); } return rollingUpgradeInfo; } @@ -6096,7 +6138,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } catch (IOException ioe) { LOG.warn("Encountered exception setting Rollback Image", ioe); } finally { - readUnlock(); + readUnlock("getRollingUpgradeStatus"); } return new RollingUpgradeInfo.Bean(upgradeInfo); } @@ -6176,6 +6218,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } RollingUpgradeInfo finalizeRollingUpgrade() throws IOException { + final String operationName = "finalizeRollingUpgrade"; checkSuperuserPrivilege(); checkOperation(OperationCategory.WRITE); writeLock(); @@ -6196,7 +6239,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, getFSImage().renameCheckpoint(NameNodeFile.IMAGE_ROLLBACK, NameNodeFile.IMAGE); } finally { - writeUnlock(); + writeUnlock(operationName); } if (!haEnabled) { @@ -6205,7 +6248,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, } if (auditLog.isInfoEnabled() && isExternalInvocation()) { - logAuditEvent(true, "finalizeRollingUpgrade", null, null, null); + logAuditEvent(true, operationName, null, null, null); } return rollingUpgradeInfo; } @@ -6218,6 +6261,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, long addCacheDirective(CacheDirectiveInfo directive, EnumSet<CacheFlag> flags, boolean logRetryCache) throws IOException { + final String operationName = "addCacheDirective"; CacheDirectiveInfo effectiveDirective = null; if (!flags.contains(CacheFlag.FORCE)) { cacheManager.waitForRescanIfNeeded(); @@ -6229,7 +6273,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, effectiveDirective = FSNDNCacheOp.addCacheDirective(this, cacheManager, directive, flags, logRetryCache); } finally { - writeUnlock(); + writeUnlock(operationName); boolean success = effectiveDirective != null; if (success) { getEditLog().logSync(); @@ -6237,7 +6281,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, String effectiveDirectiveStr = effectiveDirective != null ? effectiveDirective.toString() : null; - logAuditEvent(success, "addCacheDirective", effectiveDirectiveStr, + logAuditEvent(success, operationName, effectiveDirectiveStr, null, null); } return effectiveDirective != null ? effectiveDirective.getId() : 0; @@ -6245,6 +6289,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, void modifyCacheDirective(CacheDirectiveInfo directive, EnumSet<CacheFlag> flags, boolean logRetryCache) throws IOException { + final String operationName = "modifyCacheDirective"; boolean success = false; if (!flags.contains(CacheFlag.FORCE)) { cacheManager.waitForRescanIfNeeded(); @@ -6257,17 +6302,18 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, logRetryCache); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); if (success) { getEditLog().logSync(); } final String idStr = "{id: " + directive.getId() + "}"; - logAuditEvent(success, "modifyCacheDirective", idStr, + logAuditEvent(success, operationName, idStr, directive.toString(), null); } } void removeCacheDirective(long id, boolean logRetryCache) throws IOException { + final String operationName = "removeCacheDirective"; boolean success = false; writeLock(); try { @@ -6276,9 +6322,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, FSNDNCacheOp.removeCacheDirective(this, cacheManager, id, logRetryCache); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); String idStr = "{id: " + Long.toString(id) + "}"; - logAuditEvent(success, "removeCacheDirective", idStr, null, + logAuditEvent(success, operationName, idStr, null, null); } getEditLog().logSync(); @@ -6286,6 +6332,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, BatchedListEntries<CacheDirectiveEntry> listCacheDirectives( long startId, CacheDirectiveInfo filter) throws IOException { + final String operationName = "listCacheDirectives"; checkOperation(OperationCategory.READ); BatchedListEntries<CacheDirectiveEntry> results; cacheManager.waitForRescanIfNeeded(); @@ -6297,8 +6344,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, filter); success = true; } finally { - readUnlock(); - logAuditEvent(success, "listCacheDirectives", filter.toString(), null, + readUnlock(operationName); + logAuditEvent(success, operationName, filter.toString(), null, null); } return results; @@ -6306,6 +6353,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, void addCachePool(CachePoolInfo req, boolean logRetryCache) throws IOException { + final String operationName = "addCachePool"; writeLock(); boolean success = false; String poolInfoStr = null; @@ -6318,8 +6366,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, poolInfoStr = info.toString(); success = true; } finally { - writeUnlock(); - logAuditEvent(success, "addCachePool", poolInfoStr, null, null); + writeUnlock(operationName); + logAuditEvent(success, operationName, poolInfoStr, null, null); } getEditLog().logSync(); @@ -6327,6 +6375,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, void modifyCachePool(CachePoolInfo req, boolean logRetryCache) throws IOException { + final String operationName = "modifyCachePool"; writeLock(); boolean success = false; try { @@ -6336,10 +6385,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, FSNDNCacheOp.modifyCachePool(this, cacheManager, req, logRetryCache); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); String poolNameStr = "{poolName: " + (req == null ? null : req.getPoolName()) + "}"; - logAuditEvent(success, "modifyCachePool", poolNameStr, + logAuditEvent(success, operationName, poolNameStr, req == null ? null : req.toString(), null); } @@ -6348,6 +6397,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, void removeCachePool(String cachePoolName, boolean logRetryCache) throws IOException { + final String operationName = "removeCachePool"; writeLock(); boolean success = false; try { @@ -6357,9 +6407,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, logRetryCache); success = true; } finally { - writeUnlock(); + writeUnlock(operationName); String poolNameStr = "{poolName: " + cachePoolName + "}"; - logAuditEvent(success, "removeCachePool", poolNameStr, null, null); + logAuditEvent(success, operationName, poolNameStr, null, null); } getEditLog().logSync(); @@ -6367,6 +6417,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, BatchedListEntries<CachePoolEntry> listCachePools(String prevKey) throws IOException { + final String operationName = "listCachePools"; BatchedListEntries<CachePoolEntry> results; checkOperation(OperationCategory.READ); boolean success = false; @@ -6377,14 +6428,15 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, results = FSNDNCacheOp.listCachePools(this, cacheManager, prevKey); success = true; } finally { - readUnlock(); - logAuditEvent(success, "listCachePools", null, null, null); + readUnlock(operationName); + logAuditEvent(success, operationName, null, null, null); } return results; } void modifyAclEntries(final String src, List<AclEntry> aclSpec) throws IOException { + final String operationName = "modifyAclEntries"; HdfsFileStatus auditStat = null; checkOperation(OperationCategory.WRITE); writeLock(); @@ -6393,17 +6445,18 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot modify ACL entries on " + src); auditStat = FSDirAclOp.modifyAclEntries(dir, src, aclSpec); } catch (AccessControlException e) { - logAuditEvent(false, "modifyAclEntries", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "modifyAclEntries", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } void removeAclEntries(final String src, List<AclEntry> aclSpec) throws IOException { + final String operationName = "removeAclEntries"; checkOperation(OperationCategory.WRITE); HdfsFileStatus auditStat = null; writeLock(); @@ -6412,16 +6465,17 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot remove ACL entries on " + src); auditStat = FSDirAclOp.removeAclEntries(dir, src, aclSpec); } catch (AccessControlException e) { - logAuditEvent(false, "removeAclEntries", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "removeAclEntries", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } void removeDefaultAcl(final String src) throws IOException { + final String operationName = "removeDefaultAcl"; HdfsFileStatus auditStat = null; checkOperation(OperationCategory.WRITE); writeLock(); @@ -6430,16 +6484,17 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot remove default ACL entries on " + src); auditStat = FSDirAclOp.removeDefaultAcl(dir, src); } catch (AccessControlException e) { - logAuditEvent(false, "removeDefaultAcl", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "removeDefaultAcl", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } void removeAcl(final String src) throws IOException { + final String operationName = "removeAcl"; HdfsFileStatus auditStat = null; checkOperation(OperationCategory.WRITE); writeLock(); @@ -6448,16 +6503,17 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot remove ACL on " + src); auditStat = FSDirAclOp.removeAcl(dir, src); } catch (AccessControlException e) { - logAuditEvent(false, "removeAcl", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "removeAcl", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } void setAcl(final String src, List<AclEntry> aclSpec) throws IOException { + final String operationName = "setAcl"; HdfsFileStatus auditStat = null; checkOperation(OperationCategory.WRITE); writeLock(); @@ -6466,16 +6522,17 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot set ACL on " + src); auditStat = FSDirAclOp.setAcl(dir, src, aclSpec); } catch (AccessControlException e) { - logAuditEvent(false, "setAcl", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "setAcl", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } AclStatus getAclStatus(String src) throws IOException { + final String operationName = "getAclStatus"; checkOperation(OperationCategory.READ); boolean success = false; readLock(); @@ -6485,8 +6542,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, success = true; return ret; } finally { - readUnlock(); - logAuditEvent(success, "getAclStatus", src); + readUnlock(operationName); + logAuditEvent(success, operationName, src); } } @@ -6504,6 +6561,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, void createEncryptionZone(final String src, final String keyName, boolean logRetryCache) throws IOException, UnresolvedLinkException, SafeModeException, AccessControlException { + final String operationName = "createEncryptionZone"; try { Metadata metadata = FSDirEncryptionZoneOp.ensureKeyIsInitialized(dir, keyName, src); @@ -6519,13 +6577,13 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, resultingStat = FSDirEncryptionZoneOp.createEncryptionZone(dir, src, pc, metadata.getCipher(), keyName, logRetryCache); } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "createEncryptionZone", src, null, resultingStat); + logAuditEvent(true, operationName, src, null, resultingStat); } catch (AccessControlException e) { - logAuditEvent(false, "createEncryptionZone", src); + logAuditEvent(false, operationName, src); throw e; } } @@ -6540,6 +6598,7 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, */ EncryptionZone getEZForPath(final String srcArg) throws AccessControlException, UnresolvedLinkException, IOException { + final String operationName = "getEZForPath"; HdfsFileStatus resultingStat = null; boolean success = false; final FSPermissionChecker pc = getPermissionChecker(); @@ -6553,13 +6612,14 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, resultingStat = ezForPath.getValue(); return ezForPath.getKey(); } finally { - readUnlock(); - logAuditEvent(success, "getEZForPath", srcArg, null, resultingStat); + readUnlock(operationName); + logAuditEvent(success, operationName, srcArg, null, resultingStat); } } BatchedListEntries<EncryptionZone> listEncryptionZones(long prevId) throws IOException { + final String operationName = "listEncryptionZones"; boolean success = false; checkSuperuserPrivilege(); checkOperation(OperationCategory.READ); @@ -6572,14 +6632,15 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, success = true; return ret; } finally { - readUnlock(); - logAuditEvent(success, "listEncryptionZones", null); + readUnlock(operationName); + logAuditEvent(success, operationName, null); } } void setXAttr(String src, XAttr xAttr, EnumSet<XAttrSetFlag> flag, boolean logRetryCache) throws IOException { + final String operationName = "setXAttr"; HdfsFileStatus auditStat = null; writeLock(); try { @@ -6587,46 +6648,49 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot set XAttr on " + src); auditStat = FSDirXAttrOp.setXAttr(dir, src, xAttr, flag, logRetryCache); } catch (AccessControlException e) { - logAuditEvent(false, "setXAttr", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "setXAttr", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } List<XAttr> getXAttrs(final String src, List<XAttr> xAttrs) throws IOException { + final String operationName = "getXAttrs"; checkOperation(OperationCategory.READ); readLock(); try { checkOperation(OperationCategory.READ); return FSDirXAttrOp.getXAttrs(dir, src, xAttrs); } catch (AccessControlException e) { - logAuditEvent(false, "getXAttrs", src); + logAuditEvent(false, operationName, src); throw e; } finally { - readUnlock(); + readUnlock(operationName); } } List<XAttr> listXAttrs(String src) throws IOException { + final String operationName = "listXAttrs"; checkOperation(OperationCategory.READ); readLock(); try { checkOperation(OperationCategory.READ); return FSDirXAttrOp.listXAttrs(dir, src); } catch (AccessControlException e) { - logAuditEvent(false, "listXAttrs", src); + logAuditEvent(false, operationName, src); throw e; } finally { - readUnlock(); + readUnlock(operationName); } } void removeXAttr(String src, XAttr xAttr, boolean logRetryCache) throws IOException { + final String operationName = "removeXAttr"; HdfsFileStatus auditStat = null; writeLock(); try { @@ -6634,16 +6698,17 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, checkNameNodeSafeMode("Cannot remove XAttr entry on " + src); auditStat = FSDirXAttrOp.removeXAttr(dir, src, xAttr, logRetryCache); } catch (AccessControlException e) { - logAuditEvent(false, "removeXAttr", src); + logAuditEvent(false, operationName, src); throw e; } finally { - writeUnlock(); + writeUnlock(operationName); } getEditLog().logSync(); - logAuditEvent(true, "removeXAttr", src, null, auditStat); + logAuditEvent(true, operationName, src, null, auditStat); } void checkAccess(String src, FsAction mode) throws IOException { + final String operationName = "checkAccess"; checkOperation(OperationCategory.READ); FSPermissionChecker pc = getPermissionChecker(); readLock(); @@ -6659,10 +6724,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean, dir.checkPathAccess(pc, iip, mode); } } catch (AccessControlException e) { - logAuditEvent(false, "checkAccess", src); + logAuditEvent(false, operationName, src); throw e; } finally { - readUnlock(); + readUnlock(operationName); } } http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystemLock.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystemLock.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystemLock.java index 043f569..c7dde2b 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystemLock.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystemLock.java @@ -27,11 +27,14 @@ import java.util.concurrent.locks.ReentrantReadWriteLock; import com.google.common.annotations.VisibleForTesting; import org.apache.hadoop.conf.Configuration; +import org.apache.hadoop.metrics2.lib.MutableRatesWithAggregation; import org.apache.hadoop.util.StringUtils; import org.apache.hadoop.util.Timer; import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_LOCK_SUPPRESS_WARNING_INTERVAL_DEFAULT; import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_LOCK_SUPPRESS_WARNING_INTERVAL_KEY; +import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_NAMENODE_LOCK_DETAILED_METRICS_DEFAULT; +import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_NAMENODE_LOCK_DETAILED_METRICS_KEY; import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_NAMENODE_READ_LOCK_REPORTING_THRESHOLD_MS_DEFAULT; import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_NAMENODE_READ_LOCK_REPORTING_THRESHOLD_MS_KEY; import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_NAMENODE_WRITE_LOCK_REPORTING_THRESHOLD_MS_DEFAULT; @@ -40,11 +43,20 @@ import static org.apache.hadoop.hdfs.DFSConfigKeys.DFS_NAMENODE_WRITE_LOCK_REPOR /** * Mimics a ReentrantReadWriteLock but does not directly implement the interface * so more sophisticated locking capabilities and logging/metrics are possible. + * If {@link org.apache.hadoop.hdfs.DFSConfigKeys#DFS_NAMENODE_LOCK_DETAILED_METRICS_KEY} + * is set to be true, metrics will be emitted into the FSNamesystem metrics + * registry for each operation which acquires this lock indicating how long + * the operation held the lock for. Note that if a thread dies, metrics produced + * after the most recent snapshot will be lost due to the use of + * {@link MutableRatesWithAggregation}. However since threads are re-used + * between operations this should not generally be an issue. */ class FSNamesystemLock { @VisibleForTesting protected ReentrantReadWriteLock coarseLock; + private final boolean metricsEnabled; + private final MutableRatesWithAggregation detailedHoldTimeMetrics; private final Timer timer; /** @@ -80,12 +92,19 @@ class FSNamesystemLock { private final AtomicLong timeStampOfLastReadLockReport = new AtomicLong(0); private final AtomicLong longestReadLockHeldInterval = new AtomicLong(0); - FSNamesystemLock(Configuration conf) { - this(conf, new Timer()); + @VisibleForTesting + static final String OP_NAME_OTHER = "OTHER"; + private static final String READ_LOCK_METRIC_PREFIX = "FSNReadLock"; + private static final String WRITE_LOCK_METRIC_PREFIX = "FSNWriteLock"; + + FSNamesystemLock(Configuration conf, + MutableRatesWithAggregation detailedHoldTimeMetrics) { + this(conf, detailedHoldTimeMetrics, new Timer()); } @VisibleForTesting - FSNamesystemLock(Configuration conf, Timer timer) { + FSNamesystemLock(Configuration conf, + MutableRatesWithAggregation detailedHoldTimeMetrics, Timer timer) { boolean fair = conf.getBoolean("dfs.namenode.fslock.fair", true); FSNamesystem.LOG.info("fsLock is fair: " + fair); this.coarseLock = new ReentrantReadWriteLock(fair); @@ -100,6 +119,12 @@ class FSNamesystemLock { this.lockSuppressWarningInterval = conf.getTimeDuration( DFS_LOCK_SUPPRESS_WARNING_INTERVAL_KEY, DFS_LOCK_SUPPRESS_WARNING_INTERVAL_DEFAULT, TimeUnit.MILLISECONDS); + this.metricsEnabled = conf.getBoolean( + DFS_NAMENODE_LOCK_DETAILED_METRICS_KEY, + DFS_NAMENODE_LOCK_DETAILED_METRICS_DEFAULT); + FSNamesystem.LOG.info("Detailed lock hold time metrics enabled: " + + this.metricsEnabled); + this.detailedHoldTimeMetrics = detailedHoldTimeMetrics; } public void readLock() { @@ -110,12 +135,17 @@ class FSNamesystemLock { } public void readUnlock() { + readUnlock(OP_NAME_OTHER); + } + + public void readUnlock(String opName) { final boolean needReport = coarseLock.getReadHoldCount() == 1; final long readLockInterval = timer.monotonicNow() - readLockHeldTimeStamp.get(); coarseLock.readLock().unlock(); if (needReport) { + addMetric(opName, readLockInterval, false); readLockHeldTimeStamp.remove(); } if (needReport && readLockInterval >= this.readLockReportingThreshold) { @@ -164,6 +194,10 @@ class FSNamesystemLock { } public void writeUnlock() { + writeUnlock(OP_NAME_OTHER); + } + + public void writeUnlock(String opName) { final boolean needReport = coarseLock.getWriteHoldCount() == 1 && coarseLock.isWriteLockedByCurrentThread(); final long currentTime = timer.monotonicNow(); @@ -191,6 +225,10 @@ class FSNamesystemLock { coarseLock.writeLock().unlock(); + if (needReport) { + addMetric(opName, writeLockInterval, true); + } + if (logReport) { FSNamesystem.LOG.info("FSNamesystem write lock held for " + writeLockInterval + " ms via\n" + @@ -227,4 +265,19 @@ class FSNamesystemLock { public int getQueueLength() { return coarseLock.getQueueLength(); } + + /** + * Add the lock hold time for a recent operation to the metrics. + * @param operationName Name of the operation for which to record the time + * @param value Length of time the lock was held + */ + private void addMetric(String operationName, long value, boolean isWrite) { + if (metricsEnabled) { + String metricName = + (isWrite ? WRITE_LOCK_METRIC_PREFIX : READ_LOCK_METRIC_PREFIX) + + org.apache.commons.lang.StringUtils.capitalize(operationName); + detailedHoldTimeMetrics.add(metricName, value); + } + } + } http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/LeaseManager.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/LeaseManager.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/LeaseManager.java index 69d1619..3cc7bd1 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/LeaseManager.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/LeaseManager.java @@ -329,7 +329,7 @@ public class LeaseManager { needSync = checkLeases(); } } finally { - fsnamesystem.writeUnlock(); + fsnamesystem.writeUnlock("leaseManager"); // lease reassignments should to be sync'ed. if (needSync) { fsnamesystem.getEditLog().logSync(); http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/NamenodeFsck.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/NamenodeFsck.java b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/NamenodeFsck.java index 060cfbd..1a2deb0 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/NamenodeFsck.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/NamenodeFsck.java @@ -498,7 +498,7 @@ public class NamenodeFsck implements DataEncryptionKeyFactory { } catch (FileNotFoundException fnfe) { blocks = null; } finally { - fsn.readUnlock(); + fsn.readUnlock("fsckGetBlockLocations"); } return blocks; } http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/main/resources/hdfs-default.xml ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/main/resources/hdfs-default.xml b/hadoop-hdfs-project/hadoop-hdfs/src/main/resources/hdfs-default.xml index b5ab963..5161e7d 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/main/resources/hdfs-default.xml +++ b/hadoop-hdfs-project/hadoop-hdfs/src/main/resources/hdfs-default.xml @@ -2653,6 +2653,14 @@ </property> <property> + <name>dfs.namenode.lock.detailed-metrics.enabled</name> + <value>false</value> + <description>If true, the namenode will keep track of how long various + operations hold the Namesystem lock for and emit this as metrics. + </description> +</property> + +<property> <name>dfs.namenode.startup.delay.block.deletion.sec</name> <value>0</value> <description>The delay in seconds at which we will pause the blocks deletion http://git-wip-us.apache.org/repos/asf/hadoop/blob/818915aa/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/TestFSNamesystemLock.java ---------------------------------------------------------------------- diff --git a/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/TestFSNamesystemLock.java b/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/TestFSNamesystemLock.java index 08900ec..c97e0f0 100644 --- a/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/TestFSNamesystemLock.java +++ b/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/TestFSNamesystemLock.java @@ -21,8 +21,12 @@ package org.apache.hadoop.hdfs.server.namenode; import com.google.common.base.Supplier; import org.apache.hadoop.conf.Configuration; import org.apache.hadoop.hdfs.DFSConfigKeys; +import org.apache.hadoop.metrics2.MetricsRecordBuilder; +import org.apache.hadoop.metrics2.lib.MetricsRegistry; +import org.apache.hadoop.metrics2.lib.MutableRatesWithAggregation; import org.apache.hadoop.test.GenericTestUtils; import org.apache.hadoop.test.GenericTestUtils.LogCapturer; +import org.apache.hadoop.test.MetricsAsserts; import org.apache.hadoop.util.FakeTimer; import org.apache.log4j.Level; import org.junit.Test; @@ -36,6 +40,8 @@ import java.util.concurrent.TimeoutException; import java.util.regex.Pattern; import static org.junit.Assert.*; +import static org.apache.hadoop.test.MetricsAsserts.assertCounter; +import static org.apache.hadoop.test.MetricsAsserts.assertGauge; /** * Tests the FSNamesystemLock, looking at lock compatibilities and @@ -48,17 +54,17 @@ public class TestFSNamesystemLock { Configuration conf = new Configuration(); conf.setBoolean("dfs.namenode.fslock.fair", true); - FSNamesystemLock fsnLock = new FSNamesystemLock(conf); + FSNamesystemLock fsnLock = new FSNamesystemLock(conf, null); assertTrue(fsnLock.coarseLock.isFair()); conf.setBoolean("dfs.namenode.fslock.fair", false); - fsnLock = new FSNamesystemLock(conf); + fsnLock = new FSNamesystemLock(conf, null); assertFalse(fsnLock.coarseLock.isFair()); } @Test public void testFSNamesystemLockCompatibility() { - FSNamesystemLock rwLock = new FSNamesystemLock(new Configuration()); + FSNamesystemLock rwLock = new FSNamesystemLock(new Configuration(), null); assertEquals(0, rwLock.getReadHoldCount()); rwLock.readLock(); @@ -98,7 +104,7 @@ public class TestFSNamesystemLock { final CountDownLatch latch = new CountDownLatch(threadCount); final Configuration conf = new Configuration(); conf.setBoolean("dfs.namenode.fslock.fair", true); - final FSNamesystemLock rwLock = new FSNamesystemLock(conf); + final FSNamesystemLock rwLock = new FSNamesystemLock(conf, null); rwLock.writeLock(); ExecutorService helper = Executors.newFixedThreadPool(threadCount); @@ -141,7 +147,7 @@ public class TestFSNamesystemLock { writeLockSuppressWarningInterval, TimeUnit.MILLISECONDS); final FakeTimer timer = new FakeTimer(); - final FSNamesystemLock fsnLock = new FSNamesystemLock(conf, timer); + final FSNamesystemLock fsnLock = new FSNamesystemLock(conf, null, timer); timer.advance(writeLockSuppressWarningInterval); LogCapturer logs = LogCapturer.captureLogs(FSNamesystem.LOG); @@ -216,7 +222,7 @@ public class TestFSNamesystemLock { readLockSuppressWarningInterval, TimeUnit.MILLISECONDS); final FakeTimer timer = new FakeTimer(); - final FSNamesystemLock fsnLock = new FSNamesystemLock(conf, timer); + final FSNamesystemLock fsnLock = new FSNamesystemLock(conf, null, timer); timer.advance(readLockSuppressWarningInterval); LogCapturer logs = LogCapturer.captureLogs(FSNamesystem.LOG); @@ -303,7 +309,7 @@ public class TestFSNamesystemLock { t2.join(); // Look for the differentiating class names in the stack trace String stackTracePatternString = - String.format("INFO.+%s(.+\n){4}\\Q%%s\\E\\.run", readLockLogStmt); + String.format("INFO.+%s(.+\n){5}\\Q%%s\\E\\.run", readLockLogStmt); Pattern t1Pattern = Pattern.compile( String.format(stackTracePatternString, t1.getClass().getName())); assertTrue(t1Pattern.matcher(logs.getOutput()).find()); @@ -314,4 +320,43 @@ public class TestFSNamesystemLock { "Number of suppressed read-lock reports: 2")); } + @Test + public void testDetailedHoldMetrics() throws Exception { + Configuration conf = new Configuration(); + conf.setBoolean(DFSConfigKeys.DFS_NAMENODE_LOCK_DETAILED_METRICS_KEY, true); + FakeTimer timer = new FakeTimer(); + MetricsRegistry registry = new MetricsRegistry("Test"); + MutableRatesWithAggregation rates = + registry.newRatesWithAggregation("Test"); + FSNamesystemLock fsLock = new FSNamesystemLock(conf, rates, timer); + + fsLock.readLock(); + timer.advance(1); + fsLock.readUnlock("foo"); + fsLock.readLock(); + timer.advance(2); + fsLock.readUnlock("foo"); + + fsLock.readLock(); + timer.advance(1); + fsLock.readLock(); + timer.advance(1); + fsLock.readUnlock("bar"); + fsLock.readUnlock("bar"); + + fsLock.writeLock(); + timer.advance(1); + fsLock.writeUnlock("baz"); + + MetricsRecordBuilder rb = MetricsAsserts.mockMetricsRecordBuilder(); + rates.snapshot(rb, true); + + assertGauge("FSNReadLockFooAvgTime", 1.5, rb); + assertCounter("FSNReadLockFooNumOps", 2L, rb); + assertGauge("FSNReadLockBarAvgTime", 2.0, rb); + assertCounter("FSNReadLockBarNumOps", 1L, rb); + assertGauge("FSNWriteLockBazAvgTime", 1.0, rb); + assertCounter("FSNWriteLockBazNumOps", 1L, rb); + } + } \ No newline at end of file --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
