Jetty 8长连接上的又一个坑

新浪微博 QQ空间

Jetty 8 长连接的超时断开连接的机制:超时连接机制针对IO传输过程中的数据阻塞时间超过一定阈值时,断开该连接。阻塞指当前处于数据传输阶段,但是连续指定时间内都没有发出或者接收到任何数据时,Jetty系统断开该连接。强调一下,只有在数据传输过程中才会有超时机制。在服务端处理已经收到的数据时是不会检测该超时时间的。

下面看一下具体的代码实现。在jetty 8.1.17版本中,由以下代码控制一个连接的空闲、非空闲和断开检查方法,在SelectChannelEndpoint类中:

/* ------------------------------------------------------------ */
public void setCheckForIdle(boolean check)
{
if (check)
{
_idleTimestamp=System.currentTimeMillis();
_checkIdle=true;
}
else
_checkIdle=false;
}

/* ------------------------------------------------------------ */
public boolean isCheckForIdle()
{
return _checkIdle;
}

/* ------------------------------------------------------------ */
protected void notIdle()
{
_idleTimestamp=System.currentTimeMillis();
}

/* ------------------------------------------------------------ */
public void checkIdleTimestamp(long now)
{
if (isCheckForIdle() && _maxIdleTime>0)
{
final long idleForMs=now-_idleTimestamp;

if (idleForMs>_maxIdleTime)
{
// Don't idle out again until onIdleExpired task completes.
setCheckForIdle(false);
_manager.dispatch(new Runnable()
{
public void run()
{
try
{
onIdleExpired(idleForMs);
}
finally
{
setCheckForIdle(true);
}
}
});
}
}
}

几个关键点地方:当数据传输的过程中,发现无法接收到和写出数据时,会调用setCheckForIdle(true)方法,从当前时间点开始计时,当后台select线程发现该连接的空闲时间达到阈值时,则调用onIdleExpired方法。还有一种场景是,在一个请求结束后,立即将该请求置为空闲状态。直到连接关闭或者该连接上面来了新的请求。另外,每个新的连接建立时,会在构造函数中默认调用一次该方法设置连接为空闲状态。

在哪些情况下会调用相反的设置呢,即将该连接置为非空闲状态的setCheckForIdle(false)方法,和刷新当前的idle时间方法notIdle()呢?第一个方法每次收到一个请求的数据提交后端的servlet的时候调用,后一个方法在每次刷出或者读到数据时调用。这样确保后端的servlet在处理数据时,不至于因为处理时间过长而被自己的select线程给关闭了。

这一次jetty的bug正是出在上述的每个请求的数据收集完成进入后端处理之前发生的。看如下代码:

AsyncHttpConnection类中,handle方法:

@Override
public Connection handle() throws IOException
{
Connection connection = this;
boolean some_progress=false;
boolean progress=true;

try
{
setCurrentConnection(this);

// don't check for idle while dispatched (unless blocking IO is done).
_asyncEndp.setCheckForIdle(false);

// While progress and the connection has not changed
while (progress && connection==this)
{
progress=false;
try
{
// Handle resumed request
if (_request._async.isAsync())
{
if (_request._async.isDispatchable())
handleRequest();
}
// else Parse more input
else if (!_parser.isComplete() && _parser.parseAvailable())
progress=true;

// Generate more output
if (_generator.isCommitted() && !_generator.isComplete() && !_endp.isOutputShutdown() && !_request.getAsyncContinuation().isAsyncStarted())
if (_generator.flushBuffer()>0)
progress=true;

// Flush output
_endp.flush();

// Has any IO been done by the endpoint itself since last loop
if (_asyncEndp.hasProgressed())
progress=true;
}
catch (HttpException e)
{
if (LOG.isDebugEnabled())
{
LOG.debug("uri="+_uri);
LOG.debug("fields="+_requestFields);
LOG.debug(e);
}
progress=true;
_generator.sendError(e.getStatus(), e.getReason(), null, true);
}
finally
{
some_progress|=progress;
// Is this request/response round complete and are fully flushed?
boolean parserComplete = _parser.isComplete();
boolean generatorComplete = _generator.isComplete();
boolean complete = parserComplete && generatorComplete;
if (parserComplete)
{
if (generatorComplete)
{
// Reset the parser/generator
progress=true;

// look for a switched connection instance?
if (_response.getStatus()==HttpStatus.SWITCHING_PROTOCOLS_101)
{
Connection switched=(Connection)_request.getAttribute("org.eclipse.jetty.io.Connection");
if (switched!=null)
connection=switched;
}

reset();

// TODO Is this still required?
if (!_generator.isPersistent() && !_endp.isOutputShutdown())
{
LOG.warn("Safety net oshut!!! IF YOU SEE THIS, PLEASE RAISE BUGZILLA");
_endp.shutdownOutput();
}
}
else
{
// We have finished parsing, but not generating so
// we must not be interested in reading until we
// have finished generating and we reset the generator
_readInterested = false;
LOG.debug("Disabled read interest while writing response {}", _endp);
}
}

if (!complete && _request.getAsyncContinuation().isAsyncStarted())
{
// The request is suspended, so even though progress has been made,
// exit the while loop by setting progress to false
LOG.debug("suspended {}",this);
progress=false;
}
}
}
}
finally
{
setCurrentConnection(null);

// If we are not suspended
if (!_request.getAsyncContinuation().isAsyncStarted())
{
// return buffers
_parser.returnBuffers();
_generator.returnBuffers();

// reenable idle checking unless request is suspended
_asyncEndp.setCheckForIdle(true);
}

// Safety net to catch spinning
if (some_progress)
_total_no_progress=0;
else
{
_total_no_progress++;
if (NO_PROGRESS_INFO>0 && _total_no_progress%NO_PROGRESS_INFO==0 && (NO_PROGRESS_CLOSE<=0 || _total_no_progress< NO_PROGRESS_CLOSE))
LOG.info("EndPoint making no progress: "+_total_no_progress+" "+_endp+" "+this);
if (NO_PROGRESS_CLOSE>0 && _total_no_progress==NO_PROGRESS_CLOSE)
{
LOG.warn("Closing EndPoint making no progress: "+_total_no_progress+" "+_endp+" "+this);
if (_endp instanceof SelectChannelEndPoint)
((SelectChannelEndPoint)_endp).getChannel().close();
}
}
}
return connection;
}

可以看到,在handle方法进入时,调用了一次:

// don't check for idle while dispatched (unless blocking IO is done).
_asyncEndp.setCheckForIdle(false);

如果当前连接是一个短连接,那么这里调用完全没问题。请求处理完成后本来就可能立即断开连接。但是如果是一个长连接,该连接在处理完请求后,可能“休息”一段时间继续处理新的请求,那么就问题就来了,从该代码看,jetty在handle方法的while循环中处理多个请求,这样可以避免同一个连接上面的多个请求被分到不同的线程中处理,而是绑定在一个线程上面处理,当长连接上面的请求比较“密集”(请求之间间隔极短)时,该while会循环多次,有两种情况会进入该请求:1、一个请求上面的数据没有处理完,即

// else Parse more input
else if (!_parser.isComplete() && _parser.parseAvailable())
progress=true;

这个代码控制的。

另外当一个请求处理完了,也会在finally里面走到progess=true上面。

//  Is this request/response round complete and are fully flushed?
boolean parserComplete = _parser.isComplete();
boolean generatorComplete = _generator.isComplete();
boolean complete = parserComplete && generatorComplete;
if (parserComplete)
{
if (generatorComplete)
{
// Reset the parser/generator
progress=true;

由这个控制。

问题出在第二个上面,当一个请求处理完成后,连接会被置为空闲状态。但是这里将progess设置为true,那么while循环立即准备读取下一个请求的数据,但是并没有将连接置为非空闲状态,此时如果服务端进入耗时较长的处理流程,那么可能不等到客户端超时,连接就被后台检查空闲连接的线程断开了。

因此这里很明显,jetty有bug,应该在最后的这段代码出补充

// don't check for idle while dispatched (unless blocking IO is done).
_asyncEndp.setCheckForIdle(false);

这个调用。或者是在每次进入while循环时调用,而不是只在进入handle时调用。

该问题发生有几个关键点:长连接上面持续不断有新请求过来,并且新请求发起的时间距离上一个请求完成的时间间隔非常短。经过实测,python的http客户端在处理长连接上面,请求间隔非常短。而其他语言和库编写的客户端测试程序都有比较长的间隔,导致问题不易重现。附一个jetty的简易http长连接测试程序:

import httplib  

count=0
conn = httplib.HTTPConnection("127.0.0.1", timeout=600)
while (count < 1000000):
conn.request("PUT","/")
res = conn.getresponse()
print res.status, res.reason
print res.read()
count += 1

在jetty上面讲超时时间配置尽可能短,在servlet里面处理请求时休眠一个大于等于超时时间的值,配合上述客户端,很容易重现问题。

新浪微博 QQ空间

| 1 分2 分3 分4 分5 分 (4.92- 53票) Loading ... Loading ... | 这篇文章归档在:IO编程, Java, Jetty, 软件技术 | 标签: , . | 永久链接:链接 | 评论(2) |

2 条评论

  1. 匿名
    评论于 二月 29, 2016 at 14:27:43 CST | 评论链接

    虽然没有仔细看每行的细节,但是当看到最后一句的时候,觉得有点吹毛求疵的节奏。。。
    “在servlet里面处理请求时休眠一个大于等于超时时间的值” 这个假设是否有点不合理了?

    • 童燕群
      评论于 二月 29, 2016 at 14:41:07 CST | 评论链接

      这个超时时间本来就不是服务端自己处理数据的时间,而是服务端判断客户端空闲的时间。服务端处理时间过长,导致客户端迟迟收不到响应应该由客户端来判断是否超时。

评论

邮箱地址不会被泄露, 标记为 * 的项目必填。

8 - 2 = *



You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <img alt="" src="" class=""> <pre class=""> <q cite=""> <s> <strike> <strong>

返回顶部