Bug 342697 - [perf test] org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite doesn't run on second windows machine
Summary: [perf test] org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite doesn...
Status: RESOLVED WORKSFORME
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Text (show other bugs)
Version: 3.7   Edit
Hardware: PC Windows XP
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: JDT-Text-Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords: test
Depends on:
Blocks:
 
Reported: 2011-04-13 06:57 EDT by Satyam Kandula CLA
Modified: 2012-04-24 11:40 EDT (History)
5 users (show)

See Also:


Attachments
the thread dump (26.64 KB, text/plain)
2011-04-29 06:09 EDT, Deepak Azad CLA
no flags Details
the thread dump v2 (26.50 KB, text/plain)
2011-05-11 05:17 EDT, Deepak Azad CLA
no flags Details
Log from I20110512-0800 (26.78 KB, text/plain)
2011-05-13 13:24 EDT, Markus Keller CLA
no flags Details
Add time logging when tests start (4.49 KB, patch)
2011-05-13 14:30 EDT, Markus Keller CLA
no flags Details | Diff
Fix for KeyboardProbe (3.61 KB, patch)
2011-05-19 13:25 EDT, Markus Keller CLA
no flags Details | Diff
remove Display#sleep() from ScrollEditorTest (4.80 KB, patch)
2011-05-24 07:05 EDT, Markus Keller CLA
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Satyam Kandula CLA 2011-04-13 06:57:22 EDT
These tests run on one windows machine but doesn't run on the other windows machine. They have not been running for a while. I don't know when they ran last but they haven't run for a while. 

The console log also doesn't show up for this windows machine.
Comment 1 Satyam Kandula CLA 2011-04-13 07:03:05 EDT
Kim, 
Do you have any idea why the console log for the other windows machine doesn't
show up?
Comment 2 Kim Moir CLA 2011-04-13 08:49:45 EDT
For I20110412-1532, the tests are still running on the second windows machine.
Comment 3 Deepak Azad CLA 2011-04-14 08:38:16 EDT
Kim, the console log for the second windows machine has been missing for a while now.
http://download.eclipse.org/eclipse/downloads/drops/S-3.7M6-201103101119/performance/performance.php
http://download.eclipse.org/eclipse/downloads/drops/I20110406-1223/performance/performance.php

It is also missing in the latest I-Builds. (Though the following pages say results pending, I assume the tests have finished but something went wrong while uploading the numbers)
http://download.eclipse.org/eclipse/downloads/drops/I20110412-1532/performance/performance.php
http://download.eclipse.org/eclipse/downloads/drops/I20110412-0955/performance/performance.php
Comment 4 Deepak Azad CLA 2011-04-15 02:23:49 EDT
EventDrivenTestSuite runs on the first windows machine
http://download.eclipse.org/eclipse/downloads/drops/S-3.7M6-201103101119/performance/html/org.eclipse.jdt.text.tests_win32perf1.html

but not on the second
http://download.eclipse.org/eclipse/downloads/drops/S-3.7M6-201103101119/performance/html/org.eclipse.jdt.text.tests_win32perf2.html

The above links are for M6 build, but the same is true for I20110406-1223 as well.

This test suite is the last in jdt.text performance tests and has a timeout, other tests do not have a timeout.
    <ant target="ui-test" antfile="${library-file}" dir="${eclipse-home}">
      <property name="timeout" value="10800000"/>
      <property name="vmargs" value="-Xms250M -Xmx250M"/>
      <property name="data-dir" value="${jdt-text-performance-folder}"/>
      <property name="plugin-name" value="${plugin-name}"/>
      <property name="classname" value="org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite"/>
    </ant>

Note that EventDrivenTestSuite is not the last to run among all SDK performance tests, as can be seen from http://download.eclipse.org/eclipse/downloads/drops/S-3.7M6-201103101119/performance/consolelogs/winxp.perf1_consolelog.txt, and subsequent tests (e.g. compare performance tests) run correctly on the second windows machine.

The only thing I can think of is the timeout, but not sure if the timeout is behind the missing console log as well.

Kim, is there any difference in the 2 windows machines ? Performance results page shows them to be identical "Win XP Sun 1.6.0_17 (2 x 3.00GHz - 3GB RAM)".
Comment 5 Deepak Azad CLA 2011-04-15 04:15:56 EDT
Kim, I was talking to Dani and he said that the test suite might have been disabled on the second windows machine because at some point in the past the machine was not very fast and the test took too long to run. 

Can you please double check if the test suite has indeed been disabled ? If yes, and the machine is not slow anymore, can you please enable it again ?
Comment 6 Kim Moir CLA 2011-04-15 09:05:28 EDT
Hi Deepak

The two windows machines are identical in terms of hardware.  The way that the performance tests work is that they they run the same way as the JUnit tests except that a performance target is called instead.  Thus, the build scripts don't control which tests run, you do :-)
Comment 7 Deepak Azad CLA 2011-04-15 09:10:11 EDT
(In reply to comment #6)
> Hi Deepak
> 
> The two windows machines are identical in terms of hardware.  The way that the
> performance tests work is that they they run the same way as the JUnit tests
> except that a performance target is called instead.  Thus, the build scripts
> don't control which tests run, you do :-)

Ok, did you also check for the console log ? (see comment 3)
Comment 8 Kim Moir CLA 2011-04-15 09:48:36 EDT
Yes, I'm still investigating why the console log is missing.
Comment 9 Deepak Azad CLA 2011-04-20 01:12:18 EDT
(In reply to comment #4)
> The only thing I can think of is the timeout, but not sure if the timeout is
> behind the missing console log as well.
The time out is 10,800 seconds. The test suite takes about 3000 secs to run on the first windows machine, and other test suites take roughly the same amount of time on both machines.

See
- http://download.eclipse.org/eclipse/downloads/drops/S-3.7M6-201103101119/performance/html/org.eclipse.jdt.text.tests_win32perf1.html
- http://download.eclipse.org/eclipse/downloads/drops/S-3.7M6-201103101119/performance/html/org.eclipse.jdt.text.tests_win32perf2.html

Hence I do not think that time out should be the problem here.

Kim, I am passing this bug to you to find the missing log :)
Comment 10 Dani Megert CLA 2011-04-20 02:15:31 EDT
> The time out is 10,800 seconds. The test suite takes about 3000 secs to run on
> the first windows machine, and other test suites take roughly the same amount
> of time on both machines.
> ...
> Hence I do not think that time out should be the problem here.

Those are event driven tests and hence anything (e.g. an event/pop-up from another app or the OS or the screen saver) can influence a test or make it stop/wait.
Comment 11 Dani Megert CLA 2011-04-21 09:22:36 EDT
Ping! Any update?
Comment 12 Deepak Azad CLA 2011-04-21 09:40:32 EDT
(In reply to comment #10)
> > The time out is 10,800 seconds. The test suite takes about 3000 secs to run on
> > the first windows machine, and other test suites take roughly the same amount
> > of time on both machines.
> > ...
> > Hence I do not think that time out should be the problem here.
> 
> Those are event driven tests and hence anything (e.g. an event/pop-up from
> another app or the OS or the screen saver) can influence a test or make it
> stop/wait.

Sure, but without the console log we cannot do anything (as the test suite runs on 3 other machines without any issues). Now that Markus has contributed the fix to output stackdumps to the console log, I am hoping once we get a console log we will be able to identify the problem.
Comment 13 Kim Moir CLA 2011-04-21 10:27:14 EDT
The perf tests for http://download.eclipse.org/eclipse/downloads/drops/I20110421-0100/index.php are still running, once they are done I will copy the console log for the second windows machine over if it's not available already.
Comment 14 Dani Megert CLA 2011-04-26 05:55:09 EDT
Any update on this?
Comment 15 Kim Moir CLA 2011-04-26 09:28:03 EDT
The test result appears to be there for the latest build
http://download.eclipse.org/eclipse/downloads/drops/I20110424-2000/performance/html/org.eclipse.jdt.text.tests_win32perf2.html

Also, the console log is there. ( I had to copy it manually, still investigating why it's not copied automatically)

http://download.eclipse.org/eclipse/downloads/drops/I20110424-2000/performance/consolelogs/winxp.perf2_consolelog.txt
Comment 16 Deepak Azad CLA 2011-04-27 09:50:37 EDT
The testsuite does timeout and thanks to Markus we have the following thread dump

java-test:
     [echo] Running org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite. Result file: C:\buildtest\I20110424-2000\eclipse-testing/results/win32perf2/org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite.xml.
     [java] EclipseTestRunner almost reached timeout '10800000'.
     [java] Thread dump at 2011-04-25 13:27:02 -0400:
     [java] java.lang.Exception: Reference Handler
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
     [java] java.lang.Exception: Framework Active Thread
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.osgi.framework.internal.core.Framework.run(Framework.java:1816)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: WorkbenchTestable
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.swt.widgets.Synchronizer.syncExec(Synchronizer.java:187)
     [java] 	at org.eclipse.ui.internal.UISynchronizer.syncExec(UISynchronizer.java:150)
     [java] 	at org.eclipse.swt.widgets.Display.syncExec(Display.java:4681)
     [java] 	at org.eclipse.ui.internal.testing.WorkbenchTestable.runTest(WorkbenchTestable.java:112)
     [java] 	at org.eclipse.test.UITestApplication.runTests(UITestApplication.java:194)
     [java] 	at org.eclipse.ui.internal.testing.WorkbenchTestable$1.run(WorkbenchTestable.java:71)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: Start Level Event Dispatcher
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
     [java] java.lang.Exception: EclipseTestRunnerTimer
     [java] 	at java.lang.Thread.dumpThreads(Native Method)
     [java] 	at java.lang.Thread.getAllStackTraces(Thread.java:1487)
     [java] 	at org.eclipse.test.EclipseTestRunner$1.dump(EclipseTestRunner.java:294)
     [java] 	at org.eclipse.test.EclipseTestRunner$1.run(EclipseTestRunner.java:281)
     [java] 	at java.util.TimerThread.mainLoop(Timer.java:512)
     [java] 	at java.util.TimerThread.run(Timer.java:462)
     [java] java.lang.Exception: [Timer] - Main Queue Handler
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.equinox.internal.util.impl.tpt.timer.TimerImpl.run(TimerImpl.java:141)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: Attach Listener
     [java] java.lang.Exception: Worker-10
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
     [java] 	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:50)
     [java] java.lang.Exception: Java indexing
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.jdt.internal.core.search.processing.JobManager.run(JobManager.java:382)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: Framework Event Dispatcher
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
     [java] java.lang.Exception: Thread-43
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.jdt.text.tests.performance.DisplayWaiter$1.waitForTimeout(DisplayWaiter.java:285)
     [java] 	at org.eclipse.jdt.text.tests.performance.DisplayWaiter$1.run2(DisplayWaiter.java:250)
     [java] 	at org.eclipse.jdt.text.tests.performance.DisplayWaiter$1.run(DisplayWaiter.java:220)
     [java] java.lang.Exception: [ThreadPool Manager] - Idle Thread
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Executor.java:106)
     [java] java.lang.Exception: Worker-11
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
     [java] 	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:50)
     [java] java.lang.Exception: Worker-JM
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.core.internal.jobs.InternalWorker.run(InternalWorker.java:58)
     [java] java.lang.Exception: Signal Dispatcher
     [java] java.lang.Exception: Finalizer
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
     [java] 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
     [java] 	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
     [java] java.lang.Exception: State Data Manager
     [java] 	at java.lang.Thread.sleep(Native Method)
     [java] 	at org.eclipse.osgi.internal.baseadaptor.StateManager.run(StateManager.java:297)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: main
     [java] 	at org.eclipse.swt.internal.win32.OS.ScrollWindowEx(Native Method)
     [java] 	at org.eclipse.swt.widgets.Canvas.scroll(Canvas.java:249)
     [java] 	at org.eclipse.swt.custom.StyledText.scroll(StyledText.java:7813)
     [java] 	at org.eclipse.swt.custom.StyledText.scrollVertical(StyledText.java:7893)
     [java] 	at org.eclipse.swt.custom.StyledText.showLocation(StyledText.java:10062)
     [java] 	at org.eclipse.swt.custom.StyledText.showCaret(StyledText.java:10085)
     [java] 	at org.eclipse.swt.custom.StyledText.doLineDown(StyledText.java:2610)
     [java] 	at org.eclipse.swt.custom.StyledText.doSelectionLineDown(StyledText.java:3270)
     [java] 	at org.eclipse.swt.custom.StyledText.invokeAction(StyledText.java:6929)
     [java] 	at org.eclipse.swt.custom.StyledText.handleKey(StyledText.java:5915)
     [java] 	at org.eclipse.swt.custom.StyledText.handleKeyDown(StyledText.java:5941)
     [java] 	at org.eclipse.swt.custom.StyledText$7.handleEvent(StyledText.java:5635)
     [java] 	at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:84)
     [java] 	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1053)
     [java] 	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1077)
     [java] 	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1062)
     [java] 	at org.eclipse.swt.widgets.Widget.sendKeyEvent(Widget.java:1104)
     [java] 	at org.eclipse.swt.widgets.Widget.sendKeyEvent(Widget.java:1100)
     [java] 	at org.eclipse.swt.widgets.Widget.wmKeyDown(Widget.java:1809)
     [java] 	at org.eclipse.swt.widgets.Control.WM_KEYDOWN(Control.java:4875)
     [java] 	at org.eclipse.swt.widgets.Control.windowProc(Control.java:4543)
     [java] 	at org.eclipse.swt.widgets.Canvas.windowProc(Canvas.java:341)
     [java] 	at org.eclipse.swt.widgets.Display.windowProc(Display.java:4970)
     [java] 	at org.eclipse.swt.internal.win32.OS.DispatchMessageW(Native Method)
     [java] 	at org.eclipse.swt.internal.win32.OS.DispatchMessage(OS.java:2526)
     [java] 	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3750)
     [java] 	at org.eclipse.jdt.text.tests.performance.EditorTestHelper.runEventQueue(EditorTestHelper.java:196)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.sleepAndRun(ScrollEditorTest.java:319)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:210)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:168)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:152)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollTextEditorTest.testScrollTextEditorLineWiseSelect2(ScrollTextEditorTest.java:60)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     [java] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     [java] 	at java.lang.reflect.Method.invoke(Method.java:597)
     [java] 	at junit.framework.TestCase.runTest(TestCase.java:168)
     [java] 	at junit.framework.TestCase.runBare(TestCase.java:134)
     [java] 	at junit.framework.TestResult$1.protect(TestResult.java:110)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.framework.TestResult.run(TestResult.java:113)
     [java] 	at junit.framework.TestCase.run(TestCase.java:124)
     [java] 	at junit.framework.TestSuite.runTest(TestSuite.java:243)
     [java] 	at junit.framework.TestSuite.run(TestSuite.java:238)
     [java] 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
     [java] 	at junit.extensions.TestSetup$1.protect(TestSetup.java:23)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.extensions.TestSetup.run(TestSetup.java:27)
     [java] 	at junit.framework.TestSuite.runTest(TestSuite.java:243)
     [java] 	at junit.framework.TestSuite.run(TestSuite.java:238)
     [java] 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
     [java] 	at junit.extensions.TestSetup$1.protect(TestSetup.java:23)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.extensions.TestSetup.run(TestSetup.java:27)
     [java] 	at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:495)
     [java] 	at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:259)
     [java] 	at org.eclipse.test.UITestApplication$2.run(UITestApplication.java:197)
     [java] 	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
     [java] 	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:135)
     [java] 	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4138)
     [java] 	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3755)
     [java] 	at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2696)
     [java] 	at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2660)
     [java] 	at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2494)
     [java] 	at org.eclipse.ui.internal.Workbench$7.run(Workbench.java:674)
     [java] 	at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
     [java] 	at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:667)
     [java] 	at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
     [java] 	at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:123)
     [java] 	at org.eclipse.test.UITestApplication.runApplication(UITestApplication.java:140)
     [java] 	at org.eclipse.test.UITestApplication.run(UITestApplication.java:62)
     [java] 	at org.eclipse.test.UITestApplication.start(UITestApplication.java:212)
     [java] 	at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
     [java] 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
     [java] 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
     [java] 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
     [java] 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     [java] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     [java] 	at java.lang.reflect.Method.invoke(Method.java:597)
     [java] 	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
     [java] 	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
     [java] 	at org.eclipse.equinox.launcher.Main.run(Main.java:1410)
     [java] 	at org.eclipse.equinox.launcher.Main.main(Main.java:1386)
     [java] 	at org.eclipse.core.launcher.Main.main(Main.java:34)
     [java] FocusControl: 
     [java] StyledText {}
     [java] Canvas {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Shell {Java - org.eclipse.swt/Eclipse SWT/win32/org/eclipse/swt/graphics/TextLayout.java - Eclipse SDK}
     [java] Shells: 
     [java] visible: Shell {Java - org.eclipse.swt/Eclipse SWT/win32/org/eclipse/swt/graphics/TextLayout.java - Eclipse SDK}
     [java] EclipseTestRunner almost reached timeout '10800000'.
     [java] Thread dump at 2011-04-25 13:27:05 -0400:
     [java] java.lang.Exception: Reference Handler
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
     [java] java.lang.Exception: Framework Active Thread
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.osgi.framework.internal.core.Framework.run(Framework.java:1816)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: WorkbenchTestable
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.swt.widgets.Synchronizer.syncExec(Synchronizer.java:187)
     [java] 	at org.eclipse.ui.internal.UISynchronizer.syncExec(UISynchronizer.java:150)
     [java] 	at org.eclipse.swt.widgets.Display.syncExec(Display.java:4681)
     [java] 	at org.eclipse.ui.internal.testing.WorkbenchTestable.runTest(WorkbenchTestable.java:112)
     [java] 	at org.eclipse.test.UITestApplication.runTests(UITestApplication.java:194)
     [java] 	at org.eclipse.ui.internal.testing.WorkbenchTestable$1.run(WorkbenchTestable.java:71)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: Start Level Event Dispatcher
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
     [java] java.lang.Exception: EclipseTestRunnerTimer
     [java] 	at java.lang.Thread.dumpThreads(Native Method)
     [java] 	at java.lang.Thread.getAllStackTraces(Thread.java:1487)
     [java] 	at org.eclipse.test.EclipseTestRunner$1.dump(EclipseTestRunner.java:294)
     [java] 	at org.eclipse.test.EclipseTestRunner$1.run(EclipseTestRunner.java:287)
     [java] 	at java.util.TimerThread.mainLoop(Timer.java:512)
     [java] 	at java.util.TimerThread.run(Timer.java:462)
     [java] java.lang.Exception: [Timer] - Main Queue Handler
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.equinox.internal.util.impl.tpt.timer.TimerImpl.run(TimerImpl.java:141)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: Attach Listener
     [java] java.lang.Exception: Worker-10
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
     [java] 	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:50)
     [java] java.lang.Exception: Java indexing
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.jdt.internal.core.search.processing.JobManager.run(JobManager.java:382)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: Framework Event Dispatcher
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
     [java] 	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)
     [java] java.lang.Exception: Thread-43
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.jdt.text.tests.performance.DisplayWaiter$1.waitForTimeout(DisplayWaiter.java:285)
     [java] 	at org.eclipse.jdt.text.tests.performance.DisplayWaiter$1.run2(DisplayWaiter.java:250)
     [java] 	at org.eclipse.jdt.text.tests.performance.DisplayWaiter$1.run(DisplayWaiter.java:220)
     [java] java.lang.Exception: [ThreadPool Manager] - Idle Thread
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.Object.wait(Object.java:485)
     [java] 	at org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Executor.java:106)
     [java] java.lang.Exception: Worker-11
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
     [java] 	at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
     [java] 	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:50)
     [java] java.lang.Exception: Worker-JM
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at org.eclipse.core.internal.jobs.InternalWorker.run(InternalWorker.java:58)
     [java] java.lang.Exception: Signal Dispatcher
     [java] java.lang.Exception: Finalizer
     [java] 	at java.lang.Object.wait(Native Method)
     [java] 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
     [java] 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
     [java] 	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
     [java] java.lang.Exception: State Data Manager
     [java] 	at java.lang.Thread.sleep(Native Method)
     [java] 	at org.eclipse.osgi.internal.baseadaptor.StateManager.run(StateManager.java:297)
     [java] 	at java.lang.Thread.run(Thread.java:619)
     [java] java.lang.Exception: main
     [java] 	at org.eclipse.swt.internal.win32.OS.ScrollWindowEx(Native Method)
     [java] 	at org.eclipse.swt.widgets.Canvas.scroll(Canvas.java:249)
     [java] 	at org.eclipse.swt.custom.StyledText.scroll(StyledText.java:7813)
     [java] 	at org.eclipse.swt.custom.StyledText.scrollVertical(StyledText.java:7893)
     [java] 	at org.eclipse.swt.custom.StyledText.showLocation(StyledText.java:10062)
     [java] 	at org.eclipse.swt.custom.StyledText.showCaret(StyledText.java:10085)
     [java] 	at org.eclipse.swt.custom.StyledText.doLineDown(StyledText.java:2610)
     [java] 	at org.eclipse.swt.custom.StyledText.doSelectionLineDown(StyledText.java:3270)
     [java] 	at org.eclipse.swt.custom.StyledText.invokeAction(StyledText.java:6929)
     [java] 	at org.eclipse.swt.custom.StyledText.handleKey(StyledText.java:5915)
     [java] 	at org.eclipse.swt.custom.StyledText.handleKeyDown(StyledText.java:5941)
     [java] 	at org.eclipse.swt.custom.StyledText$7.handleEvent(StyledText.java:5635)
     [java] 	at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:84)
     [java] 	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1053)
     [java] 	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1077)
     [java] 	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1062)
     [java] 	at org.eclipse.swt.widgets.Widget.sendKeyEvent(Widget.java:1104)
     [java] 	at org.eclipse.swt.widgets.Widget.sendKeyEvent(Widget.java:1100)
     [java] 	at org.eclipse.swt.widgets.Widget.wmKeyDown(Widget.java:1809)
     [java] 	at org.eclipse.swt.widgets.Control.WM_KEYDOWN(Control.java:4875)
     [java] 	at org.eclipse.swt.widgets.Control.windowProc(Control.java:4543)
     [java] 	at org.eclipse.swt.widgets.Canvas.windowProc(Canvas.java:341)
     [java] 	at org.eclipse.swt.widgets.Display.windowProc(Display.java:4970)
     [java] 	at org.eclipse.swt.internal.win32.OS.DispatchMessageW(Native Method)
     [java] 	at org.eclipse.swt.internal.win32.OS.DispatchMessage(OS.java:2526)
     [java] 	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3750)
     [java] 	at org.eclipse.jdt.text.tests.performance.EditorTestHelper.runEventQueue(EditorTestHelper.java:196)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.sleepAndRun(ScrollEditorTest.java:319)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:210)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:168)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:152)
     [java] 	at org.eclipse.jdt.text.tests.performance.ScrollTextEditorTest.testScrollTextEditorLineWiseSelect2(ScrollTextEditorTest.java:60)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     [java] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     [java] 	at java.lang.reflect.Method.invoke(Method.java:597)
     [java] 	at junit.framework.TestCase.runTest(TestCase.java:168)
     [java] 	at junit.framework.TestCase.runBare(TestCase.java:134)
     [java] 	at junit.framework.TestResult$1.protect(TestResult.java:110)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.framework.TestResult.run(TestResult.java:113)
     [java] 	at junit.framework.TestCase.run(TestCase.java:124)
     [java] 	at junit.framework.TestSuite.runTest(TestSuite.java:243)
     [java] 	at junit.framework.TestSuite.run(TestSuite.java:238)
     [java] 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
     [java] 	at junit.extensions.TestSetup$1.protect(TestSetup.java:23)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.extensions.TestSetup.run(TestSetup.java:27)
     [java] 	at junit.framework.TestSuite.runTest(TestSuite.java:243)
     [java] 	at junit.framework.TestSuite.run(TestSuite.java:238)
     [java] 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
     [java] 	at junit.extensions.TestSetup$1.protect(TestSetup.java:23)
     [java] 	at junit.framework.TestResult.runProtected(TestResult.java:128)
     [java] 	at junit.extensions.TestSetup.run(TestSetup.java:27)
     [java] 	at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:495)
     [java] 	at org.eclipse.test.EclipseTestRunner.run(EclipseTestRunner.java:259)
     [java] 	at org.eclipse.test.UITestApplication$2.run(UITestApplication.java:197)
     [java] 	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
     [java] 	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:135)
     [java] 	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4138)
     [java] 	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3755)
     [java] 	at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2696)
     [java] 	at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2660)
     [java] 	at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2494)
     [java] 	at org.eclipse.ui.internal.Workbench$7.run(Workbench.java:674)
     [java] 	at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
     [java] 	at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:667)
     [java] 	at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
     [java] 	at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:123)
     [java] 	at org.eclipse.test.UITestApplication.runApplication(UITestApplication.java:140)
     [java] 	at org.eclipse.test.UITestApplication.run(UITestApplication.java:62)
     [java] 	at org.eclipse.test.UITestApplication.start(UITestApplication.java:212)
     [java] 	at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
     [java] 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
     [java] 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
     [java] 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
     [java] 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
     [java] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
     [java] 	at java.lang.reflect.Method.invoke(Method.java:597)
     [java] 	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
     [java] 	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
     [java] 	at org.eclipse.equinox.launcher.Main.run(Main.java:1410)
     [java] 	at org.eclipse.equinox.launcher.Main.main(Main.java:1386)
     [java] 	at org.eclipse.core.launcher.Main.main(Main.java:34)
     [java] FocusControl: 
     [java] StyledText {}
     [java] Canvas {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Composite {}
     [java] Shell {Java - org.eclipse.swt/Eclipse SWT/win32/org/eclipse/swt/graphics/TextLayout.java - Eclipse SDK}
     [java] Shells: 
     [java] visible: Shell {Java - org.eclipse.swt/Eclipse SWT/win32/org/eclipse/swt/graphics/TextLayout.java - Eclipse SDK}
     [java] Timeout: killed the sub-process
     [java] Java Result: -1

collect-results:
[junitreport] the file C:\buildtest\I20110424-2000\eclipse-testing\test-eclipse\eclipse\org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite.xml is empty.
[junitreport] This can be caused by the test JVM exiting unexpectedly
     [xslt] Transforming into C:\buildtest\I20110424-2000\eclipse-testing\results\win32perf2

cleanup:

performance:

collect:
[junitreport] the file C:\buildtest\I20110424-2000\eclipse-testing\test-eclipse\eclipse\org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite.xml is empty.
[junitreport] This can be caused by the test JVM exiting unexpectedly
Comment 17 Deepak Azad CLA 2011-04-29 06:09:51 EDT
Created attachment 194345 [details]
the thread dump

pasting the dump as a comment ruined the formatting..
Comment 18 Deepak Azad CLA 2011-04-29 06:52:18 EDT
(In reply to comment #4)
> This test suite is the last in jdt.text performance tests and has a timeout,
> other tests do not have a timeout.
>     <ant target="ui-test" antfile="${library-file}" dir="${eclipse-home}">
>       <property name="timeout" value="10800000"/>
>       <property name="vmargs" value="-Xms250M -Xmx250M"/>
>       <property name="data-dir" value="${jdt-text-performance-folder}"/>
>       <property name="plugin-name" value="${plugin-name}"/>
>       <property name="classname"
> value="org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite"/>
>     </ant>

I had a chat with Markus about this bug and he suggested to increase the timeout from 3hrs to 4hrs. I will try this for the next build.
Comment 19 Deepak Azad CLA 2011-05-04 07:35:43 EDT
(In reply to comment #18)
> (In reply to comment #4)
> > This test suite is the last in jdt.text performance tests and has a timeout,
> > other tests do not have a timeout.
> >     <ant target="ui-test" antfile="${library-file}" dir="${eclipse-home}">
> >       <property name="timeout" value="10800000"/>
> >       <property name="vmargs" value="-Xms250M -Xmx250M"/>
> >       <property name="data-dir" value="${jdt-text-performance-folder}"/>
> >       <property name="plugin-name" value="${plugin-name}"/>
> >       <property name="classname"
> > value="org.eclipse.jdt.text.tests.performance.EventDrivenTestSuite"/>
> >     </ant>
> 
> I had a chat with Markus about this bug and he suggested to increase the
> timeout from 3hrs to 4hrs. I will try this for the next build.

I have made this change in HEAD. Fingers crossed for the outcome of today's nightly build with performance results :)
Comment 21 Deepak Azad CLA 2011-05-10 13:11:56 EDT
http://download.eclipse.org/eclipse/downloads/drops/I20110509-1200/performance/performance.php

Kim, the console log for the 2nd win machine is again missing for the latest I Build. Is there a bug open for this issue? (I could not find one)

Would it be possible for you to manually copy the log for this I-Build ?
Comment 22 Kim Moir CLA 2011-05-10 13:51:49 EDT
I manually copied it for this I-build. 

The missing console log is covered in bug 343814.
Comment 23 Deepak Azad CLA 2011-05-11 05:17:31 EDT
Created attachment 195311 [details]
the thread dump v2

(In reply to comment #22)
> I manually copied it for this I-build. 
Thanks Kim!

This time also the suite is hung at 
     [java] 	at org.eclipse.swt.internal.win32.OS.ScrollWindowEx(Native Method)
     [java] 	at org.eclipse.swt.widgets.Canvas.scroll(Canvas.java:249)
     [java] 	at org.eclipse.swt.custom.StyledText.scroll(StyledText.java:7813)

However in a different test : org.eclipse.jdt.text.tests.performance.WhitespaceCharacterPainterTest.testScrollTextEditorLineWiseMoveCaret2(WhitespaceCharacterPainterTest.java:68)

Last time it was in :
org.eclipse.jdt.text.tests.performance.ScrollTextEditorTest.testScrollTextEditorLineWiseSelect2(ScrollTextEditorTest.java:60)

I have attached the complete stack trace.
Comment 24 Dani Megert CLA 2011-05-11 06:02:27 EDT
Silenio, any idea why it might hang in
org.eclipse.swt.internal.win32.OS.ScrollWindowEx(Native Method)?
Comment 25 Markus Keller CLA 2011-05-11 07:20:59 EDT
(In reply to comment #23)
After increasing the timeout, the suite is killed a few tests later. I filed bug 345400 to find out whether it could be a memory issue (GC overhead). That would still be strange, since the same test happily passes on the other machine with the same vmargs (-Xms250M -Xmx250M), but you never know...
Comment 26 Silenio Quarti CLA 2011-05-11 10:45:26 EDT
(In reply to comment #24)
> Silenio, any idea why it might hang in
> org.eclipse.swt.internal.win32.OS.ScrollWindowEx(Native Method)?

No idea. ScrollWindowEx() just copies pixels on the window, it should not hung.
Comment 27 Markus Keller CLA 2011-05-13 10:39:43 EDT
Kim, could you please copy consolelogs/winxp.perf2_consolelog.txt for I20110512-0800 (or I20110512-1400) again?
Comment 28 Kim Moir CLA 2011-05-13 11:34:10 EDT
I copied over the log for I20110512-0800. The perf tests for I20110512-1400 are still running.
Comment 29 Markus Keller CLA 2011-05-13 13:24:24 EDT
Created attachment 195609 [details]
Log from I20110512-0800

Thanks, Kim. The new memory information shows that the heap is not the problem.

This time, the thread dumps were at:

     [java] java.lang.Exception: main
     [java] 	at org.eclipse.swt.internal.win32.OS.ShowCaret(Native Method)
     [java] 	at org.eclipse.swt.widgets.Caret.setFocus(Caret.java:418)
     [java] 	at org.eclipse.swt.widgets.Canvas.scroll(Canvas.java:262)
     [java] 	at org.eclipse.swt.custom.StyledText.scroll(StyledText.java:7813)
     [java] 	at org.eclipse.swt.custom.StyledText.scrollVertical(StyledText.java:7893)
     [java] 	at org.eclipse.swt.custom.StyledText.showLocation(StyledText.java:10062)
     [java] 	at org.eclipse.swt.custom.StyledText.showCaret(StyledText.java:10085)
     [java] 	at      [java] 	at org.eclipse.swt.custom.StyledText.doLineDown(StyledText.java:2610)
     [java] 	at org.eclipse.swt.custom.StyledText.invokeAction(StyledText.java:6870)
     [java] 	at org.eclipse.swt.custom.StyledText.handleKey(StyledText.java:5915)
     [java] 	at org.eclipse.swt.custom.StyledText.handleKeyDown(StyledText.java:5941)
     [java] 	at org.eclipse.swt.custom.StyledText$7.handleEvent(StyledText.java:5635)
     [java] 	at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:84)
[..]
     [java] 	at org.eclipse.jdt.text.tests.performance.WhitespaceCharacterPainterTest.testScrollTextEditorLineWiseMoveCaret2(WhitespaceCharacterPainterTest.java:68)

... and 5 seconds later:

     [java] java.lang.Exception: main
     [java] 	at org.eclipse.swt.internal.win32.OS.SetScrollInfo(Native Method)
     [java] 	at org.eclipse.swt.widgets.ScrollBar.SetScrollInfo(ScrollBar.java:771)
     [java] 	at org.eclipse.swt.widgets.ScrollBar.setMaximum(ScrollBar.java:692)
     [java] 	at org.eclipse.swt.custom.StyledText.setScrollBars(StyledText.java:9311)
     [java] 	at org.eclipse.swt.custom.StyledText.calculateTopIndex(StyledText.java:1631)
     [java] 	at org.eclipse.swt.custom.StyledText.scrollVertical(StyledText.java:7913)
     [java] 	at org.eclipse.swt.custom.StyledText.showLocation(StyledText.java:10062)
[..]
     [java] 	at org.eclipse.jdt.text.tests.performance.WhitespaceCharacterPainterTest.testScrollTextEditorLineWiseMoveCaret2(WhitespaceCharacterPainterTest.java:68)

=> We clearly see some progress here (but we still can't tell whether we're in the same invocation of "StyledText.showLocation(StyledText.java:10062)").

I think we should revert the timeout to the default and then add more logging to find out which tests are so slow.
Comment 30 Markus Keller CLA 2011-05-13 14:30:42 EDT
Created attachment 195621 [details]
Add time logging when tests start
Comment 31 Markus Keller CLA 2011-05-13 14:56:34 EDT
Released the logging patch for RC2.
Comment 32 Deepak Azad CLA 2011-05-17 00:19:33 EDT
(In reply to comment #31)
> Released the logging patch for RC2.

Kim, can you please copy the log for I20110514-0800 ? :)
Comment 34 Markus Keller CLA 2011-05-17 12:36:35 EDT
(In reply to comment #33)
Thanks. Unfortunately, we need the sysout log this time, since winxp.perf2_consolelog.txt only captures syserr messages from the tests.

This is the analogon to e.g. http://download.eclipse.org/eclipse/downloads/drops/I20110514-0800/testresults/win32.win32.x86_6.0/org.eclipse.jdt.text.tests.jdttexttestsuite.txt, but for the performance tests. I filed bug 346122 to make it easier for us to find such files.
Comment 35 Deepak Azad CLA 2011-05-17 12:38:27 EDT
(In reply to comment #34)
> (In reply to comment #33)
> Thanks. Unfortunately, we need the sysout log this time, since
> winxp.perf2_consolelog.txt only captures syserr messages from the tests.
Ha! I didn't know that, and hence was wondering where is the debug info :)
Comment 36 Markus Keller CLA 2011-05-19 08:40:13 EDT
Found the log on the internal server at /downloads/drops/I20110518-0800/performance/win32perf2/org.eclipse.jdt.text.tests.performance.eventdriventestsuite.txt

On win32perf1, all the tests take about 1-2 minutes:

2011-05-18 12:02:54.765 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorPageWise
2011-05-18 12:04:06.218 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWiseMoveCaret2
2011-05-18 12:06:48.078 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWiseSelect2
2011-05-18 12:09:42.656 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWise2
2011-05-18 12:11:19.531 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWiseSelectHoldKeys


On win32perf2, the *LineWise* tests take 30-40 minutes each:

2011-05-18 11:57:26.500 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorPageWise
2011-05-18 11:59:44.500 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWiseMoveCaret2
2011-05-18 12:36:58.343 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWiseSelect2
2011-05-18 13:13:25.718 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWise2
2011-05-18 13:48:14.343 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWiseSelectHoldKeys
holding scroll tests disabled
2011-05-18 13:48:22.343 -0400: org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorLineWiseHoldKeys
holding scroll tests disabled
2011-05-18 13:48:30.343 -0400: org.eclipse.jdt.text.tests.performance.ScrollTextEditorTest.testScrollTextEditorPageWise
2011-05-18 13:50:37.187 -0400: org.eclipse.jdt.text.tests.performance.ScrollTextEditorTest.testScrollTextEditorLineWiseMoveCaret2
2011-05-18 14:28:20.796 -0400: org.eclipse.jdt.text.tests.performance.ScrollTextEditorTest.testScrollTextEditorLineWiseSelect2

I'm currently out of ideas on how to debug this further without getting access to the test machine and running the tests with a profiler.
Comment 37 Dani Megert CLA 2011-05-19 09:16:26 EDT
Kim, is there any way to access this machine remotely and watch the test running?
Comment 38 Kim Moir CLA 2011-05-19 10:04:00 EDT
I'm working with our sysadmin to enable this.  This is working for epwin2, but not epwin3.  I'll send you the instructions on how to do this once we have it working.
Comment 39 Markus Keller CLA 2011-05-19 12:34:37 EDT
Gotcha! The tests ran at normal speed when I ran them manually via Remote Desktop Connection. But when I started them, closed the connection, and only came back 30 min later, I saw a window with title "Keyboard Probe" that was coming from the same process as the test workbench.

=> Problem are the "fDisplay.sleep()" calls in org.eclipse.jdt.text.tests.performance.KeyboardProbe. They take forever when no display is connected.
Comment 40 Kim Moir CLA 2011-05-19 13:02:39 EDT
Wow, that's great.  Thanks Markus!
Comment 41 Markus Keller CLA 2011-05-19 13:25:32 EDT
Created attachment 196141 [details]
Fix for KeyboardProbe

Patch removes the Display#sleep(), removes the prolonged timeout, and disables the tracing (DebugSetup). Released to HEAD for next I-build.
Comment 42 Dani Megert CLA 2011-05-20 01:52:06 EDT
Cool! Any idea why it works on the other Windows machine?

Once we can confirm that it works we have to backport the fix to the perf branch.
Comment 43 Markus Keller CLA 2011-05-22 12:37:59 EDT
> Any idea why it works on the other Windows machine?

Maybe the other machine has a real display connected (or at least a graphics card installed)? Or the display on one machine is powered and the other is not.
Kim, do you know anything about the hardware differences?
Comment 44 Deepak Azad CLA 2011-05-24 00:25:40 EDT
(In reply to comment #41)
> Created attachment 196141 [details] [diff]
> Fix for KeyboardProbe
> 
> Patch removes the Display#sleep(), removes the prolonged timeout, and disables
> the tracing (DebugSetup). Released to HEAD for next I-build.

Looks like this did not help: http://download.eclipse.org/eclipse/downloads/drops/I20110521-0800/performance/html/org.eclipse.jdt.text.tests_win32perf2.html
Comment 45 Dani Megert CLA 2011-05-24 01:57:48 EDT
:-(
Comment 46 Markus Keller CLA 2011-05-24 07:05:13 EDT
Created attachment 196423 [details]
remove Display#sleep() from ScrollEditorTest

Hmm, looking closer at the EventDrivenTestSuite, I found that the KeyboardProbe problem only would shows up a lot later on win32perf2 (after the timeout already killed the whole session). The KeyboardProbe fix still makes sense, so I'll leave that in.

Here's another patch that removes the last unsafe Display#sleep() in org.eclipse.jdt.text.tests (in ScrollEditorTest which is actually run before the timeout). The patch also enables logging in setUp and tearDown again.

Released to HEAD for next build.
Comment 47 Markus Keller CLA 2011-05-26 04:44:04 EDT
Kim, I don't see any Windows perf test results on I20110524-0900 nor on I20110525-0800. Could you please copy the latest results (including the consolelogs)?
Comment 48 Kim Moir CLA 2011-05-26 08:45:58 EDT
Performance results for I20110524-0900
http://download.eclipse.org/eclipse/downloads/drops/I20110524-0900/performance/performance.php

are now available.

windows tests for I20110525-0900 are still running.  I'm going to reboot the windows machines.  It seems like results for the windows machines aren't being generated.
Comment 49 Markus Keller CLA 2011-05-27 10:05:01 EDT
Thanks, the rebooting helped.

Unfortunately, my last fix didn't help. The *LineWise* tests still need > 30min.:
http://download.eclipse.org/eclipse/downloads/drops/I20110526-0800/performance/win32perf2/org.eclipse.jdt.text.tests.performance.eventdriventestsuite.txt

I'll have to debug this again on the real machine.
Comment 50 Deepak Azad CLA 2011-05-27 10:31:17 EDT
(In reply to comment #46)
> Here's another patch that removes the last unsafe Display#sleep() in
> org.eclipse.jdt.text.tests (in ScrollEditorTest which is actually run before
> the timeout). 

Not sure if these are unsafe calls or not, but DisplayHelper includes a few calls to Display#sleep(). E.g. DisplayHelper.waitForCondition(Display, long) includes a call to Display#sleep(), and this method is called from ScrollEditorTest.
Comment 51 Markus Keller CLA 2011-05-27 11:34:48 EDT
(In reply to comment #50)
Those should be safe assuming that the comment in 
DisplayWaiter.startThread().new Thread() {...}.waitForTimeout() is valid:
// wait at least 50ms in order to avoid timing out before the display is going to sleep

When the waiter times out, it calls fDisplay.wake(), which interrupts the sleep.
Comment 52 Markus Keller CLA 2011-05-31 11:30:08 EDT
I'm out of ideas. Whatever I tried to reproduce the problem, the tests ran without delay. 

We'll defer this bug to 3.8. We could try to increase the timeout to seeveral hours and then add a vm argument like this:
-agentlib:jdwp=transport=dt_socket,suspend=y,server=y,address=80

That should allow us to remote-attach the debugger when we know approximately when the performance tests will be started.

Note that the EventDrivenTestSuite also often fails on Linkux, e.g. like this:

junit.framework.AssertionFailedError: Never scrolled to the bottom within 2000ms.
TopIndex: 7751 visibleLines: 28 totalLines: 7779 operations: 277
at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:227)
at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:167)
at org.eclipse.jdt.text.tests.performance.ScrollEditorTest.measure(ScrollEditorTest.java:152)
at org.eclipse.jdt.text.tests.performance.ScrollJavaEditorTest.testScrollJavaEditorPageWise(ScrollJavaEditorTest.java:41)
Comment 53 Markus Keller CLA 2012-04-24 11:40:27 EDT
Closing for now. We can reopen if this happens again.