使用 WebLogic 12.2.1 为并发 JAX-RS 请求提供服务
Servicing concurrent JAX-RS requests with WebLogic 12.2.1
我在 WebLogic 12.2.1 上为 运行 编写了一个 JAX-RS Web 服务方法，以测试它可以处理多少并发请求。我故意让这个方法需要 5 分钟来执行。
@Singleton
@Path("Services")
@ApplicationPath("resources")
public class Services extends Application {
private static int count = 0;
private static synchronized int addCount(int a) {
count = count + a;
return count;
}
@GET
@Path("Ping")
public Response ping(@Context HttpServletRequest request) {
int c = addCount(1);
logger.log(INFO, "Method entered, total running requests: [{0}]", c);
try {
Thread.sleep(300000);
} catch (InterruptedException exception) {
}
c = addCount(-1);
logger.log(INFO, "Exiting method, total running requests: [{0}]", c);
return Response.ok().build();
}
}
我还写了一个独立的客户端程序来向这个服务发送500个并发请求。客户端为每个请求使用一个线程。
据我了解，WebLogic默认最大线程数为400，也就是说它可以并发处理400个请求。这个数字在我下面的测试结果中得到了证实。如您所见，在前 5 分钟内，从 10:46:31 开始，只有 400 个请求得到处理。
23/08/2016 10:46:31.393 [132] [INFO] [Services.ping] - Method entered, total running requests: [1]
23/08/2016 10:46:31.471 [204] [INFO] [Services.ping] - Method entered, total running requests: [2]
23/08/2016 10:46:31.471 [66] [INFO] [Services.ping] - Method entered, total running requests: [3]
23/08/2016 10:46:31.471 [210] [INFO] [Services.ping] - Method entered, total running requests: [4]
23/08/2016 10:46:31.471 [206] [INFO] [Services.ping] - Method entered, total running requests: [5]
23/08/2016 10:46:31.487 [207] [INFO] [Services.ping] - Method entered, total running requests: [6]
23/08/2016 10:46:31.487 [211] [INFO] [Services.ping] - Method entered, total running requests: [7]
23/08/2016 10:46:31.487 [267] [INFO] [Services.ping] - Method entered, total running requests: [8]
23/08/2016 10:46:31.487 [131] [INFO] [Services.ping] - Method entered, total running requests: [9]
23/08/2016 10:46:31.502 [65] [INFO] [Services.ping] - Method entered, total running requests: [10]
23/08/2016 10:46:31.518 [265] [INFO] [Services.ping] - Method entered, total running requests: [11]
23/08/2016 10:46:31.565 [266] [INFO] [Services.ping] - Method entered, total running requests: [12]
23/08/2016 10:46:35.690 [215] [INFO] [Services.ping] - Method entered, total running requests: [13]
23/08/2016 10:46:35.690 [269] [INFO] [Services.ping] - Method entered, total running requests: [14]
23/08/2016 10:46:35.690 [268] [INFO] [Services.ping] - Method entered, total running requests: [15]
23/08/2016 10:46:35.690 [214] [INFO] [Services.ping] - Method entered, total running requests: [16]
23/08/2016 10:46:35.690 [80] [INFO] [Services.ping] - Method entered, total running requests: [17]
23/08/2016 10:46:35.690 [79] [INFO] [Services.ping] - Method entered, total running requests: [18]
23/08/2016 10:46:35.690 [152] [INFO] [Services.ping] - Method entered, total running requests: [19]
23/08/2016 10:46:37.674 [158] [INFO] [Services.ping] - Method entered, total running requests: [20]
23/08/2016 10:46:37.674 [155] [INFO] [Services.ping] - Method entered, total running requests: [21]
23/08/2016 10:46:39.674 [163] [INFO] [Services.ping] - Method entered, total running requests: [22]
23/08/2016 10:46:39.705 [165] [INFO] [Services.ping] - Method entered, total running requests: [23]
23/08/2016 10:46:39.705 [82] [INFO] [Services.ping] - Method entered, total running requests: [24]
23/08/2016 10:46:39.705 [166] [INFO] [Services.ping] - Method entered, total running requests: [25]
23/08/2016 10:46:41.690 [84] [INFO] [Services.ping] - Method entered, total running requests: [26]
23/08/2016 10:46:41.690 [160] [INFO] [Services.ping] - Method entered, total running requests: [27]
23/08/2016 10:46:43.690 [226] [INFO] [Services.ping] - Method entered, total running requests: [28]
23/08/2016 10:46:43.705 [162] [INFO] [Services.ping] - Method entered, total running requests: [29]
....
....
23/08/2016 10:50:52.008 [445] [INFO] [Services.ping] - Method entered, total running requests: [398]
23/08/2016 10:50:52.008 [446] [INFO] [Services.ping] - Method entered, total running requests: [399]
23/08/2016 10:50:54.008 [447] [INFO] [Services.ping] - Method entered, total running requests: [400]
23/08/2016 10:51:31.397 [132] [INFO] [Services.ping] - Exiting method, total running requests: [399]
23/08/2016 10:51:31.475 [207] [INFO] [Services.ping] - Exiting method, total running requests: [398]
23/08/2016 10:51:31.475 [207] [INFO] [Services.ping] - Method entered, total running requests: [399]
....
....
但是我不明白的是，为什么服务方法没有同时处理前400个请求？从测试结果可以看出，第一个请求在10:46:31.393得到了服务，但是第400个请求在10:50:54.008得到了服务，已经过了4个多分钟。
如果我们查看 access.log，我们可以看到 WebLogic 在 10:46:31 和 10:46:35 之间收到了所有 500 个请求。所以看起来即使WebLogic在很短的时间内收到请求，它也没有那么快地分配线程和调用服务方法。
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
....
....
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
已编辑
添加了工作管理器以定义至少 400 个线程。
weblogic.xml
<wls:work-manager>
<wls:name>HighPriorityWorkManager</wls:name>
<wls:fair-share-request-class>
<wls:name>HighPriority</wls:name>
<wls:fair-share>100</wls:fair-share>
</wls:fair-share-request-class>
<wls:min-threads-constraint>
<wls:name>MinThreadsCount</wls:name>
<wls:count>400</wls:count>
</wls:min-threads-constraint>
</wls:work-manager>
web.xml
<init-param>
<param-name>wl-dispatch-policy</param-name>
<param-value>HighPriorityWorkManager</param-value>
</init-param>
这就是 weblogic 缩放线程池的方式（它们是 "self-tuning"），它不会立即启动 400 个线程。更多的是缓慢增加线程以最大化吞吐量。
https://docs.oracle.com/cd/E24329_01/web.1211/e24432/self_tuned.htm#CNFGD113
我在 WebLogic 12.2.1 上为 运行 编写了一个 JAX-RS Web 服务方法，以测试它可以处理多少并发请求。我故意让这个方法需要 5 分钟来执行。
@Singleton
@Path("Services")
@ApplicationPath("resources")
public class Services extends Application {
private static int count = 0;
private static synchronized int addCount(int a) {
count = count + a;
return count;
}
@GET
@Path("Ping")
public Response ping(@Context HttpServletRequest request) {
int c = addCount(1);
logger.log(INFO, "Method entered, total running requests: [{0}]", c);
try {
Thread.sleep(300000);
} catch (InterruptedException exception) {
}
c = addCount(-1);
logger.log(INFO, "Exiting method, total running requests: [{0}]", c);
return Response.ok().build();
}
}
我还写了一个独立的客户端程序来向这个服务发送500个并发请求。客户端为每个请求使用一个线程。
据我了解，WebLogic默认最大线程数为400，也就是说它可以并发处理400个请求。这个数字在我下面的测试结果中得到了证实。如您所见，在前 5 分钟内，从 10:46:31 开始，只有 400 个请求得到处理。
23/08/2016 10:46:31.393 [132] [INFO] [Services.ping] - Method entered, total running requests: [1]
23/08/2016 10:46:31.471 [204] [INFO] [Services.ping] - Method entered, total running requests: [2]
23/08/2016 10:46:31.471 [66] [INFO] [Services.ping] - Method entered, total running requests: [3]
23/08/2016 10:46:31.471 [210] [INFO] [Services.ping] - Method entered, total running requests: [4]
23/08/2016 10:46:31.471 [206] [INFO] [Services.ping] - Method entered, total running requests: [5]
23/08/2016 10:46:31.487 [207] [INFO] [Services.ping] - Method entered, total running requests: [6]
23/08/2016 10:46:31.487 [211] [INFO] [Services.ping] - Method entered, total running requests: [7]
23/08/2016 10:46:31.487 [267] [INFO] [Services.ping] - Method entered, total running requests: [8]
23/08/2016 10:46:31.487 [131] [INFO] [Services.ping] - Method entered, total running requests: [9]
23/08/2016 10:46:31.502 [65] [INFO] [Services.ping] - Method entered, total running requests: [10]
23/08/2016 10:46:31.518 [265] [INFO] [Services.ping] - Method entered, total running requests: [11]
23/08/2016 10:46:31.565 [266] [INFO] [Services.ping] - Method entered, total running requests: [12]
23/08/2016 10:46:35.690 [215] [INFO] [Services.ping] - Method entered, total running requests: [13]
23/08/2016 10:46:35.690 [269] [INFO] [Services.ping] - Method entered, total running requests: [14]
23/08/2016 10:46:35.690 [268] [INFO] [Services.ping] - Method entered, total running requests: [15]
23/08/2016 10:46:35.690 [214] [INFO] [Services.ping] - Method entered, total running requests: [16]
23/08/2016 10:46:35.690 [80] [INFO] [Services.ping] - Method entered, total running requests: [17]
23/08/2016 10:46:35.690 [79] [INFO] [Services.ping] - Method entered, total running requests: [18]
23/08/2016 10:46:35.690 [152] [INFO] [Services.ping] - Method entered, total running requests: [19]
23/08/2016 10:46:37.674 [158] [INFO] [Services.ping] - Method entered, total running requests: [20]
23/08/2016 10:46:37.674 [155] [INFO] [Services.ping] - Method entered, total running requests: [21]
23/08/2016 10:46:39.674 [163] [INFO] [Services.ping] - Method entered, total running requests: [22]
23/08/2016 10:46:39.705 [165] [INFO] [Services.ping] - Method entered, total running requests: [23]
23/08/2016 10:46:39.705 [82] [INFO] [Services.ping] - Method entered, total running requests: [24]
23/08/2016 10:46:39.705 [166] [INFO] [Services.ping] - Method entered, total running requests: [25]
23/08/2016 10:46:41.690 [84] [INFO] [Services.ping] - Method entered, total running requests: [26]
23/08/2016 10:46:41.690 [160] [INFO] [Services.ping] - Method entered, total running requests: [27]
23/08/2016 10:46:43.690 [226] [INFO] [Services.ping] - Method entered, total running requests: [28]
23/08/2016 10:46:43.705 [162] [INFO] [Services.ping] - Method entered, total running requests: [29]
....
....
23/08/2016 10:50:52.008 [445] [INFO] [Services.ping] - Method entered, total running requests: [398]
23/08/2016 10:50:52.008 [446] [INFO] [Services.ping] - Method entered, total running requests: [399]
23/08/2016 10:50:54.008 [447] [INFO] [Services.ping] - Method entered, total running requests: [400]
23/08/2016 10:51:31.397 [132] [INFO] [Services.ping] - Exiting method, total running requests: [399]
23/08/2016 10:51:31.475 [207] [INFO] [Services.ping] - Exiting method, total running requests: [398]
23/08/2016 10:51:31.475 [207] [INFO] [Services.ping] - Method entered, total running requests: [399]
....
....
但是我不明白的是，为什么服务方法没有同时处理前400个请求？从测试结果可以看出，第一个请求在10:46:31.393得到了服务，但是第400个请求在10:50:54.008得到了服务，已经过了4个多分钟。
如果我们查看 access.log，我们可以看到 WebLogic 在 10:46:31 和 10:46:35 之间收到了所有 500 个请求。所以看起来即使WebLogic在很短的时间内收到请求，它也没有那么快地分配线程和调用服务方法。
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:31 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
....
....
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
10.204.133.176 - - [23/Aug/2016:10:46:35 +0800] "GET /Test/Services/Ping HTTP/1.1" 200 0
已编辑
添加了工作管理器以定义至少 400 个线程。
weblogic.xml
<wls:work-manager>
<wls:name>HighPriorityWorkManager</wls:name>
<wls:fair-share-request-class>
<wls:name>HighPriority</wls:name>
<wls:fair-share>100</wls:fair-share>
</wls:fair-share-request-class>
<wls:min-threads-constraint>
<wls:name>MinThreadsCount</wls:name>
<wls:count>400</wls:count>
</wls:min-threads-constraint>
</wls:work-manager>
web.xml
<init-param>
<param-name>wl-dispatch-policy</param-name>
<param-value>HighPriorityWorkManager</param-value>
</init-param>
这就是 weblogic 缩放线程池的方式（它们是 "self-tuning"），它不会立即启动 400 个线程。更多的是缓慢增加线程以最大化吞吐量。
https://docs.oracle.com/cd/E24329_01/web.1211/e24432/self_tuned.htm#CNFGD113