Failing to process large HEAP dump

Questions about YourKit Java Profiler
Post Reply
tedo
Posts: 4
Joined: Wed Jun 07, 2017 7:39 pm

Failing to process large HEAP dump

Post by tedo »

I have a 40G heap dump that I tried to load via "Open Snapshot".
It keeps failing with the following error:
17.02-59 5.664: com.yourkit.j.ni: marker: created /tmp/.yjp_ui_20161012_45729
17.02-59 10.574: com.yourkit.h.z: LWS-update: code=200 text: payload=AM... result=ok
17.02-59 12.860: com.yourkit.j.nw: UPDATES_URL: https://www.yourkit.com/updates_yjp_201 ... 2017.02.59
17.02-59 33.577: com.yourkit.d.q: snapshot_outer: starting: /storage/disk0/data/logs/analytics/2017060709.hprof size=39.4 GB (42,325,726,718)
17.02-59 33.581: com.yourkit.d.q: Loader for vanilla HPROF: /storage/disk0/data/logs/analytics/2017060709.hprof
17.02-59 33.582: com.yourkit.d.b.b.s: hprof_magic_string: JAVA PROFILE 1.0.2
17.02-59 33.588: com.yourkit.d.b.b.s: pass1: starting
17.02-59 33.589: com.yourkit.d.b.b.ai: OIDStorage: will write /storage/disk0/data/tedo/tmp/yjp_dc_7177402825496941856.oids
17.02-59 241.040: com.yourkit.d.b.b.s: pass1: finished
17.02-59 241.041: com.yourkit.d.b.b.ai: OID_converting: 1
17.02-59 260.637: com.yourkit.d.b.b.ai: OID_converting: 2
17.02-59 280.402: com.yourkit.d.b.b.ai: OID_converting: done
17.02-59 280.402: com.yourkit.d.b.b.bl: oid LUT: negative/positive: 0/807248682
17.02-59 284.900: com.yourkit.d.b.b.s: hprof_info: big_oids=true compressed=false record_order=normal
17.02-59 284.907: [m: 55931 6440] createStorage: objectCount=807248682
17.02-59 290.403: [m: 66709 17220] createStorage: result=139946881039920
17.02-59 292.945: com.yourkit.d.b.b.s: pass2: starting
17.02-59 292.947: com.yourkit.d.b.b.f: pass2: worker count: 4
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [Z
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [B
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [C
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [I
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [S
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [J
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [F
17.02-59 294.053: com.yourkit.d.b.b.s: warning: redefinition of primitive array class [D
17.02-59 449.283: with extraRefs
17.02-59 482.234: com.yourkit.d.b.b.bv: flush_all:
arr_ls: f=1 a=4
arr_same: 0
alloc: 0
gens: 0
oids: 0
crc: f=1 a=4
prim: f=1 a=17246
refs: f=1 a=82471
size: f=1 a=4
17.02-59 482.236: com.yourkit.d.b.b.bv: flush_all:
arr_ls: f=27 a=3422591
arr_same: f=2 a=261383
alloc: 0
gens: 0
oids: 0
crc: f=2287 a=299708791
prim: f=2258 a=295886298
refs: f=7361 a=964705768
size: f=27 a=3422591
17.02-59 482.238: com.yourkit.d.b.b.bv: flush_all:
arr_ls: f=26 a=3285719
arr_same: f=2 a=238357
alloc: 0
gens: 0
oids: 0
crc: f=2104 a=275706122
prim: f=2077 a=272176600
refs: f=6330 a=829563809
size: f=26 a=3285719
17.02-59 482.243: com.yourkit.d.b.b.bv: flush_all:
arr_ls: f=18 a=2342056
arr_same: f=2 a=173218
alloc: 0
gens: 0
oids: 0
crc: f=1256 a=164624283
prim: f=1237 a=162059747
refs: f=3739 a=490031532
size: f=18 a=2342056
17.02-59 482.248: com.yourkit.d.b.b.bv: flush_all:
arr_ls: f=10 a=1197558
arr_same: f=1 a=77126
alloc: 0
gens: 0
oids: 0
crc: f=489 a=64063785
prim: f=479 a=62769540
refs: f=1503 a=196971013
size: f=10 a=1197558
17.02-59 482.248: com.yourkit.d.b.b.f: worker:inst/prim/obj
sync:0/4/0
async#1:297326228/2382563/1040028
async#2:273414281/2291841/993878
async#3:162987944/1636339/705717
async#4:63255059/808726/388832

17.02-59 482.248: com.yourkit.d.b.b.s: pass2: finished
17.02-59 482.248: com.yourkit.d.b.b.bv: flush_all:
arr_ls: 0
arr_same: 0
alloc: 0
gens: 0
oids: 0
crc: 0
prim: 0
refs: 0
size: 0
17.02-59 482.248: com.yourkit.d.b.b.bk: correctReferences: enter
17.02-59 500.730: com.yourkit.d.b.b.bk: correctReferences: exit: badObjects=null correctedRefCount=0
17.02-59 514.714: com.yourkit.d.b.b.bk: patchObjectSizes: 797000754 / 807248683
17.02-59 514.715: com.yourkit.d.b.b.bv: flush_all:
arr_ls: 0
arr_same: 0
alloc: 0
gens: 0
oids: 0
crc: 0
prim: 0
refs: f=10 a=17260
size: f=6081 a=797000754
17.02-59 514.722: com.yourkit.d.b.bl: initMemPart: 0
17.02-59 556.218: com.yourkit.d.b.bl: initMemPart: 1
17.02-59 786.039: com.yourkit.d.b.bl: initMemPart: 2
17.02-59 786.040: com.yourkit.d.b.bl: initMemPart: 3
17.02-59 786.040: [m: 90788 46457] dc: 0
17.02-59 786.040: [m: 90788 46457] dc: input creation: starting...
N=807248683 roots=3918
/storage/disk0/data/tedo/tmp/yjp_dc_5243831448981280155.dc_input -> /storage/disk0/data/tedo/tmp/yjp_dc_6497552882456586432.idom
17.02-59 786.041: [m: 90788 46457] NewDominatorSupport::createInput: /storage/disk0/data/tedo/tmp/yjp_dc_5243831448981280155.dc_input
17.02-59 787.288: [m: 93867 49538] NewDominatorSupport::createInput: o2c created
17.02-59 788.422: NewDominatorSupport::createInput: roots=3918
N=807248683
NC=801509297
17.02-59 851.242: [m: 93963 49634] NewDominatorSupport::createInput: all_refs=2491444104 not_null_refs=1656195093 written_refs=1616695807
17.02-59 859.837: [m: 93963 49634] NewDominatorSupport::createInput: done
17.02-59 859.955: [m: 90788 46459] dc: input creation: ended, NC=801509297
17.02-59 859.955: [m: 90788 46459] dc: runnable...
17.02-59 859.957: com.yourkit.d.b.au: DC_process: yk.tmp.dir=/storage/disk0/data/tedo/tmp
17.02-59 859.957: com.yourkit.d.b.au: DC_process: to run:
/storage/disk0/data/tedo/yjp-2017.02/bin/linux-x86-64/yjp_dc
/storage/disk0/data/tedo/tmp/yjp_dc_5243831448981280155.dc_input
/storage/disk0/data/tedo/tmp/yjp_dc_6497552882456586432.idom
snca

17.02-59 941.098: com.yourkit.d.b.au: DC_process: output:
exit code: 100
stdout:
yjp_dc: trying to load /storage/disk0/data/tedo/yjp-2017.02/bin/linux-x86-64/libyjpagent.so
stderr:
17.02-59 0.000: [m: 40 4] Reading input: /storage/disk0/data/tedo/tmp/yjp_dc_5243831448981280155.dc_input
17.02-59 0.000: N = 801509297
17.02-59 80.685: refs: 1616695807
17.02-59 80.685: roots: 3918
17.02-59 80.685: [m: 12328 12293] creating idom...
17.02-59 80.686: error: exception caught at Dominators.cpp:167

17.02-59 941.099: [m: 90917 46459] dc: runnable: failed: java.lang.RuntimeException: Dominator computer process exited with error code 100; see the log for detail
I tried unsuccessful to get dominator calculation to not happen.
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Failing to process large HEAP dump

Post by Anton Katilin »

Hello,

It's a new issue.

Under which JVM did you capture it? Could you please provide corresponding "java -version".

Can you provide the problematic snapshot file? You can zip or otherwise compress it, upload to a file sharing web site of your choice and send the download link to [email protected]
I tried unsuccessful to get dominator calculation to not happen.
Did you add the -Dyjp.dominators=false line to ~/.yjp/ui.ini?

Best regards,
Anton
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Failing to process large HEAP dump

Post by Anton Katilin »

Update: this problem may be related with lack of virtual memory. How large is the swap file? You may try increasing its size or use a machine with more virtual memory available.

Alternatively, disable the calculation with -Dyjp.dominators=false as suggested in my previous post.
tedo
Posts: 4
Joined: Wed Jun 07, 2017 7:39 pm

Re: Failing to process large HEAP dump

Post by tedo »

I am running on a 40G snapshot on a 60G machine in AWS so no swap
I am indeed running out of virtual memory it seems.
I tried adding -Dyjp.dominators=false to ~/.yjp/ui.ini but dominator calculation still appears to be happening:
/storage/disk0/data/tedo/yjp-2017.02/bin/../jre64/bin/java -Xmx8G -XX:+HeapDumpOnOutOfMemoryError -Xmx50g -Dyjp.dom=low_mem -Dyjp.dominators=false -Dyjp.alternate.temp.dir=/storage/disk0/data/tedo/tmp -Dyk.tmp.dir=/storage/disk0/data/tedo/tmp -XX:OnError=/storage/disk0/data/tedo/yjp-2017.02/bin/../bin/yjp.sh -on_error %p -jar /storage/disk0/data/tedo/yjp-2017.02/bin/../lib/yjp.jar
From the logs:
17.02-59 866.465: [m: 90724 46666] dc: 0
17.02-59 866.465: [m: 90724 46666] dc: input creation: starting...
N=807248683 roots=3918
/storage/disk0/data/tedo/tmp/yjp_dc_2464637313964596545.dc_input -> /storage/disk0/data/tedo/tmp/yjp_dc_8401573306569535296.idom
17.02-59 866.465: [m: 90724 46666] NewDominatorSupport::createInput: /storage/disk0/data/tedo/tmp/yjp_dc_2464637313964596545.dc_input
17.02-59 867.717: [m: 93803 49747] NewDominatorSupport::createInput: o2c created
17.02-59 868.853: NewDominatorSupport::createInput: roots=3918
N=807248683
NC=801509297
17.02-59 936.705: [m: 93899 49844] NewDominatorSupport::createInput: all_refs=2491444104 not_null_refs=1656195093 written_refs=1616695807
17.02-59 943.452: [m: 93899 49844] NewDominatorSupport::createInput: done
17.02-59 943.565: [m: 90724 46668] dc: input creation: ended, NC=801509297
17.02-59 943.565: [m: 90724 46668] dc: runnable...
17.02-59 943.568: com.yourkit.d.b.au: DC_process: yk.tmp.dir=/storage/disk0/data/tedo/tmp
17.02-59 943.569: com.yourkit.d.b.au: DC_process: to run:
/storage/disk0/data/tedo/yjp-2017.02/bin/linux-x86-64/yjp_dc
/storage/disk0/data/tedo/tmp/yjp_dc_2464637313964596545.dc_input
/storage/disk0/data/tedo/tmp/yjp_dc_8401573306569535296.idom
snca

17.02-59 1024.323: com.yourkit.d.b.au: DC_process: output:
exit code: 100
stdout:
yjp_dc: trying to load /storage/disk0/data/tedo/yjp-2017.02/bin/linux-x86-64/libyjpagent.so
stderr:
17.02-59 0.000: [m: 40 4] Reading input: /storage/disk0/data/tedo/tmp/yjp_dc_2464637313964596545.dc_input
17.02-59 0.005: N = 801509297
17.02-59 80.312: refs: 1616695807
17.02-59 80.312: roots: 3918
17.02-59 80.312: [m: 12328 12293] creating idom...
17.02-59 80.314: error: exception caught at Dominators.cpp:167

17.02-59 1024.324: [m: 90853 46676] dc: runnable: failed: java.lang.RuntimeException: Dominator computer process exited with error code 100; see the log for detail
tedo
Posts: 4
Joined: Wed Jun 07, 2017 7:39 pm

Re: Failing to process large HEAP dump

Post by tedo »

Oh and java version is:

Code: Select all

java -version
java version "1.8.0_66"
Java(TM) SE Runtime Environment (build 1.8.0_66-b17)
Java HotSpot(TM) 64-Bit Server VM (build 25.66-b17, mixed mode)
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Failing to process large HEAP dump

Post by Anton Katilin »

I am running on a 40G snapshot on a 60G machine in AWS so no swap
I am indeed running out of virtual memory it seems.
Anyway, you should have enough virtual memory to open a snapshot. Do you mean you've got 60 GB of virtual memory available?
I tried adding -Dyjp.dominators=false to ~/.yjp/ui.ini but dominator calculation still appears to be happening:
Please try -Dyk.dominators=false instead. This internal option has been renamed in the latest release. Sorry for confusion.
tedo
Posts: 4
Joined: Wed Jun 07, 2017 7:39 pm

Re: Failing to process large HEAP dump

Post by tedo »

Thank you very much, the new flag name unblocked me.
I also got another server with more memory (122G!) and the product worked great. Thank you very much!
Vladimir Kondratyev
Posts: 1624
Joined: Tue Aug 10, 2004 7:52 pm

Re: Failing to process large HEAP dump

Post by Vladimir Kondratyev »

tedo , you can also try to use -Dyk.dom=low_mem instead of -Dyk.dominators=false
Post Reply