RFR: 8201516: DebugNonSafepoints generates incorrect information [v2]
Tobias Hartmann
thartmann at openjdk.org
Wed Mar 1 14:38:49 UTC 2023
> C2 emits incorrect debug information when diagnostic `-XX:+DebugNonSafepoints` is enabled. The problem is that renumbering of live nodes (`-XX:+RenumberLiveNodes`) introduced by [JDK-8129847](https://bugs.openjdk.org/browse/JDK-8129847) in JDK 8u92 / JDK 9 does not update the `_node_note_array` side table that links IR node indices to debug information. As a result, after node indices are updated, they point to unrelated debug information.
>
> The [reproducer](https://github.com/jodzga/debugnonsafepoints-problem) shared by the original reporter @jodzga (@jbachorik also reported this issue separately) does not work anymore with recent JDK versions but with a slight adjustment to trigger node renumbering, I could reproduce the wrong JFR method profile:
>
> ![Screenshot from 2023-03-01 13-17-48](https://user-images.githubusercontent.com/5312595/222146314-8b5299a8-c1c0-4360-b356-ac6a8c34371c.png)
>
> It suggests that the hottest method of the [Test](https://github.com/jodzga/debugnonsafepoints-problem/blob/f8ed40f24ef6a6bff7f86ea861c022db193ef48a/src/main/java/org/tests/Test.java#L28) is **not** the long running loop in [Test::arraycopy](https://github.com/jodzga/debugnonsafepoints-problem/blob/f8ed40f24ef6a6bff7f86ea861c022db193ef48a/src/main/java/org/tests/Test.java#L56) but several other short running methods. The hot method is not even in the profile. This is obviously wrong.
>
> With the fix, or when running with `-XX:-RenumberLiveNodes` as a workaround, the correct profile looks like this:
>
> ![Screenshot from 2023-03-01 13-20-09](https://user-images.githubusercontent.com/5312595/222146316-b036ca7d-8a92-42b7-9570-c29e3cfcc2f2.png)
>
> With the help of the IR framework, it's easy to create a simple regression test (see `testRenumberLiveNodes`).
>
> The fix is to create a new `node_note_array` and copy the debug information to the right index after updating node indices. We do the same in the matcher:
> https://github.com/openjdk/jdk/blob/c1e77e05647ca93bb4f39a320a5c7a632e283410/src/hotspot/share/opto/matcher.cpp#L337-L342
>
> Another problem is that `Parse::Parse` calls `C->set_default_node_notes(caller_nn)` before `do_exits`, which resets the `JVMState` to the caller state. We then set the bci to `InvocationEntryBci` in the **caller** `JVMState`. Any new node that is emitted in `do_exits`, for example a `MemBarRelease`, will have that `JVMState` attached and `NonSafepointEmitter::observe_instruction` -> `DebugInformationRecorder::describe_scope` will then use that information when emitting debug info. The resulting debug info is misleading because it suggests that we are at the beginning of the caller method. The tests `testFinalFieldInit` and `testSynchronized` reproduce that scenario.
>
> The fix is to move `set_default_node_notes` down to after `do_exits`.
>
> I find it also misleading that we often emit "synchronization entry" for `InvocationEntryBci` at method entry/exit in the debug info, although there is no synchronization happening. I filed [JDK-8303451](https://bugs.openjdk.org/browse/JDK-8303451) to fix that.
>
> Thanks,
> Tobias
Tobias Hartmann has updated the pull request incrementally with one additional commit since the last revision:
Removed default argument
-------------
Changes:
- all: https://git.openjdk.org/jdk/pull/12806/files
- new: https://git.openjdk.org/jdk/pull/12806/files/13281557..ec3ee517
Webrevs:
- full: https://webrevs.openjdk.org/?repo=jdk&pr=12806&range=01
- incr: https://webrevs.openjdk.org/?repo=jdk&pr=12806&range=00-01
Stats: 1 line in 1 file changed: 0 ins; 0 del; 1 mod
Patch: https://git.openjdk.org/jdk/pull/12806.diff
Fetch: git fetch https://git.openjdk.org/jdk pull/12806/head:pull/12806
PR: https://git.openjdk.org/jdk/pull/12806
More information about the hotspot-compiler-dev
mailing list