CODEWITHSUNDEEP
web-servicesconcurrencyjax-rsweblogic12c
user3573403
user3573403

Reputation: 1812

Servicing concurrent JAX-RS requests with WebLogic 12.2.1

I wrote a JAX-RS web service method to run on WebLogic 12.2.1, to test how many concurrent requests it can handle. I purposely make the method take 5 minutes to execute.

@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();
    }
}

I also wrote a stand-alone client program to send 500 concurrent requests to this service. The client uses one thread for each request.

From what I understand, WebLogic has a default maximum of 400 threads, which means that it can handle 400 requests concurrently. This figure is confirmed with my test result below. As you can see, within the first 5 minutes, starting from 10:46:31, only 400 requests were been serviced.

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]
....
....

But what I don't understand is how come the first 400 requests were not serviced at the same time by the service method? As you can see from the test result, the first request was serviced at 10:46:31.393, but the 400th request was serviced at 10:50:54.008, which is more than 4 minutes later.

If we look at access.log, we can see that all 500 requests were received by WebLogic between 10:46:31 and 10:46:35. So it seems that even though WebLogic received the requests with a very short period of time, it doesn't allocate a thread and call the service method that fast.

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

EDITED

Added work manager to define a minimum of 400 threads.

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>

Upvotes: 1

Views: 1137

Answers (1)

Slettal
Slettal

Reputation: 1029

That's how weblogic scales threadpools (they are "self-tuning"), it does not start 400 Threads immediately. It's more a slow increase of threads to maximize throughput.

https://docs.oracle.com/cd/E24329_01/web.1211/e24432/self_tuned.htm#CNFGD113

Upvotes: 0

Related Questions