This website uses cookies. By clicking Accept, you consent to the use of cookies. Click Here to learn more about how we use cookies.
Accept
Reject
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
Help

Head's Up! These forums are read-only. All users and content have migrated. Please join us at community.neo4j.com.

Execution/Memory problem with Louvain Graph Algo

axtonpitt
Node Link

‎10-20-2019 11:29 AM

Hi folks,

I'm trying to run the Louvain algorithm using the Graph Algorithms plugin. I ran the memory recommender to see how much memory I would roughly need:

2X_3_34863c4e875aeb3b1968941064a0940601d30355.png

Full map view:

{name:graph with procedure,components:[{name:Louvain,components:[{name:this.instance,memoryUsage:96 Bytes},{name:communities,memoryUsage:355 MiB},{name:nodeWeights,memoryUsage:355 MiB},{name:dendrogram,memoryUsage:[355 MiB ... 3550 MiB]},{name:modularities,memoryUsage:[24 Bytes ... 96 Bytes]},{name:modularityOptimization,components:[{name:this.instance,memoryUsage:96 Bytes},{name:communities,memoryUsage:355 MiB},{name:ki,memoryUsage:355 MiB},{name:tasks,components:[{name:this.instance,memoryUsage:48 Bytes},{name:sTot,memoryUsage:355 MiB},{name:sIn,memoryUsage:355 MiB},{name:localCommunities,memoryUsage:355 MiB}],memoryUsage:1065 MiB}],memoryUsage:1775 MiB}],memoryUsage:[2840 MiB ... 6035 MiB]},{name:HugeGraph,components:[{name:this.instance,memoryUsage:72 Bytes},{name:nodeIdMap,components:[{name:this.instance,memoryUsage:32 Bytes},{name:Neo4j identifiers,memoryUsage:355 MiB},{name:Mapping from Neo4j identifiers to internal identifiers,memoryUsage:[355 MiB ... 355 MiB]}],memoryUsage:[710 MiB ... 710 MiB]},{name:null,memoryUsage:24 Bytes},{name:outgoing,components:[{name:this.instance,memoryUsage:24 Bytes},{name:pages,memoryUsage:[1109 MiB ... 3639 MiB]}],memoryUsage:[1109 MiB ... 3639 MiB]},{name:outgoing offsets,components:[{name:this.instance,memoryUsage:32 Bytes},{name:pages wrapper,memoryUsage:40 Bytes},{name:page[],memoryUsage:384 MiB}],memoryUsage:384 MiB}],memoryUsage:[2203 MiB ... 4733 MiB]}],memoryUsage:[5044 MiB ... 10769 MiB]}

Context:
Neo4j Community Edition: 3.5.3
Graph Algorithms: 3.5.7.0
Running in AWS, on VM instance with 64GB of RAM

Memory config:

dbms.memory.heap.initial_size=24200m
dbms.memory.heap.max_size=24200m
dbms.memory.pagecache.size=28100m

Query:

CALL algo.louvain('Work', 'CITATION',
    {write:true, 
writeProperty:'community', 
concurrency:1,
includeIntermediateCommunities: true,
intermediateCommunitiesWriteProperty: 'communities'})

However when running the query above, the process gets stuck on exporting the result (I assume back into neo4j), due to a lack of memory. Has anyone else ran into a similar problem? And what is the best course of action to rectify it? I'm thinking increasing the heap size would do it but I have no idea by how much.

Thanks,
Axton

Labels:
0 Kudos
Reply
3 REPLIES 3

axtonpitt
Node Link

‎10-20-2019 11:30 AM

Here is some of the debug log:

2019-10-17 22:40:07.988+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 100% level: 2 communities: 249887 q: 0.7256487269168521
2019-10-17 22:40:11.171+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 100% level: 3 communities: 212939 q: 0.7229412325266191
2019-10-17 22:40:12.062+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 100% level: 4 communities: 211178 q: 0.7229296511429046
2019-10-17 22:40:12.677+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 47% round 2
2019-10-17 22:40:12.905+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 100% level: 5 communities: 211025 q: 0.722930113368183
2019-10-17 22:40:13.448+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 100% level: 6 communities: 211006 q: 0.7229302300481498
2019-10-17 22:40:13.995+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 100% level: 7 communities: 211003 q: 0.7229302469322282
2019-10-17 22:40:14.400+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] Louvain 100% level: 8 communities: 211003 q: -1.0
2019-10-17 22:40:14.401+0000 INFO [o.n.k.i.p.Procedures] Louvain: overall memory usage: 4706 MiB
2019-10-17 22:40:14.460+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 0%
2019-10-17 22:40:18.009+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=426, gcTime=435, gcCount=1}
2019-10-17 22:40:20.183+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=271, gcTime=282, gcCount=1}
2019-10-17 22:40:22.769+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=267, gcTime=285, gcCount=1}
2019-10-17 22:40:23.109+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=239, gcTime=244, gcCount=1}
2019-10-17 22:40:24.461+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 5%
2019-10-17 22:40:26.173+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=236, gcTime=238, gcCount=1}
2019-10-17 22:40:30.245+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=234, gcTime=307, gcCount=1}
2019-10-17 22:40:32.253+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=304, gcTime=284, gcCount=1}
2019-10-17 22:40:34.534+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=278, gcTime=288, gcCount=1}
2019-10-17 22:40:34.534+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 9%
2019-10-17 22:40:36.694+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=256, gcTime=292, gcCount=1}
2019-10-17 22:40:38.866+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=268, gcTime=286, gcCount=1}
2019-10-17 22:40:42.771+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=299, gcTime=327, gcCount=1}
2019-10-17 22:40:44.535+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 14%
2019-10-17 22:40:44.897+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=222, gcTime=293, gcCount=1}
2019-10-17 22:40:47.466+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=254, gcTime=303, gcCount=1}
2019-10-17 22:40:53.261+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=267, gcTime=314, gcCount=1}
2019-10-17 22:40:54.587+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 18%
2019-10-17 22:40:55.986+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=304, gcTime=317, gcCount=1}
2019-10-17 22:40:58.200+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=311, gcTime=316, gcCount=1}
2019-10-17 22:41:00.448+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=345, gcTime=320, gcCount=1}
2019-10-17 22:41:04.004+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=250, gcTime=312, gcCount=1}
2019-10-17 22:41:04.588+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 22%
2019-10-17 22:41:07.605+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=897, gcTime=0, gcCount=0}
2019-10-17 22:41:14.520+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=300, gcTime=326, gcCount=1}
2019-10-17 22:41:14.589+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 25%
2019-10-17 22:41:16.671+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=247, gcTime=311, gcCount=1}
2019-10-17 22:41:17.554+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=182, gcTime=175, gcCount=1}
2019-10-17 22:41:24.225+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=260, gcTime=322, gcCount=1}
2019-10-17 22:41:24.590+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 28%
2019-10-17 22:41:26.685+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=256, gcTime=318, gcCount=1}
2019-10-17 22:41:34.591+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 30%
2019-10-17 22:41:35.244+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=326, gcTime=321, gcCount=1}
2019-10-17 22:41:37.544+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=297, gcTime=328, gcCount=1}
2019-10-17 22:41:39.815+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=267, gcTime=332, gcCount=1}
2019-10-17 22:41:43.726+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=305, gcTime=319, gcCount=1}
2019-10-17 22:41:44.592+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 35%
2019-10-17 22:41:47.360+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=329, gcTime=321, gcCount=1}
2019-10-17 22:41:55.301+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 36%
2019-10-17 22:41:58.022+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=244, gcTime=314, gcCount=1}
2019-10-17 22:42:00.588+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=321, gcTime=312, gcCount=1}
2019-10-17 22:42:11.496+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 39%
2019-10-17 22:42:11.496+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=7192, gcTime=7234, gcCount=1}
2019-10-17 22:42:20.399+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1173, gcTime=1207, gcCount=1}
2019-10-17 22:43:00.569+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 39%
2019-10-17 22:43:00.669+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=40039, gcTime=0, gcCount=0}
2019-10-17 22:43:10.570+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 41%
2019-10-17 22:43:11.270+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=284, gcTime=297, gcCount=1}
2019-10-17 22:43:13.750+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=277, gcTime=332, gcCount=1}
2019-10-17 22:44:08.352+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 44%
2019-10-17 22:44:08.451+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=52096, gcTime=0, gcCount=0}
2019-10-17 22:45:05.860+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=49485, gcTime=49459, gcCount=3}
2019-10-17 22:45:05.860+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 45%
2019-10-17 22:45:56.136+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=42944, gcTime=42943, gcCount=4}
2019-10-17 22:45:56.136+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 45%
2019-10-17 22:46:45.411+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 45%
2019-10-17 22:46:45.411+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=42152, gcTime=42168, gcCount=3}
2019-10-17 22:47:31.320+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=41102, gcTime=41157, gcCount=3}
2019-10-17 22:47:31.320+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 45%
2019-10-17 22:48:17.214+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=41264, gcTime=41301, gcCount=3}
2019-10-17 22:48:17.214+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 22:49:05.314+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=140, gcTime=40912, gcCount=3}
2019-10-17 22:49:05.314+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 22:49:05.414+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=40737, gcTime=0, gcCount=0}
2019-10-17 22:49:51.588+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=172, gcTime=41537, gcCount=3}
2019-10-17 22:49:51.588+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 22:49:51.688+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=41393, gcTime=0, gcCount=0}
2019-10-17 22:51:16.118+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 22:52:37.313+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=121394, gcTime=81049, gcCount=6}
2019-10-17 22:52:37.313+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 22:52:37.313+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 22:53:58.738+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=79758, gcTime=120741, gcCount=11}
2019-10-17 22:53:58.738+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 22:54:39.060+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=41032, gcTime=40227, gcCount=7}
2019-10-17 22:56:01.109+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=122166, gcTime=81994, gcCount=4}
2019-10-17 22:56:01.109+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 23:00:44.096+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=40381, gcTime=120219, gcCount=10}
2019-10-17 23:08:00.232+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=361233, gcTime=321152, gcCount=26}
2019-10-17 23:10:41.928+0000 INFO [o.n.k.i.p.Procedures] [neo4j.BoltWorker-4 [bolt] [/27.252.51.250:54945] ] EXPORT 46%
2019-10-17 23:18:42.025+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=559409, gcTime=680056, gcCount=54}
2019-10-17 23:35:23.917+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=439810, gcTime=560097, gcCount=44}
2019-10-17 23:58:36.186+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1757995, gcTime=1474437, gcCount=115}
2019-10-18 00:09:53.491+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=715291, gcTime=832994, gcCount=66}
2019-10-18 00:36:09.322+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=977969, gcTime=1272009, gcCount=103}
2019-10-18 00:40:28.357+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1229239, gcTime=852107, gcCount=69}
2019-10-18 00:54:03.431+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=444735, gcTime=813534, gcCount=66}
2019-10-18 01:10:45.283+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1073958, gcTime=703125, gcCount=57}
2019-10-18 01:19:27.204+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=558184, gcTime=706747, gcCount=63}
2019-10-18 01:31:09.318+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=668526, gcTime=739954, gcCount=60}
2019-10-18 01:32:59.992+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=554194, gcTime=332268, gcCount=29}
2019-10-18 01:48:27.504+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=370291, gcTime=444683, gcCount=36}
2019-10-18 02:14:41.642+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1746631, gcTime=1633435, gcCount=136}
2019-10-18 02:35:07.101+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=653393, gcTime=1079742, gcCount=85}
2019-10-18 02:45:37.437+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1325797, gcTime=971473, gcCount=79}
2019-10-18 03:01:43.794+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=816612, gcTime=965462, gcCount=81}
2019-10-18 03:10:21.986+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=484010, gcTime=481206, gcCount=43}
2019-10-18 03:26:30.204+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=592670, gcTime=705335, gcCount=56}
2019-10-18 03:40:03.834+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1485877, gcTime=1224039, gcCount=100}
2019-10-18 03:51:10.523+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=405441, gcTime=480841, gcCount=41}
2019-10-18 04:04:09.925+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=704090, gcTime=701961, gcCount=57}
2019-10-18 04:17:06.768+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=816629, gcTime=777760, gcCount=63}
2019-10-18 04:25:46.456+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=628028, gcTime=778737, gcCount=63}
2019-10-18 04:28:14.405+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=520278, gcTime=258245, gcCount=22}
2019-10-18 04:31:18.628+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=184135, gcTime=184001, gcCount=16}
2019-10-18 04:34:59.722+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=36880, gcTime=183988, gcCount=16}
2019-10-18 04:35:36.734+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=221025, gcTime=73807, gcCount=6}
2019-10-18 04:43:00.649+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=111014, gcTime=294971, gcCount=24}
2019-10-18 04:47:59.475+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=517708, gcTime=409086, gcCount=33}
2019-10-18 04:55:05.045+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=307922, gcTime=347629, gcCount=26}
2019-10-18 05:09:16.601+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=657777, gcTime=773226, gcCount=62}
2019-10-18 05:17:53.775+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=721240, gcTime=672654, gcCount=54}
2019-10-18 05:35:50.344+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=813285, gcTime=703992, gcCount=58}
2019-10-18 05:40:46.359+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=558220, gcTime=555746, gcCount=43}
2019-10-18 05:50:08.587+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=332358, gcTime=370189, gcCount=30}
2019-10-18 05:55:41.656+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=525640, gcTime=672382, gcCount=54}
2019-10-18 06:23:26.914+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=740717, gcTime=1073628, gcCount=90}
2019-10-18 06:30:15.228+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1331519, gcTime=774950, gcCount=73}
2019-10-18 06:45:39.562+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=555504, gcTime=665952, gcCount=55}
2019-10-18 06:54:53.258+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=960137, gcTime=1033015, gcCount=85}
2019-10-18 07:06:34.893+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=296380, gcTime=441746, gcCount=38}
2019-10-18 07:25:40.506+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1109167, gcTime=740510, gcCount=61}
2019-10-18 07:50:18.903+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1180661, gcTime=1179424, gcCount=102}
2019-10-18 08:23:05.365+0000 ERROR [o.n.b.t.p.ProtocolHandshaker] Fatal error occurred during protocol handshaking: [id: 0x58d8dab4, L:/172.31.13.141:7687 ! R:/27.252.51.250:56918] writeAddress(..) failed: Connection timed out
io.netty.channel.unix.Errors$NativeIoException: writeAddress(..) failed: Connection timed out
	at io.netty.channel.unix.Errors.newIOException(Errors.java:122)
	at io.netty.channel.unix.Errors.ioResult(Errors.java:146)
	at io.netty.channel.unix.FileDescriptor.writeAddress(FileDescriptor.java:138)
	at io.netty.channel.epoll.AbstractEpollChannel.doWriteBytes(AbstractEpollChannel.java:356)
	at io.netty.channel.epoll.AbstractEpollStreamChannel.writeBytes(AbstractEpollStreamChannel.java:274)
	at io.netty.channel.epoll.AbstractEpollStreamChannel.doWriteSingle(AbstractEpollStreamChannel.java:483)
	at io.netty.channel.epoll.AbstractEpollStreamChannel.doWrite(AbstractEpollStreamChannel.java:441)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:938)
	at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.flush0(AbstractEpollChannel.java:512)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:905)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1396)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:115)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.flush(CombinedChannelDuplexHandler.java:533)
	at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:115)
	at io.netty.channel.CombinedChannelDuplexHandler.flush(CombinedChannelDuplexHandler.java:358)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	at io.netty.channel.ChannelDuplexHandler.flush(ChannelDuplexHandler.java:117)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:802)
	at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:814)
	at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:794)
	at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:837)
	at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1071)
	at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:304)
	at io.netty.handler.codec.http.websocketx.WebSocketServerHandshaker.handshake(WebSocketServerHandshaker.java:194)
	at io.netty.handler.codec.http.websocketx.WebSocketServerHandshaker.handshake(WebSocketServerHandshaker.java:142)
	at io.netty.handler.codec.http.websocketx.WebSocketServerProtocolHandshakeHandler.channelRead(WebSocketServerProtocolHandshakeHandler.java:83)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:438)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:323)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:297)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:249)
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:441)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:278)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
	at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:799)
	at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:433)
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:330)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909)
	at java.lang.Thread.run(Thread.java:748)
0 Kudos
Reply

david_fauth
Neo4j
Neo4j
In response to axtonpitt

‎11-13-2019 06:59 PM

The workaround is to stream the results out and then use the apoc.periodic iterate to write the data back to Neo4j.

CALL apoc.periodic.iterate("CALL algo.louvain.stream('Work', 'CITATION',{write:true,
writeProperty:'community',
concurrency:1,
includeIntermediateCommunities: true,
intermediateCommunitiesWriteProperty: 'communities'}) YIELD nodeId, community",
"match (n) where id(n) = nodeId set n.community = community",
{batchSize:2000, parallel:false})
0 Kudos
Reply

michael_hunger
Neo4j
Neo4j
In response to david_fauth

‎11-14-2019 03:09 AM

What is the size of your graph? How many CPUs does the instance have?
On AWS you benefit a lot from faster disk (instance SSD) or high IOPS settings for EBS to achieve the write volume.

You can now control independently read / compute and write concurrency, so perhaps just reduce write concurrency in the algo. (there is a newer version of the library).

0 Kudos
Reply
Nodes 2022
Nodes
NODES 2022, Neo4j Online Education Summit

All the sessions of the conference are now available online

Watch replays