RFR: JDK-8154144 Tests in com/sun/jdi fails intermittently with "jdb input stream closed prematurely

Tue May 3 05:03:44 UTC 2016

Thanks for the review Dan.  I have made the suggested changes:

http://cr.openjdk.java.net/~sballal/8154144/webrev.01/ 

I have also run the following tests successfully:

1.     Rbt for nsk.jdb.testlist, nsk.jdi.testlist, nsk.jdwp.testlist, nsk.jvmti.testlist

2.     Jtreg for com/sun/jdi/ directory. 

-Sharath Ballal

From: Daniel D. Daugherty 
Sent: Friday, April 29, 2016 7:49 PM
To: Sharath Ballal; Staffan Larsen
Cc: serviceability-dev at openjdk.java.net
Subject: Re: RFR: JDK-8154144 Tests in com/sun/jdi fails intermittently with "jdb input stream closed prematurely

Thanks for the additional details. I'm good with the
concept of this fix.

> http://cr.openjdk.java.net/~sballal/8154144/webrev.00/

General comment
    Please update the copyright years before you push.

src/jdk.jdi/share/classes/com/sun/tools/example/debug/tty/EventHandler.java
    No comments.

src/jdk.jdi/share/classes/com/sun/tools/example/debug/tty/TTY.java
    L763:                     if(!isShuttingDown()) {
        Nit: please add a space between 'if' and '('.

Thumbs up.

Dan

P.S.
Part of me wonders if this line:

L764: MessageOutput.println("Input stream closed.");

should change to:

L764: MessageOutput.println("Input stream closed unexpectedly.");

But that would likely require updating the tests that look
for this pattern. Probably not worth it.

On 4/28/16 11:55 PM, Sharath Ballal wrote:

Hi Dan,

The debugger has received a ‘vmDeathEvent’ and as part of handling this event, the System.exit() is being called (handleExitEvent() in EventHandler.java).  So the fact that debuggee has finished executing, is known to the debugger and the debugger is explicitly cleaning up after that.  This is similar to the breakpoint you mentioned.  Instead of breakpoint, we have an event.  Now as part of the explicit cleanup the readLine() (which is always blocking) sometimes returns with a ‘null’.  Since we know we are cleaning up and we also know that the debuggee has done executing, I am avoiding printing the error message.

-Sharath Ballal

From: Daniel D. Daugherty 
Sent: Thursday, April 28, 2016 7:48 PM
To: Sharath Ballal; Staffan Larsen
Cc: HYPERLINK "mailto:serviceability-dev at openjdk.java.net"serviceability-dev at openjdk.java.net
Subject: Re: RFR: JDK-8154144 Tests in com/sun/jdi fails intermittently with "jdb input stream closed prematurely

> When JDB is done, as part of the shutdown it calls System.exit()
> at Env.java:92 in a different thread 'event-handler'.

Based on the above line from below, I'm even more convinced that
this bug is hit because the debuggee VM is allowed to run off the
end of main() and that creates a race between debuggee VM's attempt
to exit and the debugger trying to control the test execution.

While this fix makes this bug "go away", I don't think this is the
right solution. You're basically trying to harden our ability to
handle this race condition instead of closing the race condition.

I'll repeat part of the comment that I added to the bug on 04.13:

> One possible solution is to add a breakpoint after main() returns and change
> the debuggee <-> debugger protocol to always expect one final breakpoint.
> Positive enforcement that the test reaches that point and it should catch any
> accidental "run of the end of main()" issues. 

Dan

On 4/28/16 2:25 AM, Sharath Ballal wrote:

Hi Staffan,

The root cause of this problem is that BufferedReader.readLine() is intermittently returning 'null' during System.exit(0). 

In TTY.java:751 we are always blocking on readLine(). Whenever a user enters a command in JDB, the readLine() returns the command, which gets executed. This is running in the 'main' thread. 

When JDB is done, as part of the shutdown it calls System.exit() at Env.java:92 in a different thread 'event-handler'. 

Usually (in the passing cases) calling System.exit() is the end of the process and readLine() doesn't return 'null', but in the failing case readLine() at TTY.java:751 returns 'null'. This causes the string "Input stream closed." to be printed. The jtreg testcase looks for this string to decide that the testcase failed. 

The fix I have done is avoiding the print because we know that we are shutting down and hence can discard the ‘null’ returned by readLine().

Regarding the testing, I have run few of the failing jtreg testcases about 200 times and not seen the problem (earlier I was able to recreate without the fix).  I have to do other tests, but sent for review to do it in parallel.

jdk/src/jdk.jdi/share/classes/com/sun/tools/example/debug/tty/TTY.java 

708 BufferedReader in = 
709 new BufferedReader(new InputStreamReader(System.in)); 
....... 
....... 
748 // Process interactive commands. 
749 MessageOutput.printPrompt(); 
750 while (true) { 
751 String ln = in.readLine(); 
752 if (ln == null) { 
753 MessageOutput.println("Input stream closed."); 
754 ln = "quit"; 
755 } 

jdk/src/jdk.jdi/share/classes/com/sun/tools/example/debug/tty/Env.java 

79 static void shutdown(String message) { 
80 if (connection != null) { 
81 try { 
82 connection.disposeVM(); 
83 } catch (VMDisconnectedException e) { 
84 // Shutting down after the VM has gone away. This is 
85 // not an error, and we just ignore it. 
86 } 
87 } 
88 if (message != null) { 
89 MessageOutput.lnprint(message); 
90 MessageOutput.println(); 
91 } 
92 System.exit(0); 
93 }

-Sharath Ballal

From: Staffan Larsen 
Sent: Thursday, April 28, 2016 1:17 PM
To: Sharath Ballal
Cc: HYPERLINK "mailto:serviceability-dev at openjdk.java.net"serviceability-dev at openjdk.java.net
Subject: Re: RFR: JDK-8154144 Tests in com/sun/jdi fails intermittently with "jdb input stream closed prematurely

Hi Sharath,

Can you explain more how this help with the problem in the bug? 

It looks like you are trying to avoid a race by not printing the "Input stream closed.” message while shutting down. You added this:

 136             ((TTY)notifier).setShuttingDown(true);
 137             Env.shutdown(shutdownMessageKey);

The call on line 137 will result in a System.exit(0) call if I am reading the code right. So adding the shutdown flag to line 136 will maybe make the race smaller, but isn’t really solving it?

What kind of testing have you run this fix through?

Thanks,

/Staffan

On 28 apr. 2016, at 09:22, Sharath Ballal <HYPERLINK "mailto:sharath.ballal at oracle.com"sharath.ballal at oracle.com> wrote:

Hi,

Pls review the change for bug 

HYPERLINK "https://bugs.openjdk.java.net/browse/JDK-8154144"JDK-8154144 - Tests in com/sun/jdi fails intermittently with "jdb input stream closed prematurely

Webrev:

http://cr.openjdk.java.net/~sballal/8154144/webrev.00/

-Sharath Ballal

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20160502/365c3c80/attachment-0001.html>