请求量突增一下,系统有效QPS为何下降很多?()

  本篇文章为你整理了请求量突增一下,系统有效QPS为何下降很多?()的详细内容,包含有 请求量突增一下,系统有效QPS为何下降很多?,希望能帮助你了解 请求量突增一下,系统有效QPS为何下降很多?。

  最近我观察到一个现象,当服务的请求量突发的增长一下时,服务的有效QPS会下降很多,有时甚至会降到0,这种现象网上也偶有提到,但少有解释得清楚的,所以这里来分享一下问题成因及解决方案。

  目前的Web服务器,如Tomcat,请求处理过程大概都类似如下:
 

  
 

  这是Tomcat请求处理的过程,如下:

  Acceptor线程:线程名类似http-nio-8080-Acceptor-0,此线程用于接收新的TCP连接,并将TCP连接注册到NIO事件中。

  Poller线程:线程名类似http-nio-8080-ClientPoller-0,此线程一般有CPU核数个,用于轮询已连接的Socket,接收新到来的Socket事件(如调用端发请求数据了),并将活跃Socket放入exec线程池的请求队列中。

  exec线程:线程名类似http-nio-8080-exec-0,此线程从请求队列中取出活跃Socket,并读出请求数据,最后执行请求的API逻辑。

  这里不用太关心Acceptor与Poller线程,这是nio编程时常见的线程模型,我们将重点放在exec线程池上,虽然Tomcat做了一些优化,但它还是从Java原生线程池扩展出来的,即有一个任务队列与一组线程。

  当请求量突发增长时,会发生如下的情况:

  当请求量不大时,任务队列基本是空的,每个请求都能得到及时的处理。

  但当请求量突发时,任务队列中就会有很多请求,这时排在队列后面的请求,就会被处理得越晚,因而请求的整体耗时就会变长,甚至非常长。

  可是,exec线程们还是在一刻不停歇的处理着请求的呀,按理说服务QPS是不会减少的呀!

  简单想想的确如此,但调用端一般是有超时时间设置的,不会无限等待下去,当客户端等待超时的时候,这个请求实际上Tomcat就不用再处理了,因为就算处理了,客户端也不会再去读响应数据的。
 

  
 

  因此,当队列比较长时,队列后面的请求,基本上都是不用再处理的,但exec线程池不知道啊,它还是会一如既往地处理这些请求。

  当exec线程执行这些已超时的请求时,若又有新请求进来,它们也会排在队尾,这导致这些新请求也会超时,所以在流量突发的这段时间内,请求的有效QPS会下降很多,甚至会降到0。

  这种超时也叫做队列延迟,但队列在软件系统中应用得太广泛了,比如操作系统调度器维护了线程队列,TCP中有backlog连接队列,锁中维护了等待队列等等。

  因此,很多系统也会存在这种现象,平时响应时间挺稳定的,但偶尔耗时很高,这种情况有很多都是队列延迟导致的。

  优化队列延迟

  知道了问题产生的原因,要优化它就比较简单了,我们只需要让队列中那些长时间未处理的请求暂时让路,让线程去执行那些等待时间不长的请求即可,毕竟这些长时间未处理的请求,让它们再等等也无防,因为客户端可能已经超时了而不需要请求结果了,虽然这破坏了队列的公平性,但这是我们需要的。

  对于Tomcat,在springboot中,我们可以如下修改:
 

  使用WebServerFactoryCustomizer自定义Tomcat的线程池,如下:

  

@Component

 

  public class TomcatExecutorCustomizer implements WebServerFactoryCustomizer TomcatServletWebServerFactory {

   @Resource

   ServerProperties serverProperties;

   @Override

   public void customize(TomcatServletWebServerFactory factory) {

   TomcatConnectorCustomizer tomcatConnectorCustomizer = connector - {

   ServerProperties.Tomcat.Threads threads = serverProperties.getTomcat().getThreads();

   TaskQueue taskqueue = new SlowDelayTaskQueue(1000);

   ThreadPoolExecutor executor = new org.apache.tomcat.util.threads.ThreadPoolExecutor(

   threads.getMinSpare(), threads.getMax(), 60L, TimeUnit.SECONDS,

   taskqueue, new CustomizableThreadFactory("http-nio-8080-exec-"));

   taskqueue.setParent(executor);

   ProtocolHandler handler = connector.getProtocolHandler();

   if (handler instanceof AbstractProtocol) {

   AbstractProtocol ? protocol = (AbstractProtocol ? ) handler;

   protocol.setExecutor(executor);

   factory.addConnectorCustomizers(tomcatConnectorCustomizer);

  

 

  注意,这里还是使用的Tomcat实现的线程池,只是将任务队列TaskQueue扩展为了SlowDelayTaskQueue,它的作用是将长时间未处理的任务移到另一个慢队列中,待当前队列中无任务时,再把慢队列中的任务移回来。

  为了能记录任务入队列的时间,先封装了一个记录时间的任务类RecordTimeTask,如下:

  

@Getter

 

  public class RecordTimeTask implements Runnable {

   private Runnable run;

   private long createTime;

   private long putQueueTime;

   public RecordTimeTask(Runnable run){

   this.run = run;

   this.createTime = System.currentTimeMillis();

   this.putQueueTime = this.createTime;

   @Override

   public void run() {

   run.run();

   public void resetPutQueueTime() {

   this.putQueueTime = System.currentTimeMillis();

   public long getPutQueueTime() {

   return this.putQueueTime;

  

 

  然后队列的扩展实现如下:

  

public class SlowDelayTaskQueue extends TaskQueue {

 

   private long timeout;

   private BlockingQueue RecordTimeTask slowQueue;

   public SlowDelayTaskQueue(long timeout) {

   this.timeout = timeout;

   this.slowQueue = new LinkedBlockingQueue ();

   @Override

   public boolean offer(Runnable o) {

   // 将任务包装一下,目的是为了记录任务放入队列的时间

   if (o instanceof RecordTimeTask) {

   return super.offer(o);

   } else {

   return super.offer(new RecordTimeTask(o));

   public void pullbackIfEmpty() {

   // 如果队列空了,从慢队列中取回来一个

   if (this.isEmpty()) {

   RecordTimeTask r = slowQueue.poll();

   if (r == null) {

   return;

   r.resetPutQueueTime();

   this.add(r);

   @Override

   public Runnable poll(long timeout, TimeUnit unit) throws InterruptedException {

   pullbackIfEmpty();

   while (true) {

   RecordTimeTask task = (RecordTimeTask) super.poll(timeout, unit);

   if (task == null) {

   return null;

   // 请求在队列中长时间等待,移入慢队列中

   if (System.currentTimeMillis() - task.getPutQueueTime() this.timeout) {

   this.slowQueue.offer(task);

   continue;

   return task;

   @Override

   public Runnable take() throws InterruptedException {

   pullbackIfEmpty();

   while (true) {

   RecordTimeTask task = (RecordTimeTask) super.take();

   // 请求在队列中长时间等待,移入慢队列中

   if (System.currentTimeMillis() - task.getPutQueueTime() this.timeout) {

   this.slowQueue.offer(task);

   continue;

   return task;

  

 

  逻辑其实挺简单的,如下:

  当任务入队列时,包装一下任务,记录一下入队列的时间。

  然后线程从队列中取出任务时,若发现任务等待时间过长,就将其移入慢队列。

  而pullbackIfEmpty的逻辑,就是当队列为空时,再将慢队列中的任务移回来执行。

  为了将请求的队列延迟记录在access.log中,我又修改了一下Task,并加了一个Filter,如下:

  使用ThreadLocal将队列延迟先存起来

  

@Getter

 

  public class RecordTimeTask implements Runnable {

   private static final ThreadLocal Long WAIT_IN_QUEUE_TIME = new ThreadLocal ();

   private Runnable run;

   private long createTime;

   private long putQueueTime;

   public RecordTimeTask(Runnable run){

   this.run = run;

   this.createTime = System.currentTimeMillis();

   this.putQueueTime = this.createTime;

   @Override

   public void run() {

   try {

   WAIT_IN_QUEUE_TIME.set(System.currentTimeMillis() - this.createTime);

   run.run();

   } finally {

   WAIT_IN_QUEUE_TIME.remove();

   public void resetPutQueueTime() {

   this.putQueueTime = System.currentTimeMillis();

   public long getPutQueueTime() {

   return this.putQueueTime;

   public static long getWaitInQueueTime(){

   return ObjectUtils.defaultIfNull(WAIT_IN_QUEUE_TIME.get(), 0L);

  

 

  再在Filter中将队列延迟取出来,放入Request对象中

  

@WebFilter

 

  @Component

  public class WaitInQueueTimeFilter extends HttpFilter {

   @Override

   public void doFilter(HttpServletRequest request, HttpServletResponse response, FilterChain chain) throws

   IOException,

   ServletException {

   long waitInQueueTime = RecordTimeTask.getWaitInQueueTime();

   // 将等待时间设置到request的attribute中,给access.log使用

   request.setAttribute("waitInQueueTime", waitInQueueTime);

   // 如果请求在队列中等待了太长时间,客户端大概率已超时,就没有必要再执行了

   if (waitInQueueTime 5000) {

   response.sendError(503, "service is busy");

   return;

   chain.doFilter(request, response);

  

 

  然后在access.log中配置队列延迟

  

server:

 

   tomcat:

   accesslog:

   enabled: true

   directory: /home/work/logs/applogs/java-demo

   file-date-format: .yyyy-MM-dd

   pattern: %h %l %u %t "%r" %s %b %Dms %{waitInQueueTime}rms "%{Referer}i" "%{User-Agent}i" "%{X-Forwarded-For}i"

  

 

  注意,在access.log中配置%{xxx}r表示取请求xxx属性的值,所以,%{waitInQueueTime}r就是队列延迟,后面的ms是毫秒单位。

  我使用接口压测工具wrk压了一个测试接口,此接口执行时间100ms,使用1000个并发去压,1s的超时时间,如下:

  

wrk -d 10d -T1s --latency http://localhost:8080/sleep -c 1000

 

  

 

  然后,用arthas看一下线程池的队列长度,如下:

  

[arthas@619]$ vmtool --action getInstances \

 

   --classLoaderClass org.springframework.boot.loader.LaunchedURLClassLoader \

   --className org.apache.tomcat.util.threads.ThreadPoolExecutor \

   --express instances.{ #{"ActiveCount":getActiveCount(),"CorePoolSize":getCorePoolSize(),"MaximumPoolSize":getMaximumPoolSize(),"QueueSize":getQueue().size()} } \

   -x 2

  

 

  
 

  可以看到,队列长度远小于1000,这说明队列中积压得不多。

  再看看access.log,如下:
 

  
 

  可以发现,虽然队列延迟任然存在,但被控制在了1s以内,这样这些请求就不会超时了,Tomcat的有效QPS保住了。

  而最后面那些队列延迟极长的请求,则是被不公平对待的请求,但只能这么做,因为在请求量超出Tomcat处理能力时,只能牺牲掉它们,以保全大局。

  以上就是请求量突增一下,系统有效QPS为何下降很多?()的详细内容,想要了解更多 请求量突增一下,系统有效QPS为何下降很多?的内容,请持续关注盛行IT软件开发工作室。

郑重声明:本文由网友发布,不代表盛行IT的观点,版权归原作者所有,仅为传播更多信息之目的,如有侵权请联系,我们将第一时间修改或删除,多谢。

留言与评论(共有 条评论)
   
验证码: