ThreadCpuStats.java
/**
* Copyright 2013 Netflix, Inc.
* <p/>
* Licensed 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
* <p/>
* http://www.apache.org/licenses/LICENSE-2.0
* <p/>
* 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 com.netflix.servo.util;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.io.OutputStream;
import java.io.OutputStreamWriter;
import java.io.PrintWriter;
import java.io.UnsupportedEncodingException;
import java.lang.management.ManagementFactory;
import java.lang.management.OperatingSystemMXBean;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collections;
import java.util.Comparator;
import java.util.Date;
import java.util.HashMap;
import java.util.Iterator;
import java.util.List;
import java.util.Map;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.atomic.AtomicLong;
import java.util.concurrent.atomic.AtomicLongArray;
/**
* Keep track of the cpu usage for threads in the jvm.
*/
public final class ThreadCpuStats {
private static final Logger LOGGER = LoggerFactory.getLogger(ThreadCpuStats.class);
private static final ThreadCpuStats INSTANCE = new ThreadCpuStats();
private static final long ONE_MINUTE_NANOS = TimeUnit.NANOSECONDS.convert(1, TimeUnit.MINUTES);
private static final long FIVE_MINUTE_NANOS = 5 * ONE_MINUTE_NANOS;
private static final long FIFTEEN_MINUTE_NANOS = 15 * ONE_MINUTE_NANOS;
/**
* Constant representing one minute.
*/
public static final String ONE_MIN = "one_min";
/**
* Constant representing five minutes.
*/
public static final String FIVE_MIN = "five_min";
/**
* Constant representing fifteen minutes.
*/
public static final String FIFTEEN_MIN = "fifteen_min";
/**
* Constant representing the overall time.
*/
public static final String OVERALL = "overall";
/**
* Current time in milliseconds.
*/
public static final String CURRENT_TIME = "time_ms";
/**
* uptime in milliseconds.
*/
public static final String UPTIME_MS = "uptime_ms";
/**
* JVM usage time in nanoseconds.
*/
public static final String JVM_USAGE_TIME = "jvm_usage_time_ns";
/**
* JVM usage as a percentage.
*/
public static final String JVM_USAGE_PERCENT = "jvm_usage_percent";
/**
* Thread ID.
*/
public static final String ID = "id";
/**
* Thread name.
*/
public static final String NAME = "name";
/**
* Threads.
*/
public static final String THREADS = "threads";
private volatile boolean running = false;
private final CpuUsage jvmCpuUsage = new CpuUsage(-1, "jvm");
private final Map<Long, CpuUsage> threadCpuUsages = new ConcurrentHashMap<>();
/**
* Return the singleton instance.
*/
public static ThreadCpuStats getInstance() {
return INSTANCE;
}
/**
* Creates a new instance.
*/
private ThreadCpuStats() {
}
/**
* Returns true if cpu status are currently being collected.
*/
public boolean isRunning() {
return false;
}
/**
* Start collecting cpu stats for the threads.
*/
public synchronized void start() {
if (!running) {
running = true;
Thread t = new Thread(new CpuStatRunnable(), "ThreadCpuStatsCollector");
t.setDaemon(true);
t.start();
}
}
/**
* Stop collecting cpu stats for the threads.
*/
public void stop() {
running = false;
}
/**
* Overall usage for the jvm.
*/
public CpuUsage getOverallCpuUsage() {
return jvmCpuUsage;
}
/**
* List of cpu usages for each thread.
*/
public List<CpuUsage> getThreadCpuUsages() {
return new ArrayList<>(threadCpuUsages.values());
}
/**
* Helper function for computing percentage.
*/
public static double toPercent(long value, long total) {
return (total > 0) ? 100.0 * value / total : 0.0;
}
private static long append(StringBuilder buf, char label, long unit, long time) {
if (time > unit) {
long multiple = time / unit;
buf.append(multiple).append(label);
return time % unit;
} else {
return time;
}
}
/**
* Convert time in nanoseconds to a duration string. This is used to provide a more human
* readable order of magnitude for the duration. We assume standard fixed size quantities for
* all units.
*/
public static String toDuration(long inputTime) {
final long second = 1000000000L;
final long minute = 60 * second;
final long hour = 60 * minute;
final long day = 24 * hour;
final long week = 7 * day;
long time = inputTime;
final StringBuilder buf = new StringBuilder();
buf.append('P');
time = append(buf, 'W', week, time);
time = append(buf, 'D', day, time);
buf.append('T');
time = append(buf, 'H', hour, time);
time = append(buf, 'M', minute, time);
append(buf, 'S', second, time);
return buf.toString();
}
/**
* Utility function that dumps the cpu usages for the threads to stdout. Output will be sorted
* based on the 1-minute usage from highest to lowest.
*/
public void printThreadCpuUsages() {
printThreadCpuUsages(System.out, CpuUsageComparator.ONE_MINUTE);
}
private static PrintWriter getPrintWriter(OutputStream out) {
try {
return new PrintWriter(new OutputStreamWriter(out, "UTF-8"), true);
} catch (UnsupportedEncodingException e) {
// should never happen
throw Throwables.propagate(e);
}
}
/**
* Utility function that returns a Map containing cpu usages for threads. Output will be sorted
* based on the {@link CpuUsageComparator} passed.
*
* @param cmp order to use for the results
*/
public Map<String, Object> getThreadCpuUsages(CpuUsageComparator cmp) {
final CpuUsage overall = getOverallCpuUsage();
final List<CpuUsage> usages = getThreadCpuUsages();
final Map<String, Object> result = new HashMap<>();
Collections.sort(usages, cmp);
final Date now = new Date();
result.put(CURRENT_TIME, now.getTime());
final long uptimeMillis = ManagementFactory.getRuntimeMXBean().getUptime();
final long uptimeNanos = TimeUnit.NANOSECONDS.convert(uptimeMillis, TimeUnit.MILLISECONDS);
result.put(UPTIME_MS, uptimeMillis);
final Map<String, Long> jvmUsageTime = new HashMap<>();
jvmUsageTime.put(ONE_MIN, overall.getOneMinute());
jvmUsageTime.put(FIVE_MIN, overall.getFiveMinute());
jvmUsageTime.put(FIFTEEN_MIN, overall.getFifteenMinute());
jvmUsageTime.put(OVERALL, overall.getOverall());
result.put(JVM_USAGE_TIME, jvmUsageTime);
final Map<String, Double> jvmUsagePercent = new HashMap<>();
final int numProcs = Runtime.getRuntime().availableProcessors();
jvmUsagePercent.put(ONE_MIN, toPercent(overall.getOneMinute(),
ONE_MINUTE_NANOS * numProcs));
jvmUsagePercent.put(FIVE_MIN, toPercent(overall.getFiveMinute(),
FIVE_MINUTE_NANOS * numProcs));
jvmUsagePercent.put(FIFTEEN_MIN, toPercent(overall.getFifteenMinute(),
FIFTEEN_MINUTE_NANOS * numProcs));
jvmUsagePercent.put(OVERALL, toPercent(overall.getOverall(), uptimeNanos * numProcs));
result.put(JVM_USAGE_PERCENT, jvmUsagePercent);
List<Map<String, Object>> threads = new ArrayList<>();
for (CpuUsage usage : usages) {
Map<String, Object> threadInfo = new HashMap<>();
threadInfo.put(ONE_MIN, toPercent(usage.getOneMinute(), overall.getOneMinute()));
threadInfo.put(FIVE_MIN, toPercent(usage.getFiveMinute(), overall.getFiveMinute()));
threadInfo.put(FIFTEEN_MIN, toPercent(usage.getFifteenMinute(),
overall.getFifteenMinute()));
threadInfo.put(OVERALL, toPercent(usage.getOverall(), overall.getOverall()));
threadInfo.put(ID, usage.getThreadId());
threadInfo.put(NAME, usage.getName());
threads.add(threadInfo);
}
result.put(THREADS, threads);
return result;
}
/**
* Utility function that dumps the cpu usages for the threads to stdout. Output will be sorted
* based on the 1-minute usage from highest to lowest.
*
* @param out stream where output will be written
* @param cmp order to use for the results
*/
public void printThreadCpuUsages(OutputStream out, CpuUsageComparator cmp) {
final PrintWriter writer = getPrintWriter(out);
final Map<String, Object> threadCpuUsages = getThreadCpuUsages(cmp);
writer.printf("Time: %s%n%n", new Date((Long) threadCpuUsages.get(CURRENT_TIME)));
final long uptimeMillis = (Long) threadCpuUsages.get(UPTIME_MS);
final long uptimeNanos = TimeUnit.NANOSECONDS.convert(uptimeMillis, TimeUnit.MILLISECONDS);
writer.printf("Uptime: %s%n%n", toDuration(uptimeNanos));
@SuppressWarnings("unchecked")
final Map<String, Long> jvmUsageTime = (Map<String, Long>)
threadCpuUsages.get(JVM_USAGE_TIME);
writer.println("JVM Usage Time: ");
writer.printf("%11s %11s %11s %11s %7s %s%n",
"1-min", "5-min", "15-min", "overall", "id", "name");
writer.printf("%11s %11s %11s %11s %7s %s%n",
toDuration(jvmUsageTime.get(ONE_MIN)),
toDuration(jvmUsageTime.get(FIVE_MIN)),
toDuration(jvmUsageTime.get(FIFTEEN_MIN)),
toDuration(jvmUsageTime.get(OVERALL)),
"-",
"jvm");
writer.println();
@SuppressWarnings("unchecked")
final Map<String, Double> jvmUsagePerc =
(Map<String, Double>) threadCpuUsages.get(JVM_USAGE_PERCENT);
writer.println("JVM Usage Percent: ");
writer.printf("%11s %11s %11s %11s %7s %s%n",
"1-min", "5-min", "15-min", "overall", "id", "name");
writer.printf("%10.2f%% %10.2f%% %10.2f%% %10.2f%% %7s %s%n",
jvmUsagePerc.get(ONE_MIN),
jvmUsagePerc.get(FIVE_MIN),
jvmUsagePerc.get(FIFTEEN_MIN),
jvmUsagePerc.get(OVERALL),
"-",
"jvm");
writer.println();
writer.println("Breakdown by thread (100% = total cpu usage for jvm):");
writer.printf("%11s %11s %11s %11s %7s %s%n",
"1-min", "5-min", "15-min", "overall", "id", "name");
@SuppressWarnings("unchecked")
List<Map<String, Object>> threads =
(List<Map<String, Object>>) threadCpuUsages.get(THREADS);
for (Map<String, Object> thread : threads) {
writer.printf("%10.2f%% %10.2f%% %10.2f%% %10.2f%% %7d %s%n",
thread.get(ONE_MIN),
thread.get(FIVE_MIN),
thread.get(FIFTEEN_MIN),
thread.get(OVERALL),
thread.get(ID),
thread.get(NAME));
}
writer.println();
writer.flush();
}
/**
* Remove entries if the last update time is over this value.
*/
private static final long AGE_LIMIT = 15 * 60 * 1000;
/**
* Update the stats for all threads and the jvm.
*/
private void updateStats() {
final ThreadMXBean bean = ManagementFactory.getThreadMXBean();
if (bean.isThreadCpuTimeEnabled()) {
// Update stats for all current threads
final long[] ids = bean.getAllThreadIds();
Arrays.sort(ids);
long totalCpuTime = 0L;
for (long id : ids) {
long cpuTime = bean.getThreadCpuTime(id);
if (cpuTime != -1) {
totalCpuTime += cpuTime;
CpuUsage usage = threadCpuUsages.get(id);
if (usage == null) {
final ThreadInfo info = bean.getThreadInfo(id);
usage = new CpuUsage(id, info.getThreadName());
threadCpuUsages.put(id, usage);
}
usage.update(cpuTime);
}
}
// Update jvm cpu usage, if possible we query the operating system mxbean so we get
// an accurate total including any threads that may have been started and stopped
// between sampling. As a fallback we use the sum of the cpu time for all threads found
// in this interval.
//
// Total cpu time can be found in:
// http://docs.oracle.com/javase/7/docs/jre/api/management/extension/\
// com/sun/management/OperatingSystemMXBean.html
//
// We use reflection to avoid direct dependency on com.sun.* classes.
final OperatingSystemMXBean osBean = ManagementFactory.getOperatingSystemMXBean();
try {
final Method m = osBean.getClass().getMethod("getProcessCpuTime");
final long jvmCpuTime = (Long) m.invoke(osBean);
jvmCpuUsage.update((jvmCpuTime < 0) ? totalCpuTime : jvmCpuTime);
} catch (NoSuchMethodException | IllegalAccessException | InvocationTargetException e) {
jvmCpuUsage.update(totalCpuTime);
}
// Handle ids in the map that no longer exist:
// * Remove old entries if the last update time is over AGE_LIMIT
// * Otherwise, update usage so rolling window is correct
final long now = System.currentTimeMillis();
final Iterator<Map.Entry<Long, CpuUsage>> iter = threadCpuUsages.entrySet().iterator();
while (iter.hasNext()) {
final Map.Entry<Long, CpuUsage> entry = iter.next();
final long id = entry.getKey();
final CpuUsage usage = entry.getValue();
if (now - usage.getLastUpdateTime() > AGE_LIMIT) {
iter.remove();
} else if (Arrays.binarySearch(ids, id) < 0) {
usage.updateNoValue();
}
}
} else {
LOGGER.debug("ThreadMXBean.isThreadCpuTimeEnabled() == false, cannot collect stats");
}
}
/**
* Update the stats for threads each minute.
*/
private class CpuStatRunnable implements Runnable {
public void run() {
final long step = 60000L;
final long maxUpdateTime = step / 6;
while (running) {
try {
long start = System.currentTimeMillis();
updateStats();
long elapsed = System.currentTimeMillis() - start;
if (elapsed > maxUpdateTime) {
LOGGER.warn("update stats is slow, took {} milliseconds", elapsed);
}
long delay = step - elapsed;
Thread.sleep((delay < 1000L) ? step : delay);
} catch (Exception e) {
LOGGER.warn("failed to update thread stats", e);
}
}
}
}
/**
* Keeps track of the cpu usage for a single thread.
*/
public static final class CpuUsage {
private static final int BUFFER_SIZE = 16;
private final long id;
private final String name;
private final AtomicLong lastUpdateTime = new AtomicLong(0L);
private final AtomicInteger nextPos = new AtomicInteger(0);
/**
* Cumulative cpu times for the different intervals.
*/
private final AtomicLongArray totals = new AtomicLongArray(BUFFER_SIZE);
private CpuUsage(long id, String name) {
this.id = id;
this.name = name;
}
/**
* The thread id that is being tracked. If the id is less than 0 it is for the jvm process
* rather than a single thread.
*/
public long getThreadId() {
return id;
}
/**
* Name of the thread.
*/
public String getName() {
return name;
}
/**
* Last time the stats for this object were updated.
*/
public long getLastUpdateTime() {
return lastUpdateTime.get();
}
/**
* Returns the overall usage for the lifetime of the thread.
*/
public long getOverall() {
final int currentPos = toIndex(nextPos.get() - 1);
return totals.get(currentPos);
}
/**
* Returns the usage for the last one minute.
*/
public long getOneMinute() {
return get(1);
}
/**
* Returns the usage for the last five minutes.
*/
public long getFiveMinute() {
return get(5);
}
/**
* Returns the usage for the last fifteen minutes.
*/
public long getFifteenMinute() {
return get(15);
}
private int toIndex(int v) {
return ((v < 0) ? v + BUFFER_SIZE : v) % BUFFER_SIZE;
}
private long get(int n) {
final int currentPos = toIndex(nextPos.get() - 1);
final int startPos = toIndex(currentPos - n);
final long currentValue = totals.get(currentPos);
final long startValue = totals.get(startPos);
final long diff = currentValue - startValue;
return (diff < 0L) ? 0L : diff;
}
private void update(long threadTotal) {
totals.set(toIndex(nextPos.getAndIncrement()), threadTotal);
lastUpdateTime.set(System.currentTimeMillis());
}
/**
* Called if the thread no longer exists. The totals are cumulative so we copy the last
* previously captured value.
*/
private void updateNoValue() {
final int currentPos = toIndex(nextPos.get() - 1);
totals.set(toIndex(nextPos.getAndIncrement()), totals.get(currentPos));
}
}
/**
* Comparator for sorting cpu usage based on one of the columns.
*/
public enum CpuUsageComparator implements Comparator<CpuUsage> {
/**
* Sort based on 1-minute usage column.
*/
ONE_MINUTE(0),
/**
* Sort based on 5-minute usage column.
*/
FIVE_MINUTE(1),
/**
* Sort based on 15-minute usage column.
*/
FIFTEEN_MINUTE(2),
/**
* Sort based on overall usage column.
*/
OVERALL(3);
private final int col;
CpuUsageComparator(int col) {
this.col = col;
}
/**
* {@inheritDoc}
*/
public int compare(CpuUsage u1, CpuUsage u2) {
long cmp;
switch (col) {
case 0:
cmp = u2.getOneMinute() - u1.getOneMinute();
break;
case 1:
cmp = u2.getFiveMinute() - u1.getFiveMinute();
break;
case 2:
cmp = u2.getFifteenMinute() - u1.getFifteenMinute();
break;
default:
cmp = u2.getOverall() - u1.getOverall();
break;
}
return (cmp < 0) ? -1 : ((cmp > 0) ? 1 : 0);
}
}
}