hello云胜

技术与生活

0%

发表于

应用不响应排查

同事给了jstack信息和dump文件，

jstack信息使用在线分析https://heaphero.io

image-20220106143845851

image-20220106143855209

image-20220106143905149

说线程数太多。刚开始还真以为是这个原因。700个dubbo handler线程全部处于waiting状态。

然后仔细看了下这个日志waiting（parking）

image-20220106144140519

dubbo业务处理使用线程池。通过这个SynchronousQueue队列，基本可以确定是CachedThreadPool

image-20220106144243702

因为其他几个线程池模型用的是LinkedBlockingQueue。

SynchronousQueue特点是，他的容量是0，进来一个任务，必须有一个处理线程取走，否则阻塞。处理线程要取任务，必须等待任务放进来，否则阻塞。所以这里是dubbo线程池没活干。闲着呢。没问题。

用mat看dump文件，也没什么问题。就是字符串有点多。

然后，没办法了。去看gc情况。容器环境还没jdk。复制了一个放进来。

image-20220106143754185

一次Full-GC,330秒，简直要疯了。

更好的情况是，添加JVM参数重启，打印gcLog，

1
2
3
4
5
6
-XX:+PrintGCDateStamps：打印 GC 发生的时间戳。
-XX:+PrintTenuringDistribution：打印 GC 发生时的代龄信息。
-XX:+PrintGCApplicationStoppedTime：打印 GC 停顿时长
-XX:+PrintGCApplicationConcurrentTime：打印 GC 间隔的服务运行时长
-XX:+PrintGCDetails：打印 GC 详情，包括 GC 前/内存等。
-Xloggc:/temp/gc.log.date：指定 GC log 的路径

但是这个是业务的应用。不让动。

Universal JVM GC analyzer - Java Garbage collection log analysis made easy (gceasy.io)

image-20220106152415295

堆大小4G，新生代只给了256M。默认是新生代：老年代= 1 ： 2。现在配的这个比例可能有问题。

通过前面的截图，YGC的次数过多，也说明了新生代太小。

让业务开发把-Xmn=256m去掉，使用默认的

用了CMS垃圾收集器，回顾一下CMS垃圾回收的6个阶段。

CMS垃圾回收的6个重要阶段

  • initial-mark 初始标记（CMS的第一个STW阶段），标记GC Root直接引用的对象，GC Root直接引用的对象不多，所以很快。

    （GC Root包括：1，所有Java线程当前活跃的栈帧里指向的堆里的对象，2一些静态结构指向的堆里的对象。）

  • concurrent-mark 并发标记阶段，可达性标记。由第一阶段标记过的对象出发，标记所有可达对象。

  • concurrent-preclean 并发预清理阶段，也是一个并发执行的阶段。在本阶段，会查找前一阶段执行过程中,从新生代晋升或新分配或被更新的对象。通过并发地重新扫描这些对象，预清理阶段可以减少下一个stop-the-world 重新标记阶段的工作量。

  • concurrent-abortable-preclean 并发可中止的预清理阶段。这个阶段其实跟上一个阶段做的东西一样，也是为了减少下一个STW重新标记阶段的工作量。增加这一阶段是为了让我们可以控制这个阶段的结束时机，比如扫描多长时间（默认5秒）或者Eden区使用占比达到期望比例（默认50%）就结束本阶段。

  • remark 重标记阶段（CMS的第二个STW阶段），暂停所有用户线程，从GC Root开始重新扫描整堆，标记存活的对象。需要注意的是，虽然CMS只回收老年代的垃圾对象，但是这个阶段依然需要扫描新生代，因为很多GC Root都在新生代，而这些GC Root指向的对象又在老年代，这称为“跨代引用”。

  • concurrent-sweep ，并发清理。