jersey server side async API not working as expected

Question

I just read the jersey document and tried to compare how much time I can save by using the async server side api, but the result I got was confusing, please help to spot if there is something wrong in my code.

This is the resource class:

@Path("/async-sync")
public class CompareAsyncAndSyncResource {
    @GET
    @Path("sync-call")
    public String syncCall() throws InterruptedException {
        expensiveComputation();
        return "sync call finished";
    }

    @GET
    @Path("async-call")
    public void asyncCall(@Suspended final AsyncResponse asyncResponse) throws InterruptedException {
        new Thread(new Runnable() {
            @Override
            public void run() {
                expensiveComputation();
                asyncResponse.resume("async call finished");
            }
        }).start();
    }

    private void expensiveComputation() {
        try {
            sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

One sync get call and one async get call.

Then I made these tests:

public class CompareAsyncAndSyncResourceTest extends JerseyTest {
    @Override
    protected Application configure() {
        return new ResourceConfig().register(CompareAsyncAndSyncResource.class);
    }

    @Test
    public void sync_call_should_take_longer() throws Exception {
        final Stopwatch stopwatch = new Stopwatch();
        stopwatch.start();

        callFiveTimes(new Runnable() {
            @Override
            public void run() {
                String resp = target("async-sync/sync-call").request().get().readEntity(String.class);
                System.out.println("sync returned " + stopwatch.elapsed(TimeUnit.MILLISECONDS));
                assertThat(resp, is("sync call finished"));
            }
        });

        stopwatch.stop();

        System.out.println("five clients calling sync get at same time " + stopwatch.elapsed(TimeUnit.MILLISECONDS));
    }

    @Test
    public void async_call_should_take_shorter() throws Exception {
        final Stopwatch stopwatch = new Stopwatch();
        stopwatch.start();

        callFiveTimes(new Runnable() {
            @Override
            public void run() {
                String resp = target("async-sync/async-call").request().get().readEntity(String.class);
                System.out.println("async returned " + stopwatch.elapsed(TimeUnit.MILLISECONDS));
                assertThat(resp, is("async call finished"));
            }
        });

        stopwatch.stop();

        System.out.println("five clients calling async get at same time " + stopwatch.elapsed(TimeUnit.MILLISECONDS));
    }

    private void callFiveTimes(final Runnable runnable) throws InterruptedException {

        Iterable<Integer> rangeOfFive = newArrayList(1, 2, 3, 4, 5);
        FluentIterable<Thread> threads = from(rangeOfFive).transform(new Function<Integer, Thread>() {
            @Override
            public Thread apply(Integer number) {
                Thread thread = new Thread(runnable);
                thread.start();
                return thread;
            }
        });

        for (Thread thread : threads) {
            thread.join();
        }
    }
}

In the tests, I simulated five clients calling the two get calls at the same time, I imagined that the five async get calls would be much faster to complete, but this is the result I got:

sync returned 1052
sync returned 2063
sync returned 3073
sync returned 4082
sync returned 5095
five clients calling sync get at same time 5096

the sync part is anticipated, it takes a little more that 5 seconds to complete, consists of five calls and a little overhead.

but the async result lost me:

async returned 1847
async returned 2893
async returned 3904
async returned 4913
async returned 5923
five clients calling async get at same time 5923

looks like those five async calls are not really processed asynchronously.

What am I doing wrong?

PS: the code is here: https://github.com/cuipengfei/jerseywhatnot/blob/master/src/main/java/com/jersey/whatnot/async/CompareAsyncAndSyncResource.java

Edit: I know what I did wrong now, it's guava, i should have called toList. The lazy eval got me again. But what seems strange is that the sync call also got faster, why is that? According to jersey's document, sync get calls are supposed to block the IO thread and slow all thins down, but it seems like it's not happening.

Answer 1

That's not what async does at all.

Fundamentally, all the asynch facility in the Java Servlet Spec (which Jersey leverages) does is allow you to separate the incoming request from the initial thread.

Normally the request and processing thread are bound together.

Facilitating this separation does not, in itself, make anything faster. It's what you do with it that can make it faster.

You mini benchmark calls the server 5 times in a row. The sync version puts, the processing on the original request thread, blocks for a second, then resumes. But if you consider this, at no time is your server ever consuming more than one active processing thread, since all of your calls are serialized to the server (i.e. 1, then 2, then 3 ...).

Your async call takes the request, then, rather than servicing it directly, it immediately creates a NEW thread, and then that thread finishes the processing. In this case, each request consume part of the initial thread, and then continues with the second thread. However, it has to allocate and dispatch to that new thread, something your original sync code does not. That dispatch takes time, time your sync thread did not take, and thus is "slower". It's slower because it's simply doing more work. (The server is also doing a little more work wrapping your request in the async context and whatever internal bookkeeping that entails).

Where async gives you its value is not on an unloaded server. It's on a loaded server.

The threading process itself take time in the server, especially when you have 100's or 1000's of requests. At that level, the threading overhead itself is impactful, particularly when loaded. Async lets you better divvy up work off of the request answering threads on to other facilities to do the heavy lifting. The request threads then simply become the reception desks, the "how may I direct your call" operators. Once they're done routing the work, they can move on to accept other requests.

Ideally you may notice that many companies don't have very many "how may I direct your call" operators, as the work isn't particularly time consuming. A single operator can direct a lot of calls compared to someone actually performing the requests. So, fewer threads are needed solely for accepting requests and routing them, compared to doing real processing.

With async you can turn your application internally in to one of those customer support places that keeps bouncing your from person to person. This actually lets your system behave more efficiently at load since folks aren't all jammed up in the hallways, but quietly sitting in individual waiting rooms (queues) to wait their turn for real work.

That's the value of the Async facility in Java Servlets. Doing what you're doing, with a simple microbenchmark, they're just doing more work for no reason.