HADOOP-12825. Log slow name resolutions. (Sidharta Seethana via stevel)
Project: http://git-wip-us.apache.org/repos/asf/hadoop/repo Commit: http://git-wip-us.apache.org/repos/asf/hadoop/commit/03cfb454 Tree: http://git-wip-us.apache.org/repos/asf/hadoop/tree/03cfb454 Diff: http://git-wip-us.apache.org/repos/asf/hadoop/diff/03cfb454 Branch: refs/heads/HDFS-1312 Commit: 03cfb454fe5a1351e283e4678ad1b432ed231485 Parents: 798babf Author: Steve Loughran <[email protected]> Authored: Sat Feb 27 20:05:35 2016 +0000 Committer: Steve Loughran <[email protected]> Committed: Sat Feb 27 20:23:51 2016 +0000 ---------------------------------------------------------------------- hadoop-common-project/hadoop-common/CHANGES.txt | 3 ++ .../hadoop/fs/CommonConfigurationKeys.java | 14 ++++++- .../apache/hadoop/security/SecurityUtil.java | 42 +++++++++++++++++++- .../src/main/resources/core-default.xml | 18 +++++++++ 4 files changed, 74 insertions(+), 3 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/hadoop/blob/03cfb454/hadoop-common-project/hadoop-common/CHANGES.txt ---------------------------------------------------------------------- diff --git a/hadoop-common-project/hadoop-common/CHANGES.txt b/hadoop-common-project/hadoop-common/CHANGES.txt index 79cf4d5..b8ae8df 100644 --- a/hadoop-common-project/hadoop-common/CHANGES.txt +++ b/hadoop-common-project/hadoop-common/CHANGES.txt @@ -1160,6 +1160,9 @@ Release 2.8.0 - UNRELEASED HADOOP-12824. Collect network and disk usage on the node running Windows. (Inigo Goiri via xyao) + HADOOP-12825. Log slow name resolutions. + (Sidharta Seethana via stevel) + OPTIMIZATIONS HADOOP-11785. Reduce the number of listStatus operation in distcp http://git-wip-us.apache.org/repos/asf/hadoop/blob/03cfb454/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/CommonConfigurationKeys.java ---------------------------------------------------------------------- diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/CommonConfigurationKeys.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/CommonConfigurationKeys.java index d3ae6b1..9b4069a 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/CommonConfigurationKeys.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/CommonConfigurationKeys.java @@ -203,7 +203,19 @@ public class CommonConfigurationKeys extends CommonConfigurationKeysPublic { "hadoop.security.token.service.use_ip"; public static final boolean HADOOP_SECURITY_TOKEN_SERVICE_USE_IP_DEFAULT = true; - + + /** See <a href="{@docRoot}/../core-default.html">core-default.xml .</a> */ + public static final String HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_ENABLED_KEY = + "hadoop.security.dns.log-slow-lookups.enabled"; + public static final boolean + HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_ENABLED_DEFAULT = false; + /** See <a href="{@docRoot}/../core-default.html">core-default.xml .</a> */ + public static final String + HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_THRESHOLD_MS_KEY = + "hadoop.security.dns.log-slow-lookups.threshold.ms"; + public static final int + HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_THRESHOLD_MS_DEFAULT = 1000; + /** * HA health monitor and failover controller. */ http://git-wip-us.apache.org/repos/asf/hadoop/blob/03cfb454/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/security/SecurityUtil.java ---------------------------------------------------------------------- diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/security/SecurityUtil.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/security/SecurityUtil.java index 38096ab..61cd516 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/security/SecurityUtil.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/security/SecurityUtil.java @@ -30,6 +30,7 @@ import java.security.PrivilegedExceptionAction; import java.util.Arrays; import java.util.List; import java.util.ServiceLoader; +import java.util.concurrent.TimeUnit; import javax.annotation.Nullable; import javax.security.auth.kerberos.KerberosPrincipal; @@ -47,6 +48,7 @@ import org.apache.hadoop.net.NetUtils; import org.apache.hadoop.security.UserGroupInformation.AuthenticationMethod; import org.apache.hadoop.security.token.Token; import org.apache.hadoop.security.token.TokenInfo; +import org.apache.hadoop.util.StopWatch; import org.apache.hadoop.util.StringUtils; @@ -79,6 +81,9 @@ public class SecurityUtil { setTokenServiceUseIp(useIp); } + private static boolean logSlowLookups = getLogSlowLookupsEnabled(); + private static int slowLookupThresholdMs = getSlowLookupThresholdMs(); + /** * For use only by tests and initialization */ @@ -480,9 +485,27 @@ public class SecurityUtil { } } + private static boolean getLogSlowLookupsEnabled() { + Configuration conf = new Configuration(); + + return conf.getBoolean(CommonConfigurationKeys + .HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_ENABLED_KEY, + CommonConfigurationKeys + .HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_ENABLED_DEFAULT); + } + + private static int getSlowLookupThresholdMs() { + Configuration conf = new Configuration(); + + return conf.getInt(CommonConfigurationKeys + .HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_THRESHOLD_MS_KEY, + CommonConfigurationKeys + .HADOOP_SECURITY_DNS_LOG_SLOW_LOOKUPS_THRESHOLD_MS_DEFAULT); + } + /** * Resolves a host subject to the security requirements determined by - * hadoop.security.token.service.use_ip. + * hadoop.security.token.service.use_ip. Optionally logs slow resolutions. * * @param hostname host or ip to resolve * @return a resolved host @@ -491,7 +514,22 @@ public class SecurityUtil { @InterfaceAudience.Private public static InetAddress getByName(String hostname) throws UnknownHostException { - return hostResolver.getByName(hostname); + if (logSlowLookups || LOG.isTraceEnabled()) { + StopWatch lookupTimer = new StopWatch().start(); + InetAddress result = hostResolver.getByName(hostname); + long elapsedMs = lookupTimer.stop().now(TimeUnit.MILLISECONDS); + + if (elapsedMs >= slowLookupThresholdMs) { + LOG.warn("Slow name lookup for " + hostname + ". Took " + elapsedMs + + " ms."); + } else if (LOG.isTraceEnabled()) { + LOG.trace("Name lookup for " + hostname + " took " + elapsedMs + + " ms."); + } + return result; + } else { + return hostResolver.getByName(hostname); + } } interface HostResolver { http://git-wip-us.apache.org/repos/asf/hadoop/blob/03cfb454/hadoop-common-project/hadoop-common/src/main/resources/core-default.xml ---------------------------------------------------------------------- diff --git a/hadoop-common-project/hadoop-common/src/main/resources/core-default.xml b/hadoop-common-project/hadoop-common/src/main/resources/core-default.xml index 95140bf..57f5274 100644 --- a/hadoop-common-project/hadoop-common/src/main/resources/core-default.xml +++ b/hadoop-common-project/hadoop-common/src/main/resources/core-default.xml @@ -113,6 +113,24 @@ </description> </property> +<property> + <name>hadoop.security.dns.log-slow-lookups.enabled</name> + <value>false</value> + <description> + Time name lookups (via SecurityUtil) and log them if they exceed the + configured threshold. + </description> +</property> + +<property> + <name>hadoop.security.dns.log-slow-lookups.threshold.ms</name> + <value>1000</value> + <description> + If slow lookup logging is enabled, this threshold is used to decide if a + lookup is considered slow enough to be logged. + </description> +</property> + <!-- === Multiple group mapping providers configuration sample === This sample illustrates a typical use case for CompositeGroupsMapping where
