设置SO_TIMEOUT，为什么还有大于超时阈值的请求？扒一下HotSpot源码看看

野英狼
216 阅读11分钟

由于Redis对时延的要求都非常高， 大多数服务都将超时时间设置成1s，防止由于网络抖动等不可预知的原因导致请求迟迟无法返回而最终导致服务雪崩的情况；
但即便如此，在监控面板上也会发现请求超时高达2s的情况？所以有些同学就有疑问了，我设置了请求超时时间为1s，请求时长最长不应该是1s吗？为什么有些请求还有超过1s呢？

可能很多人印象中，SO_TIMEOUT应该是这样的
SO_TIMEOUT = RTT = 三段时间组成：即 1+2+3；即请求发送到Server的网络耗时 + Server自身处理的耗时 + 响应返回Client的网络耗时；
file

但实际上如此吗？我们一起看看源码探讨一下

目前Redis-SDK有两种客户端；

  1. 一种是Jedis（利用BIO进行和Redis Server通信）；此篇文章重点讨论此客户端
  2. 一个是Lettuce（背靠Netty，使用Netty的异步能力和Redis Server通信）；后续在讨论

Jedis

首先先了解下内核中Socket的关键配置

Socket关键参数

首先我们先了解下关键参数，从中看看是否有蛛丝马迹；
在Java的Socket定义中

Socket常见参数含义
SO_TIMEOUT读取数据所需要的耗时 ；注：这是JVM封装的Socket参数
SO_LINGER调用close后套接字的行为；on：0/1代表是否开启，linger：写缓存区数据滞留时间； on=0，代表一旦close，socket缓存区的数据不再进行管理，而是交给内核发送出去，不再关心发送成功或者失败；on=1，linger=0，表示立刻将SND_BUF中的数据丢失，同时发送RST报文；on=1，ling>0，表示将SND_BUF中的数据在linger时间范围内完整的发送出去（不报错）后，进行正常的四次挥手
Tcp_No_Delay收到Tcp包后，是否立刻发送出去；实时性比较高，但是比较消耗性能
SO_RCVBUF接收缓存区的大小
SO_SNDBUF发送缓存区的大小
SO_KEEPALIVE是否保持长连接
SO_REUSEADDR是否重用在close_wait状态的地址

注意：这两个定义是没有在Java的Socket中体现的；

Socket常见参数含义
SO_RCV_TIMEOUT在此段时间内，未接收到数据；或者未接收完，就会报错
SO_SND_TIMEOUT在此段时间内，没有写数据；或者未写完，就会报错

那在Jedis中，我们设置的SO_TIMEOUT参数作用在哪里了？

源码溯源

简单样例

        JedisPool jedisPool = new JedisPool("localhost", 6379);
        try(Jedis jedis = jedisPool.getResource()) {
            jedis.setex("abc",12,"12b");
            System.out.println(jedis.get("abc"));

        }

源码分析

主干功能流程图

file

功能入口 redis.clients.jedis.Jedis#get
  1. 检查是否开启事务、pipeline
  2. 交给Connection进行处理；在这里Jedis对象更像是一个代理门面；
public String get(final String key) {
  checkIsInMultiOrPipeline();
  return connection.executeCommand(commandObjects.get(key));
}
执行命令 redis.clients.jedis.Connection#executeCommand
  1. 将命令发送出去，（sendCommand）
  2. 阻塞并等待返回结果
  3. 将结果封装，返回给客户端
  4. 重点在：getOne()
public <T> T executeCommand(final CommandObject<T> commandObject) {
  final CommandArguments args = commandObject.getArguments();
  // 根据RESP格式将命令封装完成后，写入到SocketOutputStream，
  sendCommand(args);
  if (!args.isBlocking()) {
  // getOne
    return commandObject.getBuilder().build(getOne());
  } else {
    try {
      setTimeoutInfinite();
      return commandObject.getBuilder().build(getOne());
    } finally {
      rollbackTimeout();
    }
  }
}
获取执行结果 redis.clients.jedis.Connection#getOne
public Object getOne() {
   // flush data
  flush();
  return readProtocolWithCheckingBroken();
}


protected Object readProtocolWithCheckingBroken() {
  if (broken) {
    throw new JedisConnectionException("Attempting to read from a broken connection");
  }

  try {
     // 开始通过将inputStream中的数据读出来
    return Protocol.read(inputStream);
}

...... 省略调用过程，直接调到read

private void ensureFill() throws JedisConnectionException {
  if (count >= limit) {
    try {
     // 如果还没有到当前最大容纳值，则可以从inputstream读取数据，读到buf中
      limit = in.read(buf);
      count = 0;
      if (limit == -1) {
        throw new JedisConnectionException("Unexpected end of stream.");
      }
    } catch (IOException e) {
      throw new JedisConnectionException(e);
    }
  }
}
java.net.SocketInputStream#read

利用JNI调用JVM中的实现

public int read(byte b[], int off, int length) throws IOException {
    // 此处将so_timeout作为一个参数传入
    return read(b, off, length, impl.getTimeout());
}

..... 省略若干次调用流转

// 利用JNI调用JVM的socketRead实现
private native int socketRead0(FileDescriptor fd,
                               byte b[], int off, int len,
                               int timeout)
    throws IOException;
HotSpot源码 Java_java_net_SocketInputStream_socketRead0

看下HotSpot里面的源码 对应版本OpenJDK_11.0.27

注：在此版本中，HotSpot调用poll系统调用，而不是select系统调用

  1. 当前传入了so_timeout，会调用Net_ReadWithTimeout方法，来获取数据；如果没有传入so_timeout，会一直阻塞这里等待结果返回；
  2. 异常场景，如果nread<=0, 那就会抛出诸多我们曾经在日志里面看到的异常
  3. 正常场景，会将读到的数据转换成java的数据结构返回给java侧；

src\java.base\unix\native\libnet\SocketInputStream.c

JNIEXPORT jint JNICALL
Java_java_net_SocketInputStream_socketRead0(JNIEnv *env, jobject this,
                                            jobject fdObj, jbyteArray data,
                                            jint off, jint len, jint timeout)
{
     
     ......省略
     
     
    // 如果设置了so_timeout，则会走此流程；
    if (timeout) {
        // 下文会讲此方法； 正常情况nread>0，代表已经读到数据，
        nread = NET_ReadWithTimeout(env, fd, bufP, len, timeout);
        if ((*env)->ExceptionCheck(env)) {
            if (bufP != BUF) {
                free(bufP);
            }
            return nread;
        }
    } else {
        nread = NET_Read(fd, bufP, len);
    }

    if (nread <= 0) {
        if (nread < 0) {
            // 这里是不是可以看到我们经常在日志里面看到Connection Reset、Socket Closed
            switch (errno) {
                case ECONNRESET:
                case EPIPE:
                    JNU_ThrowByName(env, "sun/net/ConnectionResetException",
                        "Connection reset");
                    break;

                case EBADF:
                    JNU_ThrowByName(env, "java/net/SocketException",
                        "Socket closed");
                    break;

                case EINTR:
                     JNU_ThrowByName(env, "java/io/InterruptedIOException",
                           "Operation interrupted");
                     break;
                default:
                    JNU_ThrowByNameWithMessageAndLastError
                        (env, "java/net/SocketException", "Read failed");
            }
        }
    } else {
        // 将数据转换到java的byte[]数组；
        (*env)->SetByteArrayRegion(env, data, off, nread, (jbyte *)bufP);
    }

    if (bufP != BUF) {
        free(bufP);
    }
    return nread;
}
超时轮询：SocketInputStream.c
  1. 将超时毫秒单位换算成纳秒
  2. 先检测是否有就绪读事件；如果有，则返回正数；如果result等于0，说明在这一段时间内没有可读数据，socket timeout； 如果result==-1，然后又有三种错误类型判断；
  3. 如果有就绪读事件，则触发NET_NonBlockingRead函数，非阻塞读；如果result=-1并且errno是EAGAIN、EWOULDBLOCK，说明可以重试，更新时间 ； 如果result>0，说明有可读数据，直接返回实际读取的字节数；
  4. 可以看出当前SO_TIMEOUT并不是作用在内核的Socket配置项中，而是在JVM层自己包装的一层超时检测；；作用是检测读数据是否超时

src\java.base\unix\native\libnet\SocketInputStream.c

static int NET_ReadWithTimeout(JNIEnv *env, int fd, char *bufP, int len, long timeout) {
    int result = 0;
    jlong prevNanoTime = JVM_NanoTime(env, 0);
    jlong nanoTimeout = (jlong) timeout * NET_NSEC_PER_MSEC;
    while (nanoTimeout >= NET_NSEC_PER_MSEC) {
        // 通过此方法判断是否有可读事件
        result = NET_Timeout(env, fd, nanoTimeout / NET_NSEC_PER_MSEC, prevNanoTime);
        if (result <= 0) {
            if (result == 0) {
                JNU_ThrowByName(env, "java/net/SocketTimeoutException", "Read timed out");
            } else if (result == -1) {
                if (errno == EBADF) {
                    JNU_ThrowByName(env, "java/net/SocketException", "Socket closed");
                } else if (errno == ENOMEM) {
                    JNU_ThrowOutOfMemoryError(env, "NET_Timeout native heap allocation failed");
                } else {
                    JNU_ThrowByNameWithMessageAndLastError
                            (env, "java/net/SocketException", "select/poll failed");
                }
            }
            return -1;
        }
        // 通过内核非阻塞读的方式，将数据读到bufP中；（其原理通过调用OS内核poll函数进行获取响应结果，如果没有，则返回EAGAIN；如果有响应结果，则将数据写入bufP中）
        result = NET_NonBlockingRead(fd, bufP, len);
        if (result == -1 && ((errno == EAGAIN) || (errno == EWOULDBLOCK))) {
            jlong newtNanoTime = JVM_NanoTime(env, 0);
            nanoTimeout -= newtNanoTime - prevNanoTime;
            if (nanoTimeout >= NET_NSEC_PER_MSEC) {
                prevNanoTime = newtNanoTime;
            }
        } else {
            break;
        }
    }
    return result;
}

Socket.write 有超时设置吗？

答案：没有

结论

  1. SO_TIMEOUT 是客户端用于控制Socket读取数据的超时时间（也就是下图中的阶段5）；如果从执行SocketInputStream.socketRead开始，在一段时间内没有读到数据，就会抛出SocketTimeoutException
  2. SO_TIMEOUT是JVM层设置的超时检测机制； SO_RCVTIMEOUT0 没有关系；SO_RCVTIMEOUT是OS层设置的接收时的超时时间，功能类似，但不等同； file

对于Jedis客户端，为什么还有大于超时阈值的请求呢？

背景知识
  1. Jedis使用的Socket阻塞模式；
  2. 系统调用write函数是将数据写入内核的Socket Write Buffer中，就会立刻返回；所以基本不会阻塞；只有SocketWriteBuffer满了，才会导致write函数阻塞；（一般Socket Write Buffer 满可能得原因有1、写入速率大于网卡发送速率；2、网络故障，导致数据一直重传、发送不出去）
  3. 公司封装的Redis-SDK中记录的是RTT，监控上的打点也是RTT时间，而由于历史原因，目前设置的超时时间是SO_TIMEOUT；这两个严格来说不是等价的；因为RTT是包括1+2+3+4+5这五个阶段处理；而SO_TIMEOUT统计的只有第五阶段的耗时；所以理论上两者相差4个阶段的GAP；但是当前Jedis客户端是将命令的发送和响应结果的接收放在一个方法里面了，将sendCommand（发送命令成功）后，就开始调用SocketInputStream.socketRead阻塞等待响应结果,所以可以大致理解成当前SO_TIMEOUT = 2+3+4+5阶段耗时之和；也就是近似等价了；
定位跟踪

当时有Redis命令超时，同时有同学也反馈有TCP超时；基于此，考虑是网络原因导致Redis超时，那即便是网络原因，redis命令在一个SO_TIMEOUT也会返回结果（只不过是异常结果），为什么会有2倍SO_TIMEOUT的耗时呢？ 排查一圈，终于找到问题根因；

jedis在网络异常的时候，会进行close，close的时候会调用quit命令；quit命令超时阻塞了

看下Jedis的源码

调用Jedis 关闭接口 redis.clients.jedis.Jedis#close
  1. 判断当前是否有JedisPool；若JedisPool==null，则直接close
  2. 若 JedisPool != null, 则会判断是否isBroken() 这个方法实际上是判断broken变量是否true；后续将在哪里赋值；
  3. 当前由于命令超时，所以会走到returnBrokenResource方法；
  public void close() {
    if (dataSource != null) {
      Pool<Jedis> pool = this.dataSource;
      this.dataSource = null;
      if (isBroken()) {
			// 这里就直接释放Jedis对象了，因为这个Jedis对象已经受损了；
        pool.returnBrokenResource(this);
      } else {
			// 这里是将jedis对象归还到JedisPool中，以方便重用；
        pool.returnResource(this);
      }
    } else {
      connection.close();
    }
  }
redis.clients.jedis.Connection#readProtocolWithCheckingBroken
  1. 如果读异常了，会捕获JedisConnectionException；并将broken变量赋值true
  2. 有人会有疑问了： 这里只捕获了JedisConnectionException，而SocketTimeoutException不是他的子类，这里也捕获不住呀？ 答案就在当in.read(buf)抛出SocketTimeoutException后，会被捕获，然后封装成了JedisConnectionException；（这里的细节就不在这展开了，不然逻辑太碎了）
  protected Object readProtocolWithCheckingBroken() {
	........
    try {
      return Protocol.read(inputStream);
    } catch (JedisConnectionException exc) {
		// 如果读超时了，报错了，就会将broken赋值为true，代表这个Connection已经损坏了；
      broken = true;
      throw exc;
    }
  }
	```
........
经过若干逻辑流转后，到达最重要的destroy流程了
##### 销毁对象 redis.clients.jedis.JedisFactory#destroyObject
1. 首先判断是否是连接状态，如果是连接状态，就会执行quit，进行和服务端进行建连
```java
  public void destroyObject(PooledObject<Jedis> pooledJedis) throws Exception {
    final BinaryJedis jedis = pooledJedis.getObject();
    if (jedis.isConnected()) {
      try {
        try {
          jedis.quit();
        } catch (Exception e) {
        }
        jedis.disconnect();
      } catch (Exception e) {

      }
    }

  }
redis.clients.jedis.BinaryJedis#quit
  1. 检查当前是否在事务或者pipeline中
  2. 往SocketOutputStream中发送quit命令；请求断联；
  3. 等待**SocketInputStream.read()**返回quit结果；所以这里又一次超时；
  public String quit() {
    checkIsInMultiOrPipeline();
    client.quit();
    return client.getStatusCodeReply();
  }
结论

根因就在于当出现网络抖动的情况，Jedis执行命令超时，在调用close方法的时，Jedis会发送一次quit命令，尝试通知redis server将这个连接关闭掉，但是此时网络也是在异常的情况，所以这次的quit命令也会超时；所以我们的预期应该是1倍-2倍的SO_TIMEOUT范围；
同时我们在看到最新的Jedis版本中，发现这个问题已经被修复了，不在发送quit命令了~(官方也觉得这个quit没啥必要)

案例

某主调的某集群在一段时间内出现多次超时情况，而且超时时间在2s左右；且出现超时的实例均在HB1AZ3；（其中SO_TIMEOUT=1s）

image.png 通过监控也正好看到有TCP超时情况；

Lettuce

SO_TIMEOUT是Java的Socket编程中特有的配置参数，在JVM层面进行做的超时检测，在Lettuce、Netty源码中并没有相关的设置；那Lettuce是怎么设置超时呢？

Lettuce是怎么设置超时时间呢？

答案是通过HashWheelTimer来进行设置的；

  1. 在Lettuce的调用链路上，增加一个HashWheelTimer的Task任务，交给HashWheelTimer进行检测；如果到期，并且Command还没有执行完成，就会往Command中设置LettuceTimeoutException，同时唤醒Command，回调通知；

Lettuce对应源码

io.lettuce.core.protocol.CommandExpiryWriter#potentiallyExpire

private void potentiallyExpire(RedisCommand<?, ?, ?> command, ScheduledExecutorService executors) {

    long timeout = applyConnectionTimeout ? this.timeout : source.getTimeout(command);

    if (timeout <= 0) {
        return;
    }

    if (CommandExpiryWriterUtils.isEnableTimerCheck()) {
        // 创建一个Task，将其放入到HashWheelTimer,如果到期，并且command也没有执行完，就会往Command中设置一个异常；
        Timeout commandTimeout = timer.newTimeout(it -> executors.submit(() -> {
            if (!command.isDone()) {
                command.completeExceptionally(ExceptionFactory.createTimeoutException(Duration.ofNanos(timeUnit.toNanos(timeout))));
            }
        }), timeout, timeUnit);

        if (command instanceof CompleteableCommand) {
            ((CompleteableCommand) command).onComplete((o, o2) -> {
                commandTimeout.cancel();
            });
        }
    }
    
    .......
    
}

Netty扩展

那在Netty这个异步网络框架模型中，哪些功能具有SO_RCVTIMEOUT、SO_SNDTIMEOUT类似的写入、超时检测的功能呢？
这块的内容后续再起一篇文章详细描述这些机制的源码实现，

  1. IdleStateHandler： 读写空闲检测机制，检测channelRead、write；用于判断当前handler 是否处于长时间空闲，如果处于长时间空闲，就会发送fireUserEventTriggered通知；
  2. ReadTimeoutHandler： IdleStateHandler子类，默认行为检测出长时间没有读到数据，就触发关闭事件通知；当然我们可以修改其默认的超时机制；
  3. WriteTimeoutHandler: 检测写入内容是否超时；（从第一次write到flush的时间），用于检测是否写入过长时间；
  4. HashWheelTimer ： 当前lettuce使用的就是这种机制；
  5. TCP_USER_TIMEOUT：作为内核Socket的一个配置参数，在Epoll网络模型下，Netty的源码里面也是通过JNI的方式嵌入C的代码，优化了Epoll的调用，并将这个参数成功带入（当然不只是这一个参数的优化）；具体可以参看Netty源码：transport-native-epoll包中的netty_epoll_linuxsocket.c

参考网址

  1. 从linux源码看socket(tcp)的timeout
  2. DeepSeek等AI模型
avatar
文章
阅读
粉丝