RFR: 8267926: AsyncLogGtest.java fails on assert with: decorator was not part of the decorator set specified at creation. [v3]

[David Holmes]

Hi Xin,

On 1/06/2021 3:48 pm, Liu Xin wrote:
> hi, David,
> 
> This is awkward. I think I changed too many in a patch.
> 
> Do you think it is a good idea that I revert to 
> https://openjdk.github.io/cr/?repo=jdk&pr=4257&range=00 
> <https://openjdk.github.io/cr/?repo=jdk&pr=4257&range=00>
> It is a trivial bugfix.  Does it solve tier1~4 on aarch64?

I didn't test just that patch, but will try to do so.

It might be best to revert to the simple workaround for now to fix the 
test - otherwise I need to get the test problem-listed.

> If it does, we can know that this new crash is caused by the change in 
> my new patch.
> I would recall it and rework it on aarch64.
> 
> It seems that it crashed while executing gtest in async mode.   Could 
> you tell me which gtest it was executing?
> "Command Line: -XX:+ExecutingUnitTests -Xlog:async"

[ RUN      ] LogConfigurationTest.parse_log_arguments_vm
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x0000ffff40820720, pid=3972473, tid=3972481

HTH,
David

> thanks,
> --lx
> 
> 
> On Mon, May 31, 2021 at 10:13 PM David Holmes <dholmes at openjdk.java.net 
> <mailto:dholmes at openjdk.java.net>> wrote:
> 
>     On Mon, 31 May 2021 17:09:48 GMT, Xin Liu <xliu at openjdk.org
>     <mailto:xliu at openjdk.org>> wrote:
> 
>      >> The root cause of the intermittent failure is that _decorators
>     in LogDecorations
>      >> may be inconsistent with LogOutput::_decorators. It could happen
>     when gtest disables a
>      >> Log output via set_log_config(TestLogFileName, "all=off").
>      >>
>      >> Since we copy the entire logDecorations, it's reasonable to copy
>     _decorator as well.
>      >> LogDecorator is a bitmask of uint. It's even smaller than a
>     reference on LP64 platforms.
>      >>
>      >> This patch not only fixes intermittent crash in JDK-8267926, but
>     also fixes JDK-8267952.
>      >> Two hazards of async logging in
>     `LogConfiguration::configure_output` are eliminated.
>      >> This patch also adds a storestore barrier to make sure it's safe
>     on weak consistency machines.
>      >
>      > Xin Liu has updated the pull request incrementally with one
>     additional commit since the last revision:
>      >
>      >   Increase reader's counter before creating LogDecoration.
> 
>     I put the latest patch through our tier 1-4 testing and it crashed
>     in tier 3 on Linux-Aarch64:
> 
>     #
>     # A fatal error has been detected by the Java Runtime Environment:
>     #
>     #  SIGSEGV (0xb) at pc=0x0000ffff40820720, pid=3972473, tid=3972481
>     #
>     # JRE version: Java(TM) SE Runtime Environment (17.0) (fastdebug
>     build 17-internal+0-LTS-2021-05-31-2211099.david.holmes.jdk-dev4.git)
>     # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug
>     17-internal+0-LTS-2021-05-31-2211099.david.holmes.jdk-dev4.git,
>     mixed mode, tiered, compressed oops, compressed class ptrs, g1 gc,
>     linux-aarch64)
>     # Problematic frame:
>     # C  [libc.so.6+0x60720]  flockfile+0x0
>     #
>     # Core dump will be written. Default location: Core dumps may be
>     processed with "/opt/core.sh %p" (or dumping to
>     /opt/mach5/mesos/work_dir/slaves/a4f8fba9-f017-4328-b286-c66b6a97143d-S808/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/42993029-a18a-48c4-9a4d-108aee7b3811/runs/a38508fe-5d43-48ad-b70a-61f3e712fcd8/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_misc/scratch/0/core.3972473)
>     #
>     # If you would like to submit a bug report, please visit:
>     # https://bugreport.java.com/bugreport/crash.jsp
>     <https://bugreport.java.com/bugreport/crash.jsp>
>     #
> 
>     ---------------  S U M M A R Y ------------
> 
>     Command Line: -XX:+ExecutingUnitTests -Xlog:async
> 
>     Host: AArch64, 6 cores, 46G, Oracle Linux Server release 8.3
>     Time: Mon May 31 22:37:04 2021 UTC elapsed time: 3.758723 seconds
>     (0d 0h 0m 3s)
> 
>     ---------------  T H R E A D  ---------------
> 
>     Current thread (0x0000aaadf32b1e10):  Thread "AsyncLog Thread"
>     [stack: 0x0000fffefdaa0000,0x0000fffefdca0000] [id=3972481]
> 
>     Stack: [0x0000fffefdaa0000,0x0000fffefdca0000], 
>     sp=0x0000fffefdc9e510,  free space=2041k
>     Native frames: (J=compiled Java code, j=interpreted, Vv=VM code,
>     C=native code)
>     C  [libc.so.6+0x60720]  flockfile+0x0
>     V  [libjvm.so+0x1508058] 
>     LogFileOutput::write_blocking(LogDecorations const&, char const*)+0x38
>     V  [libjvm.so+0x1502764]  AsyncLogWriter::run()+0x2c0
>     V  [libjvm.so+0x1a49d08]  Thread::call_run()+0xf8
>     V  [libjvm.so+0x1766f18]  thread_native_entry(Thread*)+0x108
>     C  [libpthread.so.0+0x76e0]  start_thread+0x198
> 
>     -------------
> 
>     PR: https://git.openjdk.java.net/jdk/pull/4257
>     <https://git.openjdk.java.net/jdk/pull/4257>
>