jackrabbit-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Harald Wellmann (JIRA)" <j...@apache.org>
Subject [jira] Created: (JCR-2787) IndexMerger: Synchronization issue on repository shutdown
Date Sat, 16 Oct 2010 19:26:23 GMT
IndexMerger: Synchronization issue on repository shutdown
---------------------------------------------------------

                 Key: JCR-2787
                 URL: https://issues.apache.org/jira/browse/JCR-2787
             Project: Jackrabbit Content Repository
          Issue Type: Bug
          Components: jackrabbit-core
    Affects Versions: 2.1.1
         Environment: JDK 1.6.0_20, Ubuntu 10.04
            Reporter: Harald Wellmann


After inserting a large number of nodes (~200000) into a repository and then closing the session,
I get the following exception:

19:42:40.556 [jackrabbit-pool-5] DEBUG o.a.j.core.query.lucene.IndexMerger - # of busy merge
workers: 2
19:42:40.556 [jackrabbit-pool-3] DEBUG o.a.j.core.query.lucene.IndexMerger - accepted merge
request
19:42:40.556 [jackrabbit-pool-5] DEBUG o.a.j.core.query.lucene.IndexMerger - Worker finished
19:42:40.556 [jackrabbit-pool-3] DEBUG o.a.j.core.query.lucene.IndexMerger - create new index
19:42:40.557 [jackrabbit-pool-3] DEBUG o.a.j.core.query.lucene.IndexMerger - get index readers
from MultiIndex
19:42:40.640 [main] INFO  c.a.kmp.generator.JpaToJcrImporter - end JCR save
19:42:40.849 [main] INFO  o.a.j.core.TransientRepository - Session closed
19:42:40.849 [main] INFO  o.a.jackrabbit.core.RepositoryImpl - Shutting down repository...
19:42:40.849 [main] DEBUG o.a.j.core.query.lucene.IndexMerger - dispose IndexMerger
19:42:40.849 [main] DEBUG o.a.j.core.query.lucene.IndexMerger - quit flag set
19:42:40.849 [main] INFO  o.a.j.core.query.lucene.SearchIndex - Index closed: repository/repository/index
19:42:40.850 [main] INFO  o.a.jackrabbit.core.RepositoryImpl - shutting down workspace 'default'...
19:42:40.850 [main] INFO  o.a.j.c.o.ObservationDispatcher - Notification of EventListeners
stopped.
19:42:40.850 [main] DEBUG o.a.j.core.query.lucene.IndexMerger - dispose IndexMerger
19:42:40.850 [main] DEBUG o.a.j.core.query.lucene.IndexMerger - quit flag set
19:42:40.850 [main] DEBUG o.a.j.core.query.lucene.IndexMerger - IndexMerger.Worker thread
stopped
19:42:40.855 [main] DEBUG o.a.j.core.query.lucene.IndexMerger - index added: name=_6h, numDocs=890
19:42:41.367 [jackrabbit-pool-3] DEBUG o.a.j.core.query.lucene.IndexMerger - deleting index
_6g
19:42:41.393 [main] INFO  o.a.j.core.query.lucene.SearchIndex - Index closed: repository/workspaces/default/index
19:42:41.410 [jackrabbit-pool-3] ERROR o.a.j.core.query.lucene.IndexMerger - Error while merging
indexes: 
org.apache.lucene.store.AlreadyClosedException: this IndexWriter is closed
	at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:412) ~[lucene-core-2.4.1.jar:2.4.1
750176 - 2009-03-04 21:56:52]
	at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:417) ~[lucene-core-2.4.1.jar:2.4.1
750176 - 2009-03-04 21:56:52]
	at org.apache.lucene.index.IndexWriter.startTransaction(IndexWriter.java:2511) ~[lucene-core-2.4.1.jar:2.4.1
750176 - 2009-03-04 21:56:52]
	at org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3273) ~[lucene-core-2.4.1.jar:2.4.1
750176 - 2009-03-04 21:56:52]
	at org.apache.jackrabbit.core.query.lucene.PersistentIndex.addIndexes(PersistentIndex.java:114)
~[jackrabbit-core-2.1.1.jar:2.1.1]
	at org.apache.jackrabbit.core.query.lucene.IndexMerger$Worker.run(IndexMerger.java:525) ~[jackrabbit-core-2.1.1.jar:2.1.1]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [na:1.6.0_20]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [na:1.6.0_20]
	at java.util.concurrent.FutureTask.run(FutureTask.java:138) [na:1.6.0_20]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
[na:1.6.0_20]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
[na:1.6.0_20]
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [na:1.6.0_20]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [na:1.6.0_20]
	at java.lang.Thread.run(Thread.java:619) [na:1.6.0_20]
19:42:41.420 [jackrabbit-pool-3] DEBUG o.a.j.core.query.lucene.IndexMerger - Worker finished
19:42:41.839 [main] INFO  o.a.j.c.p.b.DerbyPersistenceManager - Database 'repository/workspaces/default/db'
shutdown.


The problem is reproducible. Apparently, the Lucene index is closed before all IndexMerger
worker threads are terminated. The root cause seems to be the AtomicBoolean IndexMerger.Worker.terminated
which is always true. The enclosed patch solves the problem in my use case.



-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


Mime
View raw message