java - interpreting jstack output -
i have java process loading lot of data bunch of .csv files neo4j database using batchinserter
. using:
- openjdk 7
- ubuntu 12.04
- neo4j 2.0 m3
after loading first 164 gb (according ls -lh
) folder size stopped increasing process kept running, no memory released, , cpu still @ 100% (all according htop
).
the loading process single threaded, jvm using more 1 thread - guess parallelgc
.
i'm not sure how diagnose type of problem instructed try jstack
, have included output below.
anyone has idea went wrong or has suggestions on how can go diagnosing this?
full thread dump openjdk 64-bit server vm (22.0-b10 mixed mode): "attach listener" daemon prio=10 tid=0x00007fc3a4001000 nid=0x5636 runnable [0x0000000000000000] java.lang.thread.state: runnable "service thread" daemon prio=10 tid=0x00007fcf58123000 nid=0x4545 runnable [0x0000000000000000] java.lang.thread.state: runnable "c2 compilerthread1" daemon prio=10 tid=0x00007fcf58120800 nid=0x4544 waiting on condition [0x0000000000000000] java.lang.thread.state: runnable "c2 compilerthread0" daemon prio=10 tid=0x00007fcf5811d800 nid=0x4543 waiting on condition [0x0000000000000000] java.lang.thread.state: runnable "signal dispatcher" daemon prio=10 tid=0x00007fcf5811b800 nid=0x4542 waiting on condition [0x0000000000000000] java.lang.thread.state: runnable "finalizer" daemon prio=10 tid=0x00007fcf580c4800 nid=0x4541 in object.wait() [0x00007fc3f3cfb000] java.lang.thread.state: waiting (on object monitor) @ java.lang.object.wait(native method) - waiting on <0x00007fc4165fc708> (a java.lang.ref.referencequeue$lock) @ java.lang.ref.referencequeue.remove(referencequeue.java:135) - locked <0x00007fc4165fc708> (a java.lang.ref.referencequeue$lock) @ java.lang.ref.referencequeue.remove(referencequeue.java:151) @ java.lang.ref.finalizer$finalizerthread.run(finalizer.java:177) "reference handler" daemon prio=10 tid=0x00007fcf580c2000 nid=0x4540 in object.wait() [0x00007fc3f3dfc000] java.lang.thread.state: waiting (on object monitor) @ java.lang.object.wait(native method) - waiting on <0x00007fc4165ffe08> (a java.lang.ref.reference$lock) @ java.lang.object.wait(object.java:503) @ java.lang.ref.reference$referencehandler.run(reference.java:133) - locked <0x00007fc4165ffe08> (a java.lang.ref.reference$lock) "main" prio=10 tid=0x00007fcf58007800 nid=0x452c runnable [0x00007fcf606b7000] java.lang.thread.state: runnable @ java.lang.string.substring(string.java:1960) @ java.lang.string.subsequence(string.java:1993) @ java.util.regex.pattern.split(pattern.java:1202) @ com.ldbc.socialnet.neo4j.csvfilereader.parseline(csvfilereader.java:73) @ com.ldbc.socialnet.neo4j.csvfilereader.nextline(csvfilereader.java:61) @ com.ldbc.socialnet.neo4j.csvfilereader.hasnext(csvfilereader.java:33) @ com.ldbc.socialnet.neo4j.csvfileinserter.bufferlines(csvfileinserter.java:62) @ com.ldbc.socialnet.neo4j.csvfileinserter.insertallbuffered(csvfileinserter.java:93) @ com.ldbc.socialnet.neo4j.ldbcsocialneworkneo4jimporter.load(ldbcsocialneworkneo4jimporter.java:79) @ com.ldbc.socialnet.neo4j.ldbcsocialneworkneo4jimporter.main(ldbcsocialneworkneo4jimporter.java:49) "vm thread" prio=10 tid=0x00007fcf580ba000 nid=0x453f runnable "gc task thread#0 (parallelgc)" prio=10 tid=0x00007fcf58012800 nid=0x452d runnable "gc task thread#1 (parallelgc)" prio=10 tid=0x00007fcf58014800 nid=0x452e runnable "gc task thread#2 (parallelgc)" prio=10 tid=0x00007fcf58016000 nid=0x452f runnable "gc task thread#3 (parallelgc)" prio=10 tid=0x00007fcf58018000 nid=0x4530 runnable "gc task thread#4 (parallelgc)" prio=10 tid=0x00007fcf5801a000 nid=0x4531 runnable "gc task thread#5 (parallelgc)" prio=10 tid=0x00007fcf5801b800 nid=0x4532 runnable "gc task thread#6 (parallelgc)" prio=10 tid=0x00007fcf5801d800 nid=0x4533 runnable "gc task thread#7 (parallelgc)" prio=10 tid=0x00007fcf5801f800 nid=0x4534 runnable "gc task thread#8 (parallelgc)" prio=10 tid=0x00007fcf58021000 nid=0x4535 runnable "gc task thread#9 (parallelgc)" prio=10 tid=0x00007fcf58023000 nid=0x4536 runnable "gc task thread#10 (parallelgc)" prio=10 tid=0x00007fcf58025000 nid=0x4537 runnable "gc task thread#11 (parallelgc)" prio=10 tid=0x00007fcf58026800 nid=0x4538 runnable "gc task thread#12 (parallelgc)" prio=10 tid=0x00007fcf58028800 nid=0x4539 runnable "gc task thread#13 (parallelgc)" prio=10 tid=0x00007fcf5802a800 nid=0x453a runnable "gc task thread#14 (parallelgc)" prio=10 tid=0x00007fcf5802c800 nid=0x453b runnable "gc task thread#15 (parallelgc)" prio=10 tid=0x00007fcf5802e000 nid=0x453c runnable "gc task thread#16 (parallelgc)" prio=10 tid=0x00007fcf58030000 nid=0x453d runnable "gc task thread#17 (parallelgc)" prio=10 tid=0x00007fcf58032000 nid=0x453e runnable "vm periodic task thread" prio=10 tid=0x00007fcf5812d800 nid=0x4546 waiting on condition jni global references: 175 heap psyounggen total 11211840k, used 7045440k [0x00007fcb95000000, 0x00007fcf3d160000, 0x00007fcf55000000) eden space 7045440k, 100% used [0x00007fcb95000000,0x00007fcd43050000,0x00007fcd43050000) space 4166400k, 0% used [0x00007fce39510000,0x00007fce39510000,0x00007fcf379d0000) space 4035328k, 0% used [0x00007fcd43050000,0x00007fcd43050000,0x00007fce39510000) psoldgen total 31457280k, used 31300002k [0x00007fc415000000, 0x00007fcb95000000, 0x00007fcb95000000) object space 31457280k, 99% used [0x00007fc415000000,0x00007fcb8b668b98,0x00007fcb95000000) pspermgen total 21248k, used 7487k [0x00007fc40aa00000, 0x00007fc40bec0000, 0x00007fc415000000) object space 21248k, 35% used [0x00007fc40aa00000,0x00007fc40b14ff48,0x00007fc40bec0000)
in particular, can give little insight on these heap values or suggest read them?
heap psyounggen total 16348096k, used 12660905k [0x00007f833a560000, 0x00007f87639c0000, 0x00007f8765000000) eden space 15282432k, 82% used [0x00007f833a560000,0x00007f863f18a688,0x00007f86df1a0000) space 1065664k, 0% used [0x00007f86df1a0000,0x00007f86df1a0000,0x00007f8720250000) space 1036288k, 0% used [0x00007f87245c0000,0x00007f87245c0000,0x00007f87639c0000) paroldgen total 34952576k, used 34903343k [0x00007f7ae5000000, 0x00007f833a560000, 0x00007f833a560000) object space 34952576k, 99% used [0x00007f7ae5000000,0x00007f833754bd90,0x00007f833a560000) pspermgen total 21248k, used 7130k [0x00007f7adfe00000, 0x00007f7ae12c0000, 0x00007f7ae5000000) object space 21248k, 33% used [0x00007f7adfe00000,0x00007f7ae04f6860,0x00007f7ae12c0000)
it looks process out of memory:
eden space 7045440k, 100% used object space 31457280k, 99% used
in case gc may run continiosly, trying free memory, consuming alomist cpu. application logic thread under heavy starvation. may either add more memory via -xmx jvm option or profile application. profiling via jvisualvm, jprofiler or other tool give important runtime data:
- memory allocaton dynamics. if memory consumption increasing time you're have memory leak
- heap contents find out occupies momory
- gc statistics
based on data you'll certanly able resolve issue.
Comments
Post a Comment