先点赞再看,养成好习惯
接上篇《运维:大家 JAVA 服务内存占用过高,还只增不减!告警了,快来接锅》
java
在上次在运维老哥友好的和我沟通以后,还消停没几天,今天又来找(问候)我了……
git
运维:这个服务也是大家的吧,你看这个 JAVA 进程,内存占用都快 3 个 G 了,这机器才 4G,大家堆才配置 2G,都要告警了!此次是真的内存泄露了吧,不是我无知了吧!
又来搞事情……这大哥是对我有意见吗?有了上次的经验,这回更自信了。仍是按照惯例,先怼回去github
我:“不可能,咱们服务很是稳定,不会有这种问题!”segmentfault
运维:你这哪来的自信和勇气?梁静茹给的吗?你先回去查查再装后端
看来大哥这回是有备而来啊,难道真是出问题了?有点慌了……bash
不过仍是不能怂,先敷衍下运维老哥,找个借口回去先偷摸查查监控看看服务器
我:行,我待会看看,我先去跟人开个会啊……
这个服务的堆内存配置的是 2G,历史内存也确实达到过 2G,虽然如今 used 才几百兆……看起来也没啥问题
运维
再加上一些 VM 本身的开销,一共占用 2 个多 G……好像也说的过去
测试
而后我又找到了运维大哥,(友好的)沟通一下……
spa
我:和上次同样啊,没什么区别,上次都解释过那个内存管理的机制了,你咋还说咱们有问题?
运维: 你看大家这个服务,配置的是 CMS+ParNew 垃圾回收器吧,上次是你说的这个回收器组合下会释放内存给操做系统吧?那怎么还占用 2G,释放到哪去了?
我:虽然上回测试结果是会释放,但还有一些其余的说法,说是空闲时会增量释放,并且释放成本这么高,不释放又怎么样?
运维:你这话不是打本身脸么?上回说能释放,如今没释放你也说正常,你是否是以为我傻?
运维大哥好像看出了我是在狡辩……
不释放也正常啊,释放成本这么高,释放后还得从新申请,从新组织内存结构balabalabala……
这话说的我本身都没底气……毕竟上次才测试过 CMS+ParNew 确实会释放,只是时间问题
运维:你继续狡辩,这服务的内存照这个趋势,估计要不要明天就得 OOM,而后系统再给你来个 OOM Killer 的绝杀,你可就开心了!
我:没问题的,这个内存正常,本身的服务,我还能不了解嘛
此时我已经有点不安了,大哥说的有道理啊,万一 OOM Killer了,可不完蛋了!
我:我晚点有空再仔细看看,应该没啥问题,你先忙你的,放心!
打发走了运维老哥以后,我仔细思考了一会。这内存的数据好像确实不太正常,这个服务属于那种后端应用,虽然业务复杂,但只是给业务大佬们用。不过这个内存占用确实有点说不过去啊,到底内存跑哪去了……
仍是数听说话吧,上主机上找找看有没有什么线索
也没什么异常,CPU 利用率和负载啥的都很低……到底问题出在哪?
这么一点点的看指标太费劲了,仍是拿 Arthas 看吧,JVM 相关的指标它基本都显示,比较全:
[arthas@20727]$ dashboard Memory used total max usage GC heap 498M 1963M 1963M 25.1% gc.ps_scavenge.count 3 ps_eden_space 98M 512M 512M 19.5% gc.ps_scavenge.time(ms) 44 ps_survivor_space 0K 87040K 87040K 0.00% gc.ps_marksweep.count 1 ps_old_gen 39M 1365M 1365M 2.88% gc.ps_marksweep.time(ms) 87 nonheap 32M 180M -1 17.7% code_cache 10M 50M 240M 20% metaspace 20M 128M -1 15.6% compressed_class_space 2M 2M 1024M 0.25%
看起来JVM 级别的内存也没啥问题,再看看线程呢:
[arthas@20727]$ thread Threads Total: 9831, NEW: 0, RUNNABLE: 8, BLOCKED: 0, WAITING: 9789, TIMED_WAITING: 2, TERMINATED: 0, Internal threads : 17
卧槽,这什么玩意!快 1w 个线程!还基本上都是 WAITING!
赶忙看看这些 WAITING 的线程都是些啥:
[arthas@20727]$ thread --state WAITING ID NAME GROUP PRIORITY STATE %CPU DELTA_TIM TIME INTERRUPT DAEMON # 此处省略 9000+ 行…… 9822 pool-9813-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9823 pool-9814-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9824 pool-9815-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9825 pool-9816-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9826 pool-9817-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9827 pool-9818-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9828 pool-9819-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9829 pool-9820-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9830 pool-9821-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9831 pool-9822-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9832 pool-9823-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9833 pool-9824-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9834 pool-9825-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9835 pool-9826-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9836 pool-9827-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9837 pool-9828-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9838 pool-9829-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9839 pool-9830-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false 9840 pool-9831-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
看到这个线程名,我也大概明白了,必定是哪一个小天才在代码里下毒。
从线程名称来看,确定是线程池里的线程嘛,并且是默认的线程名生成规则。线程池里的线程都是经过 ThreadFactory 来建立的,而默认的 ThreadFactory 生成规则就是这样:
DefaultThreadFactory() { SecurityManager s = System.getSecurityManager(); group = (s != null) ? s.getThreadGroup() : Thread.currentThread().getThreadGroup(); // 前缀,每个新的 ThreadFactory 都有一个新的前缀 // 每个线程池,都只有一个 ThreadFactory namePrefix = "pool-" + poolNumber.getAndIncrement() + "-thread-"; } public Thread newThread(Runnable r) { // 每一个线程都会使用 factory的前缀,而后加上自增的线程数 Thread t = new Thread(group, r, namePrefix + threadNumber.getAndIncrement(), 0); if (t.isDaemon()) t.setDaemon(false); if (t.getPriority() != Thread.NORM_PRIORITY) t.setPriority(Thread.NORM_PRIORITY); return t; }
因此这个问题,确定是哪一个小天才,在代码里每次都新建线程池,而后还不 shutdown 致使的!随便找个线程,看看它的 stack:
"pool-1-thread-1" Id=10 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6ba7592 at sun.misc.Unsafe.park(Native Method) - waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6ba7592 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
实锤了,就是每次 new 线程池不 shutdown……如今只须要找到建立线程池的地方,再翻翻提交记录,就能够知道是哪一个小天才了……
但代码这么多,想找到这个新建线程池的地方仍是有点麻烦的,搜代码可不太方便。这里仍是用 Arthas 来看看,stack 一看就知道
不过若是这里直接 stack ThreadPoolExecutor#execute 方法的话,干扰信息可能太多了,毕竟调用 execute 的地方太多,很差抓到重点
因此仍是 stack 线程池初始化的方法比较好:
[arthas@20727]$ stack java.util.concurrent.ThreadPoolExecutor <init> Affect(class count: 0 , method count: 0) cost in 4 ms, listenerId: 5 No class or method is affected, try: 1. Execute `sm CLASS_NAME METHOD_NAME` to make sure the method you are tracing actually exists (it might be in your parent class). 2. Execute `options unsafe true`, if you want to enhance the classes under the `java.*` package. 3. Execute `reset CLASS_NAME` and try again, your method body might be too large. 4. Check arthas log: /home/jiangxin/logs/arthas/arthas.log 5. Visit https://github.com/alibaba/arthas/issues/47 for more details.
这……是不支持吗?
Arthas 的加强策略是比较保守的,部分系统级别的类它不作加强,java.*
包下的类默认是不加强的,须要手动开启才行:
[arthas@20727]$ options unsafe true NAME BEFORE-VALUE AFTER-VALUE ----------------------------------- unsafe false true
再次执行 stack 以后,能够用了。过了两分钟以后,终于有一次调用:
ts=2021-06-12 12:04:03;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@4e0e2f2a @java.util.concurrent.ThreadPoolExecutor.<init>() at java.util.concurrent.Executors.newFixedThreadPool(Executors.java:89) at XXXService.sendSms(XXXService.java:782) //...
终于找到了这个骚操做代码……它是这么写的:
ExecutorService executorService = Executors.newFixedThreadPool(8); executorService.submit(smsTask); //...
和我猜想的同样,果真是每次 new,而后还不 shutdown。
这也能和上面的状况对上了,多出的内存占用是由于这小一万个线程……并且这些线程池没有任务须要执行的话,线程确定是 WAITING 状态,也不会占用 CPU 的利用率,负载有不会有影响。不仔细还真看不出问题
,仍是得结合各类指标来看,综合分析。
解决这个问题倒简单,让写这个屎代码的人去改了,而后拉出去祭天。
但是运维大哥那边……已经装出去了,这下脸但是丢完了。上次好不容易挣回来的面子,此次啥都没了
我:服务确实有点问题,咱们发个紧急修复版本,晚上上线就能解决了
运维:你不是说没问题么?自信哪去了
我:这不是没吃早饭,饿的头发昏,脑子不够清醒……没看出来问题,个人锅个人锅
运维:确定是大家的屎山代码致使的,没事也搞搞 code review ,查查代码,之后少出这种低级问题,否则我一天到晚处理大家这些破事不得烦死了
没想到这运维还喘起来了,给点面子就要上天……不过谁让我理亏呢,只能应下
我:对对对,咱们之后必定多搞 code review,增强代码审查,避免这种屎代码再提交上去,影响生产。不给大佬添麻烦
原创不易,禁止未受权的转载。若是个人文章对您有帮助,就请点赞/收藏/关注鼓励支持一下吧❤❤❤❤❤❤