Bug 34941 - RC2 Conditional breakpoint excruciatingly slow, can't suspend or can't step when suspended
Summary: RC2 Conditional breakpoint excruciatingly slow, can't suspend or can't step w...
Status: VERIFIED FIXED
Alias: None
Product: Platform
Classification: Eclipse Project
Component: Debug (show other bugs)
Version: 3.0   Edit
Hardware: PC Windows XP
: P3 normal (vote)
Target Milestone: 3.1 M3   Edit
Assignee: Jared Burns CLA
QA Contact:
URL:
Whiteboard:
Keywords: performance
Depends on:
Blocks:
 
Reported: 2003-03-13 13:54 EST by Bob Foster CLA
Modified: 2004-10-14 15:54 EDT (History)
5 users (show)

See Also:


Attachments
debug view showing funky stack frame (79.12 KB, image/jpeg)
2003-03-13 13:55 EST, Bob Foster CLA
no flags Details
JavaLineBreakpoint.patch (3.51 KB, patch)
2004-06-14 14:44 EDT, Jared Burns CLA
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Bob Foster CLA 2003-03-13 13:54:15 EST
Set a conditional bp in the following method:

	private void pushPos(int pos) {
		fPositions[fPosIndex++] = pos;
	}

On the condition "fPosIndex > fRangeEnd" where fPosIndex is an int variable in 
the current class and fRangeEnd is an int variable in its superclass.

When this is run, troubles begin:

1. First, even though this condition does become true very quickly when run 
without the breakpoint, there doesn't seem to be enough time in the universe 
to hit the breakpoint.

2. Second, when I try to suspend, that fails with a message in the variables 
view "Thread not suspended...". Attachment shows why.

3. After a few tries, I do manage to suspend. It is always on that line of 
code. After a number of suspend/resumes, the value of pos never changes. Is it 
slow or is it stuck? Hard to say, because when I try to step it resumes!

4. When I sucessfully suspend and remove the breakpoint, nothing is changed. 
Every time I try to step it resumes. Every time I suspend it is on that line 
of code with the same value of pos.

Only terminating the process gets me out of this state.
Comment 1 Bob Foster CLA 2003-03-13 13:55:29 EST
Created attachment 4108 [details]
debug view showing funky stack frame

Caused by conditional bp?
Comment 2 Darin Wright CLA 2003-03-13 13:58:13 EST
Which VM?
Comment 3 Bob Foster CLA 2003-03-13 18:40:14 EST
j2sdk1.4.1_02 running on Windows XP Pro. 2.6 GHz P4, 1GB RAM, 60GB disk. Not
much else running at the time.

FWIW, afterwards I set another conditional bp that did finally get hit in less
than 10 minutes. Can't be sure how much less because I left the room.
Comment 4 Darin Wright CLA 2003-03-13 19:04:59 EST
Could you try a different VM - like Sun1.3.1 or IBM1.3.1?
Comment 5 Bob Foster CLA 2003-03-13 20:10:07 EST
Perhaps. Does changing the VM in the run-time workbench Arguments do it? I
changed it to 1.3.1 and it's still very slow.

I did the following. Set the VM in rtw args to 1.3.1. In the following code:

  int first = super.read();
  if (first < 0) {
    int c = -1;
    first = c;
  }
  if (first == '\\') {
    //...

Set a breakpoint on the first and second if. After launch when stopped at first
if, removed that bp and made the second breakpoint conditional on first < 0.
After resume, this stopped again in approx. 90 seconds.

Next time around, set breakpoint on first if and "first = c;" line. After launch
when stopped at first if, removed that bp. After resume, this stopped again
approx. 1 second. Most of this time was taken repainting the stack trace.

I'd guess it's about 100 times slower with conditional breakpoint on.

No difference when set to 1.4.1_02 VM.
Comment 6 Jared Burns CLA 2003-03-17 11:09:07 EST
Bob, can you provide a complete (preferrably as small as possible) test case?

I played with the following and the breakpoint was hit in a couple seconds:
public class Super {
  protected int fRangeEnd= 400;
}
public class Hello extends Super {
  private int[] fPositions= new int[1000];
  private int fPosIndex= 0;
  private void pushPos(int pos) {
    fPositions[fPosIndex++] = pos; // BP w/condition fPosIndex > fRangeEnd
  }
  public static void main(String[] args) {
    Hello hello= new Hello();
    for (int i= 0; i < 600; i++) {
      hello.pushPos(i);
    }
  }
}
Comment 7 Bob Foster CLA 2003-03-17 17:19:21 EST
Add a zero (to 6000) and tell me how you like it. ;-}

Sorry, but something that runs in a microsecond isn't a good test case. In 
this particular case, the real code was running inside the read() method of 
partition/color scanners. This method reads at least every character of a 
file, some of them many times. I modified your example just slightly to 
reflect more what was going on, but it hardly matters. You just picked too 
small a number to be able to measure the slowdown.

public class Hello {

	private int[] fPositions = new int [1000];
	private int fPosIndex = 0;
	public void pushPos(int pos) {
		fPositions[fPosIndex++] = pos; // conditional bp: fPosIndex >= 
500
	}
	public int popPos() {
		return fPositions[--fPosIndex];
	}
	public int getStackSize() {
		return fPosIndex;
	}
}
public class Main {
	
	public static final int MAXI = 5000;

	public static void main(String[] args) {
		Hello hello = new Hello();
		for (int i = 0; i < MAXI; i++) {
			hello.pushPos(i);
			hello.popPos();
			if ((i % 10) == 0)
				hello.pushPos(i);
		}
		int pushed = hello.getStackSize();
	}
}

(The Super thing is a red herring.) This runs in less than a second without 
the conditional breakpoint and in just under 3 minutes (!) with it.
Comment 8 Jared Burns CLA 2003-04-09 12:41:28 EDT
I definitely see the problem with the new example. :-) While the test case was
running in my selfhosting instance of Eclipse, I noticed that a thread was
coming and going very quickly. Not sure if it's the root of the problem, but
whatever this thread is we should be reusing it instead of recreating it.
Comment 9 Jared Burns CLA 2003-04-09 12:43:36 EDT
The timer in LaunchViewEventHandler creates a new thread for each
suspend/resume. This is dumb (I wrote the code, so I can say that :)  ).
Comment 10 Jared Burns CLA 2003-06-05 10:55:34 EDT
It also looks like we're creating and destroying a thread for each evaluation
in the loop. I don't understand this as I seem to recall writing code to
preserve a thread that evaluations reused. I've sent an email to the jdt debug
dev mailing list asking why this optimization was removed.
Comment 11 Luc Bourlier CLA 2003-06-12 13:16:57 EDT
I release some changes. The thread is keep alive a little longer, so it will be
reuse if a new evaluation is requested.
I also change two lines in JDIThread#computeStackFrames(boolean), the old code
was creating an extra JDWP command.

I did some test, the changes don't seem to really improve the speed of the
conditional breakpoint.
I will have to run Eclipse in a profiler.
Comment 12 Darin Wright CLA 2004-05-18 17:44:45 EDT
Nothing planned for 3.0
Comment 13 Darin Wright CLA 2004-06-01 10:37:02 EDT
Re-open. This is still true in 3.0 RC1 for simple conditions like "i == 57". 
We should investigate why even simple conditions are slow.
Comment 14 Michael Fraenkel CLA 2004-06-02 12:47:14 EDT
Here are somethings I noticed...

There are many events being fired where the array (DebugEvents[]) has zero 
length because the only event in the EventSet is a deferred event.

At the end of the day, the evalutions are being executed constantly.  Will try 
to get a profile of the cost of doing the evaluation.
The breakpoint is hit every 10-20ms and the evaluations take 10-20ms but there 
is no delay between when the evaluation is complete and the next breakpoint is 
hit.

As an aside, its not clear if all the variables in play are thread safe.  
While I haven't seen/perceived any problem, just wanted to make someone aware.
The two variables I detected were JavaLineBreakpoint.fSuspendEvents and 
ThreadTimer.fTimedOutThreads.
Comment 15 Jared Burns CLA 2004-06-11 17:53:31 EDT
Doing profiling today. Will investigate with Luc.
Comment 16 Jared Burns CLA 2004-06-14 14:44:38 EDT
Created attachment 12065 [details]
JavaLineBreakpoint.patch

The profiler shows that the vast majority of our time is spent doing source
lookup in JavaLineBreakpoint#getJavaProject(). The attached patch explores
caching the project to remove this cost.

Debugging through the patched version of the code we were able to verify that
the caching works, but we had a really wierd configuration problem trying to
get the patched version running under the profiler.
Comment 17 Darin Wright CLA 2004-06-17 10:36:21 EDT
Sadly defferred. Too late for 3.0.
Comment 18 Darin Wright CLA 2004-06-28 15:11:29 EDT
Re-open for 3.1
Comment 19 Darin Wright CLA 2004-10-13 15:53:20 EDT
The patch was stale as is, but I incorporated similar code. Appears to be a 
big win.
Comment 20 Darin Wright CLA 2004-10-13 15:53:42 EDT
Please verify, Jared. Changes in JavaLineBreakpoint.
Comment 21 Darin Swanson CLA 2004-10-13 16:16:57 EDT
Using the Java Debug UI performance tests shows a great improvement:

Before:
Scenario 'org.eclipse.jdt.debug.tests.performance.PerfConditionalBreakpointsTes
ts#testConditionalBreakpoint()' (average over 5 samples):
  Working Set: 1.47M
  Committed: 10.67M
  CPU Time: 7.41 s
  Elapsed Process: 8.06 s
  System Time: 8.06 s
  Page Faults: 657
  GDI Objects: 19
  Kernel time: 2.98 s
  Working Set Peak: 1.48M


After:
Scenario 'org.eclipse.jdt.debug.tests.performance.PerfConditionalBreakpointsTes
ts#testConditionalBreakpoint()' (average over 5 samples):
  System Time: 3.34 s
  GDI Objects: 19
  Working Set: 1.43M
  Working Set Peak: 1.41M
  Elapsed Process: 3.35 s
  CPU Time: 1.89 s
  Kernel time: 763 ms
  Committed: 10.78M
  Page Faults: 546
Comment 22 Jared Burns CLA 2004-10-14 15:54:19 EDT
Verified.