Discussion:
RFR: JDK-8169718: nsk/jdb/locals/locals002: ERROR: Cannot find boolVar with expected value: false
g***@oracle.com
2018-09-22 10:45:42 UTC
Permalink
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
...
Gary Adams
2018-10-02 18:29:25 UTC
Permalink
Looking for one more reviewer before we push this changeset.
Post by g***@oracle.com
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
...
Alex Menkov
2018-10-02 22:00:36 UTC
Permalink
Looks good to me.

--alex
Post by Gary Adams
Looking for one more reviewer before we push this changeset.
Post by g***@oracle.com
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
...
Gary Adams
2018-10-03 11:47:06 UTC
Permalink
Patch attached.
Post by Alex Menkov
Looks good to me.
--alex
Post by Gary Adams
Looking for one more reviewer before we push this changeset.
Post by g***@oracle.com
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
...
Loading...