visualvm
visualvm copied to clipboard
oracle
java.io.IOException: Heap dump is broken with visualvm 2.0.4
Description Opening a Oracle JDK 1.8_131 hprof file in the latest visualvm 2.0.4 results in the following error:
I have enabled console logging, so this is what I see:
INFO [org.graalvm.visualvm.heapdump.impl.HeapDumpView]: Failed to load heap dump
java.io.IOException: Heap dump is broken.
Tag 0x1c at offset 7535442102 has zero length.
at org.graalvm.visualvm.lib.jfluid.heap.HprofHeap.fillTagBounds(HprofHeap.java:1335)
at org.graalvm.visualvm.lib.jfluid.heap.HprofHeap.<init>(HprofHeap.java:161)
at org.graalvm.visualvm.lib.jfluid.heap.HeapFactory.createHeap(HeapFactory.java:105)
at org.graalvm.visualvm.lib.jfluid.heap.HeapFactory.createHeap(HeapFactory.java:73)
at org.graalvm.visualvm.heapviewer.HeapViewer.createHeap(HeapViewer.java:122)
at org.graalvm.visualvm.heapviewer.HeapViewer.<init>(HeapViewer.java:72)
[catch] at org.graalvm.visualvm.heapdump.impl.HeapDumpView$MasterViewSupport$1.run(HeapDumpView.java:138)
at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1418)
at org.netbeans.modules.openide.util.GlobalLookup.execute(GlobalLookup.java:45)
at org.openide.util.lookup.Lookups.executeWith(Lookups.java:278)
at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:2033)
I tried this with the older version i had - v2.0.2 and it just hangs here:
I then tried it with jvisualvm from an older Oracle JDK v1.8_161 and it parses fine:
Steps to reproduce This is an end customers heapdump which I'm afraid I cannot share at the moment. I am still seeing if I can reproduce this issue on my local environment and make it available.
Expected behavior
Since it is evident that jvisualvm from 1.8_161 was able to open the heapdump, visualvm 2.0.4 could be made tolerant to this kind of heap inconsistency.
Eclipse MAT also has a strictness mode setting where we can toggle it between "Strict" and "Warning".
Keeping it to WARNING will parse this heapdump. More on that in the eclipse bug here - https://bugs.eclipse.org/bugs/show_bug.cgi?id=404679
VisualVM log
v2.0.4_messages.log v2.0.2_messages.log jvisualvm_1.8_161_messages.log
Desktop (please complete the following information):
- Windows 10
- Version 2.0.4
Thanks for the report. The detection of the broken heap dump was added by NetBeans bugfix #254900. Older version of VisualVM does have this fix, so it will try to open it. Zero size tag 0x1c looks really suspicious and suggests that portion of the heap dump is missing. It would be great to get such heap dump for testing. If it is not possible to share heap dump, will it be possible to dump, let us say, 64 bytes around the offset 7535442102?
One more question: do you how the heap dump was obtained? What command was used?
@thurka thanks for the response.
Zero size tag 0x1c looks really suspicious and suggests that portion of the heap dump is missing.
That could very well be the threads details(?) because even jvisualvm and MAT failed to show them.
If it is not possible to share heap dump, will it be possible to dump, let us say, 64 bytes around the offset 7535442102
hexdump -C -s 7535442000 java_pid21829.hprof | more
1c125b870 00 2e 00 53 00 65 00 72 00 76 00 69 00 63 00 65 |...S.e.r.v.i.c.e|
1c125b880 00 50 00 72 00 6f 00 63 00 65 00 73 00 73 00 48 |.P.r.o.c.e.s.s.H|
1c125b890 00 6f 00 75 00 72 00 6c 00 79 00 53 00 75 00 6d |.o.u.r.l.y.S.u.m|
1c125b8a0 00 6d 00 61 00 72 00 69 00 7a 00 65 00 64 00 53 |.m.a.r.i.z.e.d.S|
1c125b8b0 00 74 00 61 00 74 1c 00 00 00 00 00 00 00 00 21 |.t.a.t.........!|
1c125b8c0 00 00 00 06 ae c0 1c 58 00 00 00 01 00 00 00 05 |.......X........|
1c125b8d0 c0 02 53 90 00 00 00 18 00 00 00 06 ae c0 1a a0 |..S.............|
1c125b8e0 00 00 00 06 ae c0 1e 08 00 00 00 06 ae c0 1c 70 |...............p|
1c125b8f0 21 00 00 00 06 ae c0 1c 70 00 00 00 01 00 00 00 |!.......p.......|
1c125b900 05 c2 65 a4 30 00 00 00 49 00 00 00 00 00 00 00 |..e.0...I.......|
1c125b910 00 00 00 00 06 ae c0 1d 38 00 00 00 00 00 00 00 |........8.......|
1c125b920 4d 00 00 00 06 ae c0 1c c8 00 00 00 00 00 00 00 |M...............|
1c125b930 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
if you want me to run it against another command, let me know.
do you how the heap dump was obtained? What command was used?
This heap was generated on out of memory error. The java application was running on 1.8.0_131 (25.131-b11) at that time.
Thanks for data, it shows that the 0x1c segment is not finished - the size of segment is written to the disk once the whole segment is done. Based on your info I guess that there was not enough space on file system to write the whole heap dump. Is it possible?
if you want me to run it against another command, let me know.
Can you, please, dump last 256 bytes of the heap dump?
Based on your info I guess that there was not enough space on file system to write the whole heap dump. Is it possible?
I did not hear the customer report a disk space issue around this time. So I am not sure if that's the case.
I can have them verify this once.
Also, does the 0x1c segment have its data at the end of the hprof file to make this a truncated one?
As you requested, here's the last 256 bytes
$ tail -c 256 java_pid21829.hprof | hexdump -C
00000000 00 00 00 00 00 06 d1 3f 59 40 00 00 00 00 00 00 |.......?Y@......|
00000010 00 4d 00 00 00 06 d1 3f 58 d0 00 00 00 00 00 00 |.M.....?X.......|
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
00000030 00 00 00 00 00 00 05 c1 4e 17 b8 00 00 00 06 d1 |........N.......|
00000040 3f 58 b0 21 00 00 00 06 d1 3f 58 b0 00 00 00 01 |?X.!.....?X.....|
00000050 00 00 00 05 c0 40 b8 d8 00 00 00 19 00 00 00 06 |.....@..........|
00000060 d1 3f 58 78 00 00 00 00 00 00 00 00 00 00 00 00 |.?Xx............|
00000070 00 00 00 00 00 21 00 00 00 06 d1 3f 58 d0 00 00 |.....!.....?X...|
00000080 00 01 00 00 00 05 c0 00 1d e0 00 00 00 0c 00 00 |................|
00000090 00 00 00 00 00 06 d1 3f 58 e8 23 00 00 00 06 d1 |.......?X.#.....|
000000a0 3f 58 e8 00 00 00 01 00 00 00 21 05 00 52 00 45 |?X........!..R.E|
000000b0 00 50 00 4f 00 2e 00 53 00 45 00 52 00 56 00 49 |.P.O...S.E.R.V.I|
000000c0 00 43 00 45 00 5f 00 50 00 52 00 4f 00 50 00 2e |.C.E._.P.R.O.P..|
000000d0 00 43 00 52 00 45 00 41 00 54 00 45 00 44 00 5f |.C.R.E.A.T.E.D._|
000000e0 00 42 00 59 00 5f 00 41 00 54 00 54 00 52 21 00 |.B.Y._.A.T.T.R!.|
000000f0 00 00 06 d1 3f 59 40 00 00 00 01 00 00 00 05 c0 |....?Y@.........|
00000100
And here's the last 1024 bytes
$ tail -c 1024 java_pid21829.hprof | hexdump -C
00000000 56 40 00 00 00 01 00 00 00 05 c0 40 b8 d8 00 00 |V@.........@....|
00000010 00 19 00 00 00 06 d1 3f 56 08 00 00 00 00 00 00 |.......?V.......|
00000020 00 00 00 00 00 00 00 00 00 00 00 21 00 00 00 06 |...........!....|
00000030 d1 3f 56 60 00 00 00 01 00 00 00 05 c0 00 1d e0 |.?V`............|
00000040 00 00 00 0c 00 00 00 00 00 00 00 06 d1 3f 56 78 |.............?Vx|
00000050 23 00 00 00 06 d1 3f 56 78 00 00 00 01 00 00 00 |#.....?Vx.......|
00000060 25 05 00 52 00 45 00 50 00 4f 00 2e 00 53 00 59 |%..R.E.P.O...S.Y|
00000070 00 53 00 54 00 45 00 4d 00 2e 00 50 00 52 00 53 |.S.T.E.M...P.R.S|
00000080 00 5f 00 50 00 41 00 52 00 45 00 4e 00 54 00 5f |._.P.A.R.E.N.T._|
00000090 00 46 00 4f 00 4c 00 44 00 45 00 52 00 5f 00 49 |.F.O.L.D.E.R._.I|
000000a0 00 44 00 5f 00 41 00 54 00 54 00 52 21 00 00 00 |.D._.A.T.T.R!...|
000000b0 06 d1 3f 56 d8 00 00 00 01 00 00 00 05 c0 00 1d |..?V............|
000000c0 e0 00 00 00 0c 00 00 00 00 00 00 00 06 d1 3f 56 |..............?V|
000000d0 f0 23 00 00 00 06 d1 3f 56 f0 00 00 00 01 00 00 |.#.....?V.......|
000000e0 00 18 05 00 55 00 3a 00 43 00 74 00 49 00 4a 00 |....U.:.C.t.I.J.|
000000f0 2d 00 36 00 4a 00 66 00 45 00 65 00 69 00 5a 00 |-.6.J.f.E.e.i.Z.|
00000100 6b 00 4e 00 4a 00 6a 00 45 00 4c 00 4b 00 4f 00 |k.N.J.j.E.L.K.O.|
00000110 64 00 41 21 00 00 00 06 d1 3f 57 30 00 00 00 01 |d.A!.....?W0....|
00000120 00 00 00 05 c0 02 53 90 00 00 00 18 00 00 00 06 |......S.........|
00000130 d1 3f 55 f0 00 00 00 06 d1 3f 58 60 00 00 00 06 |.?U......?X`....|
00000140 d1 3f 57 48 21 00 00 00 06 d1 3f 57 48 00 00 00 |.?WH!.....?WH...|
00000150 01 00 00 00 05 c2 65 a4 30 00 00 00 49 00 00 00 |......e.0...I...|
00000160 00 00 00 00 00 00 00 00 06 d1 3f 58 18 00 00 00 |..........?X....|
00000170 00 00 00 00 4d 00 00 00 06 d1 3f 57 a0 00 00 00 |....M.....?W....|
00000180 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
00000190 00 00 00 00 00 00 00 00 00 05 c1 4e 17 b8 00 00 |...........N....|
000001a0 00 06 d1 3f 57 80 21 00 00 00 06 d1 3f 57 80 00 |...?W.!.....?W..|
000001b0 00 00 01 00 00 00 05 c0 40 b8 d8 00 00 00 19 00 |........@.......|
000001c0 00 00 06 d1 3f 57 48 00 00 00 00 00 00 00 00 00 |....?WH.........|
000001d0 00 00 00 00 00 00 00 00 21 00 00 00 06 d1 3f 57 |........!.....?W|
000001e0 a0 00 00 00 01 00 00 00 05 c0 00 1d e0 00 00 00 |................|
000001f0 0c 00 00 00 00 00 00 00 06 d1 3f 57 b8 23 00 00 |..........?W.#..|
00000200 00 06 d1 3f 57 b8 00 00 00 01 00 00 00 28 05 00 |...?W........(..|
00000210 52 00 45 00 50 00 4f 00 2e 00 53 00 45 00 52 00 |R.E.P.O...S.E.R.|
00000220 56 00 49 00 43 00 45 00 5f 00 50 00 52 00 4f 00 |V.I.C.E._.P.R.O.|
00000230 50 00 2e 00 55 00 54 00 43 00 5f 00 43 00 52 00 |P...U.T.C._.C.R.|
00000240 45 00 41 00 54 00 49 00 4f 00 4e 00 5f 00 54 00 |E.A.T.I.O.N._.T.|
00000250 49 00 4d 00 45 00 5f 00 41 00 54 00 54 00 52 21 |I.M.E._.A.T.T.R!|
00000260 00 00 00 06 d1 3f 58 18 00 00 00 01 00 00 00 05 |.....?X.........|
00000270 c0 00 1d e0 00 00 00 0c 00 00 00 00 00 00 00 06 |................|
00000280 d1 3f 58 30 23 00 00 00 06 d1 3f 58 30 00 00 00 |.?X0#.....?X0...|
00000290 01 00 00 00 0d 05 00 31 00 35 00 38 00 39 00 34 |.......1.5.8.9.4|
000002a0 00 31 00 39 00 31 00 34 00 31 00 35 00 37 00 37 |.1.9.1.4.1.5.7.7|
000002b0 21 00 00 00 06 d1 3f 58 60 00 00 00 01 00 00 00 |!.....?X`.......|
000002c0 05 c0 02 53 90 00 00 00 18 00 00 00 06 d1 3f 57 |...S..........?W|
000002d0 30 00 00 00 06 d1 3f 59 88 00 00 00 06 d1 3f 58 |0.....?Y......?X|
000002e0 78 21 00 00 00 06 d1 3f 58 78 00 00 00 01 00 00 |x!.....?Xx......|
000002f0 00 05 c2 65 a4 30 00 00 00 49 00 00 00 00 00 00 |...e.0...I......|
00000300 00 00 00 00 00 06 d1 3f 59 40 00 00 00 00 00 00 |.......?Y@......|
00000310 00 4d 00 00 00 06 d1 3f 58 d0 00 00 00 00 00 00 |.M.....?X.......|
00000320 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
00000330 00 00 00 00 00 00 05 c1 4e 17 b8 00 00 00 06 d1 |........N.......|
00000340 3f 58 b0 21 00 00 00 06 d1 3f 58 b0 00 00 00 01 |?X.!.....?X.....|
00000350 00 00 00 05 c0 40 b8 d8 00 00 00 19 00 00 00 06 |.....@..........|
00000360 d1 3f 58 78 00 00 00 00 00 00 00 00 00 00 00 00 |.?Xx............|
00000370 00 00 00 00 00 21 00 00 00 06 d1 3f 58 d0 00 00 |.....!.....?X...|
00000380 00 01 00 00 00 05 c0 00 1d e0 00 00 00 0c 00 00 |................|
00000390 00 00 00 00 00 06 d1 3f 58 e8 23 00 00 00 06 d1 |.......?X.#.....|
000003a0 3f 58 e8 00 00 00 01 00 00 00 21 05 00 52 00 45 |?X........!..R.E|
000003b0 00 50 00 4f 00 2e 00 53 00 45 00 52 00 56 00 49 |.P.O...S.E.R.V.I|
000003c0 00 43 00 45 00 5f 00 50 00 52 00 4f 00 50 00 2e |.C.E._.P.R.O.P..|
000003d0 00 43 00 52 00 45 00 41 00 54 00 45 00 44 00 5f |.C.R.E.A.T.E.D._|
000003e0 00 42 00 59 00 5f 00 41 00 54 00 54 00 52 21 00 |.B.Y._.A.T.T.R!.|
000003f0 00 00 06 d1 3f 59 40 00 00 00 01 00 00 00 05 c0 |....?Y@.........|
00000400
I did not hear the customer report a disk space issue around this time. So I am not sure if that's the case. I can have them verify this once.
The log from the java process should have something like:
java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid19958.hprof ...
Heap dump file created [1214445229 bytes in 3.216 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
Also, does the
0x1csegment have its data at the end of the hprof file to make this a truncated one?
Yes, and after 0x1c there should be 0x2c segment, which closes the heap dump file.
As you requested, here's the last 256 bytes
This data shows that the heap dump file ends abruptly in the middle of instance object dump.
Just FYI: I just hit this issue, and I'm pretty sure it was because I ran out of disk space.
At a minimum, I think that this issue could be fixed by warning the user when the heap dump is actually created that the disk is full. At the moment, the dump itself fails silently and then when VisualVM tries to load it fails because the file has been truncated. I think that this could be improved.
@kriegfrj thanks for the confirmation. I agree - visualvm could be improved to be resilient to corrupt heap files given how IBM MAT doesn't have issues parsing this file.