Как предотвратить, чтобы один неотвечающий член набора реплик ухудшил работу всего приложения? - PullRequest
0 голосов
/ 14 мая 2019

Обзор

Триггер: Член набора реплик перестает отвечать на запросы.

Проблема: Драйвер продолжит маршрутизировать запросы на подключение кнеотвечающий член набора реплик.Потоки, ожидающие ответа или соединения, накапливаются «перед» этим элементом, пока они в конечном итоге не исчерпают пул потоков приложения.Целое приложение останавливается на несколько минут, пока не истечет время ожидания или возврата потоков.

Мои вопросы: Эта проблема меня действительно удивляет - не должен ли драйвер принять распределение потоков между членами набора реплик вучетная запись при принятии решения, к какому участнику направлять запросы?Как другие пользователи справляются с этим поведением?

Я создал пример проекта (https://github.com/McKeeAtx/mongo-java-driver-degradation-example), который демонстрирует, как один не отвечающий элемент набора реплик делает клиентское приложение не отвечающим в течение нескольких минут.во время тестирования использовалась локальная настройка:

  • OpenJDK 1.8.0_121
  • macOS High Sierra 10.13.6
  • версия mongod v3.4.20
  • mongo-java-driver 3.10.2

Начальная настройка

Создание трех пустых каталогов rs0-0, rs0-1 и rs0-2.

Запуск трех экземпляров mongod:

mongod --replSet rs0 --port 27017 --bind_ip 127.0.0.1 --dbpath rs0-0 --smallfiles --oplogSize 128
mongod --replSet rs0 --port 27018 --bind_ip 127.0.0.1 --dbpath rs0-1 --smallfiles --oplogSize 128
mongod --replSet rs0 --port 27019 --bind_ip 127.0.0.1 --dbpath rs0-2 --smallfiles --oplogSize 128

Войдите в оболочку mongo и настройте набор реплик

mongo
> rsconf = { _id: "rs0", members: [ { _id: 0, host: "127.0.0.1:27017" }, { _id: 1, host: "127.0.0.1:27018" }, { _id: 2,      host: "127.0.0.1:27019" } ] }
> rs.initiate(rsconf)
{ "ok" : 1 }

Создайте тестовую базу данных:

rs0:PRIMARY> use test
mongo
switched to db test

Запустите DataFixture, чтобы вставить 10000документы в коллекцию test в базе данных test.

Запуск примера

Запуск трех экземпляров mongod:

mongod --replSet rs0 --port 27017 --bind_ip 127.0.0.1 --dbpath rs0-0 --smallfiles --oplogSize 128
mongod --replSet rs0 --port 27018 --bind_ip 127.0.0.1 --dbpath rs0-1 --smallfiles --oplogSize 128
mongod --replSet rs0 --port 27019 --bind_ip 127.0.0.1 --dbpath rs0-2 --smallfiles --oplogSize 128

Запустите приложение Consumer.

ConnectionHistogramListener регистрирует простую гистограмму каждый раз, когда ConnectionPoolWaitQueueEnteredEvent событие iОпубликовано:

  • connected: нет потоков, которые установили соединение с участником
  • waiting: нет потоков, ожидающих подключения к члену

Пример:

11:47:41 [pool-2-thread-2] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 2, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}

Вышеприведенная строка гласит:

  • подключиться к 127.0.0.1:27019: драйвервыбирает 127.0.0.1: 27019 для следующего запроса на подключение
  • 127.0.0.1: 27019 [подключено: 2, ожидание: 1] : 2 потока подключены к 127.0.0.1: 27019 , 1 поток ожидает подключения
  • 127.0.0.1: 27018 [подключено: 0, ожидание: 0] : 0 потоков подключено к 127.0.0.1: 27018 , 0 потоков ожидают подключения
  • 127.0.0.1: 27017 [подключено: 0, ожидание: 0] : 0 потоков подключенодо 127.0.0.1: 27017 , 0 потоков ожидают подключения

Удалите один элемент набора реплик

Определите PID набора репликчлен:

ps -ef | grep mongo | grep "replSet"
  501 24989 11889   0  7:42AM ttys001    0:30.81 mongod --replSet rs0 --port 27017 --bind_ip 127.0.0.1 --dbpath rs0-0 --smallfiles --oplogSize 128
  501 24990 11905   0  7:42AM ttys002    0:30.02 mongod --replSet rs0 --port 27018 --bind_ip 127.0.0.1 --dbpath rs0-1 --smallfiles --oplogSize 128
  501 24991 11922   0  7:42AM ttys005    0:30.03 mongod --replSet rs0 --port 27019 --bind_ip 127.0.0.1 --dbpath rs0-2 --smallfiles --oplogSize 128

В этом примере мы выбираем 24991 (член, который прослушивает порт 27019).

Используйте cpulimit, чтобы уменьшить процент ЦП, который будет назначен этому процессу:

cpulimit -p 24991 -l 0
Process 24991 found

Алгоритм выбора сервера теперь продолжает циклически обрабатывать запросы на соединение между тремя членами набора реплик.Все участники считаются

  • приемлемыми
  • не устаревшими
  • и в пределах окна задержки.

Пример журнала:

11:47:34 [pool-2-thread-1] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:34 [pool-2-thread-1] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 0, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:34 [pool-2-thread-1] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 0, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:35 [pool-2-thread-2] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:35 [pool-2-thread-2] -    connect to 127.0.0.1:27017: {127.0.0.1:27019[connected: 0, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
11:47:35 [pool-2-thread-2] -    connect to 127.0.0.1:27017: {127.0.0.1:27019[connected: 0, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}

// now the node 127.0.0.1:27019 is 'frozen'
cpulimit -p 24991 -l 0
Process 24991 found

11:47:36 [pool-2-thread-3] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:36 [pool-2-thread-3] -    connect to 127.0.0.1:27017: {127.0.0.1:27019[connected: 0, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
11:47:36 [pool-2-thread-3] -    connect to 127.0.0.1:27017: {127.0.0.1:27019[connected: 0, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
11:47:37 [pool-2-thread-4] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:37 [pool-2-thread-4] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 0, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:38 [pool-2-thread-5] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:38 [pool-2-thread-5] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 1, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:39 [pool-2-thread-6] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:39 [pool-2-thread-6] -    connect to 127.0.0.1:27017: {127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
11:47:39 [pool-2-thread-6] -    connect to 127.0.0.1:27017: {127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
11:47:40 [pool-2-thread-1] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:40 [pool-2-thread-1] -    connect to 127.0.0.1:27018: {127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:40 [pool-2-thread-1] -    connect to 127.0.0.1:27018: {127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:41 [pool-2-thread-2] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:41 [pool-2-thread-2] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 2, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:42 [pool-2-thread-3] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:42 [pool-2-thread-3] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 2, waiting: 2],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:43 [pool-2-thread-6] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:43 [pool-2-thread-6] -    connect to 127.0.0.1:27018: {127.0.0.1:27019[connected: 2, waiting: 2],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:43 [pool-2-thread-6] -    connect to 127.0.0.1:27018: {127.0.0.1:27019[connected: 2, waiting: 2],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:44 [pool-2-thread-1] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 3286, 127.0.0.1:27017: 2081}
11:47:44 [pool-2-thread-1] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 2, waiting: 3],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
11:47:45 [pool-2-thread-6] - Roundtrip times (micro): {127.0.0.1:27019: 3257, 127.0.0.1:27018: 2885, 127.0.0.1:27017: 1917}
11:47:45 [pool-2-thread-6] -    connect to 127.0.0.1:27019: {127.0.0.1:27019[connected: 2, waiting: 4],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}

Узел 127.0.0.1:27019 не отвечает на запросы своевременно, но он по-прежнему выбирается алгоритмом выбора сервера, потому что он все еще попадает в допустимое окно задержки в соответствии с устаревшими (!) Данными туда-обратно.С каждым решением в пользу 127.0.0.1:27019 другой поток накапливается в ожидании ответа или соединения.

Сокращенная версия вышеприведенного журнала показывает, как потоки накапливаются в ожидании 127.0.0.1:27019:

127.0.0.1:27019[connected: 0, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
127.0.0.1:27019[connected: 0, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
127.0.0.1:27019[connected: 0, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 1, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 1]}
127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 0],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 1],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 2],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 2],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 2],127.0.0.1:27018[connected: 0, waiting: 1],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 3],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}
127.0.0.1:27019[connected: 2, waiting: 4],127.0.0.1:27018[connected: 0, waiting: 0],127.0.0.1:27017[connected: 0, waiting: 0]}

В конечном итоге все потоки в пуле потоков приложения (фиксированный пул с 6 потоками впример приложения) будет ожидать 127.0.0.1:27019, в результате чего все приложение не отвечает, хотя члены набора реплик 127.0.0.1:27017 и 127.0.0.1:27018 могут по-прежнему обслуживать запросы.

Через пару минут потоки, ожидающие 127.0.0.1:27019, либо возвращаются, либо истекают, и драйвер останавливает для направления дальнейших запросов на 127.0.0.1:27019. Затем приложение восстанавливается, распределяя трафик между членами набора исправных реплик 127.0.0.1:27017 и 127.0.0.1:27018.

С точки зрения пользователей, такое поведение вызывает полный сбой клиентского приложения, который длится несколько минут.

Consumer.java

public class Consumer {

    public static void main( String[] args ) throws ExecutionException, InterruptedException, IOException {
        MongoClient client = Configuration.createClient(true);
        MongoDatabase db = client.getDatabase("test");
        final MongoCollection<Document> customers = db.getCollection("test");
        ExecutorService executorService = Executors.newFixedThreadPool(6);

        for (;;) {
            executorService.submit(() -> {
                FindIterable<Document> documents = customers.find();
                documents.into(new LinkedList<>());
            });
            Thread.sleep(1000);
        }
    }
}

Configuration.java

public class Configuration {

    private static ClusterConnectionMode mode = ClusterConnectionMode.MULTIPLE;

    private static int minConnections = 2;

    private static int maxConnections = 2;

    private static int maxWaitQueueSize = 6;

    private static int connectionTimeoutInMs =  500;

    private static int readTimeoutInSeconds = 45;


    static List<ServerAddress> servers = asList(
            new ServerAddress("127.0.0.1", 27017),
            new ServerAddress("127.0.0.1", 27018),
            new ServerAddress("127.0.0.1", 27019)
    );

    static MongoClient createClient(boolean withHistogramListener) {
        return MongoClients.create(MongoClientSettings.builder()
                .applyToConnectionPoolSettings(builder -> builder.applySettings(
                        ConnectionPoolSettings.builder()
                                .addConnectionPoolListener(withHistogramListener ? new ConnectionHistogramListener() : new NoOpListener())
                                .minSize(minConnections)
                                .maxSize(maxConnections)
                                .maxWaitQueueSize(maxWaitQueueSize)
                                .build()))
                .readPreference(ReadPreference.nearest())
                .applyToSocketSettings(builder -> builder.applySettings(
                        SocketSettings.builder()
                                .connectTimeout(connectionTimeoutInMs, TimeUnit.MILLISECONDS)
                                .readTimeout(readTimeoutInSeconds, TimeUnit.SECONDS)
                                .build()
                ))

                .applyToClusterSettings(builder -> builder.applySettings(
                        ClusterSettings.builder()
                                .mode(mode)
                                .hosts(servers)
                                .maxWaitQueueSize(maxWaitQueueSize)
                                .serverSelector(new RoundtripTimeTracingSelector())
                                .build()))
                .build());
    }
}
...