|
如下是一个代码中有比较耗时的计算，导致 CPU 过高的线程信息：
这里可以看到，在请求 UserController 的时候，由于该 Controller 进行了一个比较耗时的调用，导致该线程的 CPU 一直处于 100%。
我们可以根据堆栈信息，直接定位到 UserController 的 34 行，查看代码中具体是什么原因导致计算量如此之高。
不定期出现的接口耗时现象
对于这种情况，比较典型的例子就是，我们某个接口访问经常需要 2~3s 才能返回。
这是比较麻烦的一种情况，因为一般来说，其消耗的 CPU 不多，而且占用的内存也不高，也就是说，我们通过上述两种方式进行排查是无法解决这种问题的。
而且由于这样的接口耗时比较大的问题是不定时出现的，这就导致了我们在通过 jstack 命令即使得到了线程访问的堆栈信息，我们也没法判断具体哪个线程是正在执行比较耗时操作的线程。
对于不定时出现的接口耗时比较严重的问题，我们的定位思路基本如下：首先找到该接口，通过压测工具不断加大访问力度。
如果说该接口中有某个位置是比较耗时的，由于我们的访问的频率非常高，那么大多数的线程最终都将阻塞于该阻塞点。
这样通过多个线程具有相同的堆栈日志，我们基本上就可以定位到该接口中比较耗时的代码的位置。
如下是一个代码中有比较耗时的阻塞操作通过压测工具得到的线程堆栈日志：
- "http-nio-8080-exec-2" #29 daemon prio=5 os_prio=31 tid=0x00007fd08cb26000 nid=0x9603 waiting on condition [0x00007000031d5000]
- java.lang.Thread.State: TIMED_WAITING (sleeping)
- at java.lang.Thread.sleep(Native Method)
- at java.lang.Thread.sleep(Thread.java:340)
- at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
- at com.aibaobei.user.controller.UserController.detail(UserController.java:18)
-
- "http-nio-8080-exec-3" #30 daemon prio=5 os_prio=31 tid=0x00007fd08cb27000 nid=0x6203 waiting on condition [0x00007000032d8000]
- java.lang.Thread.State: TIMED_WAITING (sleeping)
- at java.lang.Thread.sleep(Native Method)
- at java.lang.Thread.sleep(Thread.java:340)
- at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
- at com.aibaobei.user.controller.UserController.detail(UserController.java:18)
-
- "http-nio-8080-exec-4" #31 daemon prio=5 os_prio=31 tid=0x00007fd08d0fa000 nid=0x6403 waiting on condition [0x00007000033db000]
- java.lang.Thread.State: TIMED_WAITING (sleeping)
- at java.lang.Thread.sleep(Native Method)
- at java.lang.Thread.sleep(Thread.java:340)
- at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
- at com.aibaobei.user.controller.UserController.detail(UserController.java:18)
从上面的日志你可以看出，这里有多个线程都阻塞在了 UserController 的第 18 行，说明这是一个阻塞点，也就是导致该接口比较缓慢的原因。
某个线程进入 WAITING 状态
对于这种情况，这是比较罕见的一种情况，但是也是有可能出现的，而且由于其具有一定的“不可复现性”，因而我们在排查的时候是非常难以发现的。
笔者曾经就遇到过类似的这种情况，具体的场景是，在使用 CountDownLatch 时，由于需要每一个并行的任务都执行完成之后才会唤醒主线程往下执行。
而当时我们是通过 CountDownLatch 控制多个线程连接并导出用户的 Gmail 邮箱数据，这其中有一个线程连接上了用户邮箱，但是连接被服务器挂起了，导致该线程一直在等待服务器的响应。
最终导致我们的主线程和其余几个线程都处于 WAITING 状态。
对于这样的问题，查看过 jstack 日志的读者应该都知道，正常情况下，线上大多数线程都是处于 TIMED_WAITING 状态。
而我们这里出问题的线程所处的状态与其是一模一样的，这就非常容易混淆我们的判断。
解决这个问题的思路主要如下：
①通过 grep 在 jstack 日志中找出所有的处于 TIMED_WAITING 状态的线程，将其导出到某个文件中，如 a1.log，如下是一个导出的日志文件示例：
- "Attach Listener" #13 daemon prio=9 os_prio=31 tid=0x00007fe690064000 nid=0xd07 waiting on condition [0x0000000000000000]
- "DestroyJavaVM" #12 prio=5 os_prio=31 tid=0x00007fe690066000 nid=0x2603 waiting on condition [0x0000000000000000]
- "Thread-0" #11 prio=5 os_prio=31 tid=0x00007fe690065000 nid=0x5a03 waiting on condition [0x0000700003ad4000]
- "C1 CompilerThread3" #9 daemon prio=9 os_prio=31 tid=0x00007fe68c00a000 nid=0xa903 waiting on condition [0x0000000000000000]
（编辑：济南站长网）
【声明】本站内容均来自网络，其相关言论仅代表作者个人观点，不代表本站立场。若无意侵犯到您的权利，请及时与联系站长删除相关内容!
|
