You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by "Karl Wright (JIRA)" <ji...@apache.org> on 2010/08/02 10:52:16 UTC
[jira] Commented: (SOLR-2017) extractingUpdateRequestHandler waits
indefinitely, while simultaneous commit never finishes
[ https://issues.apache.org/jira/browse/SOLR-2017?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12894497#action_12894497 ]
Karl Wright commented on SOLR-2017:
-----------------------------------
I'm using a version of trunk from (roughly) July 26.
> extractingUpdateRequestHandler waits indefinitely, while simultaneous commit never finishes
> -------------------------------------------------------------------------------------------
>
> Key: SOLR-2017
> URL: https://issues.apache.org/jira/browse/SOLR-2017
> Project: Solr
> Issue Type: Bug
> Components: update
> Affects Versions: 4.0
> Environment: Windows XP, jdk 1.6.0_19
> Reporter: Karl Wright
>
> While trying to index data using extractingUpdateRequestHandler on a trunk build I made last night, I managed to trigger what appears to be a merge problem twice. Symptom is that updates are blocked, while the commit never finishes. CPU is utilized 100%. I cannot give a complete, single thread dump, but I managed to get two, which are overlapping, which are attached. If there's a quick response to this ticket I can generate more.
> First thread dump:
> ...
> at java.lang.Object.wait(Native Method)
> - waiting on <0x29642f00> (a java.util.TaskQueue)
> at java.util.TimerThread.mainLoop(Timer.java:509)
> - locked <0x29642f00> (a java.util.TaskQueue)
> at java.util.TimerThread.run(Timer.java:462)
> "25615188@qtp-20051738-9 - Acceptor0 SocketConnector@0.0.0.0:8983" prio=6 tid=0x 03076800 nid=0x19ac runnable [0x034df000]
> java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketAccept(Native Method)
> at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
> - locked <0x29770448> (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:99)
> at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.ja
> va:707)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:582)
> "11245030@qtp-20051738-8" prio=6 tid=0x03075000 nid=0x10b4 waiting on condition [0x0348e000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x2970bad8> (a java.util.concurrent.locks.Reentr
> antReadWriteLock$NonfairSync)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInt
> errupt(AbstractQueuedSynchronizer.java:747)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared
> (AbstractQueuedSynchronizer.java:877)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(A
> bstractQueuedSynchronizer.java:1197)
> at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(Reent
> rantReadWriteLock.java:594)
> at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandle
> r2.java:211)
> at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpd
> ateProcessorFactory.java:61)
> at org.apache.solr.handler.extraction.ExtractingDocumentLoader.doAdd(Ext
> ractingDocumentLoader.java:120)
> at org.apache.solr.handler.extraction.ExtractingDocumentLoader.addDoc(Ex
> tractingDocumentLoader.java:125)
> at org.apache.solr.handler.extraction.ExtractingDocumentLoader.load(Extr
> actingDocumentLoader.java:195)
> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(Co
> ntentStreamHandlerBase.java:54)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandl
> erBase.java:131)
> at org.apache.solr.core.RequestHandlers$LazyRequestHandlerWrapper.handle
> Request(RequestHandlers.java:237)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1323)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter
> .java:337)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilte
> r.java:240)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(Servlet
> Handler.java:1157)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:3
> 88)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.jav
> a:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:1
> 82)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:7
> 65)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHand
> lerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.
> java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:1
> 52)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:54
> 2)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpCo
> nnection.java:923)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:547)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.
> java:228)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:582)
> "25377109@qtp-20051738-7" prio=6 tid=0x03073800 nid=0x11c0 in Object.wait() [0x0 343e000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x2c802ee0> (a org.apache.solr.update.SolrIndexWriter)
> at org.apache.lucene.index.IndexWriter.doWait(IndexWriter.java:4270)
> - locked <0x2c802ee0> (a org.apache.solr.update.SolrIndexWriter)
> at org.apache.lucene.index.IndexWriter.waitForMerges(IndexWriter.java:27
> 81)
> - locked <0x2c802ee0> (a org.apache.solr.update.SolrIndexWriter)
> at org.apache.lucene.index.IndexWriter.finishMerges(IndexWriter.java:276
> 9)
> - locked <0x2c802ee0> (a org.apache.solr.update.SolrIndexWriter)
> at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:17
> 42)
> at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1695)
> at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1659)
> at org.apache.solr.update.SolrIndexWriter.close(SolrIndexWriter.java:231
> )
> at org.apache.solr.update.DirectUpdateHandler2.closeWriter(DirectUpdateH
> andler2.java:181)
> at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandle
> r2.java:409)
> at org.apache.solr.update.processor.RunUpdateProcessor.processCommit(Run
> UpdateProcessorFactory.java:85)
> at org.apache.solr.handler.RequestHandlerUtils.handleCommit(RequestHandl
> erUtils.java:107)
> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(Co
> ntentStreamHandlerBase.java:48)
> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandl
> erBase.java:131)
> at org.apache.solr.core.RequestHandlers$LazyRequestHandlerWrapper.handle
> Request(RequestHandlers.java:237)
> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1323)
> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter
> .java:337)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilte
> r.java:240)
> at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(Servlet
> Handler.java:1157)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:3
> 88)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.jav
> a:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:1
> 82)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:7
> 65)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHand
> lerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.
> java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:1
> 52)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:54
> 2)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpCo
> nnection.java:923)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:547)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.
> java:228)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:582)
> "15232416@qtp-20051738-6" prio=6 tid=0x0309ac00 nid=0x1458 in Object.wait() [0x0 33ef000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ece00> (a org.mortbay.thread.QueuedThreadPool$PoolThr
> ead)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:625)
> - locked <0x295ece00> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
> "381299@qtp-20051738-5" prio=6 tid=0x03099800 nid=0x19ec in Object.wait() [0x033 9f000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ece70> (a org.mortbay.thread.QueuedThreadPool$PoolThr
> ead)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:625)
> - locked <0x295ece70> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
> "2583282@qtp-20051738-4" prio=6 tid=0x03095800 nid=0x18dc in Object.wait() [0x03 34f000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ecee0> (a org.mortbay.thread.QueuedThreadPool$PoolThr
> ead)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:625)
> - locked <0x295ecee0> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
> "31289430@qtp-20051738-3" prio=6 tid=0x030a2800 nid=0x10c4 in Object.wait() [0x0 32ff000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ecf50> (a org.mortbay.thread.QueuedThreadPool$PoolThr
> ead)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:625)
> - locked <0x295ecf50> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
> "9004539@qtp-20051738-2" prio=6 tid=0x03077400 nid=0x1a38 in Object.wait() [0x03 2af000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ecfc0> (a org.mortbay.thread.QueuedThreadPool$PoolThr
> ead)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:625)
> - locked <0x295ecfc0> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
> "30971263@qtp-20051738-1" prio=6 tid=0x0308f800 nid=0x1ae0 in Object.wait() [0x0 325f000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ed030> (a org.mortbay.thread.QueuedThreadPool$PoolThr
> ead)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:625)
> - locked <0x295ed030> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
> "17758476@qtp-20051738-0" prio=6 tid=0x03094800 nid=0x1d58 in Object.wait() [0x0 320f000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ed0a0> (a org.mortbay.thread.QueuedThreadPool$PoolThr
> ead)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:625)
> - locked <0x295ed0a0> (a org.mortbay.thread.QueuedThreadPool$PoolThread)
> "Timer-0" daemon prio=6 tid=0x0308a400 nid=0x1d68 in Object.wait() [0x031bf000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295ed180> (a java.util.TaskQueue)
> at java.util.TimerThread.mainLoop(Timer.java:509)
> - locked <0x295ed180> (a java.util.TaskQueue)
> at java.util.TimerThread.run(Timer.java:462)
> "Low Memory Detector" daemon prio=6 tid=0x02c1d400 nid=0x122c runnable [0x000000 00]
> java.lang.Thread.State: RUNNABLE
> "CompilerThread0" daemon prio=10 tid=0x02c17400 nid=0x1f94 waiting on condition [0x00000000]
> java.lang.Thread.State: RUNNABLE
> "Attach Listener" daemon prio=10 tid=0x02c15c00 nid=0x11b8 runnable [0x00000000]
> java.lang.Thread.State: RUNNABLE
> "Signal Dispatcher" daemon prio=10 tid=0x02c14800 nid=0xf38 waiting on condition [0x00000000]
> java.lang.Thread.State: RUNNABLE
> "Finalizer" daemon prio=8 tid=0x02c0cc00 nid=0x1408 in Object.wait() [0x02ddf000 ]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x29590468> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
> - locked <0x29590468> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
> at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
> "Reference Handler" daemon prio=10 tid=0x02c0b400 nid=0x1614 in Object.wait() [0 x02d8f000]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x295904f0> (a java.lang.ref.Reference$Lock)
> at java.lang.Object.wait(Object.java:485)
> at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
> - locked <0x295904f0> (a java.lang.ref.Reference$Lock)
> "VM Thread" prio=10 tid=0x02c09c00 nid=0x1cc8 runnable
> "VM Periodic Task Thread" prio=10 tid=0x02c20000 nid=0x90c waiting on condition
> JNI global references: 1236
> Heap
> def new generation total 44992K, used 20928K [0x24040000, 0x27110000, 0x29590
> 000)
> eden space 40000K, 52% used [0x24040000, 0x254b0278, 0x26750000)
> from space 4992K, 0% used [0x26c30000, 0x26c30038, 0x27110000)
> to space 4992K, 0% used [0x26750000, 0x26750000, 0x26c30000)
> tenured generation total 99780K, used 74989K [0x29590000, 0x2f701000, 0x34040
> 000)
> the space 99780K, 75% used [0x29590000, 0x2decb7a8, 0x2decb800, 0x2f701000) compacting perm gen total 12288K, used 8833K [0x34040000, 0x34c40000, 0x380400
> 00)
> the space 12288K, 71% used [0x34040000, 0x348e0758, 0x348e0800, 0x34c40000)
> ro space 10240K, 54% used [0x38040000, 0x385bb760, 0x385bb800, 0x38a40000)
> rw space 12288K, 55% used [0x38a40000, 0x390df798, 0x390df800, 0x39640000)
> Here's the top part of a second thread dump (it doesn't all fit in one screen buffer, unfortunately):
> 2010-07-27 11:55:19
> Full thread dump Java HotSpot(TM) Client VM (16.2-b04 mixed mode, sharing):
> "Lucene Merge Thread #0" daemon prio=6 tid=0x02ffc400 nid=0xba0 runnable [0x042e f000]
> java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileChannelImpl.size0(Native Method)
> at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:309)
> - locked <0x2de616d8> (a java.lang.Object)
> at sun.nio.ch.FileChannelImpl.transferFrom(FileChannelImpl.java:597)
> at org.apache.lucene.store.FSDirectory.copy(FSDirectory.java:476)
> at org.apache.lucene.store.FSDirectory$FSIndexOutput.copyBytes(FSDirecto
> ry.java:513)
> at org.apache.lucene.index.FieldsWriter.addRawDocuments(FieldsWriter.jav
> a:210)
> at org.apache.lucene.index.SegmentMerger.copyFieldsWithDeletions(Segment
> Merger.java:392)
> at org.apache.lucene.index.SegmentMerger.mergeFields(SegmentMerger.java:
> 329)
> at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:153)
> at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4024
> )
> at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3618)
> at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMe
> rgeScheduler.java:339)
> at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(Conc
> urrentMergeScheduler.java:407)
> "DestroyJavaVM" prio=6 tid=0x003b6800 nid=0x1e34 waiting on condition [0x0000000 0]
> java.lang.Thread.State: RUNNABLE
> "Timer-2" daemon prio=6 tid=0x0363b400 nid=0x1e2c in Object.wait() [0x03a9f000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x297703f0> (a java.util.TaskQueue)
> at java.util.TimerThread.mainLoop(Timer.java:509)
> - locked <0x297703f0> (a java.util.TaskQueue)
> at java.util.TimerThread.run(Timer.java:462)
> "pool-1-thread-1" prio=6 tid=0x02cb1400 nid=0x1760 waiting on condition [0x03a3f 000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x296acc88> (a java.util.concurrent.locks.Abstra
> ctQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject
> .await(AbstractQueuedSynchronizer.java:1925)
> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.jav
> a:399)
> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.ja
> va:947)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
> .java:907)
> at java.lang.Thread.run(Thread.java:619)
> "Timer-1" daemon prio=6 tid=0x036de000 nid=0x1130 in Object.wait() [0x039df000]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x29642f00> (a java.util.TaskQueue)
> at java.util.TimerThread.mainLoop(Timer.java:509)
> - locked <0x29642f00> (a java.util.TaskQueue)
> at java.util.TimerThread.run(Timer.java:462)
> "25615188@qtp-20051738-9 - Acceptor0 SocketConnector@0.0.0.0:8983" prio=6 tid=0x 03076800 nid=0x19ac runnable [0x034df000]
> java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketAccept(Native Method)
> at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
> - locked <0x29770448> (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:99)
> at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.ja
> va:707)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.j
> ava:582)
> "11245030@qtp-20051738-8" prio=6 tid=0x03075000 nid=0x10b4 waiting on condition [0x0348e000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x2970bad8> (a java.util.concurrent.locks.Reentr
> antReadWriteLock$NonfairSync)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInt
> errupt(AbstractQueuedSynchronizer.java:747)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared
> (AbstractQueuedSynchronizer.java:877)
> ...
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org