Can you open a JIRA issue if you haven't already? How did you reproduce it (what's the simplest method?)
-Yonik http://www.lucidimagination.com On Mon, Nov 2, 2009 at 6:05 AM, Shalin Shekhar Mangar <shalinman...@gmail.com> wrote: > 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. >
