Re: RFR 8058506: ThreadMXBeanStateTest throws exception
Have you considered creating a LogMessage class that keeps the logCntr value and the log message, instead of putting the counter into the log string and parsing it. Seems simpler and easier to understand. Erik Jaroslav Bachorik skrev 2014-10-20 13:12: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8058506 Webrev: http://cr.openjdk.java.net/~jbachorik/8058506/webrev.00 The test fails intermittently due to the log printing blocking the test thread from time to time, resulting in incorrect data reported by ThreadMXBean. The solution is to use per-thread non-blocking StringBuilders (wrapped in Formatter instances) and aggregate the log output only after the test is finished. Thanks, -JB-
Re: RFR 8058506: ThreadMXBeanStateTest throws exception
On 10/21/2014 03:27 PM, Erik Gahlin wrote: Have you considered creating a LogMessage class that keeps the logCntr value and the log message, instead of putting the counter into the log string and parsing it. Yes. And didn't go that way in order to prevent creating a lot of throwaway stringbuilder instances (the Formatter works that way) - but it might (almost certainly) be a premature optimization. I will clean it up and resubmit the request. -JB- Seems simpler and easier to understand. Erik Jaroslav Bachorik skrev 2014-10-20 13:12: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8058506 Webrev: http://cr.openjdk.java.net/~jbachorik/8058506/webrev.00 The test fails intermittently due to the log printing blocking the test thread from time to time, resulting in incorrect data reported by ThreadMXBean. The solution is to use per-thread non-blocking StringBuilders (wrapped in Formatter instances) and aggregate the log output only after the test is finished. Thanks, -JB-
Re: system profilers and incomplete stacks
G'Day, I checked the JDK 9 early access releases, but didn't see anything for JDK-6276264. I've also since learned that Twitter has an OpenJDK fork with frame pointers disabled, for the same purpose: stack profiling (using Linux perf_events). Might this be worked on for JDK 9? I can help test. thanks, Brendan On Mon, Jun 16, 2014 at 11:52 PM, Brendan Gregg wrote: > G'Day Serguei, > > On Mon, Jun 16, 2014 at 10:45 PM, serguei.spit...@oracle.com > wrote: >> >> Hi Brendan, >> >> We are aware of these issues and work with the Solaris team to fix them in >> JDK 9. >> One is the frame pointer is used by the server compiler as a general >> purpose register on intel. >> Another is about the virtual (or inlined) frames. >> >> There are a couple of related bugs: >>https://bugs.openjdk.java.net/browse/JDK-6617153 >>https://bugs.openjdk.java.net/browse/JDK-6276264 >> >> There can be more issues filed on this. > > > Ah, thanks, it's JDK-6276264. > > As Tom Rodriguez said at the time (2005): "The server VM uses the frame > pointer as an allocatable register and there's no way to turn that off." I > was really hoping there was a way to turn that off, like > -fno-omit-frame-pointer. > > This also means DTrace jstack() has never worked fully. For the applications > I tried it on, 50% of stacks were incomplete. Perhaps it wasn't that bad in > 2005. I've been getting more mileage today from Java profilers. > >> Please, note, that the jstack action is not implemented on Linux yet. > > > Linux doesn't have DTrace jstack(), no, but its perf_events does has support > for loading an auxiliary file of symbols, which can created via a Java agent > for that purpose (eg, https://github.com/jrudolph/perf-map-agent). But that > hasn't been working fully for the same reason - incomplete stacks. > > Brendan > >> >> Thanks, >> Serguei >> >> >> >> On 6/16/14 5:14 PM, Brendan Gregg wrote: >> >> Thanks but no, I'm aware of that bug and workarounds (I'm using the >> LD_AUDIT_64=/usr/lib/dtrace/64/libdtrace_forceload.so workaround, which >> isn't mentioned in the bug comments, but probably should be). That bug is >> about missing symbols, but the stacks shown in that bug still go all the way >> to thread_start. My stacks often don't. >> >> For simple programs, the stacks are complete. But something complex (eg, >> vert.x with event loops), and the stacks are often incomplete, one frame >> only. Very much like what I see with -fomit-frame-pointer, although this is >> hotspot, not gcc. Such incomplete stacks are seen using either DTrace or >> perf_events. >> >> It was suggested to me to email the hotspot developers, because this may >> well be a hotspot optimization they are familiar with. It may also be >> something really obvious, like that the JVM breaks native stacks due to >> optimized frames / green threads / etc, and there is absolutely no way >> around it (no way to disable it). If that's true, it may also mean that the >> DTrace jstack() action has always had this issue. I'm still reading the >> source... >> >> Brendan >> >> >> >> On Mon, Jun 16, 2014 at 4:04 AM, Staffan Larsen >> wrote: >>> >>> I think this is the bug you are looking at: >>> https://bugs.openjdk.java.net/browse/JDK-7187999, but I’ll defer to someone >>> else to confirm. >>> >>> /Staffan >>> >>> >>> On 16 jun 2014, at 12:47, Roland Westrelin >>> wrote: >>> >>> Forwarding to serviceability alias where this question belongs I think. >>> >>> Begin forwarded message: >>> >>> From: Brendan Gregg >>> Subject: system profilers and incomplete stacks >>> Date: June 12, 2014 at 7:15:54 PM GMT+2 >>> To: hotspot-compiler-...@openjdk.java.net >>> >>> G'Day, >>> >>> Is there a way to run hotspot so that a system profiler (eg, DTrace, or >>> Linux perf_events) can measure complete stacks? I often get incomplete, >>> partial stacks, with one or a few frames only. I'm not worried about symbols >>> right now, what I'd like is to walk stacks all the way down to thread start. >>> >>> I've been browsing the hotspot code, but haven't found out how yet. I >>> suspect it's related to Java optimized frames, and has ditched the frame >>> pointer. I was looking for an equivalent -fno-omit-frame-pointer option. >>> >>> Here's an example: >>> >>> # dtrace -n 'profile-99 /execname == "java"/ { @[jstack(100, 8000)] = >>> count(); }' >>> [...] >>> org/mozilla/javascript/ >>> >>> ScriptableObject.createSlot(Ljava/lang/String;II)Lorg/mozilla/javascript/ScriptableObject$Slot;* >>> 0x884acce822da >>> 1 >>> >>> sun/nio/ch/SocketChannelImpl.read(Ljava/nio/ByteBuffer;)I* >>> 0x20007f4b >>> 1 >>> >>> >>> org/mozilla/javascript/ScriptRuntime.newObjectLiteral([Ljava/lang/Object;[Ljava/lang/Object;[ILorg/mozilla/javascript/Context;Lorg/mozilla/javascript/Scriptable;)Lorg/mozilla/javascript/Scriptable;* >>> 0xa2041 >>> 1 >>> [...] >>> >>> I see similar incomplete st
Re: RFR 8056143: interrupted java/lang/management/MemoryMXBean/LowMemoryTest.java leaves running process
Sorry for the delay in getting back to this - I had a long weekend. :) I think this new approach is great! So it is a big Thumbs Up from me! Thanks, David On 17/10/2014 7:55 PM, Jaroslav Bachorik wrote: On 10/16/2014 02:14 AM, David Holmes wrote: On 15/10/2014 11:55 PM, Jaroslav Bachorik wrote: On 10/15/2014 10:11 AM, David Holmes wrote: On 15/10/2014 5:50 PM, Jaroslav Bachorik wrote: On 10/15/2014 02:10 AM, David Holmes wrote: On 14/10/2014 8:46 PM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8056143 Webrev: http://cr.openjdk.java.net/~jbachorik/8056143/webrev.00 The method jdk.testlibrary.ProcessTools.getOutput(process) waits for the given process to finish (process.waitFor()) before grabbing its outputs. However, the code does not handle the process.waitFor() being interrupted correctly - it just goes ahead and tries to obtain the exit code which will fail and leave the tested process running. The correct way is to forcibly destroy the process when process.waitFor() is interrupted or throws ExecutionException to make sure the process has actually exited before checking its exit code. Why is this correct? What gives the thread calling getOutput the right to terminate the target process just because that thread was interrupted while waiting? If the interrupting thread intended the interrupt to mean "forcibly terminate the process and interrupt all threads waiting on it" then that thread should be doing the termination _not_ the one that was interrupted! Process.waitFor() gets interrupted by a thread unknown to the actual test case - probably the JTreg timeout thread. The interrupting thread doesn't know that it is supposed to destroy a process. Once JTreg can take care of cleaning up process tree upon exit this code wouldn't be needed. I was contemplating adding the check for "null" returned from ProcessTools.getOutput() and destroying the process inside the caller code - but this would have the same results as doing it in ProcessTools.getOutput() with the drawback of duplicating the same check everywhere ProcessTools.getOutput() would be used. A silent postcondition of ProcessTools.getOuptut() is that the target process has finished - and it holds for all the code paths except the InterruptedException handler. That doesn't mean it is up to getOutput to forcibly terminate the process. Multi-process cancellation is tricky, and yes eventually jtreg will handle it. But this seems the wrong place to handle it now. Part of the flaw here is that getOutput should itself throw InterruptedException so that the caller is forced to deal with this - instead it just re-asserts the interrupt state. The caller has to be aware that the thread can be interrupted and do something appropriate - which may mean punting to its caller. This is akin to a thread catching InterruptedException and calling System.exit - it simply is not its job to make that kind of decision at that level! There is no other decision to make. Not as it is written today. You can call ProcessTools.getOutput() and check whether the result is null and then end the test process. There is no other sensible action. The Process.waitFor() was interrupted you have no data to perform the checks against so the test will fail and as such it should stop any external processes it has started. Yes, I can go through all the tests using ProcessTools.getOutput() and add `if (output == null) process.destroyForcible();` - would this make it a better solution than putting this logic inside ProcessTools.getOutput()? It would be the correct solution. Hacking it into getOutput() is just a convenience. Problem is that none of these tests have given enough thought to the cancellation issue and general process management. Agreed. My concern was that the test code base would have been littered with `if (output == null) process.destroyForcible();` checks because there is no other way to react to the situation when process.waitFor() is interrupted - at least not in the JTreg context. Therefore I put the logic of properly ending the external process to ProcessTools.executeProcess() method and restricted access to the constructors of OutputBuffer and OutputAnalyzer to enforce their creation only via ProcessTools.executeProcess(). Also, in order to prevent the started process stdout/stderr overflow I moved the backround stream pumpers to OutputBuffer so they would be started ASAP, without waiting for the process to exit (which defeats the purpose of consuming the attached stdout/stderr streams in backround anyway). With these changes the API user doesn't need to worry about the external process cleanup anymore. The semantics of ProcessTools.executeProcess() guarantees that there will be no orphan process hanging about once this method returns. This change is significantly bigger than the previous attempt because it spans a lot of tests using the OutputAnalyzer but, hopefully, it add
Re: RFR: 8038468: java/lang/instrument/ParallelTransformerLoader.sh fails with ClassCircularityError
Hi, David and all, Second webrev here: http://cr.openjdk.java.net/~minqi/8038468/webrev01/ Answer to David's question about 'main' and 'DestroyJavaVM'. I still did not find how when exception printing the stack trace, 'main' was retrieved but, at the moment JavaThread for "DestroyJavaVM' was created, 'main' is not dead. They may exist and with same C thread and id. This may cause we got 'main' not 'DestroyJavaVM'. Loading another class from agent in 'transform' with same custom class loader is not a good design. We already have two threads loading from the agent in parallel, TestClass1 in 'main' and TestClass2 in 'TestThread'. Should avoid loading another class with same agent in 'transform' in nested. Thanks Yumin On 10/17/2014 10:54 PM, David Holmes wrote: Hi Yumin, Quick response ... when shutdown is initiated the Shutdown class will be loaded and initialized: at java.lang.Shutdown.(Shutdown.java:61) Presumably this static initialization is what triggers the involvement of the agent to do the transform, and hence encounters the exception. Though I'm unclear how it still reports "main" as the name when it has now become "DestroyJavaVM" David On 18/10/2014 3:08 PM, Yumin Qi wrote: David, (cc Karen) I think I got why it throws CircularityError in 'main' thread. The CircularityError thrown in TestThread, which was handled in classloading, the loading class is put into unresolved list. Note we clean pending exception and return null to caller, which in the search next will load the instance class. There is no exception in java level be caught in TestThread. When main ended, we create a JavaThread named 'DestroyJavaVM' and give the thread id the current thread id, which is the main thread id. Since the All JavaThread object should be freed when this last JavaThread exit, I have no idea how the 'DestroyJavaVM' thread saw the exception, from the stack trace, the calling begins with ShutDown.java: /* The preceding static fields are protected by this lock */ private static class Lock { }; private static Object lock = new Lock(); //<<< line 61 How come the call via agent and call transform? At shutdown time, do we need to turn down the request to agent at this time? Thanks Yumin java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(Thread.java:1329) at ParallelTransformerLoaderAgent$TestTransformer.transform(ParallelTransformerLoaderAgent.java:92) at sun.instrument.TransformerManager.transform(TransformerManager.java:188) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428) java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(Thread.java:1329) at ParallelTransformerLoaderAgent$TestTransformer.transform(ParallelTransformerLoaderAgent.java:92) at sun.instrument.TransformerManager.transform(TransformerManager.java:188) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428) at java.lang.Shutdown.(Shutdown.java:61) This output in On 10/15/2014 9:58 AM, Yumin Qi wrote: David, I will take another detail trace to see where the exception begins in main thread, it should not thrown in main thread. I only saw it is thrown in TestThread, not main, not DestroyJavaVM. If that happens, maybe something wrong in vm. The output in all 'failed' case (many failed not cause exception output, not caught), the main thread got the exception. That is not right. Thanks Yumin On 10/14/2014 5:28 PM, David Holmes wrote: Hi Yumin, On 15/10/2014 4:40 AM, Yumin Qi wrote: David, Thanks for the comment. See embedded. On 10/13/2014 7:30 PM, David Holmes wrote: Hi Yumin, jdk9-dev is not the best place for code review requests. serviceability-dev would be better for this test. On 14/10/2014 8:58 AM, Yumin Qi wrote: bug: https://bugs.openjdk.java.net/browse/JDK-8038468 webrev:*http://cr.openjdk.java.net/~minqi/8038468/webrev00/ the bug marked as confidential so post the webrev internally. Not any more :) Thanks. I changed to non security related bug. Usually when test failed, a confidential bug is filed. I would like to create bug open if the test is in open part. Problem: The test case tries to load a class from the same jar via agent in the middle of loading another class from the jar via same class loader in same thread. The call happens in transform which is a rare case --- in middle of loading class, loading another class. The result is a CircularityError. When first class is in loading, in vm we put JarLoader$2 on place holder table, then we start the defineClass, which calls transform, begins loading the second class so go along the same routine for loading JarLoader$2 first, found it already in placeholder table. A CircularityError is thrown. Fix: The test case should not call loading class with same class loader in same thread from same jar
Re: RFR: 8038468: java/lang/instrument/ParallelTransformerLoader.sh fails with ClassCircularityError
On 22/10/2014 12:52 PM, Yumin Qi wrote: Hi, David and all, Second webrev here: http://cr.openjdk.java.net/~minqi/8038468/webrev01/ Answer to David's question about 'main' and 'DestroyJavaVM'. I still did not find how when exception printing the stack trace, 'main' was retrieved but, at the moment JavaThread for "DestroyJavaVM' was created, 'main' is not dead. They may exist and with same C thread and id. This may cause we got 'main' not 'DestroyJavaVM'. They are the same native thread. The "main" thread, upon return from main() (the Java app main()) detaches from the VM and re-attaches as the DestroyJavaVMThread. So I don't see how an exception dump can show the thread name as "main". Loading another class from agent in 'transform' with same custom class loader is not a good design. We already have two threads loading from the agent in parallel, TestClass1 in 'main' and TestClass2 in 'TestThread'. Should avoid loading another class with same agent in 'transform' in nested. I'm really not sure we're getting to the bottom of this, but I don't understand the original form and purpose of the test. David Thanks Yumin On 10/17/2014 10:54 PM, David Holmes wrote: Hi Yumin, Quick response ... when shutdown is initiated the Shutdown class will be loaded and initialized: at java.lang.Shutdown.(Shutdown.java:61) Presumably this static initialization is what triggers the involvement of the agent to do the transform, and hence encounters the exception. Though I'm unclear how it still reports "main" as the name when it has now become "DestroyJavaVM" David On 18/10/2014 3:08 PM, Yumin Qi wrote: David, (cc Karen) I think I got why it throws CircularityError in 'main' thread. The CircularityError thrown in TestThread, which was handled in classloading, the loading class is put into unresolved list. Note we clean pending exception and return null to caller, which in the search next will load the instance class. There is no exception in java level be caught in TestThread. When main ended, we create a JavaThread named 'DestroyJavaVM' and give the thread id the current thread id, which is the main thread id. Since the All JavaThread object should be freed when this last JavaThread exit, I have no idea how the 'DestroyJavaVM' thread saw the exception, from the stack trace, the calling begins with ShutDown.java: /* The preceding static fields are protected by this lock */ private static class Lock { }; private static Object lock = new Lock(); //<<< line 61 How come the call via agent and call transform? At shutdown time, do we need to turn down the request to agent at this time? Thanks Yumin java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(Thread.java:1329) at ParallelTransformerLoaderAgent$TestTransformer.transform(ParallelTransformerLoaderAgent.java:92) at sun.instrument.TransformerManager.transform(TransformerManager.java:188) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428) java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(Thread.java:1329) at ParallelTransformerLoaderAgent$TestTransformer.transform(ParallelTransformerLoaderAgent.java:92) at sun.instrument.TransformerManager.transform(TransformerManager.java:188) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428) at java.lang.Shutdown.(Shutdown.java:61) This output in On 10/15/2014 9:58 AM, Yumin Qi wrote: David, I will take another detail trace to see where the exception begins in main thread, it should not thrown in main thread. I only saw it is thrown in TestThread, not main, not DestroyJavaVM. If that happens, maybe something wrong in vm. The output in all 'failed' case (many failed not cause exception output, not caught), the main thread got the exception. That is not right. Thanks Yumin On 10/14/2014 5:28 PM, David Holmes wrote: Hi Yumin, On 15/10/2014 4:40 AM, Yumin Qi wrote: David, Thanks for the comment. See embedded. On 10/13/2014 7:30 PM, David Holmes wrote: Hi Yumin, jdk9-dev is not the best place for code review requests. serviceability-dev would be better for this test. On 14/10/2014 8:58 AM, Yumin Qi wrote: bug: https://bugs.openjdk.java.net/browse/JDK-8038468 webrev:*http://cr.openjdk.java.net/~minqi/8038468/webrev00/ the bug marked as confidential so post the webrev internally. Not any more :) Thanks. I changed to non security related bug. Usually when test failed, a confidential bug is filed. I would like to create bug open if the test is in open part. Problem: The test case tries to load a class from the same jar via agent in the middle of loading another class from the jar via same class loader in same thread. The call happens in transform which is a rare case --- in middle of loading class, loading another class. The result is a CircularityErro
Re: system profilers and incomplete stacks
On 22 okt 2014, at 02:10, Brendan Gregg wrote: > G'Day, > > I checked the JDK 9 early access releases, but didn't see anything for > JDK-6276264. That bug has been closed as a duplicate of https://bugs.openjdk.java.net/browse/JDK-6617153, which is still open. > I've also since learned that Twitter has an OpenJDK fork > with frame pointers disabled, for the same purpose: stack profiling > (using Linux perf_events). Might this be worked on for JDK 9? I would welcome that change - perhaps Twitter can contribute it? Thanks, /Staffan > I can > help test. thanks, > > Brendan > > On Mon, Jun 16, 2014 at 11:52 PM, Brendan Gregg > wrote: >> G'Day Serguei, >> >> On Mon, Jun 16, 2014 at 10:45 PM, serguei.spit...@oracle.com >> wrote: >>> >>> Hi Brendan, >>> >>> We are aware of these issues and work with the Solaris team to fix them in >>> JDK 9. >>> One is the frame pointer is used by the server compiler as a general >>> purpose register on intel. >>> Another is about the virtual (or inlined) frames. >>> >>> There are a couple of related bugs: >>> https://bugs.openjdk.java.net/browse/JDK-6617153 >>> https://bugs.openjdk.java.net/browse/JDK-6276264 >>> >>> There can be more issues filed on this. >> >> >> Ah, thanks, it's JDK-6276264. >> >> As Tom Rodriguez said at the time (2005): "The server VM uses the frame >> pointer as an allocatable register and there's no way to turn that off." I >> was really hoping there was a way to turn that off, like >> -fno-omit-frame-pointer. >> >> This also means DTrace jstack() has never worked fully. For the applications >> I tried it on, 50% of stacks were incomplete. Perhaps it wasn't that bad in >> 2005. I've been getting more mileage today from Java profilers. >> >>> Please, note, that the jstack action is not implemented on Linux yet. >> >> >> Linux doesn't have DTrace jstack(), no, but its perf_events does has support >> for loading an auxiliary file of symbols, which can created via a Java agent >> for that purpose (eg, https://github.com/jrudolph/perf-map-agent). But that >> hasn't been working fully for the same reason - incomplete stacks. >> >> Brendan >> >>> >>> Thanks, >>> Serguei >>> >>> >>> >>> On 6/16/14 5:14 PM, Brendan Gregg wrote: >>> >>> Thanks but no, I'm aware of that bug and workarounds (I'm using the >>> LD_AUDIT_64=/usr/lib/dtrace/64/libdtrace_forceload.so workaround, which >>> isn't mentioned in the bug comments, but probably should be). That bug is >>> about missing symbols, but the stacks shown in that bug still go all the way >>> to thread_start. My stacks often don't. >>> >>> For simple programs, the stacks are complete. But something complex (eg, >>> vert.x with event loops), and the stacks are often incomplete, one frame >>> only. Very much like what I see with -fomit-frame-pointer, although this is >>> hotspot, not gcc. Such incomplete stacks are seen using either DTrace or >>> perf_events. >>> >>> It was suggested to me to email the hotspot developers, because this may >>> well be a hotspot optimization they are familiar with. It may also be >>> something really obvious, like that the JVM breaks native stacks due to >>> optimized frames / green threads / etc, and there is absolutely no way >>> around it (no way to disable it). If that's true, it may also mean that the >>> DTrace jstack() action has always had this issue. I'm still reading the >>> source... >>> >>> Brendan >>> >>> >>> >>> On Mon, Jun 16, 2014 at 4:04 AM, Staffan Larsen >>> wrote: I think this is the bug you are looking at: https://bugs.openjdk.java.net/browse/JDK-7187999, but I’ll defer to someone else to confirm. /Staffan On 16 jun 2014, at 12:47, Roland Westrelin wrote: Forwarding to serviceability alias where this question belongs I think. Begin forwarded message: From: Brendan Gregg Subject: system profilers and incomplete stacks Date: June 12, 2014 at 7:15:54 PM GMT+2 To: hotspot-compiler-...@openjdk.java.net G'Day, Is there a way to run hotspot so that a system profiler (eg, DTrace, or Linux perf_events) can measure complete stacks? I often get incomplete, partial stacks, with one or a few frames only. I'm not worried about symbols right now, what I'd like is to walk stacks all the way down to thread start. I've been browsing the hotspot code, but haven't found out how yet. I suspect it's related to Java optimized frames, and has ditched the frame pointer. I was looking for an equivalent -fno-omit-frame-pointer option. Here's an example: # dtrace -n 'profile-99 /execname == "java"/ { @[jstack(100, 8000)] = count(); }' [...] org/mozilla/javascript/ ScriptableObject.createSlot(Ljava/lang/String;II)Lorg/mozilla/javascript/ScriptableObject$Slot;* 0x884acce822da 1 >