Fully featured low overhead profiler for Java EE and Java SE platforms.
Ultimate profiling and monitoring solution for Gradle, Maven, Ant, JUnit and TestNG.
Easy to use performance and memory profiler for .NET framework.

Failing to process large HEAP dump

Moderators: Vladimir Kondratyev, Anton Katilin

Failing to process large HEAP dump

Postby tedo » Wed Jun 07, 2017 7:50 pm

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.
tedo
 
Posts: 4
Joined: Wed Jun 07, 2017 7:39 pm

Re: Failing to process large HEAP dump

Postby Anton Katilin » Thu Jun 08, 2017 8:26 am

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 support@yourkit.com

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: 5575
Joined: Wed Aug 11, 2004 8:37 am

Re: Failing to process large HEAP dump

Postby Anton Katilin » Thu Jun 08, 2017 8:29 am

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.
Anton Katilin
 
Posts: 5575
Joined: Wed Aug 11, 2004 8:37 am

Re: Failing to process large HEAP dump

Postby tedo » Thu Jun 08, 2017 10:25 am

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

Postby tedo » Thu Jun 08, 2017 3:10 pm

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)
tedo
 
Posts: 4
Joined: Wed Jun 07, 2017 7:39 pm

Re: Failing to process large HEAP dump

Postby Anton Katilin » Fri Jun 09, 2017 4:56 am

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.
Anton Katilin
 
Posts: 5575
Joined: Wed Aug 11, 2004 8:37 am

Re: Failing to process large HEAP dump

Postby tedo » Fri Jun 09, 2017 9:25 pm

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!
tedo
 
Posts: 4
Joined: Wed Jun 07, 2017 7:39 pm

Re: Failing to process large HEAP dump

Postby Vladimir Kondratyev » Mon Jun 12, 2017 3:55 pm

tedo , you can also try to use -Dyk.dom=low_mem instead of -Dyk.dominators=false
Vladimir Kondratyev
 
Posts: 1444
Joined: Tue Aug 10, 2004 7:52 pm
Location: Düsseldorf, Germany


Return to Java Profiler

Who is online

Users browsing this forum: Bing [Bot] and 4 guests