Measure time a tasks waits in queue before being executed Java ThreadPoolExecutor

Question

I have a ThreadPoolExecutor using a blocking queue and I am trying to debug an issue where I suspect tasks are being stuck too long in the ThreadPoolExecutor's queue for too long before being executed. I'm trying to validate this theory and was wondering what the best way to monitor the length from being enqueued to right before it is executed.

Answer 1

A trick I've used occasionally is to add "tracer" tasks that measure the time they spend in the queue. To measure the time, take the timestamp of when the task is added, and compare it with the timestamp of when the task starts running. The simplest possible form is:

    long time = System.nanoTime();
    executorService.submit(() -> {
        System.out.println("Queued for " + System.nanoTime() - time);
    });

This is a good solution if you mainly care about the tasks waiting for longer than a fixed threshold, like if you need the response within a certain time limit. The tracer tasks wait in the queue just as long as the real tasks. If you have a timeout of 1 minute, adding a tracer every 30 seconds gives you a pretty good idea of how close the queueing time is to 1 minute. It's also very easy to implement, you can apply the technique to any existing executor service.

This can only tell you how long tasks are waiting in the queue at the time when you submitted this task, which may too coarse-grained. If you need to know the queueing time for every task you submit, and you are willing to customize the executor service implementation, you can do more things:

• You can create a custom ExecutorService implementation that includes time measurements. When tasks are added through the submit or invoke method you record the current time with the task. When the task runs, you calculate and log the queueing time, for example in the beforeExecute method

• Or, you can create a custom work queue implementation that incorporates time measurements. When a task is added, it would record the current timestamp with the task, and when a task is removed, it would compare the current timestamp with the task's timestamp.