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:[email protected]]
Sent: Tuesday, October 13, 2009 8:59 PM
To: [email protected]
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 <[email protected]>
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
[email protected]
