Bug 63247 - searching for files in workspace takes a long time
Summary: searching for files in workspace takes a long time
Status: RESOLVED WORKSFORME
Alias: None
Product: Platform
Classification: Eclipse Project
Component: Search (show other bugs)
Version: 3.0   Edit
Hardware: PC Windows XP
: P2 normal (vote)
Target Milestone: ---   Edit
Assignee: Platform-Search-Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 63248 (view as bug list)
Depends on:
Blocks:
 
Reported: 2004-05-20 12:42 EDT by John Wiegand CLA
Modified: 2005-06-08 06:57 EDT (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description John Wiegand CLA 2004-05-20 12:42:52 EDT
20040520

1. Create a full source workspace (I just used import existing plugins)
2. Search files for all files named "*.java"
3. This stops 15% of the way done.  

Stack trace follows
Full thread dump Java HotSpot(TM) Client VM (1.4.2_04-b05 mixed mode):

"Worker-14" prio=5 tid=0x031a8780 nid=0xe44 in Object.wait() [462f000..462fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x117898b8> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:209)
        - locked <0x117898b8> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob
(WorkerPool.java:23
6)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:59)

"Worker-13" prio=5 tid=0x0327b5a0 nid=0xed4 in Object.wait() [44df000..44dfd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x117898b8> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:209)
        - locked <0x117898b8> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob
(WorkerPool.java:23
6)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:59)

"Worker-11" prio=5 tid=0x0327fbe0 nid=0xe28 waiting for monitor entry 
[3b4f000..
3b4fd8c]
        at 
org.eclipse.search.ui.text.AbstractTextSearchViewPage.handleSearchRes
ultsChanged(AbstractTextSearchViewPage.java:940)
        - waiting to lock <0x15b540b8> (a 
org.eclipse.search.internal.ui.text.Fi
leSearchPage)
        at org.eclipse.search.ui.text.AbstractTextSearchViewPage.access$6
(Abstra
ctTextSearchViewPage.java:939)
        at 
org.eclipse.search.ui.text.AbstractTextSearchViewPage$1.searchResultC
hanged(AbstractTextSearchViewPage.java:200)
        at org.eclipse.search.ui.text.AbstractTextSearchResult.fireChange
(Abstra
ctTextSearchResult.java:263)
        at org.eclipse.search.ui.text.AbstractTextSearchResult.addMatch
(Abstract
TextSearchResult.java:82)
        at org.eclipse.search.internal.ui.text.FileSearchQuery$1.accept
(FileSear
chQuery.java:67)
        at org.eclipse.search.internal.core.text.TextSearchVisitor.visitFile
(Tex
tSearchVisitor.java:138)
        at org.eclipse.search.internal.core.text.TypedResourceVisitor.visit
(Type
dResourceVisitor.java:53)
        at org.eclipse.search.internal.core.text.TextSearchVisitor.visit
(TextSea
rchVisitor.java:200)
        at org.eclipse.core.internal.resources.Resource$1.visitElement
(Resource.
java:54)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:78)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.doIteration
(Elem
entTreeIterator.java:82)
        at org.eclipse.core.internal.watson.ElementTreeIterator.iterate
(ElementT
reeIterator.java:123)
        at org.eclipse.core.internal.resources.Resource.accept
(Resource.java:64)

        at org.eclipse.search.internal.core.text.TextSearchVisitor.process
(TextS
earchVisitor.java:91)
        at org.eclipse.search.internal.core.text.TextSearchEngine.search
(TextSea
rchEngine.java:61)
        at org.eclipse.search.internal.ui.text.FileSearchQuery.run
(FileSearchQue
ry.java:74)
        at 
org.eclipse.search2.internal.ui.InternalSearchUI$InternalSearchJob.ru
n(InternalSearchUI.java:82)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:66)

"Worker-6" prio=5 tid=0x03107990 nid=0xd48 in Object.wait() [3bcf000..3bcfd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x117898b8> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:209)
        - locked <0x117898b8> (a org.eclipse.core.internal.jobs.WorkerPool)
        at org.eclipse.core.internal.jobs.WorkerPool.startJob
(WorkerPool.java:23
6)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:59)

"Java indexing" daemon prio=4 tid=0x02e26488 nid=0xe18 in Object.wait() 
[407f000
..407fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x119adec8> (a 
org.eclipse.jdt.internal.core.search.indexi
ng.IndexManager)
        at java.lang.Object.wait(Object.java:429)
        at org.eclipse.jdt.internal.core.search.processing.JobManager.run
(JobMan
ager.java:344)
        - locked <0x119adec8> (a 
org.eclipse.jdt.internal.core.search.indexing.I
ndexManager)
        at java.lang.Thread.run(Thread.java:534)

"Thread-1" prio=7 tid=0x02de79b8 nid=0xa6c in Object.wait() [3aaf000..3aafd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x117e62a0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x117e62a0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at 
org.eclipse.jface.action.ActionContributionItem$ImageCache$ReferenceC
leanerThread.run(ActionContributionItem.java:196)

"Thread-0" prio=7 tid=0x02f0ad68 nid=0xec0 in Object.wait() [3a6f000..3a6fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x117e6310> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x117e6310> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at 
org.eclipse.jface.action.ActionContributionItem$ImageCache$ReferenceC
leanerThread.run(ActionContributionItem.java:196)

"Start Level Event Dispatcher" daemon prio=5 tid=0x00a509b0 nid=0xca4 in 
Object.
wait() [2fbf000..2fbfd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x113ec4f0> (a 
org.eclipse.osgi.framework.eventmgr.EventTh
read)
        at java.lang.Object.wait(Object.java:429)
        at org.eclipse.osgi.framework.eventmgr.EventThread.getNextEvent
(EventThr
ead.java:162)
        - locked <0x113ec4f0> (a 
org.eclipse.osgi.framework.eventmgr.EventThread
)
        at org.eclipse.osgi.framework.eventmgr.EventThread.run
(EventThread.java:
100)

"Framework Event Dispatcher" daemon prio=5 tid=0x02d88ea8 nid=0xfa0 in 
Object.wa
it() [2f7f000..2f7fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x113ec598> (a 
org.eclipse.osgi.framework.eventmgr.EventTh
read)
        at java.lang.Object.wait(Object.java:429)
        at org.eclipse.osgi.framework.eventmgr.EventThread.getNextEvent
(EventThr
ead.java:162)
        - locked <0x113ec598> (a 
org.eclipse.osgi.framework.eventmgr.EventThread
)
        at org.eclipse.osgi.framework.eventmgr.EventThread.run
(EventThread.java:
100)

"Signal Dispatcher" daemon prio=10 tid=0x0003d808 nid=0xf9c waiting on 
condition
 [0..0]

"Finalizer" daemon prio=9 tid=0x009bfdb8 nid=0x500 in Object.wait() 
[2c1f000..2c
1fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x113ca928> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x113ca928> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x009be988 nid=0xd8c in Object.wait() 
[2b
df000..2bdfd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x113ca990> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:429)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
        - locked <0x113ca990> (a java.lang.ref.Reference$Lock)

"main" prio=7 tid=0x000352d0 nid=0x27c waiting on condition [7e000..7fc3c]
        at org.eclipse.swt.widgets.Table.wmNotifyChild(Table.java:3181)
        at org.eclipse.swt.widgets.Control.WM_NOTIFY(Control.java:3984)
        at org.eclipse.swt.widgets.Composite.WM_NOTIFY(Composite.java:722)
        at org.eclipse.swt.widgets.Control.windowProc(Control.java:3000)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:3282)
        at org.eclipse.swt.internal.win32.OS.CallWindowProcW(Native Method)
        at org.eclipse.swt.internal.win32.OS.CallWindowProc(OS.java:1399)
        at org.eclipse.swt.widgets.Table.callWindowProc(Table.java:137)
        at org.eclipse.swt.widgets.Control.windowProc(Control.java:3031)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:3282)
        at org.eclipse.swt.internal.win32.OS.SendMessageW(Native Method)
        at org.eclipse.swt.internal.win32.OS.SendMessage(OS.java:1988)
        at org.eclipse.swt.widgets.Table.setScrollWidth(Table.java:2446)
        at org.eclipse.swt.widgets.TableItem.setImage(TableItem.java:915)
        at org.eclipse.jface.viewers.TableViewer.doUpdateItem
(TableViewer.java:2
21)
        at 
org.eclipse.jface.viewers.StructuredViewer$UpdateItemSafeRunnable.run
(StructuredViewer.java:128)
        at org.eclipse.core.internal.runtime.InternalPlatform.run
(InternalPlatfo
rm.java:608)
        at org.eclipse.core.runtime.Platform.run(Platform.java:758)
        at org.eclipse.jface.viewers.StructuredViewer.updateItem
(StructuredViewe
r.java:1368)
        at org.eclipse.jface.viewers.TableViewer.add(TableViewer.java:116)
        at org.eclipse.jface.viewers.TableViewer.add(TableViewer.java:134)
        at 
org.eclipse.search.internal.ui.text.FileTableContentProvider.elements
Changed(FileTableContentProvider.java:44)
        at org.eclipse.search.internal.ui.text.FileSearchPage.elementsChanged
(Fi
leSearchPage.java:158)
        at 
org.eclipse.search.ui.text.AbstractTextSearchViewPage.runBatchedUpdat
es(AbstractTextSearchViewPage.java:965)
        - locked <0x15b540b8> (a 
org.eclipse.search.internal.ui.text.FileSearchP
age)
        at org.eclipse.search.ui.text.AbstractTextSearchViewPage.access$1
(Abstra
ctTextSearchViewPage.java:955)
        at 
org.eclipse.search.ui.text.AbstractTextSearchViewPage$UpdateUIJob.run
InUIThread(AbstractTextSearchViewPage.java:119)
        at org.eclipse.ui.progress.UIJob$1.run(UIJob.java:84)
        at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
        at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages
(Synchronizer.ja
va:106)
        - locked <0x15e28f80> (a org.eclipse.swt.widgets.RunnableLock)
        at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:2693)
        at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:2385)
        at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:1363)
        at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:1334)
        at org.eclipse.ui.internal.Workbench.createAndRunWorkbench
(Workbench.jav
a:253)
        at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:141)
        at org.eclipse.ui.internal.ide.IDEApplication.run
(IDEApplication.java:97
)
        at org.eclipse.core.internal.runtime.PlatformActivator$1.run
(PlatformAct
ivator.java:305)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run
(EclipseStarter.ja
va:256)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run
(EclipseStarter.ja
va:127)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke
(NativeMethodAccessorImpl.
java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke
(DelegatingMethodAcces
sorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:324)
        at org.eclipse.core.launcher.Main.basicRun(Main.java:184)
        at org.eclipse.core.launcher.Main.run(Main.java:637)
        at org.eclipse.core.launcher.Main.main(Main.java:621)

"VM Thread" prio=5 tid=0x009fb6e8 nid=0xd38 runnable

"VM Periodic Task Thread" prio=10 tid=0x0003fef0 nid=0xc58 waiting on condition

"Suspend Checker Thread" prio=10 tid=0x009c21d8 nid=0xbfc runnable
Comment 1 John Wiegand CLA 2004-05-20 12:45:48 EDT
*** Bug 63248 has been marked as a duplicate of this bug. ***
Comment 2 Thomas M??der CLA 2004-05-21 03:59:38 EDT
John, looking at the stack trace, I don't see a deadlock on first approach. Do
you have 0% CPU use at this time?
Comment 3 Thomas M??der CLA 2004-05-21 06:33:29 EDT
Could you provide me with the follwing information:

1) are you using the table (flat) layout?
2) how many files are in your workspace.
3) are you searching with * or with nothing (emtpty) as the search string?
Comment 4 John Wiegand CLA 2004-05-21 08:27:45 EDT
eclipse is not responding, cpu is very busy - so it is not an actual deadlock, 
however, there is no forward progress - eclipse is locked up.  (I allowed this 
to run for > 10 minutes without progress after moving for the first 15 
seconds.  I have reproduced this problem 4 times (each time I tried it).  

1. I was using the default preferences out of the box - this is flat
2. There were MANY resources - I took an empty workspace and imported ALL of 
the SDK from source (9-10K).  
3. I used an empty search string.  (side note: * is treated differently than 
empty - these should be reconciled to provide the behavior that currently 
exists on empty)

Notice the problem only occurs with MANY hits and searching many files.
Comment 5 Thomas M??der CLA 2004-05-21 08:45:05 EDT
We've seen this before. The problem in the past was:

1) TableViewer insertion is very! slow for large tables (not sure if that's
because of the O(n*n) algorithm for finding the insert position or because of
the underlying table.
2) The platform label decorator sends us thousands of update requests at the
same time. Updating thousands of items in the table viewer is slow.

The workaround is simple: switch to the hierarchical layout.

SWT has provided a faster table, but that hasn't been surfaced in the
TableViewer yet.
Comment 6 John Wiegand CLA 2004-05-23 22:39:07 EDT
this seems worse than a slow algorithm.  Here is what I am seeing: fast 
progress for 3-4 seconds, then no progress at all (this is why I called it a 
deadlock in the initial report).  I cannot cancel this operation, so the 
result is a lockup.  These steps are easily reproducable.
Comment 7 Thomas M??der CLA 2004-05-24 07:25:38 EDT
I profiled this and 98% of the time is spent in TableViewer.add(Object[] elements).
Yes, I could parcel the work to make it cancellable (but not any faster), but
that would involve architectural changes that I'm reluctant to make for an
outside case when we have an easy workaround (i.e. switch to the tree layout).
Comment 8 Dirk Baeumer CLA 2004-05-24 10:03:32 EDT
Since a Table Viewer using virtual tables would fix the problem (and I hope we 
get a corresponding viewer for 3.1) I am reluctent as well to put 
in "compilcated" code to work around the problem. 

I am in favour to fix the problem analogous to the problems view: we should 
simply limit the number of matches in the table view to lets say 500 and make 
this clear in the title bar of the search result view. The user can then 
switch to the tree view which will present all matches.
Comment 9 Dirk Baeumer CLA 2004-05-24 12:00:43 EDT
Thomas, is this doable for RC1 ?
Comment 10 Thomas M??der CLA 2004-05-24 12:10:55 EDT
I think it's not a problem for RC1
Comment 11 Thomas M??der CLA 2004-05-26 10:07:08 EDT
The problem with the limiting solution is that it can only be implemented by
each search result page contributor. I have implemented the featurn for file
search. 
Comment 12 Thomas M??der CLA 2004-05-26 10:28:05 EDT
Looking up 10000 files now takes ~5 seconds when showing 200 entries.
Comment 13 John Wiegand CLA 2004-06-04 17:59:40 EDT
bug 65381 shows that we should consider the limiting solution for java search 
as well.
Comment 14 Dirk Baeumer CLA 2004-06-05 11:06:04 EDT
John refers to bug 65831.
Comment 15 Dirk Baeumer CLA 2004-06-05 18:54:57 EDT
Regarding comment #13

We choose the solution to limit the number of matches for Text search since it 
was impossible to cancel the text search since all CPU cycles where spent to 
update the UI.

Java search is responsive enough to accept cancel requests.  So a Java search 
for all types can be canceled even if the view is in Group by Type mode. 

The problematic scenario happens when the user switches to Group by Type mode 
when there are lots of matches. So I opt to disabled this mode in cases where 
we have lots of matches (> 1000 matches). Group by File and switching to flat 
layout should be disabled as well.

Thomas, is this possible and how risky/expensive is this to be implemented for 
RC2.
Comment 16 Thomas M??der CLA 2004-06-10 06:19:36 EDT
Implemented element filter for java search. Currently it's implemented as a
filter action (view menu), but the threshold is set in the main Java preference
page. I'll see wether we'll get a better solution in with a "Filters..." dialog
like the  package explorer has.
Comment 17 Thomas M??der CLA 2004-06-10 09:21:31 EDT
I've added the "Filters..." dialog. I'll keep the bug open because we should
apply the same solution for text search post-3.0
Comment 18 Thomas M??der CLA 2004-06-29 11:19:31 EDT
This is probably quite some work. Upping priority so it gets looked at.
Comment 19 John Wiegand CLA 2005-05-25 13:42:15 EDT
New default behavior is acceptable: hierarchical table filled in 10 seconds.
If I force the problematic case below, the search takes 30 seconds.  There is 
no progress feedback and the IDE is locked up, but this is MUCH better than 
3.0.
The only reason to keep this defect open is to consider the enhancement 
request in comment #17: The idea of adding filters to text search has not 
occurred. (Advise that this defect should be closed if enhancement is not 
likely in 3.2)
Comment 20 Martin Aeschlimann CLA 2005-06-08 06:57:51 EDT
closing this bug. Will file a new bug for enhancement request in comment #17.