背景

公司有个渠道系统,专门对接三方渠道使用,没有什么业务逻辑,主要是转换报文和参数校验之类的工作,起着一个承上启下的作用。 最近在优化接口的响应时间,优化了代码之后,但是时间还是达不到要求;有一个诡异的100ms左右的耗时问题,在接口中打印了请求处理时间后,和调用方的响应时间还有差了100ms左右。比如程序里记录150ms,但是调用方等待时间却为250ms左右。 下面记录下当时详细的定位&解决流程(其实解决很简单,关键在于怎么定位并找到解决问题的方法)

一、定位过程

分析代码

:::info 渠道系统是一个常见的spring-boot web工程,使用了集成的tomcat。分析了代码之后,发现并没有特殊的地方,没有特殊的过滤器或者拦截器,所以初步排除是业务代码问题 :::

分析调用流程

出现这个问题之后,首先确认了下接口的调用流程。由于是内部测试,所以调用流程较少。 Nginx -反向代理-> 渠道系统 公司是云服务器,网络走的也是云的内网。由于不明确问题的原因,所以用排除法,首先确认服务器网络是否有问题。 先确认发送端到Nginx Host是否有问题:

  1. [jboss@VM_0_139_centos ~]$ ping 10.0.0.139
  2. PING 10.0.0.139 (10.0.0.139) 56(84) bytes of data.
  3. 64 bytes from 10.0.0.139: icmp_seq=1 ttl=64 time=0.029 ms
  4. 64 bytes from 10.0.0.139: icmp_seq=2 ttl=64 time=0.041 ms
  5. 64 bytes from 10.0.0.139: icmp_seq=3 ttl=64 time=0.040 ms
  6. 64 bytes from 10.0.0.139: icmp_seq=4 ttl=64 time=0.040 ms

从ping结果上看,发送端到Nginx主机的延迟是无问题的,接下来查看Nginx到渠道系统的网络。

  1. # 由于日志是没问题的,这里直接复制上面日志了
  2. [jboss@VM_0_139_centos ~]$ ping 10.0.0.139
  3. PING 10.0.0.139 (10.0.0.139) 56(84) bytes of data. 64 bytes from 10.0.0.139: icmp_seq=1 ttl=64 time=0.029 ms 64 bytes from 10.0.0.139: icmp_seq=2 ttl=64 time=0.041 ms
  4. 64 bytes from 10.0.0.139: icmp_seq=3 ttl=64 time=0.040 ms
  5. 64 bytes from 10.0.0.139: icmp_seq=4 ttl=64 time=0.040 ms

二、Arthas分析问题

三、Tomcat embed Bug分析&解决