2021年9月

如何找到 JVM 里面的 native C 代码

比如 java.lang.Thread.java 里面定义了定义了一些 native 代码, 那么如何找到这些 native 代码呢? 使用 google search 对应的 .c 文件:
thread.c site:openjdk.java.net

又比如: sun.nio.ch.FileDispatcherImpl.java 里面定义了一些 native 代码, 那么只要 search:
FileDispatcherImpl.c site:openjdk.java.net
就可以了.

记录一次线上 connection reset 排查

有开发人员发现他们的应用程序经常报一个空指针的错误, 他们自己查不出来是啥原因, 就报给了网络团队, 因为在这个空指针前面, 打了一行日志, 说接收回应数据为空(Response is empty), 他们认为网络时不时有问题.

  1. 找到对应的代码, 发现有人写了一段这样的代码:

    try {
    //access another service
    Response rsps = callAnotherService();
    } catch (Exception e) {
    logErr("Response is empty", e.getMessage);
    }
    return rsps;
  2. 上面这段代码中, 捕获异常, 只是打印了日志, 没有做错误处理, 这时候返回的 rsps 肯定为 null, 就可能导致上层调用者空指针异常. 通常我们需要封装之前的 Exception, 如果没有封装, 那么最好打印之前异常的错误栈到日志中, 这样方便排查问题出在哪一行. 另外这里有个特殊的地方, logErr() 方法的第二个参数并没有打印到日志中, 而是做了其它用途, 导致开发人员最后只看到 "Response is empty", 没看到具体出错原因.
  3. 对这行代码改造之后, 我们看到了出错栈和具体原因: connection reset by peer. 就是连接被断掉了.
  4. 于是做 tcpdump, 发现对于这种情况基本是客户端发出请求后, 服务端就 reset 了连接;
  5. 由于中间使用了 LB, 复制 LB 的同事在 LB 上双向抓包, 说是服务端主动 reset 连接;
  6. 于是在服务端抓包, 确实发现有时候服务端在收到请求后主动 reset 连接;
  7. 观察服务端的情况, 发现有些发来的请求服务端已经在处理了, 等处理完发现连接已经被 reset, 有些根本没进入服务端进行处理. 其它观察到的一些情况

    1. 服务端是异步 IO, 所以有些线程负责建立连接, 负责数据的读取写入, 有些负责业务处理;
    2. 服务端并没有发现特殊的线程 interrupt 的情况(这种情况很容易造成 IO 连接中断);
    3. 服务端在处理的时候, 又使用了 @suspended AsyncResponse. 基本是 Tomcat server 线程处理了 token 验证, 之后就留给线程池处理了.
  8. 通过 perf 过滤操作系统层面的 tcp:reset, 确实发现一些从tomcat 端口 reset 的连接, 可是由于是没有java 代码的栈, 所以看不出为什么要 reset;
  9. 于是对 java 进程添加 -XX:+PreserveFramePointer, 生成符号表文件, 成功看到部分 java 栈. 可是由于另外一些还是热度不够, 看到的代码仍然是翻译过来的, 所以看到的都是 Interpreter:
    interpreter.png
  10. 不过通过async-profiler 持续抓包, 终于捕获类似一个 java 栈:
    close_reset.png
  11. 通过 2 个栈相结合, 能看到导致 reset 的原因是: 代码中出了某种问题, 要 close 连接, close 的时候, 发现正常 close 的条件没达到, 比如还有没读的数据, 只能直接 reset;
  12. 导致 close 的代码段是:
    close.png

到底是什么情况导致 cancelledKey() close, 未完待续

perf-map-agent 使用步骤

使用 asyncProfiler 能捕获 Java 的栈, 使用 perf 能捕获操作系统栈, 由于 JVM 使用自己单独的虚拟机, 所以不能同时访问 2 部分栈. Netflix 的教程(https://netflixtechblog.com/java-in-flames-e763b3d32166), 能捕获 2 个在一起的栈. 需要做 2 件事情:

  1. 对 Java 进程添加 -XX:+PreserveFramePointer flag
  2. 生成当前正在运行的 Java 进程的 符号表文件. asyncProfiler 和 bpftrace 都需要这个文件在 /tmp/ 目录下, 并且以 perf-<pid>.map 的形式存在.

ls -lah /tmp/perf-2868448.map

假如不使用 Java 运行时符号表

你将看到如下的栈信息, 毫无用处:

  0x7f72beee3337
  0x7f72be72e399
  0x7f72be72ed3e
  0x7f72be1a7d98
  0x7f72be1aacb1

下面就是关于如何产生符号表文件的教程.

  1. clone 或者下载最新版本 https://github.com/jvm-profiling-tools/perf-map-agent

    curl -vvv 'https://github.com/jvm-profiling-tools/perf-map-agent/archive/refs/heads/master.zip' --output perf-map-agent.zip
    
    # or
    git clone https://github.com/jvm-profiling-tools/perf-map-agent.git
    
  2. 设置 JAVA_HOME 环境变量

    export JAVA_HOME=/home/supra/work/tools/myjdk/jdk11/jdk
  3. 编译

    # 解压并进入该文件夹
    unzip perf-map-agent.git && cd perf-map-agent
    cmake .
    make
  4. 产生 perf-.map

    ./bin/create-java-perf-map.sh $(pgrep java)
    # 到 /tmp 目录查看对应的 perf-<pid>.map 是不是存在了
    ls /tmp/ | grep .map
    -rw-rw-r--  1 root  root   29K Nov 13 06:29 perf-2868448.map

使用 bpftrace 的例子

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_pread /comm=="java"/{ @[ustack(20)] = count(); }'

# or
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_pread /pid==2868448/{ @[ustack(20)] = count(); }'

可能遇到问题:

  1. 如果遇到下面:

    -- The C compiler identification is GNU 7.5.0
    -- The CXX compiler identification is unknown
    -- Check for working C compiler: /usr/bin/cc
    -- Check for working C compiler: /usr/bin/cc -- broken
    CMake Error at /usr/share/cmake-3.10/Modules/CMakeTestCCompiler.cmake:52 (message):
     The C compiler
    
     "/usr/bin/cc"
    
     is not able to compile a simple test program.
    
     It fails with the following output:

    则安装编译工具

    sudo apt-get cmake
    sudo apt-get install build-essential
  2. 如果遇到下面:

    Sorry, user xxx is not allowed to execute '/yyyy/bin/java -cp /home/xxx/perf-map-agent-master/bin/../out/attach-main.jar:/yyyy/lib/tools.jar net.virtualvoid.perf.AttachOnce 23545 ' as xxx on hostzzzz.txh.com.

    那么我们可以到 perf-map-agent-master/out/ 目录下去执行这个命令就好了, 不是执行 create-java-perf-map.sh.

  3. 关于要如何使用 root 的, 查看 Netflix 的那个文档
  4. 创建 perf-.map 要使用 java 应用启动相同的用户名, 因为 java 应用的 agent 要使用同样的用户才能访问对应的 java 程序.
  5. 如果你发现即便使用了运行时 Java 进程的符号表, 可是还是很多翻译的栈, 如下:

    __GI___recv+110
     Java_java_net_SocketInputStream_socketRead0+434
     Interpreter+28336
     Interpreter+4352
     Interpreter+4352
     Interpreter+4352
     Interpreter+4352
     Interpreter+5875
     Interpreter+4352
     Interpreter+4352
     Interpreter+3728
     Interpreter+3728
     Interpreter+5184
     Interpreter+5184
     Interpreter+4352
     call_stub+138
     JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, Thread*)+883

    因为只有编译的代码才有符号表, 翻译的是没有的, 所以要让它尽快尽早JIT编译, 因此, 要通过下面2个参数:
    -XX:-TieredCompilation -XX:CompileThreshold=1
    2个参数分别是: 禁止分层编译, 然后只要运行1次就JIT编译. 所以完整的命令是:
    java -XX:+PreserveFramePointer -XX:-TieredCompilation -XX:CompileThreshold=1 myJavaApp.
    同时要确保你的编译cache 足够大.
    这样, 你就得到了如下的代码栈:

     __GI___recv+110
     Java_java_net_SocketInputStream_socketRead0+434
     Ljava/net/SocketInputStream;::socketRead0+244
     Ljava/net/SocketInputStream;::read+224
     Ljava/io/BufferedInputStream;::fill+784
     Ljava/io/BufferedInputStream;::read1+176
     Ljava/io/BufferedInputStream;::read+252
     Lsun/net/www/http/HttpClient;::parseHTTPHeader+444
     Lsun/net/www/http/HttpClient;::parseHTTP+1004
     Lsun/net/www/protocol/http/HttpURLConnection;::getInputStream0+1420
     Lsun/net/www/protocol/http/HttpURLConnection;::getInputStream+196
     Ljava/net/HttpURLConnection;::getResponseCode+96

Linux 的 scheduler

Linux 从 2.6.23 开始使用 CFS(Completely Fair Scheduler). 在 Linux 内核看来, 它不区分进程和线程, 每个都是可调度的 Thread.

每个新创建的 Thread 都有一个 Schedule Policy 属性和一个 Static Priority 属性. CFS 主要根据这2 个属性的值, 确定当前线程是不是能分配 CPU 时间.

Linux 上的 Scheduler Policy 主要有:

  1. SCHED_OTHER # Linux kernel 里面又名 SCHED_NORMAL
  2. SCHED_IDLE
  3. SCHED_BATCH
  4. SCHED_FIFO #First In First Out 先进先出
  5. SCHED_RR # Round Robin 是 SCHED_FIFO 的改进版本

以上这些 Policy 又被分为 2 大类(Classes):

  1. Normal scheduling policies (正常) 包含 SCHED_OTHER, SCHED_IDLE, SCHED_BATCH;
  2. real-time policies (实时) 包含 SCHED_FIFO, SCHED_RR

对于 Normal scheduling policies 的线程, 它的静态优先级一定是 0, 这个值在scheduler 安排他们在 CPU 上执行决策的时候, 是不考虑的.
对于 Real-time policies 的线程, 它的静态优先级范围是 1(低) ~ 99(高).

从概念上讲(实际并不一定是这么做的, 效果是一样的), 每个优先级都有一个线程列表, 里面都是同优先级的线程. CFS 从高优先级队列到低优先级队列按照顺序去找, 高优先级队列里面执行完了, 再执行第优先级队列. 同一个队列里面从头往后执行.

不同优先级线程之间根据优先级(priority) 去安排, 相同优先级的线程根据 Scheduler Policy 去安排执行顺序和时间;

Linux 默认的线程 Policy 是SCHED_OTHER, 所以这些默认的静态优先级都是 0. 它们都比 Real-time 的线程优先级低. 对于 SCHED_OTHER 队列里面的线程, 因为静态优先级都是0, 所以它们使用动态优先级(dynamic priority) 来决定谁先运行. 动态优先级使用 nice 的值来决定谁先运行. nice 的值决定一个线程在一个时间区间内可以运行的时长, 通常情况下没有 nice 值的线程都有相同的运行时长, 改变 nice 的值, 就能改变在一个时间区间内它能运行的时长.

nice 的值只对 policy 是 SCHED_OTHER & SCHED_BATCH 的线程有效. 在 Linux 上 nice 的值是 per-thread 的. 在当前的 Linux 系统, nice 的值可以是: -20 (high priority) to +19 (low priority). 它意味着你越 nice, 你的优先级越低, 越不 nice (负值), 你的优先级就越高. 当前 Linux 系统里面, nice 的值相差一个单位, 一个时间区间内大概运行时间比原来是 1:1.25.

PolicyStatic PriorityDynamic Priority(nice)
SCHED_OTHER0-20 ~ 19
SCHED_RR0 ~ 99N/A

我们看到上面说 Linux 的 Real-time 的线程优先级是 1(低) ~ 99(高), 而 Normal 的线程优先级是 0, 根据 nice 可以调整的值, Normal 线程可以做到nice 的值 -20 ~ 19, 如果 mapping 的到优先级, 则可以是 0 ~ 39. 这里 0 ~ 39 值越低, 优先级越高. 如果把 Real-time 的优先级都加一个负号, 就变成了 -99(高) ~ 1(低), 那么就可以连起来了. 所有优先级是: -99 ~ 1, 0 ~ 39, 并且值越小, 优先级越高. 所以可以认为 Normal 的优先级默认是 20(本来是 0), 通过 nice 改成了 0(-20) ~ 39 (19). 这样一来, 是不是就跟 top 里面的 prio 和 ni 值匹配了?

普通用户只能使用 nice 的值把进程调的更 nice (0 ~ 20), 不能调的更不 nice (-10 ~ -1). 但是 root 可以.

另外, 当没有 CPU 竞争的时候, 比如系统有 8 个 CPU, 只有 3 个在忙, Priority 基本不起作用.

参考: https://man7.org/linux/man-pages/man7/sched.7.html

Linux 线程的状态

通常的操作系统概念里, 都会区分进程和线程, 可是在 Linux 内核里面, 对于系统调度来说, 它不区分进程和线程, 统一的术语都是线程(Thread), 线程做为调度的基本单位.

对于一个系统来说, 硬件的处理器(CPU)个数(插槽数), 一个 CPU 上的核(core)的数量, 一个核上的硬件线程数(Hyper-Thread)数都是有限的. 有的线程正在 CPU 上运行(on-cpu), 有的不在 CPU 上运行(off-cpu). 那么对于 Thread 来说, 它有哪些状态呢?

通常我们会在 Linux 上面看到这些状态:
• Runnable state 可运行状态,正在 CPU 运行或在队列等待运行
• Sleeping state 等待 I/O 或 调用 sleep 函数 响应 其它 interrupt
• Uninterruptable sleep state 等待 I/O 不响应其它 interrupt
• Defunct or Zombie state 等待父线程/root 线程 ack 死亡

为什么会有僵尸(Zombie)状态?
每个进程运行结束之后, 会返回一个状态码, 本身结束运行之后, 进入 Zombie 状态, 然后创建它的父进程(除了 1 号进程没有父进程)收到这个状态码, 做个响应, 它就可以正常死亡了. 如果它的父进程一直没时间响应, 它就会一直停留在 Zombie 状态. 如果某个进程的父进程早就自己死亡了, 那么 1 号进程就会作为它的父进程进行响应.

如果在 ps 命令下, 我们能看到稍多状态:

D    uninterruptible sleep (usually IO)
I    Idle kernel thread
R    running or runnable (on run queue)
S    interruptible sleep (waiting for an event to complete)
T    stopped by job control signal
t    stopped by debugger during the tracing
X    dead (should never be seen)
Z    defunct ("zombie") process, terminated but not reaped by its parent

对于 ps 命令, 这些状态从哪里获得?
从 /proc//task//status 得到, 比如:

supra@suprabox:/proc/3119/task/3125$ cat /proc/3119/task/3125/status
Name:    gmain
Umask:    0002
State:    S (sleeping)
Tgid:    3119

对于 sleep 的线程, 它到底从哪个函数进入的 sleep?
通过 cat /proc//task//wchan 可获得(wchan: waiting channel), 比如:

cat /proc/3119/task/3125/wchan
poll_schedule_timeout.constprop.13

进入 sleep (S & D) 状态的线程, Scheduler 不会再给他们安排 CPU 执行它们的代码. 当线程进入 sleep 之前, 它会进入内核态, 更新它自己在内核的里面 scheduler 数据结构的状态, 告诉内核scheduler 把自己从等待执行的队列中放到一个等待队列中. 当自己等待的信号(I/O interrupt 或者 sleep的时间到), 内核处理 interrupt 的内核进程会重新把它们放到认为等待执行队列. 于是它们重新获得执行机会.