ExecutorFramework добавляет много времени в тест производительности?

Я работаю над проектом, в котором я пытаюсь сделать вызов URL-адреса на один из моих серверов, используя RestTemplate, который возвращает мне строку JSON в качестве ответа, и он работает нормально...

Теперь я решил провести некоторые тесты производительности на этом...

Ниже мой код, который использует ExecutorService и Callables -

public class URLTest {

    private ExecutorService executor = Executors.newFixedThreadPool(10);

    public String getData() {
        Future<String> future = executor.submit(new Task());
        String response = null;

        try {
            System.out.println("Started..");
            response = future.get(200, TimeUnit.MILLISECONDS);
            System.out.println("Finished!");
        } catch (TimeoutException e) {
            System.out.println("Terminated!");
        } catch (InterruptedException e) {
            e.printStackTrace();
        } catch (ExecutionException e) {
            e.printStackTrace();
        }

        return response;
    }
}

Ниже мой класс Task, который реализует интерфейс Callable -

class Task implements Callable<String> {

    private RestTemplate restTemplate = new RestTemplate();

    public String call() throws Exception {
        String url = "some_url";
    //  TimerTest timer = TimerTest.getInstance();  // line 3
        String response = restTemplate.getForObject(url, String.class);
    //  timer.getDuration();    // line 4
        System.out.println(response);

        return response;

    }
}

А ниже мой код в другом классе DemoTest, который вызывает метод getData в классе URLTest 500 times и измеряет его 95-й процентиль, поскольку это то, что мне нужно сделать -

public class DemoTest { 
    public static void main(String[] args) {

        URLTest bc = new URLTest();
        for (int i = 0; i <= 500; i++) {
            TimerTest timer = TimerTest.getInstance(); // line 1
            bc.getData();
            timer.getDuration(); // line 2
        }

        // this method prints out the 95th percentile
        logPercentileInfo();

    }
}   

С приведенным выше кодом я всегда вижу 95-й процентиль как 14-15 ms (что плохо для моего варианта использования, поскольку это сквозной поток, и это то, что мне нужно измерить), но если я закомментирую line 1 и line 2 в классе DemoTest и раскомментируйте line 3 и line 4 в классе Task, а затем снова запустите программу, она начнет давать мне 95-й процентиль как 3 ms.

удивляюсь почему? ExectuorFramework добавляет сюда всю задержку? И почему, если я просто измеряю производительность вызова RestTemplate, она всегда дает мне более высокую производительность по сравнению со сквозной производительностью?

Моя главная цель - максимально уменьшить задержку здесь. Мой вариант использования прост: сделать вызов URL-адреса на один из моих серверов с включенной функцией TIMEOUT, что означает, что если серверу требуется много времени для ответа, то тайм-аут весь звонок.

И моя клиентская программа, и сервер работают в PRODUCTION в одном и том же центре обработки данных, поэтому время пинга составляет около 0,5 мс.

Я запускал пару раз, чтобы сделать этот тест, и все тот же результат.

Есть ли что-то, что мне не хватает, или какие-то другие варианты ExecutorService, которые мне нужно использовать? Как я могу улучшить свою работу здесь? Любые предложения будут очень полезны ..

ОБНОВЛЕНИЕ:-

Добавлено время прогрева -

   public static void main(String[] args) {

    URLTest bc = new URLTest();

    // little bit warmup
    for (int i = 0; i <= 500; i++) {
        bc.getData();
    }

    for (int i = 0; i <= 500; i++) {
        TimerTest timer = TimerTest.getInstance();
        bc.getData();
        timer.getDuration();
    }

    logPercentileInfo();

    }

person Community    schedule 20.01.2014    source источник
comment
Может быть, это просто плохой бенчмарк? Учитывая ваши цифры, я понимаю, что весь тест занимает несколько секунд, что, вероятно, нормально, но вы должны отказаться от первых двух результатов. По сути, проделайте весь цикл один раз в качестве разминки и повторите его, чтобы получить результаты.   -  person maaartinus    schedule 20.01.2014
comment
Это то, что я сделал, маартинус.. Я запустил его в первый раз и после его завершения, а затем снова запустил, чтобы измерить производительность.. И все равно получил те же цифры..   -  person    schedule 20.01.2014


Ответы (1)


ExecutorService добавляет задержку, потому что он должен управлять рабочими потоками и рабочей очередью.

Но это НЕ должно быть причиной разницы в 12 мс.

Насколько я вижу, здесь есть несколько проблем:

  • maaartinus упомянул, что вы «насыщаете» свой бассейн. Но мне кажется наоборот: каждая задача отправляется, а поток отправки ждет (через future.get), пока задача не будет завершена.
  • Разрешение вашего таймера может быть слишком низким для надежного измерения промежутков времени ‹10 мс (это зависит от нескольких факторов — особенно говорят, что системы Windows имеют сравнительно низкое разрешение таймера)
  • В одном случае вы измеряете время для System.out.println(response), а в другом — нет.

РЕДАКТИРОВАТЬ: По запросу в комментариях пример ExecutorCompletionService:

import java.util.Random;
import java.util.concurrent.Callable;
import java.util.concurrent.CompletionService;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.ExecutorCompletionService;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;


public class ExecutorCompletionExample
{
    public static void main(String[] args) 
    {
        ExecutorService executor = Executors.newFixedThreadPool(10);
        CompletionService<String> completionService = 
            new ExecutorCompletionService<String>(executor);

        int n = 500;
        for (int i = 0; i < n; i++) 
        {
            Task task = new Task("Task"+i);
            completionService.submit(task);
        }


        for (int i = 0; i < n; ++i) 
        {
            try
            {
                Future<String> future = completionService.take();
                String response = future.get();
                System.out.println("Response: "+response);
            }
            catch (InterruptedException e)
            {
                Thread.currentThread().interrupt();
                return;
            }
            catch (ExecutionException e)
            {
                e.printStackTrace();
            }
        }
    }
}


class Task implements Callable<String> 
{
    private static Random random = new Random(0);

    private String name;
    private long delay;

    Task(String name)
    {
        this.name = name;
        this.delay = 10 + random.nextInt(10)*10;
    }
    public String call() throws Exception 
    {
        //String response = restTemplate.getForObject(url, String.class);
        Thread.sleep(delay);
        String response = "Response of "+name+" with delay "+delay;
        return response;
    }
}

Использование довольно простое, и, насколько я понимаю, исходный вопрос относился к задаче, соответствующей описанию интерфейса CompletionService:

«Служба, которая отделяет создание новых асинхронных задач от потребления результатов завершенных задач… Например, CompletionService можно использовать для управления асинхронным вводом-выводом, в котором задачи, выполняющие чтение, отправляются в одной части программы или системе, а затем действовать в другой части программы, когда чтение завершено, возможно, в другом порядке, чем они были запрошены».

Действительно ли это соответствует предполагаемому варианту использования (и, конечно, помогает ли это достичь желаемого снижения общей задержки), невозможно проверить на основе данного примера.

person Marco13    schedule 20.01.2014
comment
Спасибо, Марко, я удалил System.out.println(response), как указано в третьем пункте, и все равно получаю те же числа. Что касается вашего первого пункта, вот как мы поступаем правильно, если мне нужно прервать любой вызов, если это занимает некоторое время? Если я измеряю непосредственно производительность RestTemplate, то это дает мне 3 мс 95-го процентиля, что означает, что ответ возвращается через 3 мс, тогда почему это занимает дополнительные 12 мс, если я измеряю сквозной поток? И по вашему второму пункту я использую System.nanoTime для его измерения. - person ; 20.01.2014
comment
Что касается времени: даже System.nanoTime() не имеет разрешения в наносекундах, но это сложная (и противоречиво обсуждаемая) тема - отправной точкой может быть stackoverflow.com/questions/351565/ Что касается потоковой передачи: вы можете рассмотреть возможность использования ExecutorCompletionService для получения завершенных задач, но конечно есть несколько вариантов, в зависимости от предполагаемой инфраструктуры - person Marco13; 20.01.2014
comment
Спасибо, Марко.. Спасибо за вашу помощь.. Если возможно, можете ли вы предоставить мне пример для ExecutorCompletionService на моем примере? Я немного заржавел с многопоточным кодом. Если вы можете привести пример на моем примере, тогда я смогу кое-что узнать. Спасибо. - person ; 20.01.2014
comment
Добавил пример, надеюсь, его можно перенести на ваш вариант использования. - person Marco13; 21.01.2014