Too Much GC even has High Memory

Neo4j Graph Platform
1

Testing write operation on a small database of size 1-2 GB

du -h -s neo4j
1.5G neo4j

Assigned 12 GB of RAM

apspannu_0-1665508301647.png

Still, Neo4j continues to go for GC. Is it expected behavior?

debug.log:2022-10-11 16:52:18.087+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=467, gcTime=0, gcCount=0}
debug.log:2022-10-11 16:52:21.583+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=289, gcTime=307, gcCount=1}
debug.log.1:2022-10-11 16:31:27.402+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=263, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:32:15.611+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=377, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:32:58.184+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=436, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:33:30.349+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=320, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:34:20.063+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=327, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:36:26.117+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=241, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:40:20.877+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=407, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:45:55.982+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=699, gcTime=0, gcCount=0}
debug.log.1:2022-10-11 16:46:30.888+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=224, gcTime=259, gcCount=1}
debug.log.1:2022-10-11 16:51:41.383+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=277, gcTime=405, gcCount=1}
debug.log.11:2022-10-11 08:17:22.825+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=387, gcTime=432, gcCount=1}
debug.log.11:2022-10-11 08:37:43.259+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=611, gcTime=0, gcCount=0}
debug.log.12:2022-10-11 07:46:41.115+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=518, gcTime=0, gcCount=0}
debug.log.13:2022-10-11 06:51:41.794+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=536, gcTime=0, gcCount=0}
debug.log.13:2022-10-11 06:51:57.936+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=230, gcTime=251, gcCount=1}
debug.log.14:2022-10-11 04:41:15.046+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=347, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 04:42:44.029+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=241, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 04:45:01.460+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=297, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 04:51:03.379+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=353, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 04:54:57.597+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=418, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 04:57:51.676+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=325, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 04:58:10.048+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=513, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 04:58:29.306+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=432, gcTime=0, gcCount=0}
debug.log.14:2022-10-11 05:36:17.784+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=788, gcTime=961, gcCount=1}
debug.log.14:2022-10-11 05:57:47.608+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=306, gcTime=357, gcCount=1}
debug.log.14:2022-10-11 05:58:18.335+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1024, gcTime=0, gcCount=0}
debug.log.15:2022-10-07 16:47:05.196+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=287, gcTime=324, gcCount=1}
debug.log.15:2022-10-08 05:54:37.443+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=237, gcTime=339, gcCount=1}
debug.log.15:2022-10-09 13:51:48.991+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=715, gcTime=786, gcCount=1}
debug.log.15:2022-10-09 20:44:54.230+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=260, gcTime=292, gcCount=1}
debug.log.15:2022-10-09 22:11:31.434+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=283, gcTime=338, gcCount=1}
debug.log.15:2022-10-10 17:47:45.417+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=721, gcTime=0, gcCount=0}
debug.log.15:2022-10-10 21:15:13.230+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=204, gcTime=237, gcCount=1}
debug.log.15:2022-10-10 23:51:28.117+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=247, gcTime=264, gcCount=1}
debug.log.15:2022-10-11 02:37:32.957+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=464, gcTime=472, gcCount=1}
debug.log.15:2022-10-11 02:37:39.525+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=271, gcTime=0, gcCount=0}
debug.log.15:2022-10-11 02:37:49.049+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=346, gcTime=0, gcCount=0}
debug.log.15:2022-10-11 02:37:58.234+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=249, gcTime=0, gcCount=0}
debug.log.15:2022-10-11 02:38:03.132+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=336, gcTime=0, gcCount=0}
debug.log.15:2022-10-11 02:41:56.196+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=376, gcTime=82, gcCount=1}
debug.log.15:2022-10-11 02:42:54.827+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=366, gcTime=425, gcCount=1}
debug.log.15:2022-10-11 02:44:41.148+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-wo

2

Hi Dana,

Neo4j version is 4.4.6.

It is a complex operation to write a few (100-500) hundred nodes in one transaction.

3

@apspannu

any other details? Neo4j Version?

>>Testing write operation

???

a simple

create (n:Person {id:1});

or something more complex? i.e.

match (n:Person) with avg(n.age) as avg_age where n.country_code='GB' with avg_age
match (n2:City) ..... 
create (n3:Rollup) set .....

how many writes are in a single txn? Are you creating 10 new nodes per txn or are you trying to write 1 million new nodes in a single txn?

4

Why Neo4J has PauseTime without any GC?

2022-10-18 13:27:19.727+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=2377, gcTime=0, gcCount=0}
2022-10-18 13:27:22.401+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=2436, gcTime=0, gcCount=0}
2022-10-18 13:27:25.039+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1715, gcTime=0, gcCount=0}
2022-10-18 13:27:29.299+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=3814, gcTime=0, gcCount=0}
2022-10-18 13:27:33.007+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=3866, gcTime=0, gcCount=0}
2022-10-18 13:27:38.108+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=3265, gcTime=0, gcCount=0}
2022-10-18 13:27:41.264+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=4271, gcTime=0, gcCount=0}
2022-10-18 13:27:43.592+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=3003, gcTime=0, gcCount=0}
2022-10-18 13:27:48.365+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=2968, gcTime=0, gcCount=0}
2022-10-18 13:35:59.669+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=4885, gcTime=0, gcCount=0}
2022-10-18 13:36:16.769+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=489940, gcTime=0, gcCount=0}
2022-10-18 13:36:17.103+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=16478, gcTime=0, gcCount=0}
2022-10-18 13:36:21.874+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=3104, gcTime=0, gcCount=0}
2022-10-18 13:36:23.594+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=2860, gcTime=0, gcCount=0}
2022-10-18 13:36:23.794+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=218, gcTime=0, gcCount=0}
2022-10-18 13:36:42.752+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=16968, gcTime=0, gcCount=0}
2022-10-18 13:36:43.582+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1574, gcTime=0, gcCount=0}
2022-10-18 13:36:44.563+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1008, gcTime=0, gcCount=0}
2022-10-18 13:36:46.345+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=486, gcTime=0, gcCount=0}