分类 Troubleshooting 相关 下的文章

Java 里面的 connect timeout 的实现

在如今的微服务应用中, 有很多的服务之间相互调用. 在服务调用的时候, 我们都会设置 connect timeoutread timeout, 那么这个 connect timeout 的逻辑是什么样子的? JDK 里面到底是怎么实现的?

下面我们以一个简单的URL连接的例子, 来看这个 connect timeout 是如何工作的.

连接例子

下面是我们用来演示的代码, 它的意图就是不断的循环去获得某个网页. 不断循环的目的是为了给我们的手工操作留有足够的时间. 这段代码有网络操作, 所以会调用系统调用 connect 来拿到响应(response), 对应 bpftrace 里面的 tracepoint:syscalls:sys_enter_connect.(感谢 chatGPT 给我们演示代码)

import java.io.BufferedReader;
import java.io.InputStreamReader;
import java.net.HttpURLConnection;
import java.net.URL;

public class URLTest {
    public static void main(String[] args) throws Exception {
        for (int i = 0; i < 1000; i++) {
            try {
                URL url = new URL("http://www.tianxiaohui.com");
                HttpURLConnection con = (HttpURLConnection) url.openConnection();
                con.setRequestMethod("GET");
                con.setConnectTimeout(5000); // 连接超时时间 5000ms
                con.setReadTimeout(10000); // 读取超时时间 10000ms
                System.out.println(i + "Response code: " + con.getResponseCode());
                BufferedReader in = new BufferedReader(new InputStreamReader(con.getInputStream()));
                String line;
                StringBuilder response = new StringBuilder();
    
                while ((line = in.readLine()) != null) {
                    response.append(line);
                }
                in.close();
                //System.out.println(response.toString());
            } catch (Exception e) {
                e.printStackTrace();
                System.out.println(e.getMessage());
            }
            Thread.sleep(2000);
        }
    }
}

获取调用栈

我们可以通过拦截系统调用 connect 的时候, 去获取调用栈, 然后依次查看调用栈里面的方法, 来确认哪里使用了 timeout, 啥如何使用的.

通过 bpftrace 获取的 connect 调用栈

$ sudo bpftrace -e 'tracepoint:syscalls:sys_enter_connect /pid==288407/ { @[ustack(20)] = count(); }'
Attaching 1 probe...
^C

@[
    __connect+75
    Java_java_net_PlainSocketImpl_socketConnect+687
    Ljava/net/PlainSocketImpl;::socketConnect+213
    Ljava/net/AbstractPlainSocketImpl;::doConnect+332
    Ljava/net/AbstractPlainSocketImpl;::connect+444
    Ljava/net/Socket;::connect+596
    Lsun/net/NetworkClient;::doConnect+1208
    Lsun/net/www/http/HttpClient;::openServer+72
    Lsun/net/www/http/HttpClient;::openServer+332
    Lsun/net/www/http/HttpClient;::<init>+924
    Lsun/net/www/http/HttpClient;::New+1284
    Lsun/net/www/protocol/http/HttpURLConnection;::plainConnect0+3156
    Lsun/net/www/protocol/http/HttpURLConnection;::plainConnect+260
    Lsun/net/www/protocol/http/HttpURLConnection;::getInputStream0+2000
    Lsun/net/www/protocol/http/HttpURLConnection;::getInputStream+196
    Ljava/net/HttpURLConnection;::getResponseCode+96
    Interpreter+4352
    call_stub+138
    JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, Thread*)+883
    jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .constprop.1]+682
]: 1

通过 strace 获取的调用栈

$ sudo strace --stack-trace  -f -e trace=connect  -p  288407
[pid 288408] connect(5, {sa_family=AF_INET6, sin6_port=htons(80), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::ffff:23.222.245.123", &sin6_addr), sin6_scope_id=0}, 28) = 0
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__connect+0x4b) [0x12771b]
 > /usr/lib/jvm/java-11-openjdk-amd64/lib/libnet.so(NET_Connect+0xaa) [0xfd0a]
 > /usr/lib/jvm/java-11-openjdk-amd64/lib/libnet.so(Java_java_net_PlainSocketImpl_socketConnect+0x2af) [0xd30f]
 > unexpected_backtracing_error [0x7fd780780995]

哪里使用了 timeout

根据 bpftrace 给出的调用栈, 我们依次排查每个方法, 发现从 Ljava/net/Socket;::connect 开始, 就获取了当前设置的 connect timeout 值, 然后依次向下传递, 直到 JDK 里面的 C 代码 Java_java_net_PlainSocketImpl_socketConnect. 真正使用 timeout 的地方, 就在这个方法里面. 代码如下 (JDK11) https://github.com/openjdk/jdk11/blob/37115c8ea4aff13a8148ee2b8832b20888a5d880/src/java.base/unix/native/libnet/PlainSocketImpl.c#L344-L372

while (1) {
    jlong newNanoTime;
    struct pollfd pfd;
    pfd.fd = fd;
    pfd.events = POLLOUT;

    errno = 0;
    connect_rv = NET_Poll(&pfd, 1, nanoTimeout / NET_NSEC_PER_MSEC);

    if (connect_rv >= 0) {
        break;
    }
    if (errno != EINTR) {
        break;
    }

    /*
        * The poll was interrupted so adjust timeout and
        * restart
        */
    newNanoTime = JVM_NanoTime(env, 0);
    nanoTimeout -= (newNanoTime - prevNanoTime);
    if (nanoTimeout < NET_NSEC_PER_MSEC) {
        connect_rv = 0;
        break;
    }
    prevNanoTime = newNanoTime;

} /* while */

这是一个循环, 只有满足某些条件, 才会跳出. 涉及到 timeout 的地方, 有2处, 一处是 NET_Poll, 它的定义在: https://github.com/openjdk/jdk11/blob/37115c8ea4aff13a8148ee2b8832b20888a5d880/src/java.base/linux/native/libnet/linux_close.c#L407, 可以看到, 它其实是调用了 系统调用 poll, 这个 poll 可以传入一个timeout, 当timeout的时候, 返回0. 另外一处是下面的每次 nanoTimeout -= (newNanoTime - prevNanoTime), 相当于把已经过去的时间剪掉, 看 timeout 还剩余多少. 但是不论那种方式timeout, connect_rv 的值都会是0.

所以, 我们可以看到接着就有了下面的代码:

if (connect_rv == 0) {
   JNU_ThrowByName(env, JNU_JAVANETPKG "SocketTimeoutException",
                            "connect timed out");
   ...省略 ...
}

所以, 真正的 timeout 的处理, 要么是在 poll 的系统调用, 要么是在一个循环里面每次循环递减, 直到减没.

在结尾时候, 我们可以思考这吗一个问题: 当不设置timeout, 真的就永远等下去吗?

bpftrace 探测 Java 运行时栈-实践

开发Java应用的时候, 有时候我们想知道某个函数到底在哪里被调用的. 我们可以采取的方法有:

  1. 若是本地开发, 可以在函数体上加断点, 每当函数被调用, 都会暂停.
  2. 若是我们可以改动的代码, 我们可以加日志打印栈, 这样就能发现在哪里被调用.
  3. 不论是不是我们自己的Java代码, 我们都可以通过 Btrace 进行注入脚本, 在脚本打印运行时栈.

但是有时候, 我们想知道我们的 Java 代码是哪里调用了系统的 native 代码, 比如某些系统调用(syscall), 那么该如何获取这些栈呢?

这时候, 使用Java 提供的这些方法, 都无法达到目的, 所以, 我们要借用系统层级的 tracing 方式. 如今最流行且最简单的方式就是使用 bpftrace. 本文接下来将用一个例子来说明, 如何使用 bpftrace 来查找我们的Java应用是如何调用 recvfrom 这个系统调用的.

Java 代码

下面是我们用来演示的代码, 它的意图就是不断的循环去获得某个网页. 不断循环的目的是为了给我们的手工操作留有足够的时间. 这段代码有网络操作, 所以会调用系统调用 recvfrom 来拿到响应(response).(感谢 chatGPT 给我们演示代码)

import java.io.BufferedReader;
import java.io.InputStreamReader;
import java.net.HttpURLConnection;
import java.net.URL;

public class URLTest {
    public static void main(String[] args) throws Exception {
        for (int i = 0; i < 1000; i++) {
            try {
                URL url = new URL("http://www.tianxiaohui.com");
                HttpURLConnection con = (HttpURLConnection) url.openConnection();
                con.setRequestMethod("GET");
                System.out.println(i + "Response code: " + con.getResponseCode());
                BufferedReader in = new BufferedReader(new InputStreamReader(con.getInputStream()));
                String line;
                StringBuilder response = new StringBuilder();
    
                while ((line = in.readLine()) != null) {
                    response.append(line);
                }
                in.close();
                //System.out.println(response.toString());
            } catch (Exception e) {
                e.printStackTrace();
                System.out.println(e.getMessage());
            }
            Thread.sleep(2000);
        }
    }
}

本地编译并运行

$ javac URLTest.java
$ java -XX:+PreserveFramePointer URLTest
Response code: 301

安装编译 perf-map-agent

下载

可以直接克隆这个 git repo:

$ git clone https://github.com/jvm-profiling-tools/perf-map-agent.git

或者直接下载最新的代码

$ curl https://github.com/jvm-profiling-tools/perf-map-agent/archive/refs/heads/master.zip --output perf-map-agent.zip
$ unzip perf-map-agent.zip

编译

$ cd perf-map-agent
$ cmake .
$ make 

生成JIT编译后符号表

# 获取 java 进程号
$ jcmd 
3408161 jdk.jcmd/sun.tools.jcmd.JCmd
3406489 URLTest

# 设置 JAVA_HOME
$ export JAVA_HOME=/usr/lib/jvm/java-11-openjdk-amd64

# 生成符号表
$ bin/create-java-perf-map.sh 3406489

# 查看符号表
ls -lah /tmp/perf-3406489.map
-rw-rw-r-- 1 root root 42K Nov 15 05:08 /tmp/perf-3406489.map

bpftrace 获取调用栈

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_recvfrom /pid==3406489/{ @[ustack(20)] = count(); }'
Attaching 1 probe...
^C

@[
    recvfrom+116
]: 2
@[
    __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
    Lsun/net/www/protocol/http/HttpURLConnection;::getInputStream0+3828
    call_stub+138
    JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, Thread*)+883
    jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .constprop.1]+682
    jni_CallStaticVoidMethod+352
    JavaMain+3441
    ThreadJavaMain+13
    start_thread+755
]: 3

把翻译代码变成编译代码

java -XX:+PreserveFramePointer -XX:-TieredCompilation -XX:CompileThreshold=1 URLTest

    __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

调大code cache

在Java中,您可以通过设置-XX:ReservedCodeCacheSize标志来调整JIT代码缓存的大小。该标志控制JIT编译器可用来存储生成的代码的本机内存的最大数量。默认情况下,代码高速缓存的大小由平台确定 - 32位JVM通常为240MB,而64位JVM通常为480MB。

要调整JIT代码缓存区的大小,可以将-XX:ReservedCodeCacheSize标志设置为自定义值。该值应以字节为单位指定,并且可以是2的幂次方或2048(2KB)的倍数。以下是将标志设置为512MB的示例:

java -XX:ReservedCodeCacheSize=536870912 <your_program>
这将将JIT代码缓存的最大大小设置为512MB。

请注意,增加JIT代码缓存的大小可以通过允许JIT编译器在内存中存储更多的生成代码来提高性能。但是,这也会增加应用程序的内存使用量。您应仔细调整代码缓存的大小,并监视应用程序的内存使用情况,以确保它不超过系统上的可用内存。

bpftrace 探测 Java 运行时栈-实践

开发Java应用的时候, 有时候我们想知道某个函数到底在哪里被调用的. 我们可以采取的方法有:

  1. 若是本地开发, 可以在函数体上加断点, 每当函数被调用, 都会暂停.
  2. 若是我们可以改动的代码, 我们可以加日志打印栈, 这样就能发现在哪里被调用.
  3. 不论是不是我们自己的Java代码, 我们都可以通过 Btrace 进行注入脚本, 在脚本打印运行时栈.

但是有时候, 我们想知道我们的 Java 代码是哪里调用了系统的 native 代码, 比如某些系统调用(syscall), 那么该如何获取这些栈呢?

这时候, 使用Java 提供的这些方法, 都无法达到目的, 所以, 我们要借用系统层级的 tracing 方式. 如今最流行且最简单的方式就是使用 bpftrace. 本文接下来将用一个例子来说明, 如何使用 bpftrace 来查找我们的Java应用是如何调用 recvfrom 这个系统调用的.

Java 代码

下面是我们用来演示的代码, 它的意图就是不断的循环去获得某个网页. 不断循环的目的是为了给我们的手工操作留有足够的时间. 这段代码有网络操作, 所以会调用系统调用 recvfrom 来拿到响应(response).(感谢 chatGPT 给我们演示代码)

import java.io.BufferedReader;
import java.io.InputStreamReader;
import java.net.HttpURLConnection;
import java.net.URL;

public class URLTest {
    public static void main(String[] args) throws Exception {
        for (int i = 0; i < 1000; i++) {
            try {
                URL url = new URL("http://www.tianxiaohui.com");
                HttpURLConnection con = (HttpURLConnection) url.openConnection();
                con.setRequestMethod("GET");
                    con.setConnectTimeout(5000); // 连接超时时间 5000ms
                    con.setReadTimeout(10000); // 读取超时时间 10000ms
                System.out.println(i + "Response code: " + con.getResponseCode());
                BufferedReader in = new BufferedReader(new InputStreamReader(con.getInputStream()));
                String line;
                StringBuilder response = new StringBuilder();
    
                while ((line = in.readLine()) != null) {
                    response.append(line);
                }
                in.close();
                //System.out.println(response.toString());
            } catch (Exception e) {
                e.printStackTrace();
                System.out.println(e.getMessage());
            }
            Thread.sleep(2000);
        }
    }
}

本地编译并运行

使用 javac 编译源代码, 生成 URLTest.class. 然后启动这个带有 main 函数的类. 这里添加参数 -XX:+PreserveFramePointer 是为了在运行方法的时候保留栈指针寄存器, 这样就能使 bpftrace 获得运行时的栈. 运行开始, 输出返回的 response code.

$ javac URLTest.java
$ java -XX:+PreserveFramePointer URLTest
Response code: 301

安装编译 perf-map-agent

为了使用 bpftrace 能获得Java JIT 编译后的代码的符号, 需要通过 perf-map-agent Java agent 去获取运行时 Java 应用的符号表, 更确切来说, 是获得通过 JIT 编译后的的代码的符号表.

perf-map-agent 是一个Java agent, 它在运行时attach到目标Java进程, 然后获取JVM运行时内部JIT编译后代码的区域内存, 然后通过这个区域获取符号表, 然后把这些符号表以 Linux perf 能认识的格式放到 /tmp/perf-<pid>.map 文件中. bpftrace 底层ye shi

下载 perf-map-agent

可以直接克隆这个 git repo:

$ git clone https://github.com/jvm-profiling-tools/perf-map-agent.git

或者直接下载最新的代码

$ curl https://github.com/jvm-profiling-tools/perf-map-agent/archive/refs/heads/master.zip --output perf-map-agent.zip
$ unzip perf-map-agent.zip

编译

这个项目里面包含一些 C 代码, 需要先编译成 binary. 并且这个项目提供了一些脚本帮助我们快速生成符号表.

$ cd perf-map-agent
$ cmake .
$ make 

生成JIT编译后符号表

准备工作已经完成, 那么我们现在可以生成符号表了. 首先获取目标Java 进程的进程号, 然后设置 JAVA_HOME 环境变量, 因为 perf-map-agent 需要这个环境变量. 最后运行 bin/create-java-perf-map.sh 生成符号表.

# 获取 java 进程号
$ jcmd 
3408161 jdk.jcmd/sun.tools.jcmd.JCmd
3406489 URLTest

# 设置 JAVA_HOME
$ export JAVA_HOME=/usr/lib/jvm/java-11-openjdk-amd64

# 生成符号表
$ bin/create-java-perf-map.sh 3406489

# 查看符号表
ls -lah /tmp/perf-3406489.map
-rw-rw-r-- 1 root root 42K Nov 15 05:08 /tmp/perf-3406489.map

bpftrace 获取调用栈

万事俱备, 现在我们就可以通过 bpftrace 获取目标进程是如何调用 recvfrom 找个系统调用的了.
我们使用的probe event 是 tracepoint:syscalls:sys_enter_recvfrom, 设置过滤条件是我们的目标进程pid==3406489, 然后统计用户栈的出现的次数. 这里我们只截取用户栈的20行.

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_recvfrom /pid==3406489/{ @[ustack(20)] = count(); }'
Attaching 1 probe...
^C

@[
    recvfrom+116
]: 2
@[
    __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
    Lsun/net/www/protocol/http/HttpURLConnection;::getInputStream0+3828
    call_stub+138
    JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, Thread*)+883
    jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .constprop.1]+682
    jni_CallStaticVoidMethod+352
    JavaMain+3441
    ThreadJavaMain+13
    start_thread+755
]: 3

上面的结果里面, 我们可以看到2处不同的调用栈, 第一个调用栈只有一行, 不是我们代码调用的. 第二个栈是从我们的代码发出的, 共被调用了 3次.

最上面的一行 __GI___recv+110 找个代码是 glibc 里面的. __GI__ 表示这是 Linux 上的标准C库 GNU C Library (glibc)里面的代码. “GI”前缀用于由 glibc 的动态链接器内部重定向到其在库中实现的函数。 这些函数称为“global indirect”或“indirect”函数,它们的实际实现驻留在运行时加载的动态链接库中。所以__GI___recv 是glibc 里面的一个函数, 它调用了系统调用 recvfrom.

接着一行Java_java_net_SocketInputStream_socketRead0 是JDK 中的C 代码, 我们可以在 JDK 原代码中找到它.

然后接着是一些 Java 的代码, 只不过这些都是运行时翻译的, 所以没有符号给我们看, 只能看到关键字 Interpreter.

然后 Lsun/net/www/protocol/http/HttpURLConnection;::getInputStream0 这是Java 代码通过JIT 编译后产生的代码, 然后程序通过 /tmp/perf-3406489.map 获得了符号表, 然后展示在这.

为了搞清楚到底是怎么一层层到 Java_java_net_SocketInputStream_socketRead0的, 我们需要把翻译的这部份也通过 JIT 编译成native 代码.

把翻译代码变成编译代码

在 Java 运行时, 当一个方法在一个滑动时间窗口内, 达到了足够的执行次数之后, 就会被编译成native 代码. 所以, 为了让我们看到的被翻译的代码也被编译, 需要关掉分层编译 -XX:-TieredCompilation, 并且把需要编译的最低次数设置的足够低 -XX:CompileThreshold=1, 这里我们设置成1次.

再次运行找个 Java 应用, 并且再次执行 bpftrace, 我们获得了如下的代码栈.

$ java -XX:+PreserveFramePointer -XX:-TieredCompilation -XX:CompileThreshold=1 URLTest

$ sudo bpftrace -e 'tracepoint:syscalls:sys_enter_recvfrom /pid==<pid>/{ @[ustack(20)] = count(); }'
    __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

调大code cache

在Java中,您可以通过设置-XX:ReservedCodeCacheSize标志来调整JIT代码缓存的大小。该标志控制JIT编译器可用来存储生成的代码的本机内存的最大数量。默认情况下,代码高速缓存的大小由平台确定 - 32位JVM通常为240MB,而64位JVM通常为480MB。

要调整JIT代码缓存区的大小,可以将-XX:ReservedCodeCacheSize标志设置为自定义值。该值应以字节为单位指定,并且可以是2的幂次方或2048(2KB)的倍数。以下是将标志设置为512MB的示例:

java -XX:ReservedCodeCacheSize=536870912 <your_program>
这将将JIT代码缓存的最大大小设置为512MB。

请注意,增加JIT代码缓存的大小可以通过允许JIT编译器在内存中存储更多的生成代码来提高性能。但是,这也会增加应用程序的内存使用量。你应仔细调整代码缓存的大小,并监视应用程序的内存使用情况,以确保它不超过系统上的可用内存。

关于 Java SocketReadTimeout

在诊断Java应用程序的诊断过程中, 竟然会遇到 Connect timeout, Socket read timeout. 但是经常会遇到有些有些开发人员对这些概念有些误解. 本文就涉及到一些细节使用一些例子做些说明, 使大家更容易理解.

一个简单的例子

Jersey 做为 Jax-RS 的参考实现, 被广泛用于 Java 应用开发. 下面使用 Jersey 开发一个客户端的例子.

import java.net.URI;

import javax.ws.rs.client.Client;
import javax.ws.rs.client.ClientBuilder;
import javax.ws.rs.client.WebTarget;
import javax.ws.rs.core.MediaType;
import javax.ws.rs.core.Response;
import javax.ws.rs.core.UriBuilder;

import org.glassfish.jersey.client.ClientConfig;
import org.glassfish.jersey.client.ClientProperties;
...

public String callRestSvc() {
        ClientConfig config = new ClientConfig();
                config.property(ClientProperties.CONNECT_TIMEOUT, 500);
        config.property(ClientProperties.READ_TIMEOUT, 3000);
        Client client = ClientBuilder.newClient(config);
        WebTarget target = client.target(UriBuilder.fromUri("http://localhost:8080/").build());
        try {
            return target.path("rest").
                    request().
                    accept(MediaType.TEXT_PLAIN).
                    async().
                    get(String.class).get(10, TimeUnit.SECONDS);
        } catch (InterruptedException | ExecutionException e) {
            throw new RuntimeException(e);
        } catch (TimeoutException e) {
            throw new RuntimeException(e);
        }
    }

服务端的 Socket Read/Write timeout

Tomcat NIO

SocketTimeoutException 的初始化方法上设置断点, 然后可以看到下面的 Tomcat 异常栈.

SocketTimeoutException.<init>() (java.net.SocketTimeoutException:49)
NioEndpoint$Poller.timeout() (org.apache.tomcat.util.net.NioEndpoint$Poller:1086)
NioEndpoint$Poller.run() (org.apache.tomcat.util.net.NioEndpoint$Poller:852)
Thread.run() (java.lang.Thread:829)

如何判断是不是 timeout

Tomcat 每次在读取(read())的时候, 记录当前时间. 每次循环的时候(link)就检查是不是有 timeout: 检查当前时间和上次读的时间的差值, 如果大于设置的 timeout 值, 就设置 error: timeout exception.
code: https://github.com/apache/tomcat/blob/ec8ef7a3a2fa56afb4db4261ebdc0aba848f23ff/java/org/apache/tomcat/util/net/NioEndpoint.java#L1017-L1050

if (socketWrapper.interestOpsHas(SelectionKey.OP_READ)) {
    long delta = now - socketWrapper.getLastRead();
    long timeout = socketWrapper.getReadTimeout();
    if (timeout > 0 && delta > timeout) {
        readTimeout = true;
    }
}
// Check for write timeout
if (!readTimeout && socketWrapper.interestOpsHas(SelectionKey.OP_WRITE)) {
    long delta = now - socketWrapper.getLastWrite();
    long timeout = socketWrapper.getWriteTimeout();
    if (timeout > 0 && delta > timeout) {
        writeTimeout = true;
    }
}                          

Tomcat NIO 2

Tomcat NIO 2 的 Endpoint 直接使用的是 java.util.concurrent.Future 的 timeout 设置:
link: https://github.com/apache/tomcat/blob/ec8ef7a3a2fa56afb4db4261ebdc0aba848f23ff/java/org/apache/tomcat/util/net/Nio2Endpoint.java#L1130-L1162

if (block) {
    try {
        integer = getSocket().read(to);
        long timeout = getReadTimeout();
        if (timeout > 0) {
            nRead = integer.get(timeout, TimeUnit.MILLISECONDS).intValue();
        } else {
            nRead = integer.get().intValue();
        }
    } catch (ExecutionException e) {
        if (e.getCause() instanceof IOException) {
            throw (IOException) e.getCause();
        } else {
            throw new IOException(e);
        }
    } catch (InterruptedException e) {
        throw new IOException(e);
    } catch (TimeoutException e) {
        integer.cancel(true);
        throw new SocketTimeoutException();
    } finally {
        // Blocking read so need to release here since there will
        // not be a callback to a completion handler.
        readPending.release();
    }
} else {
    startInline();
    getSocket().read(to, toTimeout(getReadTimeout()), TimeUnit.MILLISECONDS, to,
            readCompletionHandler);
    endInline();
    if (readPending.availablePermits() == 1) {
        nRead = to.position();
    }
}

客户端的 Socket read timeout

BIO

HttpUrlConnection

HttpUrlConnection 就是使用的 BIO, 它自己是使用native 代码实现的 timeout.

NIO

例子的改正

这样即实现了最长等多少秒, 又不忘在后来的response 时候消费掉 entity, 保证连接释放.

public String asyncQuery() throws UnsupportedEncodingException, ExecutionException, InterruptedException, TimeoutException {
        WebTarget target = logsTarget.path("/").queryParam("style", "increase");
        System.out.println("url " + target.getUri().toString());
        CompletableFuture<String> result = new CompletableFuture<>();

        target.request(MediaType.APPLICATION_JSON).async().get(new InvocationCallback<String>() {

            @Override
            public void completed(String response) {
                System.out.println("I get response: " + response);
                result.complete(response);
            }

            @Override
            public void failed(Throwable throwable) {
                System.out.println("faied with URL " + target.getUri().toString() + " " + throwable.getMessage());
                result.completeExceptionally(throwable);
            }
        });

        return result.get(10, TimeUnit.SECONDS);
    }

如何从未读的 Socket Buffer 中读出数据

在诊断Java应用的过程中, 经常发现有些 Socket 连接还没读, 然后就被放弃了, 然后应用程序对这些连接就置之不理, 导致连接泄漏.

当发生连接泄漏之后, 要去诊断是那个地方导致的连接泄漏, 于是就是一个逆向的过程. 从开始知道连接泄漏的URL找到泄漏的代码. 如果这些泄漏的连接还在 Java 内存, 可以从 heap 当中找到这些 Socket, 然后读取其中未读的 Request/Response, 这样就能很容易的找到当时访问的什么请求, 对方发回的什么响应, 然后去审察代码.

如何找到这些 Socket

假如你知道要访问的 URL, 一般一个 OQL 就能查询到对应的socket, 比如:

SELECT * FROM org.apache.http.impl.conn.DefaultClientConnection c WHERE (toString(c.targetHost.hostname) like ".*.online-metrix.net")![request.png][1]

从Socket 读取请求数据

request.png

从 Socket 读取响应数据

response.png