【linux】线上超时接口排查

项目场景：

监控告警线上有个接口经常504，时不时地来一下，用户也反馈时不时页面加载不了。

---

问题排查

1. 检查所有上下游应用都是开启的
2. top查看java占用cpu为98.7%
3. 查看rds慢sql记录，当前时段并没有慢sql
4. 查看当前执行线程对cpu占用情况列表

# 使用linux的ps命令查看线程耗时情况
ps -mp 15403 -o THREAD,tid,time

		# 命令执行结果
		USER     %CPU PRI SCNT WCHAN  USER SYSTEM   TID     TIME
        root     34.5   -    - -         -      -     - 08:03:22
        root      0.1  19    - -         -      - 15538 00:02:26
        root      0.0  19    - ep_pol    -      - 15539 00:00:00
        root      0.0  19    - -         -      - 15540 00:01:20
        root      4.1  19    - -         -      - 15559 00:58:03
        root      0.2  19    - futex_    -      - 15561 00:04:08
        root      0.2  19    - futex_    -      - 15564 00:04:09
        root      0.2  19    - futex_    -      - 15565 00:04:07
        root      0.4  19    - -         -      - 15566 00:05:55
        root      4.3  19    - -         -      - 15567 01:00:59
        root      0.2  19    - futex_    -      - 15568 00:04:06
        root      4.2  19    - -         -      - 15577 00:59:25
        root      4.4  19    - -         -      - 15578 01:02:50
        root      4.2  19    - -         -      - 15579 00:58:45
        root      4.1  19    - -         -      - 15581 00:57:26
        root      0.2  19    - futex_    -      - 15582 00:04:11
        root      0.3  19    - -         -      - 15583 00:05:27
        root      0.2  19    - futex_    -      - 15584 00:04:09

5. 找到占用cpu占用比较高的几个线程 15559 15567 15577 15578
6. 线程pid转换成16进制

# 线程pid转换成16进制
printf "%x\n" 15559

# 得到结果
3cc7

7. 打印出当前线程的堆栈信息

# 使用jstack命令打印堆栈信息
jstack 19969|grep 3cc7 -A 30

# jstack堆栈信息结果
"XNIO-2 task-3" #53 prio=5 os_prio=0 tid=0x00007f6f0c6fa000 nid=0x4eb6 waiting on condition [0x00007f6ee6dfb000]
  java.lang.Thread.State: WAITING (parking)
  at sun.misc.Unsafe.park(Native Method)
  - parking to wait for  <0x00000000a596f030> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  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)
  
  "XNIO-2 task-2" #50 prio=5 os_prio=0 tid=0x00007f6f0c187800 nid=0x4eb2 waiting on condition [0x00007f6ee6efc000]
  java.lang.Thread.State: WAITING (parking)
  at sun.misc.Unsafe.park(Native Method)
  - parking to wait for  <0x00000000a596f030> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  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)

  "XNIO-2 task-1" #49 prio=5 os_prio=0 tid=0x00007f6f0cd61800 nid=0x4eac waiting on condition [0x00007f6ee6ffd000]
  java.lang.Thread.State: WAITING (parking)
  at sun.misc.Unsafe.park(Native Method)
  - parking to wait for  <0x00000000a596f030> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  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)

根据打印出的堆栈信息就可以定位到相关cpu耗时比较长的代码片段(本次只截取部分，可以调整参数jstack 19969|grep 3cc7 -A 30 为 jstack 19969|grep 3cc7 -A 100 打印出更多堆栈信息)

---

结果处理：

由于这个堆栈信息是时候写文章的时候打印出来的，没有当时的的情况，当时是直接打印出项目代码里面卡顿的堆栈行。这里就不细说了，大家写代码用while循环的时候，一定要谨慎，记得跳出循环。

---

学到的知识点：

• linux命令PS：在Linux中，PS命令用于显示当前终端会话中属于当前用户的进程列表。其基本语法为“ps [选项参数]”，通过添加不同的选项，可以获取不同类型的进程信息。

以下是一些常用的PS命令选项和用法示例：
显示所有正在运行的进程：ps -e。
显示与终端无关的所有进程：ps -a。
显示所有进程，不以终端来区分：ps -x。
显示用户主目录下所有运行的进程：ps -u <用户名>。
显示系统中所有运行状态下的进程：ps -ef | grep '^[Z]'。
显示进程的详细信息：ps -auxj。
显示包含其他用户的进程：ps -u <用户名> -o pid,args。
显示在特定终端上的进程：ps -t <终端名>。
显示在特定终端上的所有用户的进程：ps -e -t <终端名>。
显示与特定命令关联的进程：ps -p <PID>。
此外，PS命令还有一些常用的选项，如：

-f选项：使用全格式显示进程信息，包括父进程ID(PPID)、进程状态、CPU使用率(%CPU)、内存使用率(%MEM)等。
-l选项：显示长格式的进程信息，包括进程命令行、进程状态(S)、进程的会话ID(SID)等。
-o选项：自定义输出格式，可以指定要显示的列和排序方式。

• jvm的jstack命令：jstack命令是Java虚拟机（JVM）中用于生成虚拟机指定进程当前时刻的线程快照的工具。线程快照是当前虚拟机内每一条线程正在执行的方法堆栈的集合。通过生成线程快照，jstack命令主要用于定位线程长时间停顿的原因，例如线程死锁、死循环、线程请求外部资源导致的长时间等待等问题。当线程出现停顿的时候，通过jstack命令查看各个线程的调用堆栈，可以了解没有响应的线程到底在后台执行什么操作，或者正在等待什么资源。

jstack命令的基本格式如下：

jstack [ option ] pid：用于打印指定Java进程的线程堆栈跟踪信息。
jstack [ option ] executable core：如果Java程序崩溃生成了core文件，jstack命令可以用来获取该core文件的Java堆栈和本地堆栈信息，帮助分析程序崩溃的原因。
jstack [ option ] [server-id@]remote-hostname-or-IP：用于远程调试服务器上的Java线程堆栈跟踪。
其中，[option]表示可选参数，例如：

-help：打印帮助信息。
-F：当正常输出的线程不被响应时，强制输出线程堆栈。
-m：如果调用本地方法，显示C/C++的堆栈信息。