慢连接&LazyParser

Author:放翁（文初）

Mail:fangweng@taobao.com

Tblog:weibo.com/fangweng

这里要从实际的测试中给Web应用开发者一个比较直观的关于慢连接优化的建议。

测试目标：

1．证明慢连接对于Java的应用容器的影响。

2．不同前端反向代理服务器对于慢连接的处理差异。

3．如何利用LazyParser的方式来优化慢连接请求（特别是大数据量的一些异常请求的处理）

测试部署环境描述：

Apache服务器（2.2.19版本）配置基本没变，增加了http proxy模块作为反向代理。

Nginx服务器（1.0.4版本）配置基本没变，增加了反向代理。

Jetty服务器（7.1.6版本）配置基本没变。Jetty的Lazy解析缓存为8k。

部署如下，外部请求可以通过三个入口访问应用真实逻辑。（apache,nginx,jetty）

测试代码：

服务端：

简单描述一下逻辑：

1. 根据http消息头判断采用lazy还是普通方式解析。

2. 输出start test表示开始。

3. 获取key1,key2的内容，并记录消耗时间输出phase 1 use:xxx作为获取这两个参数的消耗。

4. 获取key4的内容，并记录消耗时间输出phase 2 use:xxx作为获取这个参数的消耗。

5. 获取key3的内容，并记录整个请求消耗的时间，输出end total use:xxx，作为整个处理消耗的时间。

客户端代码：

1．配置不同入口访问应用。

2．是否设置使用lazy的http header来引导服务端处理。

3．构建参数集合，参数顺序为（key1,key2,key3,key4）。其中key3作为一个大数据字段可变，用于多个场景测试。

测试结果及分析：

1．设置key3大小为1000个char，对比多个场景：

a. 不用lazy解析模式

(1) 通过nginx访问：

Nginx日志（第一位是消耗时间单位秒）：0.002 115.193.162.12 - - [20/Jun/2011:10:50:44 -0400] "POST /cometpipe/slowtest?key1=1 HTTP/1.1" 200 19 "-" "Jakarta Commons-HttpClient/3.0.1" "-"

Jetty日志：

start test: not use lazy

phase 1 use :0

phase 2 use :1

end total use:1

(2) 通过 apache访问：

Apache日志：（第二位消耗时间单位微秒）：0 3513 115.193.162.12 - - [20/Jun/2011:10:53:24 -0400] "POST /cometpipe/slowtest?key1=1 HTTP/1.1" 200 9

Jetty日志：

start test: not use lazy

phase 1 use :0

phase 2 use :0

end total use:0

(3) 直接访问jetty：

Jetty日志：

start test: not use lazy

phase 1 use :1

phase 2 use :0

end total use:1

b. 用lazy解析模式

同样是上面三种模式，web容器的日志就不写出来了结果一样，下面主要是贴一下应用服务器的情况:

----------------------------------------------------jetty

start test : uselazy

Jun 20, 2011 10:57:24 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 1019

phase 1 use :1

Jun 20, 2011 10:57:24 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: -1

phase 2 use :0

end total use:1

-----------------------------------------------------------nginx

start test : uselazy

Jun 20, 2011 10:58:37 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 1019

phase 1 use :0

Jun 20, 2011 10:58:37 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: -1

phase 2 use :0

end total use:0

-----------------------------------------------------------apache

start test : uselazy

Jun 20, 2011 10:58:45 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 1019

phase 1 use :0

Jun 20, 2011 10:58:45 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: -1

phase 2 use :1

end total use:1

上面的输出增加了一些，其实lazyparser在逐块解析字节流的时候每次装载数据的输出，lazyparser的缓冲区当前设置最大为8k，根据上面的情况可以看到不论哪一种方式，数据一次性都被装载，不存在后端处理的差异。

2．设置key3大小为100000个char，对比多个场景：

a. 不用lazy解析模式

(1) 通过nginx访问：

Nginx日志（第一位是消耗时间单位秒）：1.528 115.193.162.12 - - [20/Jun/2011:11:05:34 -0400] "POST /cometpipe/slowtest?key1=1 HTTP/1.1" 200 19 "-" "Jakarta Commons-HttpClient/3.0.1" "-"（消耗时间大幅上升）

Jetty日志：

start test: not use lazy

phase 1 use :5

phase 2 use :0

end total use:6

(2) 通过 apache访问：

Apache日志：（第二位消耗时间单位微秒）：1 1502243 115.193.162.12 - - [20/Jun/2011:11:07:10 -0400] "POST /cometpipe/slowtest?key1=1 HTTP/1.1" 200 9

Jetty日志：

start test: not use lazy

phase 1 use :609

phase 2 use :0

end total use:609

(3) 直接访问jetty：

Jetty日志：

start test: not use lazy

phase 1 use :1463

phase 2 use :0

end total use:1463

从上面几个数据来看，首先不论哪个入口进去，总的时间处理都在1.5秒左右（我的网络状况还是比较烂），但nginx的数据堆积效果对jetty起到了明显的保护作用，使得jetty整个容器线程池生命周期较短，可以处理更多的请求，apache数据堆积不是全量堆积，因此对于jetty来说还需要自身的一些堆积处理（这点在后面的lazy模式下将会更加直观的看到过程）

b. 用lazy解析模式

(1) 通过nginx访问：

Nginx日志（第一位是消耗时间单位秒）：1.513 115.193.162.12 - - [20/Jun/2011:11:13:22 -0400] "POST /cometpipe/slowtest?key1=1 HTTP/1.1" 200 19 "-" "Jakarta Commons-HttpClient/3.0.1" "-"（消耗时间大幅上升）

Jetty日志：

start test : uselazy

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 5911

phase 1 use :1

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 8192

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 3996

Jun 20, 2011 11:13:22 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: -1

phase 2 use :7

end total use:8

从上面的结果可以看到，nginx的数据堆积效果很好，jetty都是塞满lazyparser的缓存大小来处理的，所以Java IO次数少，整体消耗时间短。

(2) 通过 apache访问：

Apache日志：（第二位消耗时间单位微秒）：1 1521576 115.193.162.12 - - [20/Jun/2011:11:16:37 -0400] "POST /cometpipe/slowtest?key1=1 HTTP/1.1" 200 9

Jetty日志：

start test : uselazy

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 5787

phase 1 use :1

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 2405

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:13,count: 8096

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:280,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:6,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:13,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:10,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:265,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:7,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:13,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:7,count: 8192

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 448

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:6,count: 6419

Jun 20, 2011 11:16:38 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: -1

phase 2 use :627

end total use:628

可以看到第一阶段处理由于是lazy的模式，没有像普通请求处理那样消耗都在第一阶段，而是把消耗时间落在了真正要拿那些数据处理的第二阶段，同时可以看到apache有满cache和非满cache的数据后传，同时由于是变积累边传递，每次后传所消耗的时间都要远大于nginx，因此对于jetty的保护较弱。（所以如果你不是用mod_jk去直接反向代理到后段的应用容器（jboss,tomcat,jetty）都会使得应用服务器load比较高，线程生命周期长了，线程切换频繁）

(3) 直接访问jetty：

Jetty日志：

start test : uselazy

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 1217

phase 1 use :1

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:294,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:309,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:0,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:2,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:2,count: 1440

Jun 20, 2011 11:22:46 AM com.taobao.top.xbox.framework.http.LazyParser readBytes

SEVERE: timconsume:1,count: 1440