bug #7938
Updated by Andreas Kohlbecker over 5 years ago
This performance problem was observed at the edit production server but might also affect other installations. Users where complaining about the server being very slow since a couple of days. The reason for the server being "slow" is that two sub processes are consuming 100% CPU time of one cpu core each. This time excessive garbage collection could be excluded as cause. ![](Screenshot_20181205_112519.png) ![](Screenshot_20181205_112425.png) The cpu load is produced by the to subprocesses with the PIDs **9527** and **9528** (main process id is 9505) A stake trace with native frames (`/opt/java-oracle/jdk1.8.0_91/bin/jstack -m -F 9505`) included give first insight into what these processes are doing (attachment:jstack-with-native-frames.tdump): ~~~ ----------------- 9527 ----------------- 0x00007fe4a30c8f10 _ZNK7MemNode20can_see_stored_valueEP4NodeP14PhaseTransform + 0x2c0 0x00007fe4a30c9c74 _ZNK8LoadNode5ValueEP14PhaseTransform + 0xf4 0x00007fe4a31ac87a _ZN12PhaseIterGVN13transform_oldEP4Node + 0xea 0x00007fe4a31a9fcc _ZN12PhaseIterGVN8optimizeEv + 0x1bc 0x00007fe4a2ce51a9 _ZN7Compile8OptimizeEv + 0x159 0x00007fe4a2ce6fea _ZN7CompileC1EP5ciEnvP10C2CompilerP8ciMethodibbb + 0x13ca 0x00007fe4a2c34818 _ZN10C2Compiler14compile_methodEP5ciEnvP8ciMethodi + 0x198 0x00007fe4a2cf14da _ZN13CompileBroker25invoke_compiler_on_methodEP11CompileTask + 0xc9a 0x00007fe4a2cf2486 _ZN13CompileBroker20compiler_thread_loopEv + 0x5d6 0x00007fe4a32ae77f _ZN10JavaThread17thread_main_innerEv + 0xdf 0x00007fe4a32ae8ac _ZN10JavaThread3runEv + 0x11c 0x00007fe4a3161f78 _ZL10java_startP6Thread + 0x108 ----------------- 9528 ----------------- 0x00007fe4a30c8ed6 _ZNK7MemNode20can_see_stored_valueEP4NodeP14PhaseTransform + 0x286 0x00007fe4a30c9c74 _ZNK8LoadNode5ValueEP14PhaseTransform + 0xf4 0x00007fe4a31ac87a _ZN12PhaseIterGVN13transform_oldEP4Node + 0xea 0x00007fe4a31a9fcc _ZN12PhaseIterGVN8optimizeEv + 0x1bc 0x00007fe4a2ce51a9 _ZN7Compile8OptimizeEv + 0x159 0x00007fe4a2ce6fea _ZN7CompileC1EP5ciEnvP10C2CompilerP8ciMethodibbb + 0x13ca 0x00007fe4a2c34818 _ZN10C2Compiler14compile_methodEP5ciEnvP8ciMethodi + 0x198 0x00007fe4a2cf14da _ZN13CompileBroker25invoke_compiler_on_methodEP11CompileTask + 0xc9a 0x00007fe4a2cf2486 _ZN13CompileBroker20compiler_thread_loopEv + 0x5d6 0x00007fe4a32ae77f _ZN10JavaThread17thread_main_innerEv + 0xdf 0x00007fe4a32ae8ac _ZN10JavaThread3runEv + 0x11c 0x00007fe4a3161f78 _ZL10java_startP6Thread + 0x108 ~~~ about 30 minutes later (attachment:jstack-verbose-with-native-frames-2.tdump) these native threads are still at the same point in the stack and seem to be stock in the ['MemNode::can_see_stored_value'](https://hg.openjdk.java.net/jdk8/jdk8/hotspot/log/87ee5ee27509/src/share/vm/opto/memnode.cpp#l978)` ['MemNode::can_see_stored_value'](https://hg.openjdk.java.net/jdk8/jdk8/hotspot/file/3aa636f2a743/src/share/vm/opto/memnode.cpp#l965)` c++ function: ~~~ ----------------- 9527 ----------------- 0x00007fe4a30c8f10 _ZNK7MemNode20can_see_stored_valueEP4NodeP14PhaseTransform + 0x2c0 0x00007fe4a30c9c74 _ZNK8LoadNode5ValueEP14PhaseTransform + 0xf4 0x00007fe4a31ac87a _ZN12PhaseIterGVN13transform_oldEP4Node + 0xea 0x00007fe4a31a9fcc _ZN12PhaseIterGVN8optimizeEv + 0x1bc 0x00007fe4a2ce51a9 _ZN7Compile8OptimizeEv + 0x159 0x00007fe4a2ce6fea _ZN7CompileC1EP5ciEnvP10C2CompilerP8ciMethodibbb + 0x13ca 0x00007fe4a2c34818 _ZN10C2Compiler14compile_methodEP5ciEnvP8ciMethodi + 0x198 0x00007fe4a2cf14da _ZN13CompileBroker25invoke_compiler_on_methodEP11CompileTask + 0xc9a 0x00007fe4a2cf2486 _ZN13CompileBroker20compiler_thread_loopEv + 0x5d6 0x00007fe4a32ae77f _ZN10JavaThread17thread_main_innerEv + 0xdf 0x00007fe4a32ae8ac _ZN10JavaThread3runEv + 0x11c 0x00007fe4a3161f78 _ZL10java_startP6Thread + 0x108 ----------------- 9528 ----------------- 0x00007fe4a30c8eaa _ZNK7MemNode20can_see_stored_valueEP4NodeP14PhaseTransform + 0x25a 0x00007fe4a30c9c74 _ZNK8LoadNode5ValueEP14PhaseTransform + 0xf4 0x00007fe4a31ac87a _ZN12PhaseIterGVN13transform_oldEP4Node + 0xea 0x00007fe4a31a9fcc _ZN12PhaseIterGVN8optimizeEv + 0x1bc 0x00007fe4a2ce51a9 _ZN7Compile8OptimizeEv + 0x159 0x00007fe4a2ce6fea _ZN7CompileC1EP5ciEnvP10C2CompilerP8ciMethodibbb + 0x13ca 0x00007fe4a2c34818 _ZN10C2Compiler14compile_methodEP5ciEnvP8ciMethodi + 0x198 0x00007fe4a2cf14da _ZN13CompileBroker25invoke_compiler_on_methodEP11CompileTask + 0xc9a 0x00007fe4a2cf2486 _ZN13CompileBroker20compiler_thread_loopEv + 0x5d6 0x00007fe4a32ae77f _ZN10JavaThread17thread_main_innerEv + 0xdf 0x00007fe4a32ae8ac _ZN10JavaThread3runEv + 0x11c 0x00007fe4a3161f78 _ZL10java_startP6Thread + 0x108 ~~~ These processes seem to be stuck in a loop while attempting to find a value in memory. May be interesting in in this context is that the `jstack` command threw some UnmappedAddressException: ~~~ sun.jvm.hotspot.debugger.UnmappedAddressException: ddf4471a42deeae8 at sun.jvm.hotspot.debugger.PageCache.checkPage(PageCache.java:208) at sun.jvm.hotspot.debugger.PageCache.getData(PageCache.java:63) at sun.jvm.hotspot.debugger.DebuggerBase.readBytes(DebuggerBase.java:225) at sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal.readCInteger(LinuxDebuggerLocal.java:498) at sun.jvm.hotspot.debugger.DebuggerBase.readAddressValue(DebuggerBase.java:462) at sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal.readAddress(LinuxDebuggerLocal.java:433) at sun.jvm.hotspot.debugger.linux.LinuxAddress.getAddressAt(LinuxAddress.java:74) at sun.jvm.hotspot.debugger.linux.amd64.LinuxAMD64CFrame.sender(LinuxAMD64CFrame.java:68) at sun.jvm.hotspot.tools.PStack.run(PStack.java:161) at sun.jvm.hotspot.tools.PStack.run(PStack.java:58) at sun.jvm.hotspot.tools.PStack.run(PStack.java:53) at sun.jvm.hotspot.tools.JStack.run(JStack.java:66) at sun.jvm.hotspot.tools.Tool.startInternal(Tool.java:260) at sun.jvm.hotspot.tools.Tool.start(Tool.java:223) at sun.jvm.hotspot.tools.Tool.execute(Tool.java:118) at sun.jvm.hotspot.tools.JStack.main(JStack.java:92) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at sun.tools.jstack.JStack.runJStackTool(JStack.java:140) at sun.tools.jstack.JStack.main(JStack.java:106) ~~~ From reading https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8208091 these exceptions seem to be unrelated to `MemNode::can_see_stored_value` being stuck.