search

eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.28k stars 721 forks source link

java_util_logging_CheckZombieLockTest Unexpected lock files found #9186

Open pshipton opened 4 years ago

pshipton commented 4 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_x86-64_windows_Nightly/3 win2012r2-x86-2 java/util/logging/CheckZombieLockTest.java.CheckZombieLockTest (from java_util_logging_CheckZombieLockTest.java)

WARNING: unable to delete/cleanup writable test directory: C:\\temp\\writable-lockfile-dir\\log.log
WARNING: unable to delete/cleanup writable test directory: C:\\temp\\writable-lockfile-dir\\log.log.lck
WARNING: unable to delete/cleanup writable test directory: C:\\temp\\writable-lockfile-dir
WARNING: unable to delete/cleanup writable test directory: C:\\temp\\writable-lockfile-dir\\log.log
WARNING: unable to delete/cleanup writable test directory: C:\\temp\\writable-lockfile-dir\\log.log.lck
WARNING: unable to delete/cleanup writable test directory: C:\\temp\\writable-lockfile-dir
java.lang.RuntimeException: Unexpected lock files found: []
    C:\\temp\\writable-lockfile-dir\\log.log.lck should not have been reused
    at CheckZombieLockTest.testFileHandlerReuse(CheckZombieLockTest.java:257)
    at CheckZombieLockTest.runTests(CheckZombieLockTest.java:105)
    at CheckZombieLockTest.main(CheckZombieLockTest.java:78)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
    at java.base/java.lang.Thread.run(Thread.java:834)

JavaTest Message: Test threw exception: java.lang.RuntimeException: Unexpected lock files found: []
    C:\\temp\\writable-lockfile-dir\\log.log.lck should not have been reused
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Unexpected lock files found: [] C:\\temp\\writable-lockfile-dir\\log.log.lck should not have been reused
pshipton commented 4 years ago

3x grinder on the same machine https://ci.eclipse.org/openj9/job/Grinder/761/ - passed

lumpfish commented 4 years ago

Occurred on jdk-11.0.7+10 GA build: https://ci.adoptopenjdk.net/job/Test_openjdk11_j9_sanity.openjdk_x86-64_windows_xl/188/consoleFull

M-Davies commented 4 years ago

Occurred on a nightly build https://ci.adoptopenjdk.net/view/Test_openjdk/job/Test_openjdk11_j9_sanity.openjdk_x86-64_windows_xl/191/

Exclude PR https://github.com/AdoptOpenJDK/openjdk-tests/pull/1740

andrew-m-leonard commented 4 years ago

Re-occurred: https://ci.adoptopenjdk.net/job/Test_openjdk14_j9_sanity.openjdk_ppc64_aix/114/testReport/junit/java_util_logging_CheckZombieLockTest/java/CheckZombieLockTest/

JasonFengJ9 commented 4 years ago

Occurred in a JDK16 internal build Test_openjdknext_j9_sanity.openjdk_ppc64_aix_Nightly/232:

22:28:13  openjdk version "16-internal" 2021-03-16
22:28:13  OpenJDK Runtime Environment (build 16-internal+0-adhoc.jenkins.BuildJDKnextppc64aixNightly)
22:28:13  Eclipse OpenJ9 VM (build master-c2d4f396055, JRE 16 AIX ppc64-64-Bit Compressed References 20200922_334 (JIT enabled, AOT enabled)
22:28:13  OpenJ9   - c2d4f396055
22:28:13  OMR      - 4c2d9a1f1c2
22:28:13  JCL      - ed102a5ef9d based on jdk-16+16)

23:21:18  --------------------------------------------------
23:21:18  TEST: java/util/logging/CheckZombieLockTest.java
23:21:18  TEST JDK: /home/jenkins/workspace/Test_openjdknext_j9_sanity.openjdk_ppc64_aix_Nightly/openjdkbinary/j2sdk-image
23:21:18  

23:21:18  STDERR:
23:21:18  WARNING: unable to delete/cleanup writable test directory: /tmp/writable-lockfile-dir
23:21:18  java.lang.RuntimeException: Unexpected lock files found: []
23:21:18    /tmp/writable-lockfile-dir/log.log.lck should not have been reused
23:21:18    at CheckZombieLockTest.testFileHandlerReuse(CheckZombieLockTest.java:257)
23:21:18    at CheckZombieLockTest.runTests(CheckZombieLockTest.java:105)
23:21:18    at CheckZombieLockTest.main(CheckZombieLockTest.java:78)
23:21:18    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
23:21:18    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
23:21:18    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
23:21:18    at java.base/java.lang.reflect.Method.invoke(Method.java:564)
23:21:18    at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
23:21:18    at java.base/java.lang.Thread.run(Thread.java:845)
pshipton commented 4 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Release/11

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/186/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk15_j9_sanity.openjdk_ppc64_aix_Nightly/157

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_xl_Nightly/46

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_mixed_Nightly/3/

JasonFengJ9 commented 3 years ago

Also seen in an internal JDK11 AIX mixed build Test_openjdk11_j9_sanity.openjdk_ppc64_aix_mixed/1.

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_OpenJDK8/29

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_mixed_Nightly/8

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_mixed_Nightly/9

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk16_j9_sanity.openjdk_ppc64_aix_mixed_Nightly/6/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_mixed_Nightly/15/ https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_mixed_Nightly/21/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_mixed_Nightly/17/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk16_j9_sanity.openjdk_x86-64_windows_mixed_Nightly/14

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_Nightly/299/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_Nightly/300/ https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/285/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_Nightly/307/

tajila commented 3 years ago

Do we know if this has failed with -XX:-GlobalLockReservation ?

pshipton commented 3 years ago

@tajila -XX:-GlobalLockReservation is still the default until https://github.com/eclipse/openj9/issues/11424 is merged, so yes it has.

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_Nightly/308

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk16_j9_sanity.openjdk_x86-64_windows_Nightly/32 https://ci.eclipse.org/openj9/job/Test_openjdk16_j9_sanity.openjdk_ppc64_aix_Nightly/32

tajila commented 3 years ago

After taking a closer look at the issue, I believe it has nothing to do with globalLockReservation. Given the intermittent nature of the failure, it may be a file system issue.

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/293/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk16_j9_sanity.openjdk_x86-64_windows_Nightly/35/

pshipton commented 3 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix_Nightly/318/

lumpfish commented 3 years ago

https://ci.adoptopenjdk.net/job/Test_openjdk8_j9_sanity.openjdk_ppc64_aix/373/consoleFull

pshipton commented 3 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk16_j9_sanity.openjdk_ppc64_aix_Nightly/29/

pshipton commented 3 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk16_j9_sanity.openjdk_ppc64_aix_Nightly/44/

pshipton commented 3 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/48

JasonFengJ9 commented 3 years ago

JDK11 (0.27 release) jdk_util_1_FAILED at https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Release/5/consoleFull

17:52:23  --------------------------------------------------
17:52:23  TEST: java/util/logging/CheckZombieLockTest.java
17:52:23  STDERR:
17:52:23  WARNING: unable to delete/cleanup writable test directory: /tmp/writable-lockfile-dir
17:52:23  java.lang.RuntimeException: Unexpected lock files found: []
17:52:23    /tmp/writable-lockfile-dir/log.log.lck should not have been reused
17:52:23    at CheckZombieLockTest.testFileHandlerReuse(CheckZombieLockTest.java:257)
17:52:23    at CheckZombieLockTest.runTests(CheckZombieLockTest.java:105)
17:52:23    at CheckZombieLockTest.main(CheckZombieLockTest.java:78)
17:52:23    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
17:52:23    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
17:52:23    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
17:52:23    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
17:52:23    at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
17:52:23    at java.base/java.lang.Thread.run(Thread.java:866)
17:52:23  
17:52:23  JavaTest Message: Test threw exception: java.lang.RuntimeException: Unexpected lock files found: []
17:52:23    /tmp/writable-lockfile-dir/log.log.lck should not have been reused
17:52:23  JavaTest Message: shutting down test
pshipton commented 3 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/90/

pshipton commented 3 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/109

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_OpenJDK17/10 jdk_util_0 -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops java/util/logging/CheckZombieLockTest.java

12:48:34  java.lang.RuntimeException: Unexpected lock files found: []
12:48:34    C:\temp\writable-lockfile-dir\log.log.lck should not have been reused
12:48:34    at CheckZombieLockTest.testFileHandlerReuse(CheckZombieLockTest.java:257)
12:48:34    at CheckZombieLockTest.runTests(CheckZombieLockTest.java:105)
12:48:34    at CheckZombieLockTest.main(CheckZombieLockTest.java:78)
pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64_aix_Nightly/55

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_Nightly/68 jdk_util_0 java/util/logging/CheckZombieLockTest.java

22:28:45  ACTION: main -- Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Unexpected lock files found: [] C:\temp\writable-lockfile-dir\log.log.lck should not have been reused
22:28:45  REASON: User specified action: run main/othervm CheckZombieLockTest REUSE 
22:28:45  TIME:   0.61 seconds
22:28:45  messages:
22:28:45  command: main CheckZombieLockTest REUSE
22:28:45  reason: User specified action: run main/othervm CheckZombieLockTest REUSE 
22:28:45  Mode: othervm [/othervm specified]
22:28:45  Additional options from @modules: --add-modules java.logging
22:28:45  elapsed time (seconds): 0.61
22:28:45  configuration:
22:28:45  Boot Layer
22:28:45    add modules: java.logging
22:28:45  
22:28:45  STDOUT:
22:28:45  Writable dir is: C:\temp\writable-lockfile-dir
22:28:45  before: 0 locks found
22:28:45  handler created: java.util.logging.FileHandler@cb28c645
22:28:45  Found file: log.log
22:28:45  Found file: log.log.lck
22:28:45  after creating handler: 1 locks found
22:28:45  Found file: log.log
22:28:45  after closing handler: 0 locks found
22:28:45  Found file: log.log
22:28:45  Found file: log.log.lck
22:28:45  before: 1 locks found
22:28:45  handler created: java.util.logging.FileHandler@c0252d4a
22:28:45  Found file: log.log
22:28:45  Found file: log.log.lck
22:28:45  after creating handler: 1 locks found
22:28:45  handler closed: java.util.logging.FileHandler@c0252d4a
22:28:45  Found file: log.log
22:28:45  after closing handler: 0 locks found
22:28:45  locked: C:\temp\writable-lockfile-dir\log.log.lck
22:28:45  handler created: java.util.logging.FileHandler@f2c74daa
22:28:45  Found file: log.log
22:28:45  Found file: log.log.lck
22:28:45  after creating handler: 1 locks found
22:28:45  end: 1 locks found
22:28:45  STDERR:
22:28:45  WARNING: unable to delete/cleanup writable test directory: C:\temp\writable-lockfile-dir\log.log
22:28:45  WARNING: unable to delete/cleanup writable test directory: C:\temp\writable-lockfile-dir\log.log.lck
22:28:45  WARNING: unable to delete/cleanup writable test directory: C:\temp\writable-lockfile-dir
22:28:45  WARNING: unable to delete/cleanup writable test directory: C:\temp\writable-lockfile-dir\log.log
22:28:45  WARNING: unable to delete/cleanup writable test directory: C:\temp\writable-lockfile-dir\log.log.lck
22:28:45  WARNING: unable to delete/cleanup writable test directory: C:\temp\writable-lockfile-dir
22:28:45  java.lang.RuntimeException: Unexpected lock files found: []
22:28:45    C:\temp\writable-lockfile-dir\log.log.lck should not have been reused
22:28:45    at CheckZombieLockTest.testFileHandlerReuse(CheckZombieLockTest.java:257)
22:28:45    at CheckZombieLockTest.runTests(CheckZombieLockTest.java:105)
22:28:45    at CheckZombieLockTest.main(CheckZombieLockTest.java:78)
tajila commented 2 years ago

@mikezhang1234567890 Can you please take a look at this

mikezhang1234567890 commented 2 years ago

Looking into it.

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64_aix_Nightly/82

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/147

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_Nightly/94

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64_aix_Nightly/99/

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64_aix_Nightly/102/

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/169/

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64_aix_Nightly/153/

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_Nightly/164

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64_aix_Nightly/217/