[prev in list] [next in list] [prev in thread] [next in thread] 

List:       openjdk-serviceability-dev
Subject:    RFR: JDK-8169718: nsk/jdb/locals/locals002: ERROR: Cannot find boolVar with expected value: false
From:       "gary.adams () oracle ! com" <gary ! adams () oracle ! com>
Date:       2018-09-22 10:45:42
Message-ID: a192ec42-fe5e-54e0-596a-870c6f2c374d () oracle ! com
[Download RAW message or body]

This is a very old bug that started off as a closed test, but should 
have an open review
before it finally gets pushed. Many other jdb bugs will be closed as 
duplicates as a
result of this change.

The problem shows up as a corrupted log when running the jdb tests.
The tests send commands to a jdb process and parse the output to determine
if the correct functions were performed. Sometimes the tests will timeout,
sometimes the test will report the commands were not successful.

When running jdb the output can come from several different threads.
        - the command processing thread
        - the event handler thread
        - asynchronous command threads
        - debuggee class (separate process)

This fix works around an issue between the command
thread and the event handler thread. In the TTY.executeCommand()
method there is a large dispatch to commands that ends with the printing
of a prompt for the user to enter another command.

When commands {cont, next, step, stepi} are processed they
resume the vm in the debuggee. This can cause the event handler
to be woken up. Events typically display messages, such
as "Breakpoint hit", "Step completed". They also set the
current thread variable so a "current location" in the source can
be identified. The event finishes by printing a prompt so the user will
enter the next command.

The corruption in the log shows up when the event handler
starts running between the printing of the command and
command issuing the prompt. It also shows up when
a prompt is written in the middle of the event output.

The proposed fix allows the {cont,next,step,stepi} commands
to issue a simple prompt before performing the command
that resumes the debuggee. It then skips the prompt that is issued
at the end of the excuteCommand() dispatch.

A variety of other fixes had been tried such as locks and
output buffering, but all fell short. Many of the output
routines are shared. Even the executeCommand() processing
is called from the event handler thread to process monitor
commands.

    Webrev: http://cr.openjdk.java.net/~gadams/8169718/webrev.03/

This fix was tested with 1000 test runs on the slower debug builds
where the problem was observed more often. Before the fix it was
common to see 9/1000 failures on windows-x64 and solaris-sparc9
platforms.

Here's a sample of a corrupted log. A prompt is displayed after
an event header was displayed. As the next command is processed
the rest of the event output shows up.
...
Breakpoint hit: main[1]
Sending command: locals

reply[0]: "thread=main", 
nsk.jdb.locals.locals002.locals002a.allKindsOfLocals(), line=82 bci=62
...

[Attachment #3 (text/html)]

<html>
  <head>

    <meta http-equiv="content-type" content="text/html; charset=utf-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    This is a very old bug that started off as a closed test, but should
    have an open review<br>
    before it finally gets pushed. Many other jdb bugs will be closed as
    duplicates as a <br>
    result of this change.<br>
    <br>
    The problem shows up as a corrupted log when running the jdb tests.<br>
    The tests send commands to a jdb process and parse the output to
    determine<br>
    if the correct functions were performed. Sometimes the tests will
    timeout,<br>
    sometimes the test will report the commands were not successful.<br>
    <br>
    When running jdb the output can come from several different threads.<br>
           - the command processing thread<br>
           - the event handler thread<br>
           - asynchronous command threads<br>
           - debuggee class (separate process)<br>
    <br>
    This fix works around an issue between the command <br>
    thread and the event handler thread. In the TTY.executeCommand()<br>
    method there is a large dispatch to commands that ends with the
    printing<br>
    of a prompt for the user to enter another command.<br>
    <br>
    When commands {cont, next, step, stepi} are processed they<br>
    resume the vm in the debuggee. This can cause the event handler<br>
    to be woken up. Events typically display messages, such<br>
    as "Breakpoint hit", "Step completed". They also set the <br>
    current thread variable so a "current location" in the source can <br>
    be identified. The event finishes by printing a prompt so the user
    will<br>
    enter the next command.<br>
    <br>
    The corruption in the log shows up when the event handler <br>
    starts running between the printing of the command and <br>
    command issuing the prompt. It also shows up when <br>
    a prompt is written in the middle of the event output.<br>
    <br>
    The proposed fix allows the {cont,next,step,stepi} commands<br>
    to issue a simple prompt before performing the command<br>
    that resumes the debuggee. It then skips the prompt that is issued<br>
    at the end of the excuteCommand() dispatch.<br>
    <br>
    A variety of other fixes had been tried such as locks and <br>
    output buffering, but all fell short. Many of the output <br>
    routines are shared. Even the executeCommand() processing<br>
    is called from the event handler thread to process monitor<br>
    commands.<br>
    <br>
       Webrev: <a class="moz-txt-link-freetext"
      href="http://cr.openjdk.java.net/%7Egadams/8169718/webrev.03/">http://cr.openjdk.java.net/~gadams/8169718/webrev.03/</a><br>
  <br>
    This fix was tested with 1000 test runs on the slower debug builds<br>
    where the problem was observed more often. Before the fix it was <br>
    common to see 9/1000 failures on windows-x64 and solaris-sparc9<br>
    platforms.<br>
    <br>
    Here's a sample of a corrupted log. A prompt is displayed after <br>
    an event header was displayed. As the next command is processed<br>
    the rest of the event output shows up.<br>
    ...<br>
    Breakpoint hit: main[1] <br>
    Sending command: locals<br>
    <br>
    reply[0]: "thread=main",
    nsk.jdb.locals.locals002.locals002a.allKindsOfLocals(), line=82
    bci=62<br>
    ...<br>
  </body>
</html>



[prev in list] [next in list] [prev in thread] [next in thread] 

Configure | About | News | Add a list | Sponsored by KoreLogic