RFR: 8284115: [IR Framework] Compilation is not found due to rare safepoint while dumping PrintIdeal/PrintOptoAssembly

[Christian Hagedorn]

On Fri, 13 May 2022 07:45:18 GMT, Christian Hagedorn <chagedorn at openjdk.org> wrote:

> This is yet another manifestation of the safepointing problem while printing a `PrintIdeal/PrintOptoAssembly` block.
> 
> In this case here, a safepoint is done and the `` message is emitted while dumping a `PrintIdeal` block of `retainDenominator()` inside the `hotspot_pid` file. During this interruption, another test class method is enqueued for compilation which is logged to the `hotspot_pid` file before the printing of the `PrintIdeal` block resumes:
> 
> 
> # PrintIdeal output of retainDenominator()
>  3 Start === 3 0 [[ 3 5 6 7 8 9 13 11 ]] #{0:control, 1:abIO, 2:memory, 3:rawptr:BotPTR, 4:return_address, 5:compiler/c2/irTests/DivLNodeIdealizationTests:NotNull *, 6:long, 7:half, 8:long, 9:half}
>  36 CallStaticJava === 34 6 7 8 9 ( 35 1 1 1 1 1 26 1 27 1 ) [[ 37 ]] # Static uncommon_trap(reason='div0_check' action='maybe_recompile' debug_id='0') void ( int ) C=0.000100 DivLNodeIdealizationTests::retainDenominator @ bci:4 (line 130) !jvms: DivLNodeIdealizationTests::retainDenominator
> 
> # Safepoint interruption
> <writer thread='40451'/>
> 
> # Enqueuing of another test class method identityThird()
> <task_queued compile_id='205' method='compiler.c2.irTests.DivLNodeIdealizationTests identityThird (JJ)J' bytes='6' count='6000' iicount='6000' blocking='1' stamp='1.046' comment='whitebox' hot_count='6000'/>
> <writer thread='23811'/>
>  @ bci:4 (line 130)
> 
> # Continue to dump PrintIdeal of retainDenominator()
>  41 DivL === 33 26 13 [[ 42 ]] !jvms: DivLNodeIdealizationTests::retainDenominator @ bci:4 (line 130)
>  9 Parm === 3 [[ 42 36 ]] ReturnAdr !jvms: DivLNodeIdealizationTests::retainDenominator @ bci:-1 (line 130)
> 
> 
> The `HotSpotPidFileParser` looks for these enqueue messages containing the method name in order to find and correctly map the corresponding `PrintIdeal` and `PrintOptoAssembly` outputs. However, the `HotSpotPidFileParser` does not expect such an enqueuing message to be found inside a `PrintIdeal/PrintOptoAssembly` block and thus ignores it. As a result, we later do not parse the `PrintIdeal` and `PrintOptoAssembly` output of the enqueued method during the safepoint and fail with the assertion that we did not find any compilation output for the method.
> 
> In the example above, the assertion says that we did not find the compilation output of `identityThird()` whose enqueue message was ignored inside the `PrintIdeal` block of `retainDominator()`.
> 
> The proposed fix is to make `HotSpotPidFileParser` aware of the possibility of a safepoint while reading the `PrintIdeal` or `PrintOptoAssembly` output and therefore add a check if there was a method enqueued for compilation while reading inside `BlockOutputReader::readBlock()`.
> 
> Thanks,
> Christian

Thanks for your review Vladimir!

> I am concern that PrintIdeal output is interrupted by output from other threads. It may cause other issues in future again. Can we redirect `PrintIdeal` output into a separate file or reorder output like `LogCompilation` since it is used for IR testing now (automatic tool)? Originally it was not matter since such output was not used in any tool.

Can you elaborate more on what you mean by reordering the `LogCompilation` output? 

I agree that we could make this safer by dumping `PrintIdeal` and `PrintOptoAssembly` to a separate file. However, this would require a change to the VM to generate the new file which probably also needs to be documented and might be a security concern? With this new file, I think we should also add a new flag to enable/disable such a redirection because it will only be used by the IR framework. Since this kind of bug is quite rare and only concerns the IR framework, I'm not sure if it would be justified to make such a change to the VM. The current fix seems to be less invasive and hopefully now completes the entire handling of safepoints while printing. What do you think?

-------------

PR: https://git.openjdk.java.net/jdk/pull/8692