Return-Path: Delivered-To: apmail-jackrabbit-users-archive@minotaur.apache.org Received: (qmail 28486 invoked from network); 27 Feb 2010 00:36:39 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.3) by minotaur.apache.org with SMTP; 27 Feb 2010 00:36:39 -0000 Received: (qmail 59706 invoked by uid 500); 27 Feb 2010 00:36:38 -0000 Delivered-To: apmail-jackrabbit-users-archive@jackrabbit.apache.org Received: (qmail 59684 invoked by uid 500); 27 Feb 2010 00:36:38 -0000 Mailing-List: contact users-help@jackrabbit.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: users@jackrabbit.apache.org Delivered-To: mailing list users@jackrabbit.apache.org Received: (qmail 59674 invoked by uid 99); 27 Feb 2010 00:36:38 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 27 Feb 2010 00:36:38 +0000 X-ASF-Spam-Status: No, hits=-0.0 required=10.0 tests=SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of justinedelson@gmail.com designates 74.125.92.27 as permitted sender) Received: from [74.125.92.27] (HELO qw-out-2122.google.com) (74.125.92.27) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 27 Feb 2010 00:36:29 +0000 Received: by qw-out-2122.google.com with SMTP id 5so144713qwd.13 for ; Fri, 26 Feb 2010 16:36:08 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:reply-to :user-agent:mime-version:to:subject:references:in-reply-to :content-type:content-transfer-encoding; bh=u/o7/zrOv42jH+TCSPUtpGuriVde2VLPSmXiRELQSmg=; b=Lbv0dF2hJNvx3i1OmL7dbV96NRAepMTAThMH4SPwMmrUR1JvC0qAbhKMblJC6y2BWT 9r8jbkCpRhUQv0nEEcjSd6WSryDvMk9jtmYGXu6mPf83ygXOnAe4+11IX/gd6fxWrmnL TKS2F7jXu5ZPgSrEtc8kuLKwO7g1qdNezoGpg= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:reply-to:user-agent:mime-version:to:subject :references:in-reply-to:content-type:content-transfer-encoding; b=OPDL39AAnvRgs06Pl8BR7hWYalUdeF62VE/LtXML0FBhp6TV9zNkQmRsRxwsFXxRwE HlIWH/fd2j+E+DcQPg2X7sswPU5IF9yA5Yuhxb6gHg9twwB1RhhJVabVdatMePSSElSY rKOFiFbgeF6dtNdsyXW8WYIT/8R2P96N0e9Wc= Received: by 10.224.89.194 with SMTP id f2mr673766qam.350.1267230966830; Fri, 26 Feb 2010 16:36:06 -0800 (PST) Received: from Justin-Edelsons-iMac.local (ool-44c6554e.dyn.optonline.net [68.198.85.78]) by mx.google.com with ESMTPS id 7sm1922137qwb.20.2010.02.26.16.36.04 (version=SSLv3 cipher=RC4-MD5); Fri, 26 Feb 2010 16:36:05 -0800 (PST) Message-ID: <4B8868F3.4080506@gmail.com> Date: Fri, 26 Feb 2010 19:36:03 -0500 From: Justin Edelson Reply-To: justin@justinedelson.com User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-US; rv:1.9.1.8) Gecko/20100216 Thunderbird/3.0.2 MIME-Version: 1.0 To: users@jackrabbit.apache.org Subject: Re: Oracle 10g and Jackrabbit References: <9A860BD1-1204-4D94-9EA0-957815B7238E@yahoo.com> In-Reply-To: <9A860BD1-1204-4D94-9EA0-957815B7238E@yahoo.com> Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit On 2/26/10 7:22 PM, Neil Lott wrote: > Hi, > > I'm having trouble inserting more than 2450 or so nodes underneath one parent node. I'm using oracle persistence and jackrabbit-2.0.0. > Nothing in the log below indicates what kind of "trouble" you're having. That'd probably be useful. Jackrabbit definitely shouldn't stop you from adding all these nodes. But... (continued below) > It looks like the issue is happening between here these log messages. > > 2010-02-26 17:10:01,679 INFO [main] (BundleCache.get:106) - num=1977 mem=8189k max=8192k avg=4242 hits=2078548 miss=221452 > 2010-02-26 17:10:02,450 DEBUG [main] (AbstractBundlePersistenceManager.putBundle:686) - stored bundle 9d35fed4-47b1-4462-b88d-4a2d579b2161 > > I've read: > > http://n4.nabble.com/Explanation-and-solutions-of-some-Jackrabbit-queries-regarding-performance-td516614.html#a516614 > > but limiting child node sizes to 4000 seems a bit odd. I need to store 1.7 million nodes at the very least underneath a given parent. > > Would someone provide some pointers if possible? Don't have 1.7 million nodes under a single parent. Jackrabbit will not perform well. See https://issues.apache.org/jira/browse/JCR-642 for discussion. You also might want to read this recent thread about possibly improving this in Jackrabbit 3: http://markmail.org/thread/v2wl5nh43zf2shkp Justin > > Thanks, > > Neil > > > > > > Full log: > > 2010-02-26 17:09:57,585 DEBUG [main] (JackRabbitProgram.addProgram:56) - Adding program [Program{UUID='null', name='EP2586',....] > 2010-02-26 17:09:57,585 TRACE [main] (TraceLogger.logBefore:48) - Before public org.jcrom.Jcrom com.twc.mystro.resource.dao.jcr.JCROMBootstrapper.getJcrom() > 2010-02-26 17:09:57,601 TRACE [main] (TraceLogger.logAfterReturning:55) - AfterReturning public org.jcrom.Jcrom com.twc.mystro.resource.dao.jcr.JCROMBootstrapper.getJcrom() returning org.jcrom.Jcrom@11ba3c1f > 2010-02-26 17:09:57,602 DEBUG [main] (ProgramDAOJCR.createParentNode:108) - Root node [/Program] already exists. > 2010-02-26 17:09:57,602 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f > 2010-02-26 17:09:57,603 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{http://www.jcp.org/jcr/1.0}primaryType > 2010-02-26 17:09:57,603 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{http://www.jcp.org/jcr/1.0}mixinTypes > 2010-02-26 17:09:57,604 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{http://www.jcp.org/jcr/1.0}uuid > 2010-02-26 17:09:57,604 DEBUG [main] (ItemManager.cacheItem:904) - caching item 67004716-ec8d-4013-aca2-045cb5d057a2 > 2010-02-26 17:09:57,605 DEBUG [main] (ItemManager.cacheItem:904) - caching item 67004716-ec8d-4013-aca2-045cb5d057a2/{http://www.jcp.org/jcr/1.0}primaryType > 2010-02-26 17:09:57,605 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}tmsSeriesID > 2010-02-26 17:09:57,605 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}tmsParentID > 2010-02-26 17:09:57,605 DEBUG [main] (ItemManager.itemDestroyed:1001) - destroyed item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}tmsParentID > 2010-02-26 17:09:57,606 DEBUG [main] (ItemManager.evictItems:918) - removing items 80925a14-4a53-4d66-80b7-3c3b0481377f/{}tmsParentID from cache > 2010-02-26 17:09:57,606 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}tmsProgramID > 2010-02-26 17:09:57,606 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}description > 2010-02-26 17:09:57,606 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}programType > 2010-02-26 17:09:57,607 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}rating > 2010-02-26 17:09:57,607 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}title > 2010-02-26 17:09:57,607 DEBUG [main] (ItemManager.cacheItem:904) - caching item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}images > 2010-02-26 17:09:57,607 DEBUG [main] (ItemManager.itemDestroyed:1001) - destroyed item 80925a14-4a53-4d66-80b7-3c3b0481377f/{}images > 2010-02-26 17:09:57,608 DEBUG [main] (ItemManager.evictItems:918) - removing items 80925a14-4a53-4d66-80b7-3c3b0481377f/{}images from cache > 2010-02-26 17:09:57,601 DEBUG [ObservationManager] (ObservationDispatcher.run:156) - got EventStateCollection > 2010-02-26 17:09:57,609 DEBUG [ObservationManager] (ObservationDispatcher.run:157) - event delivery to 0 consumers started... > 2010-02-26 17:09:57,609 DEBUG [ObservationManager] (ObservationDispatcher.run:168) - event delivery finished. > 2010-02-26 17:09:57,710 INFO [main] (LRUNodeIdCache.contains:70) - num=179/10240 hits=1823 miss=2298177 > 2010-02-26 17:10:01,352 DEBUG [Timer-1] (MultiIndex.checkFlush:1281) - Flushing index after being idle for 3769 ms. > 2010-02-26 17:10:01,356 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: setInfoStream deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@462f654 > 2010-02-26 17:10:01,356 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: setInfoStream: dir=org.apache.lucene.store.RAMDirectory@325a92d5 autoCommit=false mergePolicy=org.apache.lucene.index.LogByteSizeMergePolicy@7d1a070b mergeScheduler=org.apache.lucene.index.ConcurrentMergeScheduler@37c4a357 ramBufferSizeMB=16.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1 maxFieldLength=10000 index= > 2010-02-26 17:10:01,361 DEBUG [Timer-1] (AbstractIndex.addDocuments:207) - Inverted document in 3 ms > 2010-02-26 17:10:01,361 DEBUG [Timer-1] (AbstractIndex.addDocuments:207) - Inverted document in 1 ms > 2010-02-26 17:10:01,361 DEBUG [Timer-1] (AbstractIndex.commit:380) - committing IndexWriter. > 2010-02-26 17:10:01,362 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: commit: start > 2010-02-26 17:10:01,362 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: commit: now prepare > 2010-02-26 17:10:01,362 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: prepareCommit: flush > 2010-02-26 17:10:01,362 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: flush: segment=_0 docStoreSegment=_0 docStoreOffset=0 flushDocs=true flushDeletes=true flushDocStores=true numDocs=2 numBufDelTerms=0 > 2010-02-26 17:10:01,362 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: index before flush > 2010-02-26 17:10:01,362 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: DW: flush postings as segment _0 numDocs=2 > 2010-02-26 17:10:01,362 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: DW: closeDocStore: 5 files to flush to segment _0 numDocs=2 > 2010-02-26 17:10:01,364 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: DW: oldRAMSize=223232 newFlushedSize=1493 docs/MB=1,404.656 new/old=0.669% > 2010-02-26 17:10:01,364 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: now checkpoint "segments_1" [1 segments ; isCommit = false] > 2010-02-26 17:10:01,364 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: now checkpoint "segments_1" [1 segments ; isCommit = false] > 2010-02-26 17:10:01,364 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.fnm" > 2010-02-26 17:10:01,365 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.frq" > 2010-02-26 17:10:01,365 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.prx" > 2010-02-26 17:10:01,365 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.tis" > 2010-02-26 17:10:01,365 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.tii" > 2010-02-26 17:10:01,365 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.nrm" > 2010-02-26 17:10:01,365 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.tvx" > 2010-02-26 17:10:01,366 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.tvf" > 2010-02-26 17:10:01,366 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.tvd" > 2010-02-26 17:10:01,366 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.fdx" > 2010-02-26 17:10:01,366 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "_0.fdt" > 2010-02-26 17:10:01,366 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: LMP: findMerges: 1 segments > 2010-02-26 17:10:01,367 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: LMP: level -1.0 to 3.3818367: 1 segments > 2010-02-26 17:10:01,367 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: now merge > 2010-02-26 17:10:01,367 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: index: _0:c2 > 2010-02-26 17:10:01,367 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: no more merges pending; now return > 2010-02-26 17:10:01,367 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: startCommit(): start sizeInBytes=0 > 2010-02-26 17:10:01,367 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: startCommit index=_0:c2 changeCount=3 > 2010-02-26 17:10:01,367 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: now sync _0.cfs > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: done all syncs > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: commit: pendingCommit != null > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: now checkpoint "segments_2" [1 segments ; isCommit = true] > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: deleteCommits: now decRef commit "segments_1" > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IFD [Timer-1]: delete "segments_1" > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: commit: done > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: optimize: index now _0:c2 > 2010-02-26 17:10:01,368 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: flush: segment=null docStoreSegment=null docStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0 > 2010-02-26 17:10:01,369 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: index before flush _0:c2 > 2010-02-26 17:10:01,369 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: now merge > 2010-02-26 17:10:01,369 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: index: _0:c2 > 2010-02-26 17:10:01,369 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: no more merges pending; now return > 2010-02-26 17:10:01,369 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: now flush at close > 2010-02-26 17:10:01,369 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: flush: segment=null docStoreSegment=null docStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0 > 2010-02-26 17:10:01,369 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: index before flush _0:c2 > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: now merge > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: index: _0:c2 > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: CMS: no more merges pending; now return > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: now call final commit() > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: startCommit(): start sizeInBytes=0 > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: skip startCommit(): no changes pending > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: commit: pendingCommit == null; skip > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: commit: done > 2010-02-26 17:10:01,370 DEBUG [Timer-1] (AbstractIndex$LoggingPrintStream.println:636) - IW 122 [Timer-1]: at close: _0:c2 > 2010-02-26 17:10:01,394 DEBUG [Timer-1] (IndexMerger.indexAdded:170) - index added: name=_3b, numDocs=2 > 2010-02-26 17:10:01,395 DEBUG [Timer-1] (MultiIndex.commitVolatileIndex:1178) - Committed in-memory index in 43ms. > 2010-02-26 17:10:01,395 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,395 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,395 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,395 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,396 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,396 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,396 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,396 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,396 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,396 DEBUG [Timer-1] (AbstractIndex.commit:376) - committing IndexReader. > 2010-02-26 17:10:01,412 DEBUG [Timer-1] (IndexInfos.write:155) - Writing IndexInfos indexes_2w > 2010-02-26 17:10:01,412 DEBUG [Timer-1] (IndexInfos.write:164) - + _1:4 > 2010-02-26 17:10:01,412 DEBUG [Timer-1] (IndexInfos.write:164) - + _2:2 > 2010-02-26 17:10:01,412 DEBUG [Timer-1] (IndexInfos.write:164) - + _3:2 > 2010-02-26 17:10:01,412 DEBUG [Timer-1] (IndexInfos.write:164) - + _4:2 > 2010-02-26 17:10:01,412 DEBUG [Timer-1] (IndexInfos.write:164) - + _5:2 > 2010-02-26 17:10:01,413 DEBUG [Timer-1] (IndexInfos.write:164) - + _6:2 > 2010-02-26 17:10:01,413 DEBUG [Timer-1] (IndexInfos.write:164) - + _7:2 > 2010-02-26 17:10:01,413 DEBUG [Timer-1] (IndexInfos.write:164) - + _1v:1 > 2010-02-26 17:10:01,413 DEBUG [Timer-1] (IndexInfos.write:164) - + _3a:1 > 2010-02-26 17:10:01,413 DEBUG [Timer-1] (IndexInfos.write:164) - + _3b:2 > 2010-02-26 17:10:01,413 DEBUG [Timer-1] (IndexHistory.pruneOutdated:133) - Pruning index infos older than: 1267229401413(org.apache.jackrabbit.core.query.lucene.directory.FSDirectoryManager$FSDir@org.apache.lucene.store.FSDirectory@/Users/neil/Business/SnowyRangeConsulting/projects/twc/depot/server/releases/prelude/components/nationalmetadata/target/nationalmetadata-1.0.0.0-nationalmetadata/usr/local/prelude/components/nationalmetadata/jackrabbit/server/workspaces/default/index) > 2010-02-26 17:10:01,414 DEBUG [Timer-1] (IndexHistory.pruneOutdated:138) - Skipping first index infos. generation=104 > 2010-02-26 17:10:01,414 DEBUG [Timer-1] (IndexHistory.pruneOutdated:156) - Deleted redo log with generation=103, timestamp=1267229401000 > 2010-02-26 17:10:01,415 DEBUG [Timer-1] (IndexHistory.pruneOutdated:166) - Deleted index infos with generation=103 > 2010-02-26 17:10:01,679 INFO [main] (BundleCache.get:106) - num=1977 mem=8189k max=8192k avg=4242 hits=2078548 miss=221452 > 2010-02-26 17:10:02,450 DEBUG [main] (AbstractBundlePersistenceManager.putBundle:686) - stored bundle 9d35fed4-47b1-4462-b88d-4a2d579b2161 > 2010-02-26 17:10:02,451 DEBUG [main] (AbstractBundlePersistenceManager.putBundle:686) - stored bundle 67004716-ec8d-4013-aca2-045cb5d057a2 > 2010-02-26 17:10:02,453 DEBUG [main] (AbstractBundlePersistenceManager.putBundle:686) - stored bundle 80925a14-4a53-4d66-80b7-3c3b0481377f > 2010-02-26 17:10:02,490 DEBUG [main] (SharedItemStateManager$Update.end:738) - persisting change log {#addedStates=12, #modifiedStates=1, #deletedStates=0, #modifiedRefs=0} took 92ms > 2010-02-26 17:10:02,491 DEBUG [main] (ObservationDispatcher.dispatchEvents:210) - notifying 4 synchronous listeners. > 2010-02-26 17:10:02,491 DEBUG [main] (EventConsumer.consumeEvents:249) - listener org.apache.jackrabbit.core.lock.LockManagerImpl processed events in 0 ms. > 2010-02-26 17:10:02,492 DEBUG [main] (SearchManager.onEvent:327) - onEvent: indexing started > 2010-02-26 17:10:02,493 DEBUG [main] (SearchManager.onEvent:429) - onEvent: indexing finished in 1 ms. > 2010-02-26 17:10:02,494 DEBUG [main] (EventConsumer.consumeEvents:249) - listener org.apache.jackrabbit.core.SearchManager processed events in 2 ms. > 2010-02-26 17:10:02,494 DEBUG [main] (JackRabbitProgram.addProgram:62) - Added program > > > > Here is my repository.xml file: > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > workspaceName="security"> > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > >