From 03cfb454fe5a1351e283e4678ad1b432ed231485 Mon Sep 17 00:00:00 2001 From: Steve Loughran Date: Sat, 27 Feb 2016 20:05:35 +0000 Subject: [PATCH] HADOOP-12825. Log slow name resolutions. (Sidharta Seethana via stevel) --- .../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(-) diff --git a/hadoop-common-project/hadoop-common/CHANGES.txt b/hadoop-common-project/hadoop-common/CHANGES.txt index 79cf4d56e4c..b8ae8dff094 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 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 d3ae6b1c4c7..9b4069a422a 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 core-default.xml . */ + 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 core-default.xml . */ + 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. */ 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 38096ab4715..61cd516fef6 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 { 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 95140bfc33e..57f527401aa 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 @@ + + hadoop.security.dns.log-slow-lookups.enabled + false + + Time name lookups (via SecurityUtil) and log them if they exceed the + configured threshold. + + + + + hadoop.security.dns.log-slow-lookups.threshold.ms + 1000 + + If slow lookup logging is enabled, this threshold is used to decide if a + lookup is considered slow enough to be logged. + + +