Почему время проверки контрольной точки neo4j увеличивается с размером графика? - PullRequest
2 голосов
/ 23 мая 2019

У меня есть набор данных размером примерно 100 ГБ, разбитый на 50 файлов, которые я хочу импортировать в пустое предприятие neo4j-3.5.5 с кучей 16 ГБ и кешем страниц 8 ГБ на сервере AWS с 32 ГБ ОЗУ.Данные представлены в формате строк JSON и передаются через Python в этот запрос:

WITH {list} as list
UNWIND list as data
MERGE (p:LabelA {id: data.id})
    SET p.prop1 = data.prop1, p.prop2 = data.prop2, p.prop3 = data.prop3, p.prop4 = data.prop4,
        p.prop5 = data.prop5, p.prop6 = data.prop6, p.prop7 = data.prop7, p.prop8 = data.prop8

MERGE (j:LabelF {name: data.prop9})
MERGE (p) -[:RELATION_A {prop1: data.prop10, prop2: data.prop11}]-> (j)

MERGE (v:LabelC {name: data.prop12})
MERGE (p) -[:RELATION_B]-> (v)

FOREACH (elem IN data.prop13 |
    MERGE (a:LabelB {id: elem.id}) ON CREATE
        SET a.name = elem.name
    MERGE (a) -[:RELATION_C]-> (p)
)

FOREACH (elem IN data.prop14 |
    MERGE (u:LabelF {name: elem.name})
    MERGE (u) -[:RELATION_C]-> (p)
)

FOREACH (elem IN data.prop15 |
    MERGE (e:LabelD {name: elem})
    MERGE (p) -[:RELATION_D]-> (e)
)

FOREACH (elem IN data.prop16 |
    MERGE (out:LabelA {id: elem})
    MERGE (p) -[:RELATION_E]-> (out)
)

FOREACH (elem IN data.prop17 |
    MERGE (inc:LabelA {id: elem})
    MERGE (p) <-[:RELATION_E]- (inc)
)

FOREACH (elem IN data.prop18 |
    MERGE (pdf:LabelG {name: elem})
    MERGE (p) -[:RELATION_F]-> (pdf)
)

FOREACH (elem IN data.prop19 |
    MERGE (s:LabelE {name: elem})
    MERGE (p) -[:RELATION_G]-> (s)
)

list содержит 200 строк JSON, и каждый запрос выполняется в своей собственной транзакции.

Индексы устанавливаются ранеек импорту данных:

self.graph.run('CREATE INDEX ON :LabelB(name)')
self.graph.run('CREATE CONSTRAINT ON (p:LabelA) ASSERT (p.id) IS NODE KEY;')
self.graph.run('CREATE CONSTRAINT ON (p:LabelB) ASSERT (p.id) IS NODE KEY;')
for label in ['LabelC', 'LabelD', 'LabelE', 'LabelF', 'LabelG', 'LabelF']:
    self.graph.run(f'CREATE CONSTRAINT ON (p:{label}) ASSERT (p.name) IS NODE KEY;')

Первая пара контрольных точек все еще несколько быстрая (?):

2019-05-23 15:49:10.141+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 45 checkpoint completed in 134ms
2019-05-23 16:04:45.515+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 1603 checkpoint completed in 35s 345ms
2019-05-23 16:22:38.299+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 3253 checkpoint completed in 2m 52s 483ms

Но в какой-то момент они придерживаются длительности около 20-25 минут наконтрольная точка (это с предыдущей попытки):

2019-05-23 07:40:03.755 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 18240 checkpoint started...
2019-05-23 07:42:15.942 INFO [o.n.k.NeoStoreDataSource] Rotated to transaction log [/var/lib/neo4j/data/databases/graph.db/neostore.transaction.db.144] version=144, last transaction in previous log=18253
2019-05-23 07:45:51.982 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=224, gcTime=240, gcCount=1}
2019-05-23 07:46:42.059 INFO [o.n.k.i.s.c.CountsTracker] Rotated counts store at transaction 18279 to [/data/databases/graph.db/neostore.counts.db.a], from [/data/databases/graph.db/neostore.counts.db.b].
2019-05-23 07:53:49.108 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=158, gcTime=157, gcCount=1}
2019-05-23 08:03:11.556 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 18240 checkpoint completed in 23m 7s 800ms 
2019-05-23 08:03:11.710 INFO [o.n.k.i.t.l.p.LogPruningImpl] Pruned log versions 140-141, last checkpoint was made in version 143

2019-05-23 08:04:38.454 INFO [o.n.k.NeoStoreDataSource] Rotated to transaction log [/var/lib/neo4j/data/databases/graph.db/neostore.transaction.db.145] version=145, last transaction in previous log=18377
2019-05-23 08:05:57.288 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=248, gcTime=253, gcCount=1}
2019-05-23 08:11:08.331 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=143, gcTime=224, gcCount=1}
2019-05-23 08:16:37.491 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=228, gcTime=237, gcCount=1}

2019-05-23 08:18:11.732 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 18471 checkpoint started...
2019-05-23 08:23:18.767 INFO [o.n.k.NeoStoreDataSource] Rotated to transaction log [/var/lib/neo4j/data/databases/graph.db/neostore.transaction.db.146] version=146, last transaction in previous log=18496
2019-05-23 08:24:55.141 INFO [o.n.k.i.s.c.CountsTracker] Rotated counts store at transaction 18505 to [/data/databases/graph.db/neostore.counts.db.b], from [/data/databases/graph.db/neostore.counts.db.a].
2019-05-23 08:38:21.660 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=136, gcTime=195, gcCount=1}
2019-05-23 08:40:46.261 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 18471 checkpoint completed in 22m 34s 529ms
2019-05-23 08:40:46.281 INFO [o.n.k.i.t.l.p.LogPruningImpl] Pruned log versions 142-143, last checkpoint was made in version 145

Может кто-нибудь сказать мне, что здесь происходит?Я попытался изменить свойства сохранения транзакций и размера журнала (увеличение / уменьшение) безрезультатно и запустил его на сервере AWS 64 ГБ с кучей 24 ГБ и кэшем страниц 24 ГБ.Во всех сценариях время, необходимое для прохождения контрольной точки, увеличивается.Хотя первые два файла заняли менее двух часов, я прервал процесс импорта третьего файла через 6 часов, потому что он будет работать 15 минут (время по умолчанию между контрольными точками), а затем застревает в контрольной точке на 25 минут.

Обновление 2019-05-24 17:35 UTC + 2

Я попытался выполнить первую часть решения cybersam, используя CREATE для создания отношений, где это применимо (т.е.отношение представлено только один раз в 100 ГБ) и выбросило создание RELATION_E, которое я выполню на более позднем этапе с предварительно обработанными входными файлами.Это приводит к следующему запросу на импорт:

WITH {list} as list
UNWIND list as data
MERGE (p:LabelA {id: data.id})
    SET p.prop1 = data.prop1, p.prop2 = data.prop2, p.prop3 = data.prop3, p.prop4 = data.prop4,
        p.prop5 = data.prop5, p.prop6 = data.prop6, p.prop7 = data.prop7, p.prop8 = data.prop8

MERGE (j:LabelF {name: data.prop9})
CREATE (p) -[:RELATION_A {prop1: data.prop10, prop2: data.prop11}]-> (j)

MERGE (v:LabelC {name: data.prop12})
CREATE (p) -[:RELATION_B]-> (v)

FOREACH (elem IN data.prop13 |
    MERGE (a:LabelB {id: elem.id}) ON CREATE
        SET a.name = elem.name
    CREATE (a) -[:RELATION_C]-> (p)
)

FOREACH (elem IN data.prop14 |
    MERGE (u:LabelF {name: elem.name})
    CREATE (u) -[:RELATION_C]-> (p)
)

FOREACH (elem IN data.prop15 |
    MERGE (e:LabelD {name: elem})
    CREATE (p) -[:RELATION_D]-> (e)
)

FOREACH (elem IN data.prop18 |
    MERGE (pdf:LabelG {name: elem})
    CREATE (p) -[:RELATION_F]-> (pdf)
)

FOREACH (elem IN data.prop19 |
    MERGE (s:LabelE {name: elem})
    CREATE (p) -[:RELATION_G]-> (s)
)

Затем я остановил свой Neo4j, удалил каталог graph.db, изменил конфигурацию для выполнения контрольных точек каждые 15 секунд, чтобы я мог быстро определить, увеличивается ли время контрольных точеки начал импорт данных.К сожалению, время все еще увеличивается:

2019-05-24 15:25:40.718+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 59 checkpoint completed in 240ms
2019-05-24 15:26:02.003+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 86 checkpoint completed in 1s 283ms
2019-05-24 15:26:27.518+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 105 checkpoint completed in 5s 514ms
2019-05-24 15:26:55.079+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 141 checkpoint completed in 7s 559ms
2019-05-24 15:27:23.944+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 179 checkpoint completed in 8s 864ms
2019-05-24 15:27:59.768+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 218 checkpoint completed in 15s 823ms
2019-05-24 15:28:42.819+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 269 checkpoint completed in 23s 9ms
2019-05-24 15:29:33.318+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 328 checkpoint completed in 30s 498ms
2019-05-24 15:30:32.847+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 397 checkpoint completed in 39s 489ms
2019-05-24 15:31:41.918+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 480 checkpoint completed in 49s 30ms
2019-05-24 15:33:03.113+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] Checkpoint triggered by scheduler for time threshold @ txId: 576 checkpoint completed in 1m 1s 194ms 

Где-нибудь отсутствует индекс?

Обновление 2019-05-28 18:44 UTC + 2

Я создал набор параметров из 100 строк и импортировал их, используя PROFILE, в пустой Neo4j.План запроса выглядит следующим образом:

query execution plan

Обновление 2019-07-14 16:11 UTC + 2

Я обошел проблему, предварительно обработав мои файлы JSONL в файлы CSV без дубликатов и используя neo4j-admin import.

1 Ответ

2 голосов
/ 24 мая 2019

Стоимость каждой операции MERGE для отношения будет линейно увеличиваться с количеством отношений, которые необходимо отсканировать. Индексирование узлов поможет оптимизировать поиск конечных точек взаимосвязи , но neo4j все еще должен сканировать отношения одной из этих конечных точек, чтобы MERGE узнал, существует ли желаемая взаимосвязь.

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

Вот двухэтапный процесс исправления.

  1. Используйте запрос, который просто использует MERGE для создания узлов (без каких-либо связей). В этом случае вы можете продолжать использовать MERGE, поскольку вы имеете дело только с индексированными узлами. Например:

    UNWIND $list as data
    MERGE (p:LabelA {id: data.id})
    ON CREATE SET
      p.prop1 = data.prop1, p.prop2 = data.prop2, p.prop3 = data.prop3, p.prop4 = data.prop4,
      p.prop5 = data.prop5, p.prop6 = data.prop6, p.prop7 = data.prop7, p.prop8 = data.prop8
    
    MERGE (j:LabelF {name: data.name})    
    MERGE (v:LabelC {name: data.propA})
    
    FOREACH (e IN data.propB |
      MERGE (a:LabelB {id: e.id}) ON CREATE SET a.name = e.name)
    FOREACH (e IN data.propC |
      MERGE (:LabelF {name: e.name}))
    FOREACH (e IN data.propD + data.propG + data.propH |
      MERGE (:LabelD {name: e}))
    FOREACH (e IN data.propE + data.propF |
      MERGE (:LabelA {id: e}))
    
  2. Используйте запрос, который будет обрабатывать каждое отношение только один раз , что позволит вам использовать CREATE (который не нужно сканировать) вместо MERGE.

    ПРИМЕЧАНИЕ. Этот второй шаг требует, чтобы никакие параметры 2 $list (используемые в отдельных вызовах запросов) не содержали данных, которые могли бы привести к созданию той же самой взаимосвязи. И такое же ограничение существует в пределах одного параметра $list. Генерация таких $list параметров - это упражнение, оставленное на ваше усмотрение.

    Если у вас есть соответствующие $list параметры, вы можете сделать это:

    UNWIND $list as data
    MATCH (p:LabelA {id: data.id})
    
    MATCH (j:LabelF {name: data.name})
    CREATE (p) -[:RELATION_A {prop1: data.prop1, prop2: data.prop2}]-> (j) 
    
    WITH p, data
    
    MATCH (v:LabelC) WHERE v.name IN data.propA
    CREATE (p) -[:RELATION_B]-> (v) 
    
    WITH p, data
    
    UNWIND data.propB as elem
    MATCH (a:LabelB {id: elem.id})
    CREATE (a) -[:RELATION_C]-> (p)   
    
    WITH p, data
    
    UNWIND data.propC as elem
    MATCH (u:LabelF) WHERE u.name IN elem.name
    CREATE (u) -[:RELATION_C]-> (p)
    
    WITH p, data
    
    MATCH (e:LabelD) WHERE e.name IN data.propD
    CREATE (p) -[:RELATION_D]-> (e) 
    
    WITH p, data
    
    MATCH (out:LabelA) WHERE out.id IN data.propE
    CREATE (p) -[:RELATION_E]-> (out)
    
    WITH p, data
    
    MATCH (inc:LabelA) WHERE inc.id IN data.propF
    CREATE (p) <-[:RELATION_E]- (inc)
    
    WITH p, data
    
    MATCH (pdf:G) WHERE pdf.name IN data.propG
    CREATE (p) -[:RELATION_F]-> (pdf)
    
    WITH p, data
    
    MATCH (s:LabelE) WHERE s.name IN data.propH
    CREATE (p) -[:RELATION_G]-> (s)
    
Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...