背景介绍
好久没有时间写文章了，今天跟大家分享最近在维护的老系统中的遇到的一个问题；由于老系统从公司创建初期就一直存在，笔者不会对现有系统不合理处进行分析，仅仅描述502异常的定位处理过程。
首先介绍下我们的业务场景，为了分析用户的行为轨迹，通过都需要将用户在客户端的行为日志上传到后端服务器上，消息流转图如下所示：
消息流转图
- 用户行为日志存储到本地系统中，或者是直接通过message-api请求公网的消息上报接口
- 用户行为日志累计到一定的大小后者超过一定时间的时候通过http upload接口将文件上传到埋点服务上
- Nginx将请求分发到后端的埋点服务集群上，埋点服务将文件下载在本地磁盘上
- 埋点服务中解析已经上传完毕的文件，通过解密、解析、转化为一条条的消息后发往Kafka系统中
问题描述
上述是整个埋点服务的消息流转和业务处理流程，从某一天开发，监控经常会出现某台机器流量突然下跌的情况，图中某一台机器的流量下跌了差不多30%（纵坐标不是从0开始），该问题差不多每天会出现好几次。
数据量监控图
问题追踪
首先怀疑是GC导致系统的抖动，登录到机器上查看了下GC日志，显示一切正常，接下来找运维同学一起查看了下Nginx上的access日志，发现出现了大量的502异常，具体消息为
502异常
nginx配置的策略是发现两次502响应后就认为是失败，在接下来的一段时间内（一般设置为30s）不会转发请求到该机器上；502异常一般是服务不可用，继续查看另外一台nginx上的日志，发现在这一刻有些访问请求是200的；说明服务不是完全不可用的，只是出现有些请求返回502。
知识回顾
由于笔者曾经有过相关的经验，怀疑是TCP请求队列满了，导致有些请求TCP请求无法建立，接下来先跟大家回顾下TCP三次握手的过程。
TCP传输过程
相信大家对TCP连接应该有相应的理解，笔者在此不做过多的介绍，有疑问的同学可以自行百度。
操作系统连接处理
接收端的操作系统内核收到客户端发来的SYNC请求后，会创建一个连接放入到SYNC队列中，当连接从SYNC_RECV变为ESTABLISHED状态时，请求从SYNC队列移交到ESTABLISH队列中。在这个过程中一定会出现队列满的状况，当ESTABLISH满的时候，连接就只能一直处于SYNC_RECV状态，一般称之为半连接状态；当SYNC队列满的时候则会拒绝连接。那这些队列长度如何控制呢，我们来看几个参数
net.ipv4.tcp_max_syn_backlog 处于半连接状态的队列长度
net.core.somaxconn 处于连接状态的队列长度
系统参数
查看了下我们的系统，两个参数都很大，按照我们的流量评估来算，不可能会达到这个阈值，由此排除是系统参数设置不合理导致的原因。
问题再分析
经过前面阶段分析后，笔者陷入了迷雾中，又重新回顾了下系统的架构，同时再仔细的分析了下nginx日志，发送502请求的耗时和正常建立连接的耗时差不多，开始怀疑是不是tomcat自身进行了connection refused，查阅了相关资料和代码，在tomcat的类NioEndpoint中发现了如下代码
@Override
public void bind() throws Exception {
serverSock = ServerSocketChannel.open();
socketProperties.setProperties(serverSock.socket());
InetSocketAddress addr = (getAddress()!=null?new InetSocketAddress(getAddress(),getPort()):new InetSocketAddress(getPort()));
serverSock.socket().bind(addr,getBacklog());
serverSock.configureBlocking(true); //mimic APR behavior
serverSock.socket().setSoTimeout(getSocketProperties().getSoTimeout());
// Initialize thread count defaults for acceptor, poller
if (acceptorThreadCount == 0) {
// FIXME: Doesn't seem to work that well with multiple accept threads
acceptorThreadCount = 1;
}
if (pollerThreadCount <= 0) {
//minimum one poller thread
pollerThreadCount = 1;
在开启服务段监听端口的时候在bind方法中传入了backlog参数，查看下相关的解释
* @param backlog requested maximum length of the queue of
* incoming connections.
猛然一看还是不太明白，是说能够接收的socket数目吗？继续查看相关资料
acceptCount(backlog)
在源码里头是backlog参数，默认值为100。该参数是指当前连接数超过maxConnections的时候，还可接受的连接数，即tcp的完全连接队列(accept队列)的大小。
backlog参数提示内核监听队列的最大长度。监听队列的长度如果超过backlog，服务器将不受理新的客户连接，客户端也将收到ECONNREFUSED错误信息。在内核版本2.2之前的Linux中，backlog参数是指所有处于半连接状态（SYN_RCVD）和完全连接状态（ESTABLISHED）的socket的上限。但自内核版本2.2之后，它只表示处于完全连接状态的socket的上限，处于半连接状态的socket的上限则由/proc/sys/net/ipv4/tcp_max_syn_backlog内核参数定义。
由此可知，其表示处于连接状态的socket数量，默认是100，参数由acceptAccount控制，spring boot中通过server.tomcat.accept-count设置，因此需要加大该参数的配置，按照我们的流量，将其改为300后问题得到解决。
扩展知识
相信大家都接触过tomcat，大家肯定对maxconnections、maxthreads、acceptcount等相关参数区分的不是很清楚，在此一并介绍下，首先看下流转图
tomcat处理机制
- acceptor线程通过 serverSocket.accept方法摘取一个socket
- poller线程监听一些socket的事件，用来读取和写入
- poller线程在socket上读取一些消息完毕后将其转化为相应的对象提交给handler线程池进行处理
maxthreads其实就是handler的最大线程数，那maxconnections是什么呢，其实是最多支持同时从established队列中摘取多少个socket,
即允许同时accept的数量，NIO下默认是10000；
protected class Acceptor extends AbstractEndpoint.Acceptor {
@Override
public void run() {
int errorDelay = 0;
// Loop until we receive a shutdown command
while (running) {
// Loop if endpoint is paused
while (paused && running) {
state = AcceptorState.PAUSED;
try {
Thread.sleep(50);
} catch (InterruptedException e) {
// Ignore
}
}
if (!running) {
break;
}
state = AcceptorState.RUNNING;
try {
//if we have reached max connections, wait
//达到maxconnection的上限，等待，然后再accept摘取新的socket
countUpOrAwaitConnection();
SocketChannel socket = null;
try {
// Accept the next incoming connection from the server
// socket
socket = serverSock.accept();
} catch (IOException ioe) {
//we didn't get a socket
countDownConnection();
// Introduce delay if necessary
errorDelay = handleExceptionWithDelay(errorDelay);
// re-throw
throw ioe;
}
// Successful accept, reset the error delay
errorDelay = 0;
// setSocketOptions() will add channel to the poller
// if successful
if (running && !paused) {
if (!setSocketOptions(socket)) {
countDownConnection();
closeSocket(socket);
}
} else {
countDownConnection();
closeSocket(socket);
}
} catch (SocketTimeoutException sx) {
// Ignore: Normal condition
} catch (IOException x) {
if (running) {
log.error(sm.getString("endpoint.accept.fail"), x);
}
} catch (OutOfMemoryError oom) {
try {
oomParachuteData = null;
releaseCaches();
log.error("", oom);
}catch ( Throwable oomt ) {
try {
try {
System.err.println(oomParachuteMsg);
oomt.printStackTrace();
}catch (Throwable letsHopeWeDontGetHere){
ExceptionUtils.handleThrowable(letsHopeWeDontGetHere);
}
}catch (Throwable letsHopeWeDontGetHere){
ExceptionUtils.handleThrowable(letsHopeWeDontGetHere);
}
}
} catch (Throwable t) {
ExceptionUtils.handleThrowable(t);
log.error(sm.getString("endpoint.accept.fail"), t);
}
}
state = AcceptorState.ENDED;
}
}
网友评论