机器情况
启动参数 : -Xms4700m -Xmx4700m
简单监控图
jstack 分析
fastthread.io 分析
有较多未命名的线程. 但项目中搜了使用线程的地方都加了命名
OOM KILLER 日志
grep "Out of memory" /var/log/messages
ps -A -ostat,ppid,pid,cmd | grep -e '^[Zz]' 查看僵尸进程 -> 无
arthas -> vmtool --action forceGc 强制full gc, 并不能减少进程的内存占用
目前线上未开启 VM.native_memory
初步诊断
应用存在大量的 ThreadPoolExecutor 以及派生类对象生成,可能的情
- 预初始化(启动)核心(core)线程(数量:1),并且没有任务来执行
- 已经执行过一次任务,再也没有新任务执行
- 可能造成的原因:
- ThreadPoolExecutor 由于某种缓存机制失效,导致了 computeIfAbsent
- ThreadPoolExecutor 没有合理 Shutdown,比如在方法内部创建 ThreadPoolExecutor,示例代码如下:
- ThreadPoolExecutor 由于某种缓存机制失效,导致了 computeIfAbsent
- 可能造成的原因:
public void sum() {
ThreadPoolExecutor executor = Executors.newFixedThreadPool(1);
for(int i=0;i<10;i++){
executor.submit(...);
}
// core thread 一直在执行,不过没有任务罢了,当下 Keep-Live = 0 ,永久等待
// core thread Thread.State == Thread.State.WAITING
// core thread 是否是 ThreadPoolExecutor 成员
// ThreadPoolExecutor -> workers(HashSet<Worker>) -> Worker -> Thread
// executor.shutdown();
}
后续观测现象
每30分钟有一段线程凸起, 并且大致看下来有残留 , 可能就是上文创建过多单个线程池的原因?
看了下30分钟定时任务 , 执行的任务列表
1 有部分临时线程池没有shutdown
定时任务里确实 存在部分临时创建的线程池没有shutdown, 导致一直waiting
2 client 没单例
定时任务里 发现其中有的定时任务使用 okHttpClient , 但根据经验来看, 每个请求创建一个client存在一定问题
但不是原因 , 发布后 waiting线程数依旧很多
3 机器是双核导致部分问题
发现有 completeableFuture 没有使用自定义线程池, 同时机器是2核8G 实质并没有用到 默认commonPool
内部使用completeableFuture的方法会导致没有复用pool , 每次创建了新线程
真正原因
排查方法
持续监控未命名线程池的活动, 保存runnable时候的堆栈, 在waiting较久时打印出来
/**
* 2秒打一次
*/
@SneakyThrows
@Scheduled(cron = "0/2 * * * * ?")
public void localMetricPrintSchedule() {
jvmObserve();
}
private static Map<Long, ThreadInfoStore> runStatsMap = new WeakHashMap<>();
@Data
public static class ThreadInfoStore {
private Long threadId;
private String threadName;
private List<String> runPrintStackTraces = Lists.newArrayList();
private int waitingCheckCount = 0;
public boolean printEnabled() {
return this.waitingCheckCount == 100;
}
String formatTraceToString(StackTraceElement[] stackTrace) {
StringBuilder sb = new StringBuilder();
for (int i = 0; i < stackTrace.length; i++) {
StackTraceElement element = stackTrace[i];
sb.append(element.toString()).append("\n");
}
return sb.toString();
}
public void pushPrintStackTrace(StackTraceElement[] stackTrace) {
if (stackTrace.length == 0) {
return;
}
if (runPrintStackTraces == null) {
runPrintStackTraces = new ArrayList<>();
}
//保存3次run堆栈, 超过3次, 将最后一次作为第三次
if (runPrintStackTraces.size() == 0 || runPrintStackTraces.size() == 1 || runPrintStackTraces.size() == 2) {
runPrintStackTraces.add(formatTraceToString(stackTrace));
} else {
runPrintStackTraces.remove(runPrintStackTraces.size() - 1);
runPrintStackTraces.add(formatTraceToString(stackTrace));
}
}
}
/**
* 当线程从 run -> waiting 并且一直waiting的时候, 打印出堆栈
*
* 注意点 :
* 针对的是 未命名线程
* 临时的线程要过滤, 防止内存泄露
*/
public static void jvmObserve() {
ThreadMXBean tmx = ManagementFactory.getThreadMXBean();
long[] allThreadIds = tmx.getAllThreadIds();
ThreadInfo[] allThreadInfo = tmx.getThreadInfo(allThreadIds);
List<ThreadInfo> noNameThreadInfoList = Lists.newArrayList();
for (ThreadInfo threadInfo : allThreadInfo) {
String threadName = threadInfo.getThreadName();
//针对目前发现的多pool 单core线程池过多过滤
if (threadName.startsWith("pool-")
&& threadName.endsWith("-1")) {
noNameThreadInfoList.add(threadInfo);
}
}
//当线程从 run -> waiting 并且一直waiting的时候, 打印出堆栈
for (ThreadInfo threadInfo : noNameThreadInfoList) {
threadInfo = tmx.getThreadInfo(threadInfo.getThreadId(), 10);
long threadId = threadInfo.getThreadId();
String threadName = threadInfo.getThreadName();
ThreadInfoStore threadInfoStore = new ThreadInfoStore();
threadInfoStore.setThreadId(threadId);
threadInfoStore.setThreadName(threadName);
if (threadInfo.getThreadState() == Thread.State.RUNNABLE) {
//只记录runnable的几次堆栈
ThreadInfoStore runThreadInfoStore = runStatsMap.get(threadId);
if (null == runThreadInfoStore) {
threadInfoStore.pushPrintStackTrace(threadInfo.getStackTrace());
runStatsMap.put(threadId, threadInfoStore);
} else {
runThreadInfoStore.pushPrintStackTrace(threadInfo.getStackTrace());
runThreadInfoStore.setWaitingCheckCount(0);
}
} else if (threadInfo.getThreadState() == Thread.State.WAITING) {
ThreadInfoStore runThreadInfoStore = runStatsMap.get(threadId);
if (runThreadInfoStore == null) {
continue;
}
runThreadInfoStore.waitingCheckCount++;
//清除感觉已经死了的线程 , 105次判断
if (runThreadInfoStore.waitingCheckCount > 105) {
runStatsMap.remove(threadId);
}
}
}
//清理不存在的线程
Set<Long> existThreadIds = noNameThreadInfoList.stream().map(ThreadInfo::getThreadId).collect(Collectors.toSet());
for (Long threadId : runStatsMap.keySet()) {
if (!existThreadIds.contains(threadId)) {
runStatsMap.remove(threadId);
}
}
if (noPrintEnableThreads(runStatsMap)) {
return;
}
//打印一下 waiting次数达到100次的线程run堆栈
StringBuilder stringBuilder = new StringBuilder();
stringBuilder
.append("jvm waiting线程观测").append("\n")
.append("allThreadIds: ").append(allThreadIds.length).append("\n")
.append("noNameThreadCount: ").append(noNameThreadInfoList.size()).append("\n")
;
for (Map.Entry<Long, ThreadInfoStore> entry : runStatsMap.entrySet()) {
if (entry.getValue().printEnabled()) {
stringBuilder.append("====较久waiting线程堆栈打印====").append("\n");
stringBuilder
.append("waiting线程name: ").append(entry.getValue().getThreadName()).append("\n");
List<String> runPrintStackTraces = entry.getValue().getRunPrintStackTraces();
for (int i = 0; i < runPrintStackTraces.size(); i++) {
String stackTrace = runPrintStackTraces.get(i);
stringBuilder.append(">>>> waiting线程runStackTrace[").append(i).append("]: ").append("\n")
.append(stackTrace).append("\n");
}
}
}
BizLogUtil.info(log, stringBuilder.toString());
}
private static boolean noPrintEnableThreads(Map<Long, ThreadInfoStore> runStatsMap) {
if (runStatsMap.isEmpty()) {
return true;
}
for (Map.Entry<Long, ThreadInfoStore> entry : runStatsMap.entrySet()) {
if (entry.getValue().printEnabled()) {
return false;
}
}
return true;
}
观察现象
jvm waiting线程观测
allThreadIds: 1118
noNameThreadCount: 517
====较久waiting线程堆栈打印====
waiting线程name: pool-572-thread-1
>>>> waiting线程runStackTrace[0]:
java.net.PlainSocketImpl.socketConnect(Native Method)
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:476)
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:218)
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:200)
java.net.SocksSocketImpl.connect(SocksSocketImpl.java:394)
java.net.Socket.connect(Socket.java:606)
org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)
com.amazonaws.http.conn.ssl.SdkTLSSocketFactory.connectSocket(SdkTLSSocketFactory.java:142)
org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
sun.reflect.GeneratedMethodAccessor549.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:498)
com.amazonaws.http.conn.ClientConnectionManagerFactory$Handler.invoke(ClientConnectionManagerFactory.java:76)
com.amazonaws.http.conn.$Proxy494.connect(Unknown Source)
org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
com.amazonaws.http.apache.client.impl.SdkHttpClient.execute(SdkHttpClient.java:72)
com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1330)
com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1145)
com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:802)
com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:770)
com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:744)
com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:704)
com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:686)
com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:550)
com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:530)
com.amazonaws.services.securitytoken.AWSSecurityTokenServiceClient.doInvoke(AWSSecurityTokenServiceClient.java:1719)
com.amazonaws.services.securitytoken.AWSSecurityTokenServiceClient.invoke(AWSSecurityTokenServiceClient.java:1686)
com.amazonaws.services.securitytoken.AWSSecurityTokenServiceClient.invoke(AWSSecurityTokenServiceClient.java:1675)
com.amazonaws.services.securitytoken.AWSSecurityTokenServiceClient.executeAssumeRole(AWSSecurityTokenServiceClient.java:589)
com.amazonaws.services.securitytoken.AWSSecurityTokenServiceClient.assumeRole(AWSSecurityTokenServiceClient.java:561)
com.amazonaws.auth.STSAssumeRoleSessionCredentialsProvider.newSession(STSAssumeRoleSessionCredentialsProvider.java:321)
com.amazonaws.auth.STSAssumeRoleSessionCredentialsProvider.access$000(STSAssumeRoleSessionCredentialsProvider.java:37)
com.amazonaws.auth.STSAssumeRoleSessionCredentialsProvider$1.call(STSAssumeRoleSessionCredentialsProvider.java:76)
com.amazonaws.auth.STSAssumeRoleSessionCredentialsProvider$1.call(STSAssumeRoleSessionCredentialsProvider.java:73)
com.amazonaws.auth.RefreshableTask.refreshValue(RefreshableTask.java:257)
com.amazonaws.auth.RefreshableTask.access$100(RefreshableTask.java:41)
com.amazonaws.auth.RefreshableTask$1.run(RefreshableTask.java:238)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
java.util.concurrent.FutureTask.run(FutureTask.java:266)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:750)
发现是引的三方包 亚马逊的http client 导致..
应用中创建了多个client , 但是每个client 都会维护一个检测连接相关东西的task , 并且是直接使用executors new出来的未命名线程 , 最终重写class 定义了一个全局唯一的线程池解决
类似案例
JVM 线程无法回收排查 -- 实例_linux jvm未回收_Golden_Dog的博客-CSDN博客
java真实占用内存分布
操作系统对内存的分配管理典型地分为两个阶段:保留(reserve)和提交(commit)。保留阶段告知系统从某一地址开始到后面的dwSize大小的连续虚拟内存需要供程序使用,进程其他分配内存的操作不得使用这段内存;提交阶段将虚拟地址映射到对应的真实物理内存中,这样这块内存就可以正常使用[1]。
top 与 jvm实际占用内存分析
比较结果发现
实际600MB > (jvm堆内+堆外)319MB
但是有一点是可以知道的,就是这些600M 内存的确被jvm所属进程使用了。
使用 jcmd pid VM.native_memory summary
-XX:NativeMemoryTracking=summary
jcmd pid VM.native_memory summary 查看jvm 真实占用的内存分布情况
committed就是实际使用的内存
所以一个java进程的内存占用:
- heap:堆内存,即-Xmx限制的最大堆大小的内存。
- class:加载的类与方法信息,其实就是 metaSpace,包含两部分:
-
- 一是metadata,被-XX:MaxMetaspaceSize限制最大大小,
- 二是classSpace,被-XX:CompressedClassSpaceSize限制最大大小
- thread:线程与线程栈占用内存,每个线程栈占用大小受-Xss限制,但是总大小没有限制
- code:JIT 即时编译后(C1 C2 编译器优化)的代码占用内存,受-XX:ReservedCodeCacheSize限制
- gc:垃圾回收占用内存,例如垃圾回收需要的 CardTable,标记数,区域划分记录,还有标记 GC Root等等,都需要内存。这个不受限制,一般不会很大的。Parallel GC 不会占什么内存,G1 最多会占堆内存 10%左右额外内存,ZGC 会最多会占堆内存 15~20%左右额外内存,但是这些都在不断优化。(注意,不是占用堆的内存,而是大小和堆内存里面对象占用情况相关)
- compiler:C1 C2 编译器本身的代码和标记占用的内存,这个不受限制,一般不会很大的
- internal:命令行解析,JVMTI 使用的内存,这个不受限制,一般不会很大的
- symbol:常量池占用的大小,字符串常量池受-XX:StringTableSize个数限制,总内存大小不受限制
- Native Memory Tracking:内存采集本身占用的内存大小,如果没有打开采集(那就看不到这个了)
- Arena Chunk:所有通过 arena 方式分配的内存,这个不受限制,一般不会很大的
由下图可以看到 600M实际的占用分布 , total的 600M也基本符合