Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.
Bug 348040 - Over active search indexer
Summary: Over active search indexer
Status: RESOLVED FIXED
Alias: None
Product: Orion
Classification: ECD
Component: Client (show other bugs)
Version: 0.2   Edit
Hardware: PC Windows 7
: P3 major (vote)
Target Milestone: 0.2   Edit
Assignee: John Arthorne CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-06-01 22:44 EDT by John J. Barton CLA
Modified: 2011-09-01 11:41 EDT (History)
4 users (show)

See Also:
Szymon.Brandys: review+


Attachments
Screen shot of jvisualvm (45.29 KB, image/png)
2011-06-02 14:07 EDT, John Arthorne CLA
no flags Details
A list of all extensions in the fbug project (638 bytes, text/plain)
2011-06-03 18:09 EDT, John J. Barton CLA
no flags Details
screen shot of process explorer while Orion server runs (91.50 KB, image/png)
2011-06-03 18:14 EDT, John J. Barton CLA
no flags Details
Fix (3.36 KB, text/plain)
2011-06-08 09:40 EDT, John Arthorne CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description John J. Barton CLA 2011-06-01 22:44:54 EDT
Here is what I was doing when I noticed the Orion server pegging my CPU:
1. svn checkout https://fbug.googlecode.com/svn fbug
2. cd /fbug/tests/content/branches/1.8/loader/diagnostics
3. git clone git@github.com:johnjbarton/requirejs.git
4. find your orion.conf and allow it to see the fbug directory
5. open orion client and link fbug directory to fbug
6. open
http://localhost:8080/file/i/tests/content/branches/1.8/loader/diagnostics/requirejs/tests/index.html
But change the "i" so it works
7. click into the All Automated Tests and push the arrow beside "Stopped" (which of course means go ;-).

I had seen this before on the same computer doing similar work.

HOWEVER, just now I cannot reproduce this result.

Two other things I do a lot:
   svn update on fbug
   git on require.js

I think we will need to look a bit to find the cause.
Comment 1 Boris Bokowski CLA 2011-06-02 10:59:09 EDT
John, would you be able to generate a thread dump at the time the CPU is pegged? This wiki page has fairly detailed information on how to do it: http://wiki.eclipse.org/How_to_report_a_deadlock

(Ignore the fact that you are not experiencing a deadlock situation, the thread dump is going to be useful because it tells us what the CPU is doing when it's at 100%.)
Comment 2 John J. Barton CLA 2011-06-02 13:42:32 EDT
I tried to follow the page on jvisualvm, but I did not get an application to click on other than jvisualvm itself.
Comment 3 John Arthorne CLA 2011-06-02 14:07:59 EDT
Created attachment 197257 [details]
Screen shot of jvisualvm
Comment 4 John Arthorne CLA 2011-06-02 14:09:35 EDT
(In reply to comment #2)
> I tried to follow the page on jvisualvm, but I did not get an application to
> click on other than jvisualvm itself.

Not sure if this is a question, but there is no other application to click on besides jvisualvm. If you have a java process running with that system property, then at any time you can launch jvisualvm, and see that process in the "Applications" pane. From there you can request a stack dump, heap dump, start profiling, etc. Note you don't actually need to launch jvisualvm until the problem scenario happens.
Comment 5 John J. Barton CLA 2011-06-02 23:10:48 EDT
The screen shot in comment 3 is more like I was expecting. You have four nodes under Local, VisualVM and three others. I only have one, VisualVM.
Comment 6 Boris Bokowski CLA 2011-06-02 23:14:54 EDT
How did you launch Orion? Which VM version is being used? Is it a Sun VM?
Comment 7 John J. Barton CLA 2011-06-02 23:32:20 EDT
(In reply to comment #6)
> How did you launch Orion? 
Double click eclipse.exe
> Which VM version is being used? 
> Is it a Sun VM?
Here are some osgi>props values:
awt.toolkit = sun.awt.windows.WToolkit
com.sun.management.jmxremote =
eclipse.application = org.eclipse.orion.application
...
java.runtime.name = Java(TM) SE Runtime Environment
java.runtime.version = 1.6.0_25-b06
java.specification.name = Java Platform API Specification
java.specification.vendor = Sun Microsystems Inc.
java.specification.version = 1.6
java.vendor = Sun Microsystems Inc.
java.vendor.url = http://java.sun.com/
java.vendor.url.bug = http://java.sun.com/cgi-bin/bugreport.cgi
java.version = 1.6.0_25
java.vm.info = mixed mode, sharing
java.vm.name = Java HotSpot(TM) Client VM
java.vm.specification.name = Java Virtual Machine Specification
java.vm.specification.vendor = Sun Microsystems Inc.
java.vm.specification.version = 1.0
java.vm.vendor = Sun Microsystems Inc.
java.vm.version = 20.0-b11

Tried turning off Windows Firewall, no change.
Comment 9 John J. Barton CLA 2011-06-02 23:48:49 EDT
Thread Dump doesn't seem to interesting


2011-06-02 20:48:17
Full thread dump Java HotSpot(TM) Client VM (20.0-b11 mixed mode, sharing):

"Worker-5" - Thread t@40
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <130500f> (a org.eclipse.core.internal.jobs.WorkerPool)
	at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188)
	at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:50)

   Locked ownable synchronizers:
	- None

"RMI TCP Connection(idle)" - Thread t@39
   java.lang.Thread.State: TIMED_WAITING
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for <4383e3> (a java.util.concurrent.SynchronousQueue$TransferStack)
	at java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(Unknown Source)
	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(Unknown Source)
	at java.util.concurrent.SynchronousQueue.poll(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"RMI TCP Connection(14)-192.168.1.116" - Thread t@37
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(Unknown Source)
	at java.io.BufferedInputStream.fill(Unknown Source)
	at java.io.BufferedInputStream.read(Unknown Source)
	- locked <87c8db> (a java.io.BufferedInputStream)
	at java.io.FilterInputStream.read(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- locked <93a63d> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"Worker-3" - Thread t@36
   java.lang.Thread.State: RUNNABLE
	at org.eclipse.core.internal.filesystem.local.LocalFileNatives.internalGetFileInfoW(Native Method)
	at org.eclipse.core.internal.filesystem.local.LocalFileNatives.fetchFileInfo(LocalFileNatives.java:112)
	at org.eclipse.core.internal.filesystem.local.LocalFileNativesManager.fetchFileInfo(LocalFileNativesManager.java:32)
	at org.eclipse.core.internal.filesystem.local.LocalFile.fetchInfo(LocalFile.java:144)
	at org.eclipse.core.filesystem.provider.FileStore.fetchInfo(FileStore.java:280)
	at org.eclipse.orion.internal.server.search.Indexer.collectFiles(Indexer.java:62)
	at org.eclipse.orion.internal.server.search.Indexer.collectFiles(Indexer.java:64)
	at org.eclipse.orion.internal.server.search.Indexer.collectFiles(Indexer.java:64)
	at org.eclipse.orion.internal.server.search.Indexer.collectFiles(Indexer.java:64)
	at org.eclipse.orion.internal.server.search.Indexer.collectFiles(Indexer.java:64)
	at org.eclipse.orion.internal.server.search.Indexer.collectFiles(Indexer.java:64)
	at org.eclipse.orion.internal.server.search.Indexer.indexProject(Indexer.java:115)
	at org.eclipse.orion.internal.server.search.Indexer.run(Indexer.java:201)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:54)

   Locked ownable synchronizers:
	- None

"RMI TCP Connection(12)-192.168.1.116" - Thread t@35
   java.lang.Thread.State: RUNNABLE
	at sun.management.ThreadImpl.dumpThreads0(Native Method)
	at sun.management.ThreadImpl.dumpAllThreads(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor53.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(Unknown Source)
	at com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(Unknown Source)
	at com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(Unknown Source)
	at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(Unknown Source)
	at com.sun.jmx.mbeanserver.PerInterface.invoke(Unknown Source)
	at com.sun.jmx.mbeanserver.MBeanSupport.invoke(Unknown Source)
	at javax.management.StandardMBean.invoke(Unknown Source)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(Unknown Source)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(Unknown Source)
	at javax.management.remote.rmi.RMIConnectionImpl.doOperation(Unknown Source)
	at javax.management.remote.rmi.RMIConnectionImpl.access$200(Unknown Source)
	at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(Unknown Source)
	at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(Unknown Source)
	at javax.management.remote.rmi.RMIConnectionImpl.invoke(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor41.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at sun.rmi.server.UnicastServerRef.dispatch(Unknown Source)
	at sun.rmi.transport.Transport$1.run(Unknown Source)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- locked <1644de7> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"JMX server connection timeout 33" - Thread t@33
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <17b60b6> (a [I)
	at com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"RMI Scheduler(0)" - Thread t@31
   java.lang.Thread.State: TIMED_WAITING
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for <fe53cf> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)
	at java.util.concurrent.DelayQueue.take(Unknown Source)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"Worker-2" - Thread t@29
   java.lang.Thread.State: RUNNABLE
	at java.lang.StringCoding$StringDecoder.decode(Unknown Source)
	at java.lang.StringCoding.decode(Unknown Source)
	at java.lang.String.<init>(Unknown Source)
	at org.apache.lucene.store.IndexInput.readString(IndexInput.java:127)
	at org.apache.lucene.index.FieldsReader.addField(FieldsReader.java:392)
	at org.apache.lucene.index.FieldsReader.doc(FieldsReader.java:229)
	at org.apache.lucene.index.SegmentReader.document(SegmentReader.java:948)
	at org.apache.lucene.index.DirectoryReader.document(DirectoryReader.java:506)
	at org.apache.lucene.index.IndexReader.document(IndexReader.java:947)
	at org.apache.solr.search.SolrIndexReader.document(SolrIndexReader.java:444)
	at org.apache.solr.search.SolrIndexSearcher.doc(SolrIndexSearcher.java:427)
	at org.apache.solr.request.BinaryResponseWriter$Resolver.writeDocList(BinaryResponseWriter.java:122)
	at org.apache.solr.request.BinaryResponseWriter$Resolver.resolve(BinaryResponseWriter.java:88)
	at org.apache.solr.common.util.JavaBinCodec.writeVal(JavaBinCodec.java:143)
	at org.apache.solr.common.util.JavaBinCodec.writeNamedList(JavaBinCodec.java:133)
	at org.apache.solr.common.util.JavaBinCodec.writeKnownType(JavaBinCodec.java:221)
	at org.apache.solr.common.util.JavaBinCodec.writeVal(JavaBinCodec.java:138)
	at org.apache.solr.common.util.JavaBinCodec.marshal(JavaBinCodec.java:87)
	at org.apache.solr.request.BinaryResponseWriter.getParsedResponse(BinaryResponseWriter.java:185)
	at org.apache.solr.client.solrj.embedded.EmbeddedSolrServer.getParsedResponse(EmbeddedSolrServer.java:170)
	at org.apache.solr.client.solrj.embedded.EmbeddedSolrServer.request(EmbeddedSolrServer.java:145)
	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:89)
	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:118)
	at org.eclipse.orion.internal.server.search.IndexPurgeJob.run(IndexPurgeJob.java:120)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:54)

   Locked ownable synchronizers:
	- None

"Worker-JM" - Thread t@25
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <d8326d> (a java.util.ArrayList)
	at org.eclipse.core.internal.jobs.InternalWorker.run(InternalWorker.java:58)

   Locked ownable synchronizers:
	- None

"pool-1-thread-1" - Thread t@24
   java.lang.Thread.State: WAITING
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for <1d6b049> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(Unknown Source)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)
	at java.util.concurrent.LinkedBlockingQueue.take(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"Timer-0" - Thread t@23
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <1cfad77> (a java.util.TaskQueue)
	at java.util.TimerThread.mainLoop(Unknown Source)
	at java.util.TimerThread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"24435002@qtp-32380043-1" - Thread t@22
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <174d93a> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)

   Locked ownable synchronizers:
	- None

"15354046@qtp-32380043-0 - Acceptor0 SelectChannelConnector@0.0.0.0:8080" - Thread t@21
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
	at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source)
	at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source)
	at sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source)
	- locked <970b8a> (a sun.nio.ch.Util$2)
	- locked <76c49d> (a java.util.Collections$UnmodifiableSet)
	- locked <1665d34> (a sun.nio.ch.WindowsSelectorImpl)
	at sun.nio.ch.SelectorImpl.select(Unknown Source)
	at org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:484)
	at org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:191)
	at org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124)
	at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:707)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)

   Locked ownable synchronizers:
	- None

"[ThreadPool Manager] - Idle Thread" - Thread t@19
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <1d349e2> (a org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor)
	at java.lang.Object.wait(Object.java:485)
	at org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Executor.java:106)

   Locked ownable synchronizers:
	- None

"[Timer] - Main Queue Handler" - Thread t@18
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <18590c5> (a java.lang.Object)
	at org.eclipse.equinox.internal.util.impl.tpt.timer.TimerImpl.run(TimerImpl.java:141)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"Framework Event Dispatcher" - Thread t@17
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <1e3940a> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
	at java.lang.Object.wait(Object.java:485)
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)

   Locked ownable synchronizers:
	- None

"Start Level Event Dispatcher" - Thread t@16
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <9ff0a8> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)
	at java.lang.Object.wait(Object.java:485)
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)

   Locked ownable synchronizers:
	- None

"State Data Manager" - Thread t@15
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Thread.sleep(Native Method)
	at org.eclipse.osgi.internal.baseadaptor.StateManager.run(StateManager.java:297)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"Framework Active Thread" - Thread t@14
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <c3c44> (a org.eclipse.osgi.framework.internal.core.Framework)
	at org.eclipse.osgi.framework.internal.core.Framework.run(Framework.java:1816)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"OSGi Console" - Thread t@13
   java.lang.Thread.State: RUNNABLE
	at java.io.FileInputStream.readBytes(Native Method)
	at java.io.FileInputStream.read(Unknown Source)
	at java.io.BufferedInputStream.read1(Unknown Source)
	at java.io.BufferedInputStream.read(Unknown Source)
	- locked <171206a> (a java.io.BufferedInputStream)
	at java.io.FilterInputStream.read(Unknown Source)
	at sun.nio.cs.StreamDecoder.readBytes(Unknown Source)
	at sun.nio.cs.StreamDecoder.implRead(Unknown Source)
	at sun.nio.cs.StreamDecoder.read(Unknown Source)
	- locked <71504> (a java.io.InputStreamReader)
	at java.io.InputStreamReader.read(Unknown Source)
	at java.io.BufferedReader.fill(Unknown Source)
	at java.io.BufferedReader.readLine(Unknown Source)
	- locked <71504> (a java.io.InputStreamReader)
	at java.io.BufferedReader.readLine(Unknown Source)
	at org.eclipse.osgi.framework.internal.core.FrameworkConsole.runConsole(FrameworkConsole.java:131)
	at org.eclipse.osgi.framework.internal.core.FrameworkConsole.run(FrameworkConsole.java:104)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"RMI TCP Accept-0" - Thread t@11
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.socketAccept(Native Method)
	at java.net.PlainSocketImpl.accept(Unknown Source)
	- locked <f4d23e> (a java.net.SocksSocketImpl)
	at java.net.ServerSocket.implAccept(Unknown Source)
	at java.net.ServerSocket.accept(Unknown Source)
	at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"RMI TCP Accept-3333" - Thread t@10
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.socketAccept(Native Method)
	at java.net.PlainSocketImpl.accept(Unknown Source)
	- locked <116f559> (a java.net.SocksSocketImpl)
	at java.net.ServerSocket.implAccept(Unknown Source)
	at java.net.ServerSocket.accept(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"RMI TCP Accept-0" - Thread t@9
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.socketAccept(Native Method)
	at java.net.PlainSocketImpl.accept(Unknown Source)
	- locked <45bb22> (a java.net.SocksSocketImpl)
	at java.net.ServerSocket.implAccept(Unknown Source)
	at java.net.ServerSocket.accept(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"Attach Listener" - Thread t@5
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Signal Dispatcher" - Thread t@4
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Finalizer" - Thread t@3
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <148a8e6> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"Reference Handler" - Thread t@2
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <148b272> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:485)
	at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)

   Locked ownable synchronizers:
	- None

"main" - Thread t@1
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	- waiting on <b8f675> (a org.eclipse.equinox.internal.app.DefaultApplicationListener)
	at org.eclipse.equinox.internal.app.DefaultApplicationListener.waitOnRunning(DefaultApplicationListener.java:99)
	at org.eclipse.equinox.internal.app.DefaultApplicationListener.run(DefaultApplicationListener.java:66)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
	at org.eclipse.equinox.launcher.Main.run(Main.java:1410)

   Locked ownable synchronizers:
	- None
Comment 10 John Arthorne CLA 2011-06-03 09:48:43 EDT
That's exactly the info I was looking for. It is indeed the search indexing.  There are log trace settings that can be turned on to narrow down which project in your workspace is taking the time. It could be we are doing something stupid like trying to index certain kinds of binaries. I will have to dig up the instructions on how to enable the tracing a bit later.
Comment 11 John J. Barton CLA 2011-06-03 16:55:36 EDT
I only have one project.  

Is there a way to turn off indexing? I basically can't use the orion server on localhost.
Comment 12 John Arthorne CLA 2011-06-03 17:51:33 EDT
Unfortunately there is no way to turn indexing off. It is supposed to throttle its frequency if it takes too long, and never run more than once a minute. But in the worst case it could run for 60s, sleep for 60s, run for 60s, ...

I have a suspicion you have a file type that we should be ignoring but we aren't. Here are the current file types we don't attempt to index:

	private static final List<String> IGNORED_FILE_TYPES = Arrays.asList("png", "jpg", "gif", "bmp", "pdf", "tiff", "class", "so", "zip", "jar", "tar");


Is there another type of non-text file that you have large numbers of in that particular project? We obviously need a better general solution for determining if a file is text vs binary, but the ignored types list is our short term solution.
Comment 13 John J. Barton CLA 2011-06-03 18:09:50 EDT
Created attachment 197340 [details]
A list of all extensions in the fbug project
Comment 14 John J. Barton CLA 2011-06-03 18:14:27 EDT
Created attachment 197341 [details]
screen shot of process explorer while Orion server runs
Comment 15 John J. Barton CLA 2011-06-03 18:20:39 EDT
Doesn't the indexer just run on changed files?

I have a modern two CPU machine and one of those is essentially devote to Orion server now. This won't work for most potential users, esp those with a bit older equipment.
Comment 16 John Arthorne CLA 2011-06-04 14:35:09 EDT
Note to myself. See:

org.eclipse.search.internal.core.text.TextSearchVisitor#processFile for the platform code that determines if a file is binary for the purpose of searching.
Comment 17 John Arthorne CLA 2011-06-07 17:20:08 EDT
(In reply to comment #0)
> Here is what I was doing when I noticed the Orion server pegging my CPU:
> 1. svn checkout https://fbug.googlecode.com/svn fbug

Step 1 has taken me about an hour so I'll have to dig into this more tomorrow. But essentially, you are pointing Orion at a folder with 42,000 files taking about 500MB of space. I think this is just killing our search indexer. As a workaround try linking Orion to more specific folders that you are working on rather than the whole repo.
Comment 18 John Arthorne CLA 2011-06-07 17:33:26 EDT
Ok, here is what I see:

The first indexing pass takes 57 seconds to index the entire fbug directory.

Then the "purge" job runs every 30 seconds look for stale index entries to remove. Simply traversing the project to see if each file still exists takes about 5 seconds.

Then once a minute the "index update" job runs. This is just checking file timestamps against the index entries to see if any file has been modified and needs re-indexing. This takes about 8 seconds.

So in total we have about 18 seconds every minute just to determine if the indexes are up to date. This is for the case where nothing has changed.

Here is the complete trace output:

2011-06-07 17:24:07.711 [Worker-0] DEBUG o.e.o.internal.server.search.Indexer - Indexing project id: k name: fbug
2011-06-07 17:25:04.038 [Worker-0] DEBUG o.e.o.internal.server.search.Indexer - 	Indexed: 10252 Unchanged:  0
2011-06-07 17:25:04.065 [Worker-0] DEBUG o.e.o.internal.server.search.Indexer - Indexed 11 projects in 57319ms
2011-06-07 17:25:04.065 [Worker-0] DEBUG o.e.o.internal.server.search.Indexer - Rescheduling indexing in 60000ms


2011-06-07 17:25:05.109 [Worker-3] DEBUG o.e.o.internal.server.search.Indexer - Purging indexes
2011-06-07 17:25:09.838 [Worker-3] DEBUG o.e.o.internal.server.search.Indexer - 	Purged: 0
2011-06-07 17:25:09.839 [Worker-3] DEBUG o.e.o.internal.server.search.Indexer - Purge job took 4730ms

2011-06-07 17:26:04.992 [Worker-3] DEBUG o.e.o.internal.server.search.Indexer - Indexing project id: k name: fbug
2011-06-07 17:26:12.297 [Worker-3] DEBUG o.e.o.internal.server.search.Indexer - 	Indexed: 0 Unchanged:  10252
2011-06-07 17:26:12.321 [Worker-3] DEBUG o.e.o.internal.server.search.Indexer - Indexed 11 projects in 8254ms
2011-06-07 17:26:12.321 [Worker-3] DEBUG o.e.o.internal.server.search.Indexer - Rescheduling indexing in 60000ms
Comment 19 John Arthorne CLA 2011-06-07 17:38:29 EDT
Some things we can do:

Increase the number of "ignored types".

Switch from an "ignored types" list to an "included types" list. I didn't want to do this because it prevents someone writing a plugin with an editor for a new file type that we then fail to index. For this release we could probably get away with it.

Make the indexing jobs back off more aggressively. E.g., reschedule for 15x the previous duration. So if it takes 8 seconds we only index every 2 minutes instead of every minute.
Comment 20 John J. Barton CLA 2011-06-07 18:45:52 EDT
My little firebug, 500MB?  ;-) 

What matters: the orion.conf value or the link point?
Comment 21 Boris Bokowski CLA 2011-06-07 21:07:35 EDT
the link point is what matters.
Comment 22 John Arthorne CLA 2011-06-08 09:40:22 EDT
Created attachment 197596 [details]
Fix

- Changed to only index file types we know about
- Use binary search on file extension when checking if we need to index a file
- Reschedule less often if indexing/purging takes a long time.
Comment 23 John Arthorne CLA 2011-06-08 09:44:03 EDT
Switching to only index known file types was only a modest speedup. About 1.5 seconds on indexing time on a workspace containing all of Orion + the fbug repository, and 500ms reducing of "index purge" time.

Bigger gains on indexing time will require more infrastructure in our indexer. For example create a cache of file timestamps so we don't need to perform solr queries to determine if the index is up to date. This won't be for 0.2.
Comment 24 Mark Macdonald CLA 2011-06-08 11:36:36 EDT
I once linked to my top-level user folder (C:\Users\mamacdon) as a test. I then deleted the linked project and removed it from my allowedPaths. Despite that, I could still see the indexer walking it and using a ton of CPU/memory.

I noticed this line was still in Projects.prefs:
> q/ContentLocation=file\:/C\:/Users/mamacdon/

Does the indexer traverse deleted projects?
Comment 25 John Arthorne CLA 2011-06-08 12:49:37 EDT
Szymon can you take a look at this changes? They are a modest improvement but still worth doing.
Comment 26 John Arthorne CLA 2011-06-10 10:44:11 EDT
Fix released.

http://git.eclipse.org/c/e4/org.eclipse.orion.server.git/commit/?id=c754fd7586cf772fd305dd988a51654d5931bf03

I have opened bug 349041 for the longer term problem of determining binary vs text file content automatically in the indexer.
Comment 27 John J. Barton CLA 2011-06-11 13:17:13 EDT
If the server has multiple 'users' (eg me logging in via google, myopen.id and a couple of local names) will each one of these users cause indexing based on their link even if they all point into the same filesystem branch?
Comment 28 John Arthorne CLA 2011-06-13 08:25:06 EDT
(In reply to comment #27)
> If the server has multiple 'users' (eg me logging in via google, myopen.id and
> a couple of local names) will each one of these users cause indexing based on
> their link even if they all point into the same filesystem branch?

Yes, those are separate index entries. The project id is one of the fields in the index, so different project ids means different index entries. This is used for access control - you can only search over index entries for projects in your workspace(s).

On the server the system is designed to allow sharing projects across users and workspaces. So, if it made sense we could enable sharing a project with another user, and then that content would only be indexed once. This is covered by bug 343159.