I'm able to reproduce this issue consistently using JDK 1.6.0_16
After an optimize is called, only one thread keeps adding documents and the
rest wait on StreamingUpdateSolrServer line 196.
On Sun, Oct 25, 2009 at 8:03 AM, Dadasheva, Olga <olga_dadash...@harvard.edu
> wrote:
> I am using java 1.6.0_05
>
> To illustrate what is happening I wrote this test program that has 10
> threads adding a collection of documents and one thread optimizing the index
> every 10 sec.
>
> I am seeing that after the first optimize there is only one thread that
> keeps adding documents. The other ones are locked.
>
> In the real code I ended up adding synchronized around add on optimize to
> avoid this.
>
> public static void main(String[] args) {
>
> final JettySolrRunner jetty = new JettySolrRunner("/solr", 8983 );
> try {
> jetty.start();
> // setup the server...
> String url = "http://localhost:8983/solr";;
> final StreamingUpdateSolrServer server = new
> StreamingUpdateSolrServer( url, 2, 5 ) {
> @Override
> public void handleError(Throwable ex) {
> // do somethign...
> }
> };
> server.setConnectionTimeout(1000);
> server.setDefaultMaxConnectionsPerHost(100);
> server.setMaxTotalConnections(100);
> int i = 0;
> while (i++ < 10) {
> new Thread("add-thread"+i) {
> public void run(){
> int j = 0;
> while (true) {
> try {
> List<SolrInputDocument> docs
> = new ArrayList<SolrInputDocument>();
> for (int n = 0; n < 50; n++)
> {
> SolrInputDocument doc =
> new SolrInputDocument();
> String docID =
> this.getName()+"_doc_"+j++;
> doc.addField( "id",
> docID);
> doc.addField( "content",
> "document_"+docID);
> docs.add(doc);
> }
> server.add(docs);
>
> System.out.println(this.getName()+" added "+docs.size()+" documents");
> Thread.sleep(100);
> } catch (Exception e) {
> e.printStackTrace();
>
> System.err.println(this.getName()+" "+e.getLocalizedMessage());
> System.exit(0);
> }
> }
> }
> }.start();
> }
>
> new Thread("optimizer-thread") {
> public void run(){
> while (true) {
> try {
> Thread.sleep(10000);
> server.optimize();
> System.out.println(this.getName()+"
> optimized");
> } catch (Exception e) {
> e.printStackTrace();
> System.err.println("optimizer
> "+e.getLocalizedMessage());
> System.exit(0);
> }
> }
> }
> }.start();
>
>
> } catch (Exception e) {
> e.printStackTrace();
> }
>
> }
> -----Original Message-----
> From: Lance Norskog [mailto:goks...@gmail.com]
> Sent: Tuesday, October 13, 2009 8:59 PM
> To: solr-user@lucene.apache.org
> Subject: Re: StreamingUpdateSolrServer - indexing process stops in a couple
> of hours
>
> Which Java release is this? There are known thread-blocking problems in
> Java 1.5.
>
> Also, what sockets are used during this time? Try 'netstat -s | fgrep 8983'
> (or your Solr URL port #) and watch the active, TIME_WAIT, CLOSE_WAIT
> sockets build up. This may give a hint.
>
> On Tue, Oct 13, 2009 at 8:47 AM, Dadasheva, Olga <
> olga_dadash...@harvard.edu> wrote:
> > Hi,
> >
> > I am indexing documents using StreamingUpdateSolrServer. My 'setup'
> > code is almost a copy of the junit test of the Solr trunk.
> >
> > try {
> > StreamingUpdateSolrServer streamingServer = new
> > StreamingUpdateSolrServer( url, 2, 5 ) {
> > @Override
> > public void handleError(Throwable ex) {
> > System.out.println(" new
> > StreamingUpdateSolrServer error "+ex);
> > mail.send(new
> > Date()+"StreamingUpdateSolrServer error. "+ex);
> > }
> > };
> > streamingServer.setConnectionTimeout(20*60*1000);
> > // 20 min
> >
> > streamingServer.setDefaultMaxConnectionsPerHost(100);
> > streamingServer.setMaxTotalConnections(100);
> > server = streamingServer;
> > } catch(Exception e) {
> > mail.send(new Date()+"StreamingUpdateSolrServer error.
> > "+e);
> > e.printStackTrace();
> > }
> >
> >
> > This is what happens:
> >
> > The crawler is running for a couple+/- of hours and I am seeing that
> > the thread number is being reused , but in general it keeps increasing
> > up to
> > thread-119
> >
> >
> > 2009-10-09 16:53:24,532 INFO starting runner:
> > org.apache.solr.client.solrj.impl.streamingupdatesolrserver$run...@def
> > 14 f (StreamingUpdateSolrServer.java:86) - [pool-1-thread-1]
> > 2009-10-09 16:53:24,543 INFO starting runner:
> > org.apache.solr.client.solrj.impl.streamingupdatesolrserver$run...@34b
> > 35 0 (StreamingUpdateSolrServer.java:86) - [pool-1-thread-2]
> > 2009-10-09 16:53:25,338 INFO finished:
> > org.apache.solr.client.solrj.impl.streamingupdatesolrserver$run...@34b
> > 35 0 (StreamingUpdateSolrServer.java:164) - [pool-1-thread-2]
> > 2009-10-09 16:53:25,504 INFO finished:
> > org.apache.solr.client.solrj.impl.streamingupdatesolrserver$run...@def
> > 14 f (StreamingUpdateSolrServer.java:164) - [pool-1-thread-1] ....
> > 2009-10-09 18:22:49,844 INFO finished:
> > org.apache.solr.client.solrj.impl.streamingupdatesolrserver$run...@563
> > d5
> > 6 (StreamingUpdateSolrServer.java:164) - [pool-1-thread-117]
> > 2009-10-09 18:22:49,848 INFO finished:
> > org.apache.solr.client.solrj.impl.streamingupdatesolrserver$run...@10f
> > ff 00 (StreamingUpdateSolrServer.java:164) - [pool-1-thread-119]
> > 2009-10-09 18:22:49,859 INFO finished:
> > org.apache.solr.client.solrj.impl.streamingupdatesolrserver$run...@10e
> > 52
> > c1 (StreamingUpdateSolrServer.java:164) - [pool-1-thread-118]
> >
> > At this point the log stops.
> >
> >
> >
> > Full thread dump Java HotSpot(TM) Server VM (10.0-b19 mixed mode):
> >
> > "btpool0-70" prio=3 tid=0x0078a800 nid=0xd7 in Object.wait()
> > [0x8a5ff000..0x8a5ff970]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.
> > ja
> > va:482)
> > - locked <0xb0a7d620> (a
> > org.mortbay.thread.BoundedThreadPool$PoolThread)
> >
> > "Java2D Disposer" daemon prio=3 tid=0x0033f400 nid=0x21 in
> > Object.wait() [0x893ff000..0x893ff870]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
> > - locked <0xabc000f8> (a java.lang.ref.ReferenceQueue$Lock)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
> > at sun.java2d.Disposer.run(Disposer.java:125)
> > at java.lang.Thread.run(Thread.java:619)
> >
> > "MultiThreadedHttpConnectionManager cleanup" daemon prio=3
> > tid=0x002afc00 nid=0x1f in Object.wait() [0x897ff000..0x897ff970]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > - waiting on <0xabc001c8> (a java.lang.ref.ReferenceQueue$Lock)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
> > - locked <0xabc001c8> (a java.lang.ref.ReferenceQueue$Lock)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
> > at
> > org.apache.commons.httpclient.MultiThreadedHttpConnectionManager$Refer
> > en
> > ceQueueThread.run(MultiThreadedHttpConnectionManager.java:1122)
> >
> > "DefaultQuartzScheduler_QuartzSchedulerThread" prio=3 tid=0x00cb5c00
> > nid=0x1c in Object.wait() [0x899ff000..0x899ffbf0]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:4
> > 33
> > )
> > - locked <0xabc695d8> (a java.lang.Object)
> >
> > "DefaultQuartzScheduler_Worker-10" prio=3 tid=0x00e26c00 nid=0x1b in
> > Object.wait() [0x89aff000..0x89affb70]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc83ac0> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-9" prio=3 tid=0x00dd8400 nid=0x1a in
> > Object.wait() [0x89bff000..0x89bff8f0]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc83920> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-8" prio=3 tid=0x0074ac00 nid=0x19 in
> > Object.wait() [0x89cff000..0x89cff870]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc83780> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-7" prio=3 tid=0x0074a400 nid=0x18 in
> > Object.wait() [0x89dff000..0x89dff9f0]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc835e0> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-6" prio=3 tid=0x00826800 nid=0x17 in
> > Object.wait() [0x89eff000..0x89eff970]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc83440> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-5" prio=3 tid=0x0074dc00 nid=0x16 in
> > Object.wait() [0x89fff000..0x89fffaf0]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc832a0> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-4" prio=3 tid=0x00e04400 nid=0x15 in
> > Object.wait() [0x8a0ff000..0x8a0ffa70]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc83100> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-3" prio=3 tid=0x006b4800 nid=0x14 in
> > Object.wait() [0x8a1ff000..0x8a1ffbf0]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc82f60> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-2" prio=3 tid=0x00879800 nid=0x13 in
> > Object.wait() [0x8a2ff000..0x8a2ffb70]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :519)
> > - locked <0xabc82dc0> (a
> > org.quartz.simpl.SimpleThreadPool$WorkerThread)
> >
> > "DefaultQuartzScheduler_Worker-1" prio=3 tid=0x00e51c00 nid=0x12
> > waiting on condition [0x8a3ff000..0x8a3ff8f0]
> > java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for <0xac07acb8> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at
> > java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.
> > aw
> > ait(AbstractQueuedSynchronizer.java:1925)
> > at
> > java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:
> > 25
> > 4)
> > at
> > org.apache.solr.client.solrj.impl.StreamingUpdateSolrServer.request(St
> > re
> > amingUpdateSolrServer.java:199)
> > at
> > org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(Abs
> > tr
> > actUpdateRequest.java:89)
> > at
> > org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:49)
> > at
> > harvard.solr.crawl.AbstractSearchService.update(AbstractSearchService.
> > ja
> > va:180)
> > at harvard.solr.crawl.Updater.internalUpdate(Updater.java:97)
> > at harvard.solr.crawl.Updater.update(Updater.java:34)
> > at
> > harvard.solr.crawl.crawler.SiteStructureCrawler.start(SiteStructureCra
> > wl
> > er.java:71)
> > at
> > harvard.solr.crawl.job.NewIndexJob.execute(NewIndexJob.java:36)
> > at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va
> > :525)
> >
> > "pool-2-thread-1" prio=3 tid=0x00232400 nid=0xf waiting on condition
> > [0x8a6ff000..0x8a6ff970]
> > java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for <0xac06ffc0> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at
> > java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.
> > aw
> > ait(AbstractQueuedSynchronizer.java:1925)
> > at
> > java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java
> > :3
> > 58)
> > at
> > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:
> > 946)
> > at
> > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.
> > ja
> > va:906)
> > at java.lang.Thread.run(Thread.java:619)
> >
> > "Timer-0" prio=3 tid=0x0083b800 nid=0xe in Object.wait()
> > [0x8a7ff000..0x8a7ffaf0]
> > java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at java.util.TimerThread.mainLoop(Timer.java:509)
> > - locked <0xac073d30> (a java.util.TaskQueue)
> > at java.util.TimerThread.run(Timer.java:462)
> >
> > "btpool0-0 - Acceptor0 SocketConnector @ 0.0.0.0:8983" prio=3
> > tid=0x00826000 nid=0xd runnable [0x8a8ff000..0x8a8ffa70]
> > java.lang.Thread.State: RUNNABLE
> > at java.net.PlainSocketImpl.socketAccept(Native Method)
> > at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
> > - locked <0xabe279d8> (a java.net.SocksSocketImpl)
> > at java.net.ServerSocket.implAccept(ServerSocket.java:453)
> > at java.net.ServerSocket.accept(ServerSocket.java:421)
> > at
> > org.mortbay.jetty.bio.SocketConnector.accept(SocketConnector.java:97)
> > at
> > org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:
> > 516)
> > at
> > org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.
> > ja
> > va:442)
> >
> > "Low Memory Detector" daemon prio=3 tid=0x00118800 nid=0xb runnable
> > [0x00000000..0x00000000]
> > java.lang.Thread.State: RUNNABLE
> >
> > "CompilerThread1" daemon prio=3 tid=0x00116000 nid=0xa waiting on
> > condition [0x00000000..0x8aefec18]
> > java.lang.Thread.State: RUNNABLE
> >
> > "CompilerThread0" daemon prio=3 tid=0x00115000 nid=0x9 waiting on
> > condition [0x00000000..0x8affeb98]
> > java.lang.Thread.State: RUNNABLE
> >
> > "Signal Dispatcher" daemon prio=3 tid=0x00113400 nid=0x8 waiting on
> > condition [0x00000000..0x00000000]
> > java.lang.Thread.State: RUNNABLE
> >
> > "Finalizer" daemon prio=3 tid=0x000f9400 nid=0x7 in Object.wait()
> > [0x8b1ff000..0x8b1ff970]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
> > - locked <0xac2e46c0> (a java.lang.ref.ReferenceQueue$Lock)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
> > at
> > java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
> >
> > "Reference Handler" daemon prio=3 tid=0x000f5000 nid=0x6 in
> > Object.wait() [0x8b2ff000..0x8b2ffaf0]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at java.lang.Object.wait(Object.java:485)
> > at
> > java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
> > - locked <0xabc87150> (a java.lang.ref.Reference$Lock)
> >
> > "main" prio=3 tid=0x00030000 nid=0x2 in Object.wait()
> > [0xfe67f000..0xfe67fd80]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > - waiting on <0xac07c6f0> (a java.lang.Object)
> > at java.lang.Object.wait(Object.java:485)
> > at harvard.solr.crawl.Scheduler.schedule(Scheduler.java:61)
> > - locked <0xac07c6f0> (a java.lang.Object)
> > at harvard.solr.crawl.Scheduler.main(Scheduler.java:99)
> >
> > "VM Thread" prio=3 tid=0x000f1400 nid=0x5 runnable
> >
> > "GC task thread#0 (ParallelGC)" prio=3 tid=0x00037000 nid=0x3 runnable
> >
> > "GC task thread#1 (ParallelGC)" prio=3 tid=0x00038800 nid=0x4 runnable
> >
> > "VM Periodic Task Thread" prio=3 tid=0x0011a400 nid=0xc waiting on
> > condition
> >
> > JNI global references: 689
> >
> > Heap
> > PSYoungGen total 417792K, used 27487K [0xe1400000, 0xfc000000,
> > 0xfc000000)
> > eden space 403456K, 6% used [0xe1400000,0xe2becae8,0xf9e00000)
> > from space 14336K, 20% used [0xfb200000,0xfb4eb208,0xfc000000)
> > to space 17408K, 0% used [0xf9e00000,0xf9e00000,0xfaf00000)
> > PSOldGen total 876544K, used 86178K [0xabc00000, 0xe1400000,
> > 0xe1400000)
> > object space 876544K, 9% used [0xabc00000,0xb1028b90,0xe1400000)
> > PSPermGen total 131072K, used 44021K [0x8bc00000, 0x93c00000,
> > 0xabc00000)
> > object space 131072K, 33% used [0x8bc00000,0x8e6fd460,0x93c00000)
> >
>
>
>
> --
> Lance Norskog
> goks...@gmail.com
>
--
Regards,
Shalin Shekhar Mangar.
