1

I developing a SpringBoot-Application. During stress-testing the application shows some strange behaviour according parallel execution. AFAIK there should not be some parallel execution...

To test this behaviour i created this RestController:

@RestController
public class TestController2 {

private static int instancecount = 0;

@PostConstruct
public void con() {
    System.out.println("instancecount: " + ++instancecount);
}

@PreDestroy
public void des() {
    System.out.println("PreDestroy");
}

@RequestMapping(value = { "/", "/**" }, method = RequestMethod.GET)
@ResponseBody
public ResponseEntity<String> entrypoint(@RequestHeader Map<String, String> requestHeaders) {
    System.out.println("PRE!!!!!!!!!!!!!");
    try {
         Thread.sleep(120000);
    } catch (InterruptedException e) {
    }
    System.out.println("POST!!!!!!!!!!!!!!!!!");

    return new ResponseEntity<String>("qwertz", null, HttpStatus.OK);
}

}

The application compiles and works like expected. Now i open the browser with 14 tabs simultaneously.

In the log i can see instant:

PRE!!!!!!!!!!!!!

after approximately 15 sek. the next 5: PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!!

After 2 minutes the first finished. The other 5 finished at ~2:15.

This repeats until every 14 tabs are finished.

and now my question:

  1. Why is there a parallel execution?
  2. Why 6?
  3. Why the second starts after ~15 seconds?

I am a little bit confused. I don't know where or what i have to look for?

Need input!

THX

JekO
  • 78
  • 6
  • Why should there not be any parallel execution? Each request is handled by a thread. The max number of concurrent executions = max size of your thread pool. By the way, if there were no concurrent execution, what are you stress testing your application for by opening 14 tabs? – Prashant Oct 17 '19 at 12:10
  • hello! "...Why should there not be any parallel execution...": I read this somewhere. But thanks for this hint! "... opening 14 tabs..." Thats is not my stresstest!! It was a simple dirk and quick workaround for better/aesier describing. – JekO Oct 17 '19 at 12:24

1 Answers1

0

In the log i can see instant:

PRE!!!!!!!!!!!!!

after approximately 15 sek. the next 5: PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!! PRE!!!!!!!!!!!!!

I think this is a problem / limitation from the browser.

When a request arrives to the servlet container (Tomcat for an example), a thread is retrieved from the pool to serve it. This means that the each request has it's own thread and it will work with this thread during it's whole lifecycle (i.e: you sent a response).

That's why I think this is a limitation imposed by the browser.

Take a look:

@RestController
@RequestMapping(path = "test")
public class TestController {

    private final Logger log = LoggerFactory.getLogger(this.getClass());

    @GetMapping
    public ResponseEntity<Object> handleTest() throws InterruptedException {
        log.info("Thread {} started", Thread.currentThread().toString());
        Thread.sleep(5000);
        log.info("Thread {} finished", Thread.currentThread().toString());

        return ResponseEntity.ok("EXECUTED!!");
    }

}

First test

5 opened tabs in the browser

This gets logged instantly

2019-10-17 09:36:37.514  INFO 10324 --- [nio-8083-exec-1] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-1,5,main] started

Now, after all 5 request (5 tabs) receive a response (take a look at the time - one is executed after another):

2019-10-17 09:36:37.514  INFO 10324 --- [nio-8083-exec-1] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-1,5,main] started
2019-10-17 09:36:42.515  INFO 10324 --- [nio-8083-exec-1] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-1,5,main] finished
2019-10-17 09:36:42.551  INFO 10324 --- [nio-8083-exec-2] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-2,5,main] started
2019-10-17 09:36:47.551  INFO 10324 --- [nio-8083-exec-2] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-2,5,main] finished
2019-10-17 09:36:47.559  INFO 10324 --- [nio-8083-exec-4] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-4,5,main] started
2019-10-17 09:36:52.560  INFO 10324 --- [nio-8083-exec-4] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-4,5,main] finished
2019-10-17 09:36:52.571  INFO 10324 --- [nio-8083-exec-5] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-5,5,main] started
2019-10-17 09:36:57.572  INFO 10324 --- [nio-8083-exec-5] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-5,5,main] finished
2019-10-17 09:36:57.582  INFO 10324 --- [nio-8083-exec-6] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-6,5,main] started
2019-10-17 09:37:02.584  INFO 10324 --- [nio-8083-exec-6] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-6,5,main] finished

Second test

Refreshing the page in the browser

Go ahead, open your browser, type the URL, press ENTER and start pressing CTRL + R.

I pressed CTRL + R four times.

So there will be 1 + 4 request (the first (with ENTER) and the subsequent 4 requests (with CTRL + R))

I can see that all 5 threads start running in parallel:

2019-10-17 09:46:30.149  INFO 10324 --- [nio-8083-exec-9] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-9,5,main] started
2019-10-17 09:46:30.471  INFO 10324 --- [io-8083-exec-28] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-28,5,main] started
2019-10-17 09:46:30.713  INFO 10324 --- [io-8083-exec-29] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-29,5,main] started
2019-10-17 09:46:30.981  INFO 10324 --- [io-8083-exec-10] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-10,5,main] started
2019-10-17 09:46:31.244  INFO 10324 --- [nio-8083-exec-1] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-1,5,main] started

Third test

Using two different clients

Go ahead, try with Postman (or any other http client) and with your browser.

Send a request with the browser, ALT + TAB and send the request with Postman.

I can see that the two threads start running in paralel (first request was from the browser and the second request were made using Postman):

2019-10-17 09:50:31.663  INFO 10324 --- [nio-8083-exec-5] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-5,5,main] started
2019-10-17 09:50:32.587  INFO 10324 --- [nio-8083-exec-9] b.c.d.m.controller.TestController        : Thread Thread[http-nio-8083-exec-9,5,main] started

By seeing these tests, I'm convinced that this is a limitation imposed by the browser.

Matheus
  • 3,058
  • 7
  • 16
  • 37
  • 1
    hello! Thanks for your answer! Your right, it is a limitation by the browser https://docs.pushtechnology.com/cloud/latest/manual/html/designguide/solution/support/connection_limitations.html After using multiple 'curl' all work like it should! Good for this problem and my knowledge about "parallel" execution, but not for my initial Problem! (which was not described here) Thanks a lot! – JekO Oct 17 '19 at 13:27
  • In case anyone else comes across this but for 2 parallel requests, Chromium browsers block when requesting cacheable resources. See https://stackoverflow.com/q/27513994/2506594 – Devin H. Nov 12 '19 at 13:05