-
Bug
-
Resolution: Fixed
-
P4
-
17, 18, 19, 20
-
b09
Issue | Fix Version | Assignee | Priority | Status | Resolution | Resolved In Build |
---|---|---|---|---|---|---|
JDK-8307801 | 17.0.9-oracle | Joakim Nordström | P4 | Resolved | Fixed | b01 |
JDK-8310373 | 17.0.9 | Martin Doerr | P4 | Resolved | Fixed | b01 |
jfr command was in infinite loop when I passed invalid file which are in JFR repository of GraalVM Native Image (I attached the recording file in this ticket).
CPU usage was 100% when jfr hanged, and I got following thread stacks:
```
"main" #1 prio=5 os_prio=0 cpu=10333.35ms elapsed=10.67s tid=0x00007f4994013810 nid=10079 runnable [0x00007f499adfe000]
java.lang.Thread.State: RUNNABLE
at java.io.RandomAccessFile.seek0(java.base@18.0.1/Native Method)
at java.io.RandomAccessFile.seek(java.base@18.0.1/RandomAccessFile.java:591)
at jdk.jfr.internal.consumer.RecordingInput.positionPhysical(jdk.jfr@18.0.1/RecordingInput.java:102)
at jdk.jfr.internal.consumer.ChunkHeader.refresh(jdk.jfr@18.0.1/ChunkHeader.java:124)
at jdk.jfr.internal.consumer.ChunkHeader.<init>(jdk.jfr@18.0.1/ChunkHeader.java:108)
at jdk.jfr.internal.consumer.ChunkHeader.<init>(jdk.jfr@18.0.1/ChunkHeader.java:66)
at jdk.jfr.internal.consumer.ChunkParser.<init>(jdk.jfr@18.0.1/ChunkParser.java:117)
at jdk.jfr.internal.consumer.ChunkParser.<init>(jdk.jfr@18.0.1/ChunkParser.java:113)
at jdk.jfr.consumer.RecordingFile.findNext(jdk.jfr@18.0.1/RecordingFile.java:256)
at jdk.jfr.consumer.RecordingFile.<init>(jdk.jfr@18.0.1/RecordingFile.java:89)
at jdk.jfr.internal.tool.EventPrintWriter.print(jdk.jfr@18.0.1/EventPrintWriter.java:72)
at jdk.jfr.internal.tool.Print.execute(jdk.jfr@18.0.1/Print.java:164)
at jdk.jfr.internal.tool.Main.main(jdk.jfr@18.0.1/Main.java:87)
```
And also I got following log with `-J-Xlog:"jfr*=info"` - chunk size was 0, and the parser hanged in processing first chunk (id = 0):
```
$ jfr -J-Xlog:"jfr*=info" print ~/2022_07_04_18_05_11.jfr
[0.353s][info][jfr,system,parser] Chunk: 0
[0.353s][info][jfr,system,parser] Chunk: file=/home/ysuenaga/2022_07_04_18_05_11.jfr
[0.353s][info][jfr,system,parser] Chunk: startPosition=0
[0.353s][info][jfr,system,parser] Chunk: major=2
[0.353s][info][jfr,system,parser] Chunk: minor=0
[0.353s][info][jfr,system,parser] Chunk: chunkSize=0
[0.353s][info][jfr,system,parser] Chunk: constantPoolPosition=0
[0.353s][info][jfr,system,parser] Chunk: metadataPosition=0
[0.353s][info][jfr,system,parser] Chunk: startNanos=0
[0.353s][info][jfr,system,parser] Chunk: durationNanos=0
[0.354s][info][jfr,system,parser] Chunk: startTicks=9410187
[0.354s][info][jfr,system,parser] Chunk: ticksPerSecond=1000000000
```
We should abort the process when invalid chunk was detected.
CPU usage was 100% when jfr hanged, and I got following thread stacks:
```
"main" #1 prio=5 os_prio=0 cpu=10333.35ms elapsed=10.67s tid=0x00007f4994013810 nid=10079 runnable [0x00007f499adfe000]
java.lang.Thread.State: RUNNABLE
at java.io.RandomAccessFile.seek0(java.base@18.0.1/Native Method)
at java.io.RandomAccessFile.seek(java.base@18.0.1/RandomAccessFile.java:591)
at jdk.jfr.internal.consumer.RecordingInput.positionPhysical(jdk.jfr@18.0.1/RecordingInput.java:102)
at jdk.jfr.internal.consumer.ChunkHeader.refresh(jdk.jfr@18.0.1/ChunkHeader.java:124)
at jdk.jfr.internal.consumer.ChunkHeader.<init>(jdk.jfr@18.0.1/ChunkHeader.java:108)
at jdk.jfr.internal.consumer.ChunkHeader.<init>(jdk.jfr@18.0.1/ChunkHeader.java:66)
at jdk.jfr.internal.consumer.ChunkParser.<init>(jdk.jfr@18.0.1/ChunkParser.java:117)
at jdk.jfr.internal.consumer.ChunkParser.<init>(jdk.jfr@18.0.1/ChunkParser.java:113)
at jdk.jfr.consumer.RecordingFile.findNext(jdk.jfr@18.0.1/RecordingFile.java:256)
at jdk.jfr.consumer.RecordingFile.<init>(jdk.jfr@18.0.1/RecordingFile.java:89)
at jdk.jfr.internal.tool.EventPrintWriter.print(jdk.jfr@18.0.1/EventPrintWriter.java:72)
at jdk.jfr.internal.tool.Print.execute(jdk.jfr@18.0.1/Print.java:164)
at jdk.jfr.internal.tool.Main.main(jdk.jfr@18.0.1/Main.java:87)
```
And also I got following log with `-J-Xlog:"jfr*=info"` - chunk size was 0, and the parser hanged in processing first chunk (id = 0):
```
$ jfr -J-Xlog:"jfr*=info" print ~/2022_07_04_18_05_11.jfr
[0.353s][info][jfr,system,parser] Chunk: 0
[0.353s][info][jfr,system,parser] Chunk: file=/home/ysuenaga/2022_07_04_18_05_11.jfr
[0.353s][info][jfr,system,parser] Chunk: startPosition=0
[0.353s][info][jfr,system,parser] Chunk: major=2
[0.353s][info][jfr,system,parser] Chunk: minor=0
[0.353s][info][jfr,system,parser] Chunk: chunkSize=0
[0.353s][info][jfr,system,parser] Chunk: constantPoolPosition=0
[0.353s][info][jfr,system,parser] Chunk: metadataPosition=0
[0.353s][info][jfr,system,parser] Chunk: startNanos=0
[0.353s][info][jfr,system,parser] Chunk: durationNanos=0
[0.354s][info][jfr,system,parser] Chunk: startTicks=9410187
[0.354s][info][jfr,system,parser] Chunk: ticksPerSecond=1000000000
```
We should abort the process when invalid chunk was detected.
- backported by
-
JDK-8307801 jfr command hangs when it processes invalid file
- Resolved
-
JDK-8310373 jfr command hangs when it processes invalid file
- Resolved
- links to
-
Commit openjdk/jdk17u-dev/d85a8477
-
Commit openjdk/jdk/dd9bd31b
-
Review openjdk/jdk17u-dev/1472
-
Review openjdk/jdk/9363
(1 links to)