Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Test_openjdk8_j9_extended.functional_s390x_linux testDDRExt_JITExt_openj9_0 CorruptDataException thrown walking stack #5449

Closed
pshipton opened this issue Apr 11, 2019 · 15 comments · Fixed by #5996
Closed

Test_openjdk8_j9_extended.functional_s390x_linux testDDRExt_JITExt_openj9_0 CorruptDataException thrown walking stack #5449

pshipton opened this issue Apr 11, 2019 · 15 comments · Fixed by #5996
Labels
test failure

Comments

@pshipton
Copy link
Member

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/1

     [java] [SetupConfig] [INFO] Created new DDR Interactive instance using core file : /home/jenkins/jenkins-agent/workspace/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/openjdk-tests/TestConfig/scripts/testKitGen/../../../TestConfig/test_output_1554951932431/testDDRExt_JITExt_openj9_0/DDREXT.J9CORE.DMP
     [java] [AutoRun] [INFO] Running 1 tests for /home/jenkins/jenkins-agent/workspace/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/openjdk-tests/TestConfig/scripts/testKitGen/../../../TestConfig/test_output_1554951932431/testDDRExt_JITExt_openj9_0/DDREXT.J9CORE.DMP
     [java] [AutoRun] [INFO] Starting testJITStack(j9vm.test.ddrext.junit.TestJITExt)
     [java] Apr 11, 2019 12:01:39 AM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
     [java] WARNING: CorruptDataException thrown walking stack. walkThread = 0x0000000000014F00
     [java] com.ibm.j9ddr.corereaders.memory.MemoryFault: Memory Fault reading 0x9966996E 
     [java] 	at com.ibm.j9ddr.corereaders.memory.AbstractMemory.getBytesAt(AbstractMemory.java:185)
     [java] 	at com.ibm.j9ddr.corereaders.memory.AbstractMemory.getBytesAt(AbstractMemory.java:177)
     [java] 	at com.ibm.j9ddr.corereaders.memory.AbstractMemory.getLongAt(AbstractMemory.java:242)
     [java] 	at com.ibm.j9ddr.corereaders.memory.ProcessAddressSpace.getPointerAt(ProcessAddressSpace.java:75)
     [java] 	at com.ibm.j9ddr.vm29.pointer.AbstractPointer.getPointerAtOffset(AbstractPointer.java:385)
     [java] 	at com.ibm.j9ddr.vm29.pointer.generated.J9ClassPointer.romClass(J9ClassPointer.java:681)
     [java] 	at com.ibm.j9ddr.vm29.j9.ROMHelp$ROMHelp_29_V0.getOriginalROMMethod(ROMHelp.java:250)
     [java] 	at com.ibm.j9ddr.vm29.j9.ROMHelp.getOriginalROMMethod(ROMHelp.java:139)
     [java] 	at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkBytecodeFrame(StackWalker.java:969)
     [java] 	at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:449)
     [java] 	at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
     [java] 	at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.JitstackCommand.run(JitstackCommand.java:118)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:182)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:390)
     [java] 	at j9vm.test.ddrext.DDRExtTesterBase.exec(DDRExtTesterBase.java:101)
     [java] 	at j9vm.test.ddrext.junit.TestJITExt.testJITStack(TestJITExt.java:90)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
     [java] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
     [java] 	at java.lang.reflect.Method.invoke(Method.java:498)
     [java] 	at junit.framework.TestCase.runTest(TestCase.java:168)
     [java] 	at junit.framework.TestCase.runBare(TestCase.java:134)
     [java] 	at junit.framework.TestResult$1.protect(TestResult.java:110)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.framework.TestResult.run(TestResult.java:113)
     [java] 	at junit.framework.TestCase.run(TestCase.java:124)
     [java] 	at junit.framework.TestSuite.runTest(TestSuite.java:243)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:74)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:69)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:55)
     [java] 	at j9vm.test.ddrext.AutoRun.runTest(AutoRun.java:275)
     [java] 	at j9vm.test.ddrext.AutoRun.main(AutoRun.java:110)
     [java] 
     [java] [DDRExtTesterBase] [INFO] Validation started for : '!jitmetadatafrompc  0x000003FF71FBFC98'
     [java] [AutoRun] [INFO] Finished testJITStack(j9vm.test.ddrext.junit.TestJITExt)
     [java] 
     [java] [AutoRun] [INFO] ================Test Result for /home/jenkins/jenkins-agent/workspace/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/openjdk-tests/TestConfig/scripts/testKitGen/../../../TestConfig/test_output_1554951932431/testDDRExt_JITExt_openj9_0/DDREXT.J9CORE.DMP==================
     [java] [AutoRun] [INFO] Errors:   0 out of 1 test cases.
     [java] [AutoRun] [INFO] Failures: 1 out of 1 test cases.
     [java] [AutoRun] [INFO] Total Error/Failures: 1
     [java] Apr 11, 2019 12:01:39 AM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
     [java] WARNING: CorruptDataException thrown walking stack. walkThread = 0x0000000000014F00
     [java] com.ibm.j9ddr.corereaders.memory.MemoryFault: Memory Fault reading 0x9966996E 
     [java] 	at com.ibm.j9ddr.corereaders.memory.AbstractMemory.getBytesAt(AbstractMemory.java:185)
     [java] 	at com.ibm.j9ddr.corereaders.memory.AbstractMemory.getBytesAt(AbstractMemory.java:177)
     [java] 	at com.ibm.j9ddr.corereaders.memory.AbstractMemory.getLongAt(AbstractMemory.java:242)
     [java] 	at com.ibm.j9ddr.corereaders.memory.ProcessAddressSpace.getPointerAt(ProcessAddressSpace.java:75)
     [java] 	at com.ibm.j9ddr.vm29.pointer.AbstractPointer.getPointerAtOffset(AbstractPointer.java:385)
     [java] 	at com.ibm.j9ddr.vm29.pointer.generated.J9ClassPointer.romClass(J9ClassPointer.java:681)
     [java] 	at com.ibm.j9ddr.vm29.j9.ROMHelp$ROMHelp_29_V0.getOriginalROMMethod(ROMHelp.java:250)
     [java] 	at com.ibm.j9ddr.vm29.j9.ROMHelp.getOriginalROMMethod(ROMHelp.java:139)
     [java] 	at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkBytecodeFrame(StackWalker.java:969)
     [java] 	at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:449)
     [java] 	at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
     [java] 	at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.JitstackCommand.run(JitstackCommand.java:118)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:182)
     [java] 	at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:390)
     [java] 	at j9vm.test.ddrext.DDRExtTesterBase.exec(DDRExtTesterBase.java:101)
     [java] 	at j9vm.test.ddrext.junit.TestJITExt.testJITStack(TestJITExt.java:92)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
     [java] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
     [java] 	at java.lang.reflect.Method.invoke(Method.java:498)
     [java] 	at junit.framework.TestCase.runTest(TestCase.java:168)
     [java] 	at junit.framework.TestCase.runBare(TestCase.java:134)
     [java] 	at junit.framework.TestResult$1.protect(TestResult.java:110)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.framework.TestResult.run(TestResult.java:113)
     [java] 	at junit.framework.TestCase.run(TestCase.java:124)
     [java] 	at junit.framework.TestSuite.runTest(TestSuite.java:243)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:74)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:69)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:55)
     [java] 	at j9vm.test.ddrext.AutoRun.runTest(AutoRun.java:275)
     [java] 	at j9vm.test.ddrext.AutoRun.main(AutoRun.java:110)
     [java] 
     [java] [DDRExtTesterBase] [ERROR] '!jitmetadatafrompc  0x000003FF71FBFC98' output contains failure key : STACK_CORRUPT
     [java] [DDRExtTesterBase] [ERROR] '!jitmetadatafrompc  0x000003FF71FBFC98' output :
     [java] <14f00> *** BEGIN STACK WALK, flags = 01000001 walkThread = 0x0000000000014F00 ***
     [java] <14f00> 	START_AT_JIT_FRAME
     [java] <14f00> 	RECORD_BYTECODE_PC_OFFSET
     [java] <14f00> Initial values: walkSP = 0x00000000000D2CE8, PC = 0x000003FF71FBFC98, literals = 0x0000000000000000, A0 = 0x0000000000000000, j2iFrame = 0x00000000000D2CD0, ELS = 0x000003FF8937E918, decomp = 0x0000000000000000
     [java] <14f00> JIT frame: bp = 0x00000000000D2D28, pc = 0x000003FF71FBFC98, unwindSP = 0x00000000000D2CE8, cp = 0x0000000000144690, arg0EA = 0x00000000000D2D30, jitInfo = 0x000003FF537FF878
     [java] <14f00> 	Method: j9vm/test/corehelper/CoreGen.main([Ljava/lang/String;)V !j9method 0x0000000000144728
     [java] <14f00> I2J values: PC = 0x000003FF3951B019, A0 = 0x00000000000D2AA0, walkSP = 0x00000000000D2A78, literals = 0x00000000000F1210, JIT PC = 0x000003FF83ABFE90, pcAddress = 0x000003FF8937E940, decomp = 0x0000000000000000
     [java] <14f00> Bytecode frame: bp = 0x00000000000D2A88, sp = 0x00000000000D2A78, pc = 0x000003FF3951B019, cp = 0x00000000000F0690, arg0EA = 0x00000000000D2AA0, flags = 0x0000000000000000
     [java] <14f00> 	Method: java/security/AccessControlContext.<init>([Ljava/security/ProtectionDomain;I)V !j9method 0x00000000000F1210
     [java] <14f00> Bytecode frame: bp = 0x00000000000D2AC0, sp = 0x00000000000D2AA8, pc = 0x000003FF3949E62D, cp = 0x00000000000907A0, arg0EA = 0x00000000000D2B20, flags = 0x0000000000000000
     [java] <14f00> 	Method: java/security/AccessController.getContextHelper(Z)Ljava/security/AccessControlContext; !j9method 0x0000000000091090
     [java] <14f00> Bytecode frame: bp = 0x00000000000D2B38, sp = 0x00000000000D2B28, pc = 0x000003FF3949E5A5, cp = 0x00000000000907A0, arg0EA = 0x00000000000D2B38, flags = 0x0000000000000000
     [java] <14f00> 	Method: java/security/AccessController.getContext()Ljava/security/AccessControlContext; !j9method 0x0000000000091070
     [java] Stack walk result: STACK_CORRUPT
     [java] 
     [java] junit.framework.AssertionFailedError
     [java] 	at junit.framework.Assert.fail(Assert.java:48)
     [java] 	at junit.framework.Assert.assertTrue(Assert.java:20)
     [java] 	at junit.framework.Assert.assertTrue(Assert.java:27)
     [java] 	at j9vm.test.ddrext.junit.TestJITExt.testJITStack(TestJITExt.java:96)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
     [java] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
     [java] 	at java.lang.reflect.Method.invoke(Method.java:498)
     [java] 	at junit.framework.TestCase.runTest(TestCase.java:168)
     [java] 	at junit.framework.TestCase.runBare(TestCase.java:134)
     [java] 	at junit.framework.TestResult$1.protect(TestResult.java:110)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.framework.TestResult.run(TestResult.java:113)
     [java] 	at junit.framework.TestCase.run(TestCase.java:124)
     [java] 	at junit.framework.TestSuite.runTest(TestSuite.java:243)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:74)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:69)
     [java] 	at j9vm.test.ddrext.junit.DDRTestSuite.run(DDRTestSuite.java:55)
     [java] 	at j9vm.test.ddrext.AutoRun.runTest(AutoRun.java:275)
     [java] 	at j9vm.test.ddrext.AutoRun.main(AutoRun.java:110)
     [java] [AutoRun] [ERROR] testJITStack(j9vm.test.ddrext.junit.TestJITExt)
@pshipton
Copy link
Member Author

@DanHeidinga

@DanHeidinga
Copy link
Member 

Memory Fault reading 0x9966996E

That looks like a J9Class->eyecatcher being used as an index 0x9966996E = 0x99669966 + 0x8

@DanHeidinga
Copy link
Member

@theresa-m Can you take a look at this?

@pshipton pshipton mentioned this issue Apr 13, 2019
Closed
@theresa-m
Copy link
Contributor

theresa-m commented Apr 15, 2019 •
edited
Loading

On further inspection of a core dump !stackslots works properly but !jitstackslots for the same thread throws this CorruptDataException. The failure is intermittent.

These tests were enabled and run for the first time in OpenJ9 only recently #5137 so there aren't any obvious changes to the stackwalker that I can find that might have caused this. @pshipton should these tests be excluded until this is resolved?

@pshipton
Copy link
Member Author

It's only failed once so far, I think we should keep the test running unless the failure starts to occur more often.

@pshipton
Copy link
Member Author

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/7

@pshipton
Copy link
Member Author

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/10

@pshipton
Copy link
Member Author

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/13

This failure continues to occur, but I'm not going to keep reporting them.

@theresa-m
Copy link
Contributor

So far I've seen that a failing !jistacktrace run prints out the complete same trace as a passing run, however instead of terminating as it should in StackWalker:404 , an incorrect run does not have its pc set to zero where it should and as a result walkBytecodeFrame (line 449) is called one more iteration than it should be.

At the point of the extra iteration walkState.pc is pointing to a method: java/lang/Thread.getThreadGroup()Ljava/lang/ThreadGroup. I'm not too sure where this is coming from since I haven't seen it in any other stack trace or the test code. walkState.method is not referencing a valid method or class (hence the error).

I'm not too familiar with how the stack walks over jit frames, so I'm not sure where I should look next. Any suggestions?

@DanHeidinga
Copy link
Member

I'm not too familiar with how the stack walks over jit frames, so I'm not sure where I should look next. Any suggestions?

Connect with @gacholio to get details on how to walk jit stackframes

@gacholio
Copy link
Contributor

I have a suspicion that this is just a poorly-written test - it's looking for a random JIT frame and then trying to start a walk there, but it has ignored the ELS, which is one of the roots.

@gacholio gacholio mentioned this issue May 31, 2019
Open
@gacholio
Copy link
Contributor

Rather than fixing the test, it might be better to test something more deterministic. Can you update the core generator to fork a thread specifically for this test? Basically, we want to ensure a JIT frame at the top of stack so the exiting test will work (once it's changed to target this specific thread rather than searching).

@gacholio
Copy link
Contributor

To ensure a compiled method, use Compiler.compileClass. I would suggest a thread which ends with a jitted method that calls wait().

@gacholio
Copy link
Contributor

Also, once the test is targetting the known thread, it should succeed if a jitted method is not found (the test was run in a mode which prevented jitting for whatever reason).

@LongyuZhang LongyuZhang mentioned this issue Jun 2, 2019
Merged
@pshipton
Copy link
Member Author

pshipton commented Jun 3, 2019

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_extended.functional_s390x_linux_Nightly/52

@theresa-m theresa-m mentioned this issue Jun 3, 2019
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
test failure
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Modify TestJITExt to be more deterministic theresa-m/openj9
4 participants
@DanHeidinga @theresa-m @gacholio @pshipton