Java Garbage Collection (gc) pauses are monitored by the MonitorGc process in Neo4j, and recorded in the $NEO4J_HOME/logs/debug.log ( or $NEO4J_HOME/data/graph.db/messages.log for Neo4j v2.3.x and prior). To quickly find the 10 longest pauses in Neo4j 3.x and above, one can run:

grep -n -i blocked debug.log | sort -r -n -k 11 | head -10

which will result in output similar to:

7830:2016-12-05 19:04:23.865+0000 WARN  [o.n.k.i.c.MonitorGc] GC Monitor: Application threads blocked for 707ms.
3283:2016-12-02 13:25:52.264+0000 WARN  [o.n.k.i.c.MonitorGc] GC Monitor: Application threads blocked for 579ms.
6360:2016-12-02 15:38:35.502+0000 WARN  [o.n.k.i.c.MonitorGc] GC Monitor: Application threads blocked for 381ms.
6349:2016-12-02 15:02:33.156+0000 WARN  [o.n.k.i.c.MonitorGc] GC Monitor: Application threads blocked for 285ms.
6361:2016-12-02 15:50:45.560+0000 WARN  [o.n.k.i.c.MonitorGc] GC Monitor: Application threads blocked for 274ms.
6920:2016-12-05 16:57:47.170+0000 WARN  [o.n.k.i.c.MonitorGc] GC Monitor: Application threads blocked for 251ms.

The example grep command will perform a case-insensitive search (as a result of the -i argument) of the debug.log for the string ‘blocked’ and return the respective line number (as a result of the -n argument). These results are then sorted by way of the 11th field (as a result of -k 11) and sorted in numeric order rather than ASCII order (as a result of the -n argument) and then presented in reverse chronological order (as a result of the -r argument). Lastly the head -10 will only display the top 10 results after the sort.

Details


Author:
Dana Canzano
Applicable versions:
2.3, 3.0, 3.1
Keywords:
long GC pauseneo4j-2.3neo4j-3.0neo4j-3.1