org.apache.hadoop.hive.common.JvmPauseMonitor Maven / Gradle / Ivy
/**
* Licensed to the Apache Software Foundation (ASF) under one
* or more contributor license agreements. See the NOTICE file
* distributed with this work for additional information
* regarding copyright ownership. The ASF licenses this file
* to you under the Apache License, Version 2.0 (the
* "License"); you may not use this file except in compliance
* with the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.apache.hadoop.hive.common;
import com.google.common.base.Joiner;
import com.google.common.base.Preconditions;
import com.google.common.base.Stopwatch;
import com.google.common.collect.Lists;
import com.google.common.collect.Maps;
import com.google.common.collect.Sets;
import org.apache.hadoop.conf.Configuration;
import org.apache.hadoop.hive.common.metrics.common.Metrics;
import org.apache.hadoop.hive.common.metrics.common.MetricsConstant;
import org.apache.hadoop.hive.common.metrics.common.MetricsFactory;
import org.apache.hadoop.util.Daemon;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.lang.management.GarbageCollectorMXBean;
import java.lang.management.ManagementFactory;
import java.util.List;
import java.util.Map;
import java.util.Set;
/**
* Based on the JvmPauseMonitor from Hadoop.
*/
public class JvmPauseMonitor {
private static final Logger LOG = LoggerFactory.getLogger(
JvmPauseMonitor.class);
/** The target sleep time */
private static final long SLEEP_INTERVAL_MS = 500;
/** log WARN if we detect a pause longer than this threshold */
private final long warnThresholdMs;
private static final String WARN_THRESHOLD_KEY =
"jvm.pause.warn-threshold.ms";
private static final long WARN_THRESHOLD_DEFAULT = 10000;
/** log INFO if we detect a pause longer than this threshold */
private final long infoThresholdMs;
private static final String INFO_THRESHOLD_KEY =
"jvm.pause.info-threshold.ms";
private static final long INFO_THRESHOLD_DEFAULT = 1000;
private long numGcWarnThresholdExceeded = 0;
private long numGcInfoThresholdExceeded = 0;
private long totalGcExtraSleepTime = 0;
private Thread monitorThread;
private volatile boolean shouldRun = true;
public JvmPauseMonitor(Configuration conf) {
this.warnThresholdMs = conf.getLong(WARN_THRESHOLD_KEY, WARN_THRESHOLD_DEFAULT);
this.infoThresholdMs = conf.getLong(INFO_THRESHOLD_KEY, INFO_THRESHOLD_DEFAULT);
}
public void start() {
Preconditions.checkState(monitorThread == null,
"JvmPauseMonitor thread is Already started");
monitorThread = new Daemon(new Monitor());
monitorThread.start();
}
public void stop() {
shouldRun = false;
if (isStarted()) {
monitorThread.interrupt();
try {
monitorThread.join();
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
}
}
}
public boolean isStarted() {
return monitorThread != null;
}
public long getNumGcWarnThreadholdExceeded() {
return numGcWarnThresholdExceeded;
}
public long getNumGcInfoThresholdExceeded() {
return numGcInfoThresholdExceeded;
}
public long getTotalGcExtraSleepTime() {
return totalGcExtraSleepTime;
}
private String formatMessage(long extraSleepTime,
Map gcTimesAfterSleep,
Map gcTimesBeforeSleep) {
Set gcBeanNames = Sets.intersection(
gcTimesAfterSleep.keySet(),
gcTimesBeforeSleep.keySet());
List gcDiffs = Lists.newArrayList();
for (String name : gcBeanNames) {
GcTimes diff = gcTimesAfterSleep.get(name).subtract(
gcTimesBeforeSleep.get(name));
if (diff.gcCount != 0) {
gcDiffs.add("GC pool '" + name + "' had collection(s): " +
diff.toString());
}
}
String ret = "Detected pause in JVM or host machine (eg GC): " +
"pause of approximately " + extraSleepTime + "ms\n";
if (gcDiffs.isEmpty()) {
ret += "No GCs detected";
} else {
ret += Joiner.on("\n").join(gcDiffs);
}
return ret;
}
private Map getGcTimes() {
Map map = Maps.newHashMap();
List gcBeans =
ManagementFactory.getGarbageCollectorMXBeans();
for (GarbageCollectorMXBean gcBean : gcBeans) {
map.put(gcBean.getName(), new GcTimes(gcBean));
}
return map;
}
private static class GcTimes {
private GcTimes(GarbageCollectorMXBean gcBean) {
gcCount = gcBean.getCollectionCount();
gcTimeMillis = gcBean.getCollectionTime();
}
private GcTimes(long count, long time) {
this.gcCount = count;
this.gcTimeMillis = time;
}
private GcTimes subtract(GcTimes other) {
return new GcTimes(this.gcCount - other.gcCount,
this.gcTimeMillis - other.gcTimeMillis);
}
@Override
public String toString() {
return "count=" + gcCount + " time=" + gcTimeMillis + "ms";
}
private final long gcCount;
private final long gcTimeMillis;
}
private class Monitor implements Runnable {
@Override
public void run() {
Stopwatch sw = new Stopwatch();
Map gcTimesBeforeSleep = getGcTimes();
while (shouldRun) {
sw.reset().start();
try {
Thread.sleep(SLEEP_INTERVAL_MS);
} catch (InterruptedException ie) {
return;
}
long extraSleepTime = sw.elapsedMillis() - SLEEP_INTERVAL_MS;
Map gcTimesAfterSleep = getGcTimes();
if (extraSleepTime > warnThresholdMs) {
++numGcWarnThresholdExceeded;
LOG.warn(formatMessage(
extraSleepTime, gcTimesAfterSleep, gcTimesBeforeSleep));
incrementMetricsCounter(MetricsConstant.JVM_PAUSE_WARN, 1);
} else if (extraSleepTime > infoThresholdMs) {
++numGcInfoThresholdExceeded;
LOG.info(formatMessage(
extraSleepTime, gcTimesAfterSleep, gcTimesBeforeSleep));
incrementMetricsCounter(MetricsConstant.JVM_PAUSE_INFO, 1);
}
incrementMetricsCounter(MetricsConstant.JVM_EXTRA_SLEEP, extraSleepTime);
totalGcExtraSleepTime += extraSleepTime;
gcTimesBeforeSleep = gcTimesAfterSleep;
}
}
private void incrementMetricsCounter(String name, long count) {
Metrics metrics = MetricsFactory.getInstance();
if (metrics != null) {
try {
metrics.incrementCounter(name, count);
} catch (Exception e) {
LOG.warn("Error Reporting JvmPauseMonitor to Metrics system", e);
}
}
}
}
/**
* Simple 'main' to facilitate manual testing of the pause monitor.
*
* This main function just leaks memory into a list. Running this class
* with a 1GB heap will very quickly go into "GC hell" and result in
* log messages about the GC pauses.
*/
public static void main(String []args) throws Exception {
new JvmPauseMonitor(new Configuration()).start();
List list = Lists.newArrayList();
int i = 0;
while (true) {
list.add(String.valueOf(i++));
}
}
}