Статьи

Интенсивный анализ сборки мусора Java JVM Neo4j, размера кучи, ротации журналов и т. Д.

Мы начали сталкиваться с некоторыми проблемами тайм-аута при загрузке десятков тысяч узлов с полнотекстовыми индексами в Neo4j. Мы решили взглянуть на него с установки по умолчанию, а затем настроить его до приемлемых уровней. В настоящее время при загрузке узлов через Rest API происходит сбой около отметки 4000 узлов. Ниже приведены записи о том, что нам нужно было сделать для успешного выполнения импорта узлов.

Примечание: это относится к использованию Neo4j только через REST API! Мы используем Neo4jClient, который можно найти на NuGet: http://nuget.org/List/Packages/Neo4jClient

Конечно, если вы используете нативный Java, то обход остальных API и использование встроенного пакетного API будет НАМНОГО быстрее!

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

Вкратце:

Оптимизируйте потоки вашего клиента, чтобы они были ниже 80, поскольку сервер Neo4j выделил 80 потоков для JVM, поэтому нет смысла отправлять вызовы отдыха более чем на 80 потоков. (Это для машины с 8 ядрами (Neo4j выделил 10 потоков на ядро)).

Так что если у вас neo4j сервер двухъядерный (10 * 2) = 20 потоков. Четырехъядерный процессор = 40 потоков.

Используйте API остатка дозирования.

Если вы используете Gremlin, используйте параметризованные запросы.

Использовать схему автоматического выключателя для реализации логики повторных попыток в случае сбоя вызовов (необязательно)

Шаги по настройке профилирования

Убедитесь, что в файле neo4j-wrapper.conf находятся следующие записи:

# Исходный размер кучи Java (в МБ)
wrapper.java.initmemory = <Ваше значение>

# Максимальный размер кучи Java (в МБ)
wrapper.java.maxmemory = <Ваше значение>

#Enable Журнал сбора мусора JVM
wrapper.java.additional.3 = -Xloggc: data / log / neo4j-gc.log

Загрузите следующий инструмент, чтобы получить графическое представление статистики GC и кучи.

http://www.tagtraum.com/gcviewer.html

сценарий

  • Загрузка 30000 клиентских узлов в граф с одним отношением и + — 5 записями полнотекстового индекса.
  • + — 12 активных HTTP-соединений с Neo4JServer
  • Neo4j работает в эмуляторе облачного хранилища Windows Azure в качестве рабочей роли.
  • Java 1.6

Спецификация машины

Ноутбук Lenovo W701, диск 5400 об / мин для базы данных, SSD для загрузки / системы, память 18 ГБ, Intel LGA 1156 I7 820QM (Clarksfield)

Размер кучи по умолчанию

# Исходный размер кучи Java (в МБ)
wrapper.java.initmemory = 3

# Максимальный размер кучи Java (в МБ)
wrapper.java.maxmemory = 64

 

образ

  • Обратите внимание, что стрелка показывает количество сборов GC второго поколения ( черные линии ), сразу после этого произошел сбой импорта примерно на 4500 записей узлов, а затем мы начали получать тайм-ауты с сервера Neo4j.
  • Java.exe занимал примерно от 150 до 200 МБ памяти.
  • Производительность ГХ при 785M / S

Пользовательский размер кучи (Windows)

# Исходный размер кучи Java (в МБ)
wrapper.java.initmemory = 1024

# Максимальный размер кучи Java (в МБ)
wrapper.java.maxmemory = 2048

образ

  • Java.exe занимал примерно от 600 до 750 МБ памяти.
  • Размер кучи казался разумным местом, так как было достаточно свободного места для кучи.
  • Тайм-ауты начали появляться на уровне около 3500 узлов.
  • Сборка мусора (второе поколение) теперь оптимизирована, не так много черных линий
  • Размер кучи увеличился в размерах около точки ожидания
  • Синяя линия работает хорошо, это использованная куча, которая остается неизменной на отметке 450 МБ.
  • Производительность ГХ при 4762 м / с

образ

образ

Другой прогон загрузки, показанный ниже, показывает аналогичные результаты, но более высокую производительность GC после следующих изменений в системе:

  • JRE 1.7.0
  • Windows Azure SDK 1.5
  • Загрузите данные в новое чистое хранилище БД.

образ

  • Производительность сборщика мусора теперь составляет 12 974 М / с.
    Размер настраиваемой кучи определенно увеличил производительность сборщика мусора за счет меньшего количества сборок второго поколения, однако он не решил основную причину проблемы, когда происходят тайм-ауты в сети. на остальных звонках около отметки 3500-4500 узлов.

Тайм-аут API остальных в 3:11 по местному времени.

[03:11:20] [Thread  27] Failed importing client

Интересно, что в течение следующих 5 минут сервер использовал все мои 8 ядер на процессоре, и я полагаю, что это было для очистки или пролистывания журналов транзакций, что, возможно, и стало основной причиной того, что остальная часть API перестала отвечать. Мы можем видеть доказательства этого в файловой системе. Поскольку метка даты и времени находится ровно через 5 минут после записи в журнале 3:11, когда API отдыха остановлен. Обратите внимание, что размер файла в байтах. то есть 3, 362 544 + — 3 МБ.

Каталог C: \ AzureTemp \ neo4j-db

20.09.2011 15:16 11 active_tx_log

20.09.2011 15:15 3 362 544 nioneo_logical.log.

20.09.2011 15:16 29 372 tm_tx_log.1

20.09.2011 15:16 596 tm_tx_log.2

Каталог C: \ AzureTemp \ neo4j-db \ index

20.09.2011 15:17 1 499 357 lucene.log.1

оптимизация

JVM

Первым делом я добавил, что JVM работает в режиме сервера, 64-битный, с размером стека 2048 КБ на поток (по умолчанию 1024 КБ для 64-битного). Я добавил следующие строки в neo4j-wrapper.conf.

wrapper.java.additional.1 = -d64

wrapper.java.additional.1 = -server

wrapper.java.additional.1 = -Xss2048k (Мы используем несколько потоков в приложении.)

Использование JVM в режиме сервера оптимизирует код. JIT, используемый в режиме сервера, собирает больше информации о работающем коде перед оптимизацией и, таким образом, выполняет работу по оптимизации кода намного лучше

Авторация журнала транзакций базы данных Neo4J

Следующая часть — улучшить производительность записи системы баз данных Neo4j. Для этого мы можем пойти двумя путями.

  • Отключить авторизацию журнала транзакций
  • Увеличить размер журнала транзакций,

Подробнее об этом читайте здесь: http://wiki.neo4j.org/content/Performance_Guide (раздел «Запись производительности»)


    Таким образом, снижается частота сбрасываний из памяти в дисковую подсистему БД, что в свою очередь уменьшит количество не отвечающих ответов Rest API.

Теперь мы являемся клиентом .Net, поэтому мы будем использовать API Rest для выполнения Groovy-скрипта, который будет динамически запускать Java-код для нас. Тем не менее, прежде чем мы привыкнем к Neo4jClient, давайте сначала протестируем это, загрузив сервер neo4j, а затем используя встроенный веб-сервер api, чтобы вручную выполнить код java в руководстве по производительности, чтобы отключить автоматическое вращение журнала tx, например:

import org.neo4j.kernel.EmbeddedGraphDatabase. *

neo4j = g.getRawGraph ()

txModule = neo4j.getConfig (). getTxModule ();

xaDsMgr = txModule.getXaDataSourceManager ();

xaDs = xaDsMgr.getXaDataSource («nioneodb»);

xaDs.setAutoRotate (false);

Вот скриншот команд, выполняемых через консоль. Я буду обновлять пакет NUGET Neo4jClient для поддержки отключения журналов TX, а также с помощью оставшихся вызовов API.

образ

Сейчас я начинаю импорт 35000 узлов, которые также имеют полнотекстовые индексы Lucene. Ниже приведены скриншоты на разных этапах

+ — 400 узлов импортировано

образ

+ — 1000 узлов импортировано

образ

образ

После работы в течение + — 50 минут системе не хватило памяти (несмотря на то, что на машине было более 8 ГБ свободной памяти!)

образ

Интересно то, что Java использует только 706 памяти.

Таким образом, вывод здесь заключается в том, что поворот роликов TX Log не повлиял на производительность или отзывчивое увеличение остального API.

Остальные звонки Lucene Index

Затем мы отключили все вызовы создания полнотекстового индекса при создании узлов, чтобы увидеть производительность, и попытались изолировать, откуда возникла проблема: Neo4j, Lucene или их комбинация.

Отключив индексные вызовы Lucene, мы получили более быстрое время отклика. Примерно 4,5 узла в секунду, по сравнению с 3,9 узлами в секунду.

Тем не менее, реальный тест будет состоять в том, чтобы убедиться, что API REST перестает отвечать на запросы, JVM действительно перестает отвечать на запросы с отключенными вызовами индекса, это произошло примерно при 20000 созданиях узлов. Создание узла — это два вызова для нас, запрос gremlin для проверки существования узла и затем POST.

Сценарий — Неоптимизированный код Gremlin (не параметризован)

При отключенных вызовах индекса Lucene и размере кучи 512-> 1024

Попытка загрузки 37619 узлов, каждый узел имеет одно отношение. Только + — 22000 узлов сделали это. У JAVA VM не хватило памяти.

Ниже приведены статистические данные GC и Heap. Обратите внимание, что Java VM потерпела крах здесь, она также исчерпала память. Что не имеет смысла, так как куча как можно больше места. Это довольно актуально, поскольку каждая операция Create Node представляет собой 2 запроса на отдых, один запрос gremlin для проверки узла не существует, а затем другой POST для создания узла. Я не ожидал бы, что это станет нестабильным.

образ

образ

образ

 

Сценарий — оптимизированный код Gremlin (параметризованный)

Мы подумали, что, возможно, использование не параметризованных запросов было причиной нестабильности из-за большого количества JIT-компиляций. Поэтому мы решили обновить Neo4jClient, чтобы использовать параметризованные запросы gremlin для оптимизации JIT. Мы также обновили Neo4j до 1.5.M01, поэтому комбинация обоих может улучшить проблемы, с которыми мы сталкиваемся.

При отключенных вызовах индекса Lucene и размере кучи 512-> 1024

пакет Neo4jClient NuGet теперь использует PARAMTERISED запросы для уменьшения JIT-компиляции.

Загружено 37619 узлов, каждый узел имеет одно отношение.

Примечание. Используется neo4j-community-1.5.M01-windows, а не 1.4..M04.

Ниже приведены статистические данные GC и Heap. Теоретически, теперь куча должна использоваться меньше из-за уменьшения JIT-компиляции путем передачи параметризованных запросов gremlin.

Мы заметили, что с параметризованными запросами мы получили более быструю загрузку клиентов, вместо 5 в секунду, она достигла 6 в секунду.

Мы сразу заметили, что при параметризованных запросах использование кучи меньше. Обратите внимание на этот график ниже, где синие линии расположены менее плотно, чем все предыдущие графики. График внизу изображения ниже с параметризованными запросами гремлина и Neo4j 1.5.M01.

образ

Приблизительно в 23000 узлов рабочая роль Azure на моей локальной машине разработки завершилась неудачно:

Неизвестная ошибка. Это интересно, поскольку я не получил никаких ошибок памяти JVM. Это подразумевает проблему в нашем клиенте Stress Test, так как мы заметили более 27000 дескрипторов в нашем клиентском приложении .Net. Это подняло для меня красный флаг об использовании ресурсов и возможном управлении потоками, давайте перейдем к этой захватывающей части анализа…

Оптимизация потоков

Мы оптимизировали клиент .Net, обеспечив, чтобы не более 70 потоков вызывали API остальных, я выбрал 70 потоков, поскольку сервер Neo4j выделяет 80 потоков в JVM, поэтому мы могли бы быть чуть ниже этого значения. Это совершенно удивительно, если сопоставить количество одновременных потоков для вызова операций rest с зарезервированными потоками, которые есть у neo4j, мы получим увеличение производительности в 5 раз !!! Мы также заметили, что загрузка процессора теперь намного эффективнее.

образ

Теперь, когда новый поток оптимизирован, мы смогли полностью загрузить систему. Без ошибок.

MyStory Добро пожаловать, временно от администрации MyStory. Выйти?

Агентство Импорт Работа 301

Выход журнала:

[01:44:58] [Тема 10] Сообщение о миграции получено по адресу: 26.09.2011 1:44:58 +00: 00

[01:44:59] [Thread 10] Полезная нагрузка сообщения миграции: JobUniqueId: 301, AgencyUniqueId: 201

[01:44:59] [Поток 10] Выполнение сценария sql: e: \ AzureTemp \ Resources \ 4bb24cfd-0b35-4c91-83de-97f335159a49 \ temp \ temp \ RoleTemp \ 634526342992784034 \ output.sql

[01:45:01] [Thread 10] Обработка сценария командной строки 10000/37620

[01:45:03] [Thread 10] Обработка сценария командной строки 20000/37620

[01:45:05] [Thread 10] Обработка сценария командной строки 30000/37620

[01:45:06] [Thread 10] Все команды сценария sql выполнены 37620/37620

[01:45:13] [Тема 10] Импорт 37619 клиентов в базу данных

[01:45:44] [Поток 12] Обработано 169/37619 клиентов, 5,62 клиентов в секунду, осталось 01:51:06

[01:46:16] [Поток 29] Обработано 360/37619 клиентов, 5,80 клиентов в секунду, осталось 01:47:02

[01:46:29] [Тема 69] Обработано 1000/37619 клиентов, 13,30 клиентов в секунду, осталось 00:45:52

[01:46:50] [Поток 28] Обработано 2000/37619 клиентов, 20,78 клиентов в секунду, осталось 00:28:34

[01:47:11] [Поток 30] Обработано 3000/37619 клиентов, 25,47 клиентов в секунду, осталось 00:22:39

[01:47:33] [Поток 32] Обработано 4000/37619 клиентов, 28,71 клиента в секунду, осталось 00:19:31

[01:47:55] [Тема 76] Обработано 5000/37619 клиентов, 30,95 клиентов в секунду, осталось 00:17:33

[01:48:18] [Поток 87] Обработано 6000/37619 клиентов, 32,52 клиента в секунду, осталось 00:16:12

[01:48:46] [Поток 13] Обработано 7000/37619 клиентов, 32,95 клиентов в секунду, осталось 00:15:29

[01:49:10] [Thread 70] Обработано 8000/37619 клиентов, 33,84 клиента в секунду, осталось 00:14:35

[01:49:36] [Поток 54] Обработано 9000/37619 клиентов, 34,25 клиентов в секунду, осталось 00:13:55

[01:50:02] [Thread 64] Обработано 10000/37619 клиентов, 34,69 клиентов в секунду, осталось 00:13:16

[01:50:29] [Поток 50] Обработано 11000/37619 клиентов, 34,85 клиентов в секунду, осталось 00:12:43

[01:50:57] [Поток 82] Обработано 12000/37619 клиентов, 34,97 клиентов в секунду, осталось 00:12:12

[01:51:25] [Поток 27] Обработано 13000/37619 клиентов, 35,02 клиентов в секунду, осталось 00:11:42

[01:51:54] [Поток 10] Обработано 14000/37619 клиентов, 34,99 клиентов в секунду, осталось 00:11:15

[01:52:24] [Тема 76] Обработано 15000/37619 клиентов, 34,89 клиентов в секунду, осталось 00:10:48

[01:52:54] [Тема 68] Обработано 15970/37619 клиентов, 34,70 клиентов в секунду, осталось 00:10:23

[01:52:55] [Поток 17] Обработано 16000/37619 клиентов, 34,69 клиентов в секунду, осталось 00:10:23

[01:53:25] [Поток 59] Обработано 16918/37619 клиентов, 34,43 клиента в секунду, осталось 00:10:01

[01:53:27] [Поток 46] Обработано 17000/37619 клиентов, 34,42 клиента в секунду, осталось 00:09:59

[01:53:58] [Thread 58] Обработано 17998/37619 клиентов, 34,33 клиента в секунду, осталось 00:09:31

[01:53:58] [Thread 34] Обработано 18000/37619 клиентов, 34,32 клиентов в секунду, осталось 00:09:31

[01:54:28] [Thread 21] Обработано 18900/37619 клиентов, 34,07 клиентов в секунду, осталось 00:09:09

[01:54:34] [Thread 13] Обработано 19000/37619 клиентов, 33,90 клиентов в секунду, осталось 00:09:09

[01:55:04] [Поток 35] Обработано 19973/37619 клиентов, 33,81 клиента в секунду, осталось 00:08:41

[01:55:05] [Thread 86] Обработано 20000/37619 клиентов, 33,80 клиентов в секунду, осталось 00:08:41

[01:55:36] [Поток 93] Обработано 20910/37619 клиентов, 33,61 клиента в секунду, осталось 00:08:17

[01:55:40] [Поток 42] Обработано 21000/37619 клиентов, 33,54 клиента в секунду, осталось 00:08:15

[01:56:10] [Тема 31] Обработано 21886/37619 клиентов, 33,35 клиентов в секунду, осталось 00:07:51

[01:56:14] [Поток 81] Обработано 22000/37619 клиентов, 33,32 клиентов в секунду, осталось 00:07:48

[01:56:44] [Тема 17] Обработано 22809/37619 клиентов, 33,02 клиента в секунду, осталось 00:07:28

[01:56:51] [Thread 77] Обработано 23000/37619 клиентов, 32,96 клиента в секунду, осталось 00:07:23

[01:57:22] [Thread 42] Обработано 23770/37619 клиентов, 32,63 клиента в секунду, осталось 00:07:04

[01:57:30] [Thread 71] Обработано 24000/37619 клиентов, 32,57 клиентов в секунду, осталось 00:06:58

[01:58:01] [Поток 44] Обработано 24652/37619 клиентов, 32,13 клиентов в секунду, осталось 00:06:43

[01:58:16] [Thread 42] Обработано 25000/37619 клиентов, 31,94 клиента в секунду, осталось 00:06:35

[01:58:47] [Тема 9] Обработано 25691/37619 клиентов, 31,60 клиентов в секунду, осталось 00:06:17

[01:59:03] [Тема 84] Обработано 26000/37619 клиентов, 31,33 клиента в секунду, осталось 00:06:10

[01:59:36] [Тема 91] Обработано 26625/37619 клиентов, 30,88 клиентов в секунду, осталось 00:05:56

[01:59:57] [Поток 74] Обработано 27000/37619 клиентов, 30,57 клиентов в секунду, осталось 00:05:47

[02:00:27] [Тема 79] Обработано 27583/37619 клиентов, 30,20 клиентов в секунду, осталось 00:05:32

[02:00:47] [Тема 82] Обработано 28000/37619 клиентов, 30,01 клиента в секунду, осталось 00:05:20

[02:01:17] [Thread 64] Обработано 28591/37619 клиентов, 29,67 клиентов в секунду, осталось 00:05:04

[02:01:38] [Тема 17] Обработано 29000/37619 клиентов, 29,46 клиентов в секунду, осталось 00:04:52

[02:02:08] [Тема 24] Обработано 29610/37619 клиентов, 29,18 клиентов в секунду, осталось 00:04:34

[02:02:29] [Thread 58] Обработано 30000/37619 клиентов, 28,98 клиентов в секунду, 00:04:22 осталось

[02:02:59] [Тема 69] Обработано 30566/37619 клиентов, 28,68 клиентов в секунду, осталось 00:04:05

[02:03:23] [Тема 89] Обработано 31000/37619 клиентов, 28,46 клиентов в секунду, осталось 00:03:52

[02:03:23] [Тема 88] Обработано 31000/37619 клиентов, 28,46 клиентов в секунду, осталось 00:03:52

[02:03:53] [Поток 30] Обработано 31556/37619 клиентов, 28,18 клиентов в секунду, осталось 00:03:35

[02:04:16] [Тема 61] Обработано 32000/37619 клиентов, 28,00 клиентов в секунду, осталось 00:03:20

[02:04:48] [Тема 66] Обработано 32568/37619 клиентов, 27,73 клиентов в секунду, осталось 00:03:02

[02:05:18] [Поток 20] Обработано 33000/37619 клиентов, 27,41 клиентов в секунду, осталось 00:02:48

[02:05:48] [Тема 13] Обработано 33529/37619 клиентов, 27,16 клиентов в секунду, осталось 00:02:30

[02:06:15] [Поток 56] Обработано 34000/37619 клиентов, 26,95 клиентов в секунду, осталось 00:02:14

[02:06:45] [Тема 92] Обработано 34442/37619 клиентов, 26,66 клиентов в секунду, осталось 00:01:59

[02:07:16] [Поток 95] Обработано 34959/37619 клиентов, 26,44 клиента в секунду, осталось 00:01:40

[02:07:17] [Поток 91] Обработано 35000/37619 клиентов, 26,44 клиента в секунду, осталось 00:01:39

[02:07:49] [Thread 95] Обработано 35369/37619 клиентов, 26,09 клиентов в секунду, осталось 00:01:26

[02:08:19] [Поток 41] Обработано 35867/37619 клиентов, 25,88 клиентов в секунду, осталось 00:01:07

[02:08:28] [Поток 66] Обработано 36000/37619 клиентов, 25,81 клиента в секунду, осталось 00:01:02

[02:08:59] [Thread 45] Обработано 36485/37619 клиентов, 25,60 клиентов в секунду, осталось 00:00:44

[02:09:29] [Поток 78] Обработано 36922/37619 клиентов, 25,37 клиентов в секунду, осталось 00:00:27

[02:09:34] [Поток 81] Обработано 37000/37619 клиентов, 25,34 клиента в секунду, осталось 00:00:24

[02:10:04] [Тема 12] Обработано 37287/37619 клиентов, 25,01 клиента в секунду, осталось 00:00:13

[02:10:27] [Тема 10] Все 37619 клиентов импортированы

Темы на .Net Client

Настроив клиент .Net для использования такого же количества потоков, которое использует Neo4j, мы смогли увеличить производительность в 5 раз.

Использование процессора также стало более эффективным. Обратите внимание, что Neo4j имеет 80 потоков, поэтому мы ограничиваем остальные вызовы примерно до этой суммы, я выбрал 70 потоков.

Итак, в .Net мы сопоставляем потоки примерно так:

var processorCount = Environment.ProcessorCount;

var threadsToAllocate = (int)Math.Ceiling(processorCount*10 * 0.9);

var options = new ParallelOptions { MaxDegreeOfParallelism = threadsToAllocate };

Parallel.ForEach(clients, options, client =>{…

 

образ

 

Примечание: моя машина имеет 8 ядер, Neo4j выделил 10 потоков на ядро, поэтому ваш код должен определить количество ядер, а затем распределить потоки по 10 потоков на ядро ​​!!

Например, если вы запустите его на двухъядерном процессоре, Neo4j будет иметь только 20 потоков.

Пакетные запросы на отдых

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

Мы реализовали пакетирование в пакете Neo4jClient NuGet, это уменьшит количество REST-вызовов к серверу для каждого узла, который ему нужно создать, поэтому, если узлу нужно два отношения, вместо 3-х вызовов покоя, мы делаем один вызов покоя.

Тестовый прогон (без индексов)

Пакетная обработка не привела к значительному улучшению производительности, когда она выполнялась только в среднем за два вызова покоя. Однако мы проведем еще один тестовый прогон с индексированием вызовов покоя, так как, возможно, вы заметите это только для определенного количества вызовов покоя, объединенных вместе.

Средний размер Bach (создание узла + создание отношения) = 2 запроса на отдых

[02:37:04] [Тема 34] Обработано 17000/37619 клиентов, 34,51 клиента в секунду, осталось 00:09:57

Test Run (With Indexes)

We now included the indexes in the batch request. We noticed that sometimes web calls would timeout, but since we use the CIRCUIT BREAKER pattern, the service level always stayed above 80% and never tripped.

[04:52:38] [Thread    9] Importing 37592 clients into the database

[04:53:09] [Thread   46] Processed 169/37592 clients, 5.55 clients per second, 01:52:19 remaining

[04:53:40] [Thread   62] Processed 422/37592 clients, 6.76 clients per second, 01:31:35 remaining

[04:53:55] [Thread   49] Processed 1000/37592 clients, 13.03 clients per second, 00:46:48 remaining

[04:53:55] [Thread   54] Processed 1000/37592 clients, 13.03 clients per second, 00:46:48 remaining

[04:54:19] [Thread   10] Processed 2000/37592 clients, 19.89 clients per second, 00:29:49 remaining

[04:54:19] [Thread   50] Processed 2000/37592 clients, 19.88 clients per second, 00:29:49 remaining

[04:54:43] [Thread   32] Processed 3000/37592 clients, 23.96 clients per second, 00:24:03 remaining

[04:54:43] [Thread   11] Processed 3000/37592 clients, 23.96 clients per second, 00:24:03 remaining

[04:55:09] [Thread   64] Processed 4000/37592 clients, 26.51 clients per second, 00:21:07 remaining

[04:55:09] [Thread   23] Processed 4000/37592 clients, 26.50 clients per second, 00:21:07 remaining

[04:55:36] [Thread   70] Processed 5000/37592 clients, 28.13 clients per second, 00:19:18 remaining

[04:55:36] [Thread   57] Processed 5000/37592 clients, 28.13 clients per second, 00:19:18 remaining

[04:56:02] [Thread   25] Processed 6000/37592 clients, 29.41 clients per second, 00:17:54 remaining

[04:56:02] [Thread   85] Processed 6000/37592 clients, 29.41 clients per second, 00:17:54 remaining

[04:56:30] [Thread  102] Processed 7000/37592 clients, 30.13 clients per second, 00:16:55 remaining

[04:56:30] [Thread   51] Processed 7000/37592 clients, 30.13 clients per second, 00:16:55 remaining

[04:57:01] [Thread  102] Processed 7995/37592 clients, 30.46 clients per second, 00:16:11 remaining

[04:57:01] [Thread   96] Processed 8000/37592 clients, 30.45 clients per second, 00:16:11 remaining

[04:57:01] [Thread   70] Processed 8000/37592 clients, 30.45 clients per second, 00:16:11 remaining

[04:57:31] [Thread   65] Processed 8988/37592 clients, 30.68 clients per second, 00:15:32 remaining

[04:57:31] [Thread   84] Processed 9000/37592 clients, 30.68 clients per second, 00:15:31 remaining

[04:57:32] [Thread   46] Processed 9000/37592 clients, 30.68 clients per second, 00:15:31 remaining

[04:58:02] [Thread  109] Processed 10000/37592 clients, 30.89 clients per second, 00:14:53 remaining

[04:58:32] [Thread   12] Processed 10950/37592 clients, 30.93 clients per second, 00:14:21 remaining

[04:58:34] [Thread   11] Processed 11000/37592 clients, 30.94 clients per second, 00:14:19 remaining

[04:58:34] [Thread   16] Processed 11000/37592 clients, 30.94 clients per second, 00:14:19 remaining

[04:58:39] [Thread   91] Error occured importing client EAW2000203-Child4128. Started this attempt at 26/09/2011 4:58:37 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:58:37 AM +00:00.

[04:58:39] [Thread   91] Circuit breaker now reports the service level as 80.

[04:58:39] [Thread  101] Circuit breaker now reports the service level as 100.

[04:58:42] [Thread   69] Error occured importing client EAW2000002-Child3994. Started this attempt at 26/09/2011 4:58:40 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:58:40 AM +00:00.

[04:58:42] [Thread   69] Circuit breaker now reports the service level as 80.

[04:58:42] [Thread   24] Circuit breaker now reports the service level as 100.

[04:59:04] [Thread   25] Processed 11963/37592 clients, 31.01 clients per second, 00:13:46 remaining

[04:59:05] [Thread   89] Processed 12000/37592 clients, 31.02 clients per second, 00:13:45 remaining

[04:59:05] [Thread   21] Processed 12000/37592 clients, 31.02 clients per second, 00:13:45 remaining

[04:59:13] [Thread   22] Error occured importing client EAW3000118. Started this attempt at 26/09/2011 4:59:11 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:59:11 AM +00:00.

[04:59:13] [Thread   22] Circuit breaker now reports the service level as 80.

[04:59:13] [Thread   58] Circuit breaker now reports the service level as 100.

[04:59:28] [Thread   99] Error occured importing client EAW3000105-Child4273. Started this attempt at 26/09/2011 4:59:26 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:59:26 AM +00:00.

[04:59:28] [Thread   99] Circuit breaker now reports the service level as 80.

[04:59:28] [Thread   89] Circuit breaker now reports the service level as 100.

[04:59:35] [Thread   43] Processed 12956/37592 clients, 31.06 clients per second, 00:13:13 remaining

[04:59:37] [Thread   49] Processed 13000/37592 clients, 31.06 clients per second, 00:13:11 remaining

[04:59:37] [Thread  102] Processed 13000/37592 clients, 31.06 clients per second, 00:13:11 remaining

[05:00:07] [Thread  106] Processed 13966/37592 clients, 31.11 clients per second, 00:12:39 remaining

[05:00:08] [Thread   25] Processed 14000/37592 clients, 31.12 clients per second, 00:12:38 remaining

[05:00:08] [Thread   86] Processed 14000/37592 clients, 31.12 clients per second, 00:12:38 remaining

[05:00:38] [Thread   78] Processed 14926/37592 clients, 31.08 clients per second, 00:12:09 remaining

[05:00:41] [Thread   83] Processed 15000/37592 clients, 31.09 clients per second, 00:12:06 remaining

I wanted to also ensure indexing via Neo4j to Lucene did not affect the heap usage and frequency is a negative way,, that could possible cause the heap to grow, below is a image showing that the indexing is keeping the heap size and usage within normal range (blue lines)

образ

Also, CPU Utilisation was high with the indexing, proving efficient use of CPU.

образ

Below is a graph of heap usage importing 37000 clients, with all the optimisation and tweaks. This run in around 30 minutes.

образ

Desired throughput achieved Улыбка

Note, heap size did not need to grow beyond 512, as gremlin queries are parameterised.

Summary

Increasing Heap Size to 512m –> 1024m was sufficient to reduce GC collection.

Increasing Stack size from 1024 –> 2048k improves multiple thread operations.

Switching on GC logging is definitely a good way to get a view of how your heap is being used.

Disabling neo4j transaction roll over logging did not improve performance.

Disabling the Lucene index creations via the REST API solved the instability issues with the Rest API. optimising the threads on the client, and using parameterised queries removed the instability issue.

The REST API calls are causing the system to become unstable (Out Of memory errors). If the threads are  optimised on the client with the use of parameterised gremlin queries, upgrade to Neo4j1.5.01M, incorporate batching, then Lucene indexing is also optimised.

CPU utilization is much more efficient after thread optimisation.

Parameterised queries and upgrading to Neo4j1.5.M01 increased performance and DRASTICALLY reduced the frequency of the heap size usage thus stabilising the heap usage.

*** By configuring the .Net client that sent REST calls on different threads to limit the thread count to 70 threads, we were able to improve performance 5 fold. This is the most significant improvement. 70 threads were chosen to match the similar number (80) that Neo4j reserves in the JVM. +- 35 nodes per second as compared with 5-6 nodes per second.

We now implemented batching in the Neo4Client NUGet package to further increase performance.

Batching improved performance.

Basically in our scenario, a node created between 4 to 8 index entries, this with the current release of Neo4j 1.4.1, means 4-8 rest calls. An issue has been logged to improve the rest calls to just one, where you can then parse in a dictionary of key/val pairs in the request body of the POST. The issue is located here:

https://github.com/neo4j/community/issues/25

A separate issue has been created to investigate why the REST API for indexes causes the system to become unstable.

https://github.com/neo4j/community/issues/28

In Short:

Optimise Threads from your client to be below 80 as Neo4j Server allocated 80 threads to the JVM, so no point in sending rest calls on more than 80 threads. (This is for a machine with 8 cores (Neo4j allocated 10 threads per core)).

So if you neo4j server is a dual core (10 * 2) = 20 threads. Quad Core = 40 Threads.

Use the Rest batching API.

If using Gremlin, use parameterised queries.

Use Circuit Breaker pattern to implement retry logic if calls fail (Optional)