Return-Path: Delivered-To: apmail-jackrabbit-users-archive@locus.apache.org Received: (qmail 27721 invoked from network); 31 Mar 2008 00:06:43 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 31 Mar 2008 00:06:43 -0000 Received: (qmail 35025 invoked by uid 500); 31 Mar 2008 00:06:40 -0000 Delivered-To: apmail-jackrabbit-users-archive@jackrabbit.apache.org Received: (qmail 35009 invoked by uid 500); 31 Mar 2008 00:06:40 -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 35000 invoked by uid 99); 31 Mar 2008 00:06:40 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 30 Mar 2008 17:06:40 -0700 X-ASF-Spam-Status: No, hits=1.2 required=10.0 tests=SPF_NEUTRAL X-Spam-Check-By: apache.org Received-SPF: neutral (athena.apache.org: local policy) Received: from [207.97.245.185] (HELO smtp185.iad.emailsrvr.com) (207.97.245.185) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 31 Mar 2008 00:05:56 +0000 Received: from relay8.relay.iad.mlsrvr.com (localhost [127.0.0.1]) by relay8.relay.iad.mlsrvr.com (SMTP Server) with ESMTP id 8D4B71B531F; Sun, 30 Mar 2008 20:06:00 -0400 (EDT) Received: by relay8.relay.iad.mlsrvr.com (Authenticated sender: dbrosius-AT-baybroadband.net) with ESMTP id 00AA91B4147; Sun, 30 Mar 2008 20:05:58 -0400 (EDT) Message-ID: <004c01c892cb$685fbbe0$6501a8c0@MeBigFatGuy> From: "Dave Brosius" To: , References: <47EFE756.5060500@proteanit.net> Subject: Re: Node unfound, Node unsaved Date: Sun, 30 Mar 2008 20:06:09 -0500 MIME-Version: 1.0 Content-Type: text/plain; format=flowed; charset="iso-8859-1"; reply-type=original Content-Transfer-Encoding: 7bit X-Priority: 3 X-MSMail-Priority: Normal X-Mailer: Microsoft Outlook Express 6.00.2900.3138 X-MimeOLE: Produced By Microsoft MimeOLE V6.00.2900.3198 X-Virus-Checked: Checked by ClamAV on apache.org Absolute queries need to start with /jcr:root which is something i was just informed of myself. cheers, dave ----- Original Message ----- From: "Charles Johnson" To: Sent: Sunday, March 30, 2008 2:17 PM Subject: Node unfound, Node unsaved > I'm trying to get a repository set up for web use, initially offline. > > There seem to be problems with the most fundamental functionality. I'm > trying to create a single Node, /reviews, which I'll later use as the > root for /reviews/review[0..n] > > I try a 'find or create' approach, but it never gets found and it never > gets saved. There must be (I hope) something simple that's wrong. Below > is the code and attached is its log file, representing three runs of the > programme. > > Charles > > import net.proteanit.mantex.util.JackUtils; > > import org.apache.jackrabbit.core.TransientRepository; > > import org.apache.log4j.Logger; > > import javax.jcr.Node; > import javax.jcr.NodeIterator; > import javax.jcr.Property; > import javax.jcr.RepositoryException; > import javax.jcr.Session; > import javax.jcr.SimpleCredentials; > import javax.jcr.Workspace; > import javax.jcr.query.Query; > import javax.jcr.query.QueryManager; > import javax.jcr.query.QueryResult; > > > public class RC5 { > private static Logger log = Logger.getLogger(RC5.class); > private Session session; > > public RC5() { > //Runtime.getRuntime().addShutdownHook(new Thread(new > SessionCloser())); > } > > public Session getSession() { > return session; > } > > private void login() { > TransientRepository repository = null; > > try { > repository = new TransientRepository(); > session = repository.login(new SimpleCredentials("username", > "password".toCharArray())); > > if ((session != null) && log.isInfoEnabled()) { > log.info(String.format("Got session. Workspace is %s", > session.getWorkspace().getName())); > } > > if (session == null) { > log.error("******** Did not get session in RC5 ********"); > } > } catch (Exception e) { > log.error("", e); > } > } > > public static void main(String[] args) throws Exception { > System.setProperty("org.apache.jackrabbit.repository.home", > "/apache-tomcat-6.0.16/rep-mantex.co.uk"); > > RC5 rc5 = new RC5(); > final String rootPath = "/reviews[0]"; > > try { > rc5.login(); > > Node reviews = rc5.getReviewsRoot(rootPath); > > if ((reviews != null) && log.isDebugEnabled()) { > log.debug("/reviews node found - no need to create it"); > } > > if (reviews == null) { > if (log.isDebugEnabled()) { > log.debug("/reviews node not found - creating it"); > } > > rc5.createReviewsRoot(); > } > > //rc5.printNodes(); > rc5.dumpNodes(); > > if (log.isDebugEnabled()) { > log.debug("Attempting to save session..."); > } > > try { > rc5.getSession().save(); > } catch (Exception e) { > log.fatal("", e); > } > } finally { > if (log.isDebugEnabled()) { > log.debug("Attempting to log out..."); > } > rc5.getSession().logout(); > } > } > > private Node getReviewsRoot(String rootPath) { > Node reviewsRoot = null; > > try { > Workspace workSpace = session.getWorkspace(); > QueryManager queryManager = workSpace.getQueryManager(); > > Query query = queryManager.createQuery(rootPath, Query.XPATH); > > QueryResult queryResult = query.execute(); > > NodeIterator queryResultNodeIterator = queryResult.getNodes(); > > if (queryResultNodeIterator.hasNext()) { > reviewsRoot = (Node) queryResultNodeIterator.next(); > } > } catch (RepositoryException e) { > log.fatal("", e); > } > > return reviewsRoot; > } > > private void dumpNodes() { > try { > Node root = session.getRootNode(); > JackUtils.dump(root); > } catch (RepositoryException e) { > log.fatal("", e); > } > } > > private void printNodes() { > try { > Node root = session.getRootNode(); > NodeIterator i = root.getNodes(); > Node n = null; > > while (i.hasNext()) { > n = (Node) i.next(); > > if (log.isInfoEnabled()) { > log.info(String.format("Node:name=%s,depth=%d", > n.getName(), n.getDepth())); > } > } > } catch (RepositoryException e) { > log.fatal("", e); > } > } > > private Node createReviewsRoot() { > Node reviews = null; > > try { > final String rootPath = "reviews"; > Node root = session.getRootNode(); > > if (log.isDebugEnabled()) { > log.debug(String.format( > "Attempting to create node with path %s", > rootPath)); > } > > reviews = root.addNode(rootPath); > > if (log.isDebugEnabled()) { > log.debug(String.format("Attempting to save node %s", > rootPath)); > } > > session.save(); > } catch (RepositoryException e) { > log.fatal("", e); > } > > return reviews; > } > > private class SessionCloser implements Runnable { > public void run() { > if (log.isInfoEnabled()) { > log.info("Attempting to close down session..."); > } > > // Trouble at t'mill: this is running before it should be... > /* > if ((session != null) && session.isLive()) { > session.logout(); > } > */ > } > } > } > > > -------------------------------------------------------------------------------- 30.03.2008 11:24:52 *DEBUG* TransientRepository: Initializing transient repository (TransientRepository.java, line 260) 30.03.2008 11:24:53 *INFO * RepositoryImpl: Starting repository... (RepositoryImpl.java, line 234) 30.03.2008 11:24:53 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/repository (LocalFileSystem.java, line 166) 30.03.2008 11:24:54 *INFO * NodeTypeRegistry: no custom node type definitions found (NodeTypeRegistry.java, line 836) 30.03.2008 11:24:54 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/version (LocalFileSystem.java, line 166) 30.03.2008 11:25:04 *INFO * ConnectionRecoveryManager: Database: Apache Derby / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 345) 30.03.2008 11:25:04 *INFO * ConnectionRecoveryManager: Driver: Apache Derby Embedded JDBC Driver / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 346) 30.03.2008 11:25:09 *DEBUG* AbstractBundlePersistenceManager: stored bundle deadbeef-face-babe-cafe-babecafebabe (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 11:25:10 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@9903f4 size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:25:10 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@b0095d size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:25:10 *INFO * RepositoryImpl: initializing workspace 'default'... (RepositoryImpl.java, line 1733) 30.03.2008 11:25:10 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default (LocalFileSystem.java, line 166) 30.03.2008 11:25:14 *INFO * ConnectionRecoveryManager: Database: Apache Derby / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 345) 30.03.2008 11:25:14 *INFO * ConnectionRecoveryManager: Driver: Apache Derby Embedded JDBC Driver / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 346) 30.03.2008 11:25:15 *DEBUG* AbstractBundlePersistenceManager: stored bundle deadbeef-cafe-babe-cafe-babecafebabe (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 11:25:15 *DEBUG* AbstractBundlePersistenceManager: stored bundle cafebabe-cafe-babe-cafe-babecafebabe (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 11:25:15 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@18e609b size=1, 964/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=1 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=2 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=3 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=4 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=5 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=6 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=7 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=8 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=9 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=10 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=11 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=12 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=13 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=14 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=15 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=16 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=17 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=18 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=19 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=20 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=21 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=22 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=23 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=24 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=25 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=26 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=27 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=28 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=29 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=30 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:15 *DEBUG* AbstractVISProvider: item added to cache. size=31 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=32 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=33 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=34 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=35 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=36 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=37 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=38 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=39 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=40 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=41 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=42 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=43 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=44 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=45 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=46 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=47 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=48 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=49 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=50 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=51 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=52 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=53 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=54 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=55 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=56 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=57 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=58 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=59 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=60 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=61 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=62 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=63 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=64 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=65 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=66 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=67 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=68 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=69 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=70 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=71 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=72 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=73 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=74 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=75 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=76 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=77 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=78 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=79 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=80 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=81 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=82 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=83 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=84 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=85 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=86 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=87 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=88 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=89 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=90 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=91 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=92 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *DEBUG* AbstractVISProvider: item added to cache. size=93 (AbstractVISProvider.java, line 334) 30.03.2008 11:25:16 *INFO * RepositoryImpl: workspace 'default' initialized (RepositoryImpl.java, line 1736) 30.03.2008 11:25:17 *WARN * BeanConfig: org.apache.jackrabbit.core.query.lucene.SearchIndex does not support 'extractorPoolSize '; the setting is ignored. (BeanConfig.java, line 120) 30.03.2008 11:25:17 *DEBUG* JackrabbitTextExtractor: JackrabbitTextExtractor(org.apache.jackrabbit.extractor.MsWordTextExtractor,org.apache.jackrabbit.extractor.MsExcelTextExtractor,org.apache.jackrabbit.extractor.MsPowerPointTextExtractor,org.apache.jackrabbit.extractor.PdfTextExtractor,org.apache.jackrabbit.extractor.OpenOfficeTextExtractor,org.apache.jackrabbit.extractor.RTFTextExtractor,org.apache.jackrabbit.extractor.HTMLTextExtractor,org.apache.jackrabbit.extractor.XMLTextExtractor) (JackrabbitTextExtractor.java, line 108) 30.03.2008 11:25:18 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index (LocalFileSystem.java, line 166) 30.03.2008 11:25:18 *DEBUG* AbstractIndex: closing IndexWriter. (AbstractIndex.java, line 226) 30.03.2008 11:25:18 *DEBUG* CachingIndexReader: initialized 0 DocIds in 1 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 11:25:18 *DEBUG* Recovery: RedoLog is empty, no recovery needed. (Recovery.java, line 80) 30.03.2008 11:25:18 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@8ddb93 size=1, 1264/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:25:18 *DEBUG* CacheManager: resizeAll size=4 (CacheManager.java, line 135) 30.03.2008 11:25:18 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@b0095d now:4194304 used:664 access:2 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:18 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@8ddb93 now:4194304 used:47920 access:127 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:18 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@18e609b now:4194304 used:3256 access:7 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:18 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@9903f4 now:4194304 used:1178 access:5 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:18 *DEBUG* AbstractIndex: closing IndexReader. (AbstractIndex.java, line 296) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 96 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 101 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 231 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 6 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 20 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 24 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:19 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 6 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 10 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* CacheManager: resizeAll size=4 (CacheManager.java, line 135) 30.03.2008 11:25:20 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@b0095d now:131072 used:664 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:20 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@8ddb93 now:131072 used:130660 access:381 new:16384000 (CacheManager.java, line 204) 30.03.2008 11:25:20 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@18e609b now:131072 used:3256 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:20 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@9903f4 now:131072 used:1178 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 22 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 8 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:20 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 6 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 11 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 65 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 25 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 19 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 17 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 12 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 6 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 19 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* CacheManager: resizeAll size=4 (CacheManager.java, line 135) 30.03.2008 11:25:21 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@b0095d now:131072 used:664 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:21 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@8ddb93 now:16384000 used:346470 access:635 new:346470 (CacheManager.java, line 204) 30.03.2008 11:25:21 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@18e609b now:131072 used:3256 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:21 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@9903f4 now:131072 used:1178 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 25 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 6 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 8 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 18 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:21 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 24 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 16 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 26 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 6 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 28 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 7 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 2 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 19 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 16 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:22 *DEBUG* CacheManager: resizeAll size=4 (CacheManager.java, line 135) 30.03.2008 11:25:22 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@b0095d now:131072 used:664 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:22 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@8ddb93 now:346470 used:346382 access:889 new:16384000 (CacheManager.java, line 204) 30.03.2008 11:25:22 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@18e609b now:131072 used:3256 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:22 *DEBUG* CacheManager: org.apache.jackrabbit.core.state.MLRUItemStateCache@9903f4 now:131072 used:1178 access:0 new:131072 (CacheManager.java, line 204) 30.03.2008 11:25:22 *INFO * SearchIndex: Index initialized: /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index Version: 2 (SearchIndex.java, line 460) 30.03.2008 11:25:23 *DEBUG* JackrabbitTextExtractor: JackrabbitTextExtractor(org.apache.jackrabbit.extractor.MsWordTextExtractor,org.apache.jackrabbit.extractor.MsExcelTextExtractor,org.apache.jackrabbit.extractor.MsPowerPointTextExtractor,org.apache.jackrabbit.extractor.PdfTextExtractor,org.apache.jackrabbit.extractor.OpenOfficeTextExtractor,org.apache.jackrabbit.extractor.RTFTextExtractor,org.apache.jackrabbit.extractor.HTMLTextExtractor,org.apache.jackrabbit.extractor.XMLTextExtractor) (JackrabbitTextExtractor.java, line 108) 30.03.2008 11:25:23 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index (LocalFileSystem.java, line 166) 30.03.2008 11:25:23 *DEBUG* AbstractIndex: closing IndexWriter. (AbstractIndex.java, line 226) 30.03.2008 11:25:23 *DEBUG* CachingIndexReader: initialized 0 DocIds in 0 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 11:25:23 *DEBUG* Recovery: RedoLog is empty, no recovery needed. (Recovery.java, line 80) 30.03.2008 11:25:23 *INFO * SearchIndex: Index initialized: /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index Version: 2 (SearchIndex.java, line 460) 30.03.2008 11:25:23 *INFO * RepositoryImpl: Repository started (RepositoryImpl.java, line 342) 30.03.2008 11:25:23 *INFO * TransientRepository: Transient repository initialized (TransientRepository.java, line 262) 30.03.2008 11:25:23 *DEBUG* TransientRepository: Opening a new session (TransientRepository.java, line 333) 30.03.2008 11:25:23 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@1742dfe size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:25:23 *INFO * TransientRepository: Session opened (TransientRepository.java, line 337) 30.03.2008 11:25:23 *INFO * RC5: Got session. Workspace is default (RC5.java, line 40) 30.03.2008 11:25:24 *DEBUG* QueryImpl: Executing query: + Root node + Select properties: * + PathQueryNode + LocationStepQueryNode: NodeTest={}reviews Descendants=false Index=0 (QueryImpl.java, line 105) 30.03.2008 11:25:24 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@1fc25e5 size=1, 964/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:25:24 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 11:25:24 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 11:25:24 *DEBUG* QueryResultImpl: getResults(2147483647) limit=0 (QueryResultImpl.java, line 273) 30.03.2008 11:25:24 *DEBUG* QueryResultImpl: query executed in 236 ms (QueryResultImpl.java, line 293) 30.03.2008 11:25:24 *DEBUG* QueryResultImpl: retrieved ScoreNodes in 1 ms (QueryResultImpl.java, line 314) 30.03.2008 11:25:24 *DEBUG* QueryImpl: executed in 0.61 s. (/reviews[0]) (QueryImpl.java, line 184) 30.03.2008 11:25:24 *DEBUG* RC5: /reviews node not found - creating it (RC5.java, line 69) 30.03.2008 11:25:24 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 11:25:24 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 11:25:24 *DEBUG* RC5: Attempting to create node with path reviews (RC5.java, line 154) 30.03.2008 11:25:24 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 750) 30.03.2008 11:25:24 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 689) 30.03.2008 11:25:24 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 11:25:24 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 11:25:24 *DEBUG* RC5: Attempting to save node reviews (RC5.java, line 161) 30.03.2008 11:25:25 *DEBUG* AbstractBundlePersistenceManager: stored bundle 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 11:25:25 *DEBUG* AbstractBundlePersistenceManager: stored bundle cafebabe-cafe-babe-cafe-babecafebabe (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 11:25:25 *DEBUG* SharedItemStateManager: persisting change log {#addedStates=2, #modifiedStates=1, #deletedStates=0, #modifiedRefs=0} took 195ms (SharedItemStateManager.java, line 729) 30.03.2008 11:25:25 *DEBUG* ObservationDispatcher: notifying 3 synchronous listeners. (ObservationDispatcher.java, line 196) 30.03.2008 11:25:25 *DEBUG* SearchManager: onEvent: indexing started (SearchManager.java, line 344) 30.03.2008 11:25:25 *DEBUG* SearchManager: onEvent: indexing finished in 26 ms. (SearchManager.java, line 459) 30.03.2008 11:25:25 *DEBUG* ObservationDispatcher: got EventStateCollection (ObservationDispatcher.java, line 140) 30.03.2008 11:25:25 *DEBUG* ObservationDispatcher: event delivery to 1 consumers started... (ObservationDispatcher.java, line 141) 30.03.2008 11:25:25 *DEBUG* ObservationDispatcher: event delivery finished. (ObservationDispatcher.java, line 152) 30.03.2008 11:25:25 *INFO * JackUtils: / (JackUtils.java, line 13) 30.03.2008 11:25:25 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 11:25:25 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 11:25:25 *INFO * JackUtils: /jcr:primaryType = rep:root (JackUtils.java, line 32) 30.03.2008 11:25:25 *DEBUG* ItemManager: created item deadbeef-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 11:25:25 *DEBUG* ItemManager: caching item deadbeef-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 11:25:25 *INFO * JackUtils: /jcr:system (JackUtils.java, line 13) 30.03.2008 11:25:25 *INFO * JackUtils: /reviews (JackUtils.java, line 13) 30.03.2008 11:25:25 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 11:25:25 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 11:25:25 *INFO * JackUtils: /reviews/jcr:primaryType = nt:unstructured (JackUtils.java, line 32) 30.03.2008 11:25:25 *DEBUG* RC5: Attempting to save session... (RC5.java, line 79) 30.03.2008 11:25:25 *DEBUG* RC5: Attempting to log out... (RC5.java, line 89) 30.03.2008 11:25:25 *DEBUG* ItemManager: invalidated item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 761) 30.03.2008 11:25:25 *DEBUG* ItemManager: removing item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 from cache (ItemManager.java, line 702) 30.03.2008 11:25:25 *DEBUG* ItemManager: invalidated item deadbeef-cafe-babe-cafe-babecafebabe (ItemManager.java, line 761) 30.03.2008 11:25:25 *DEBUG* ItemManager: removing item deadbeef-cafe-babe-cafe-babecafebabe from cache (ItemManager.java, line 702) 30.03.2008 11:25:25 *DEBUG* ItemManager: invalidated item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 761) 30.03.2008 11:25:25 *DEBUG* ItemManager: removing item cafebabe-cafe-babe-cafe-babecafebabe from cache (ItemManager.java, line 702) 30.03.2008 11:25:25 *INFO * TransientRepository: Session closed (TransientRepository.java, line 415) 30.03.2008 11:25:25 *DEBUG* TransientRepository: Shutting down transient repository (TransientRepository.java, line 270) 30.03.2008 11:25:25 *INFO * RepositoryImpl: Shutting down repository... (RepositoryImpl.java, line 971) 30.03.2008 11:25:25 *DEBUG* IndexMerger: dispose IndexMerger (IndexMerger.java, line 218) 30.03.2008 11:25:25 *INFO * IndexMerger: IndexMerger terminated (IndexMerger.java, line 347) 30.03.2008 11:25:25 *DEBUG* IndexMerger: quit sent (IndexMerger.java, line 232) 30.03.2008 11:25:25 *DEBUG* IndexMerger: IndexMerger thread stopped (IndexMerger.java, line 245) 30.03.2008 11:25:25 *DEBUG* IndexMerger: merge queue size: 0 (IndexMerger.java, line 247) 30.03.2008 11:25:25 *DEBUG* AbstractIndex: Inverted document in 4 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:25 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:25 *DEBUG* AbstractIndex: Inverted document in 40 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:25 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:25 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:25 *DEBUG* AbstractIndex: Inverted document in 5 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:25 *DEBUG* AbstractIndex: committing IndexWriter. (AbstractIndex.java, line 333) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: merging segments _ram_0 (1 docs) _ram_1 (1 docs) _ram_2 (1 docs) _ram_3 (1 docs) _ram_4 (1 docs) _ram_5 (1 docs) _ram_6 (1 docs) _ram_7 (1 docs) _ram_8 (1 docs) _ram_9 (1 docs) _ram_a (1 docs) _ram_b (1 docs) _ram_c (1 docs) _ram_d (1 docs) _ram_e (1 docs) _ram_f (1 docs) _ram_g (1 docs) _ram_h (1 docs) _ram_i (1 docs) _ram_j (1 docs) _ram_k (1 docs) _ram_l (1 docs) _ram_m (1 docs) _ram_n (1 docs) _ram_o (1 docs) _ram_p (1 docs) _ram_q (1 docs) _ram_r (1 docs) _ram_s (1 docs) _ram_t (1 docs) _ram_u (1 docs) _ram_v (1 docs) _ram_w (1 docs) _ram_x (1 docs) _ram_y (1 docs) _ram_z (1 docs) _ram_10 (1 docs) _ram_11 (1 docs) _ram_12 (1 docs) _ram_13 (1 docs) _ram_14 (1 docs) _ram_15 (1 docs) _ram_16 (1 docs) _ram_17 (1 docs) _ram_18 (1 docs) _ram_19 (1 docs) _ram_1a (1 docs) _ram_1b (1 docs) _ram_1c (1 docs) _ram_1d (1 docs) _ram_1e (1 docs) _ram_1f (1 docs) _ram_1g (1 docs) _ram_1h (1 docs) _ram_1i (1 docs) _ram_1j (1 docs) _ram_1k (1 docs) _ram_1l (1 docs) _ram_1m (1 docs) _ram_1n (1 docs) _ram_1o (1 docs) _ram_1p (1 docs) _ram_1q (1 docs) _ram_1r (1 docs) _ram_1s (1 docs) _ram_1t (1 docs) _ram_1u (1 docs) _ram_1v (1 docs) _ram_1w (1 docs) _ram_1x (1 docs) _ram_1y (1 docs) _ram_1z (1 docs) _ram_20 (1 docs) _ram_21 (1 docs) _ram_22 (1 docs) _ram_23 (1 docs) _ram_24 (1 docs) _ram_25 (1 docs) _ram_26 (1 docs) _ram_27 (1 docs) _ram_28 (1 docs) _ram_29 (1 docs) _ram_2a (1 docs) _ram_2b (1 docs) _ram_2c (1 docs) _ram_2d (1 docs) _ram_2e (1 docs) _ram_2f (1 docs) _ram_2g (1 docs) _ram_2h (1 docs) _ram_2i (1 docs) _ram_2j (1 docs) _ram_2k (1 docs) _ram_2l (1 docs) _ram_2m (1 docs) _ram_2n (1 docs) into _0 (96 docs) (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: now checkpoint "segments_2" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.fnm": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.fdx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.fdt": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.tii": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.tis": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.frq": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.prx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.tvx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.tvd": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.tvf": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.nrm": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: deleteCommits: now remove commit "segments_1" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "segments_1": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "segments_1" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: now checkpoint "segments_3" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: IncRef "_0.cfs": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: deleteCommits: now remove commit "segments_2" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.fnm": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.fnm" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.fdx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.fdx" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.fdt": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.fdt" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.tii": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.tii" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.tis": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.tis" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.frq": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.frq" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.prx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.prx" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.tvx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.tvx" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.tvd": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.tvd" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.tvf": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.tvf" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "_0.nrm": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "_0.nrm" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: DecRef "segments_2": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@796e1c main: delete "segments_2" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* IndexMerger: index added: name=_0, numDocs=96 (IndexMerger.java, line 162) 30.03.2008 11:25:26 *DEBUG* MultiIndex: Committed in-memory index in 1206ms. (MultiIndex.java, line 999) 30.03.2008 11:25:26 *INFO * SearchIndex: Index closed: /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index (SearchIndex.java, line 639) 30.03.2008 11:25:26 *INFO * RepositoryImpl: shutting down workspace 'default'... (RepositoryImpl.java, line 1840) 30.03.2008 11:25:26 *INFO * ObservationDispatcher: Notification of EventListeners stopped. (ObservationDispatcher.java, line 106) 30.03.2008 11:25:26 *DEBUG* IndexMerger: dispose IndexMerger (IndexMerger.java, line 218) 30.03.2008 11:25:26 *INFO * IndexMerger: IndexMerger terminated (IndexMerger.java, line 347) 30.03.2008 11:25:26 *DEBUG* IndexMerger: quit sent (IndexMerger.java, line 232) 30.03.2008 11:25:26 *DEBUG* IndexMerger: IndexMerger thread stopped (IndexMerger.java, line 245) 30.03.2008 11:25:26 *DEBUG* IndexMerger: merge queue size: 0 (IndexMerger.java, line 247) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: closing IndexReader. (AbstractIndex.java, line 296) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: Inverted document in 1 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: Inverted document in 3 ms (AbstractIndex.java, line 195) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: committing IndexWriter. (AbstractIndex.java, line 333) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: merging segments _ram_0 (1 docs) _ram_1 (1 docs) into _0 (2 docs) (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: now checkpoint "segments_2" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.fnm": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.fdx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.fdt": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.tii": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.tis": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.frq": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.prx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: deleteCommits: now remove commit "segments_1" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "segments_1": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "segments_1" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: now checkpoint "segments_3" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: IncRef "_0.cfs": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: deleteCommits: now remove commit "segments_2" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "_0.fnm": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "_0.fnm" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "_0.fdx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "_0.fdx" (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "_0.fdt": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:26 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "_0.fdt" (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "_0.tii": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "_0.tii" (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "_0.tis": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "_0.tis" (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "_0.frq": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "_0.frq" (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "_0.prx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "_0.prx" (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: DecRef "segments_2": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@19f90e3 main: delete "segments_2" (AbstractIndex.java, line 583) 30.03.2008 11:25:27 *DEBUG* IndexMerger: index added: name=_0, numDocs=2 (IndexMerger.java, line 162) 30.03.2008 11:25:27 *DEBUG* MultiIndex: Committed in-memory index in 295ms. (MultiIndex.java, line 999) 30.03.2008 11:25:27 *INFO * SearchIndex: Index closed: /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index (SearchIndex.java, line 639) 30.03.2008 11:25:27 *INFO * DerbyPersistenceManager: Database '/apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/db' shutdown. (DerbyPersistenceManager.java, line 334) 30.03.2008 11:25:27 *ERROR* ConnectionRecoveryManager: failed to close connection, reason: No current connection., state/code: 08003/40000 (ConnectionRecoveryManager.java, line 453) 30.03.2008 11:25:27 *DEBUG* ConnectionRecoveryManager: dump: (ConnectionRecoveryManager.java, line 455) java.sql.SQLException: No current connection. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.getAutoCommit(Unknown Source) at org.apache.jackrabbit.core.persistence.bundle.util.ConnectionRecoveryManager.close(ConnectionRecoveryManager.java:314) at org.apache.jackrabbit.core.persistence.bundle.BundleDbPersistenceManager.close(BundleDbPersistenceManager.java:926) at org.apache.jackrabbit.core.persistence.bundle.DerbyPersistenceManager.close(DerbyPersistenceManager.java:337) at org.apache.jackrabbit.core.RepositoryImpl$WorkspaceInfo.doDispose(RepositoryImpl.java:1890) at org.apache.jackrabbit.core.RepositoryImpl$WorkspaceInfo.dispose(RepositoryImpl.java:1841) at org.apache.jackrabbit.core.RepositoryImpl.doShutdown(RepositoryImpl.java:1005) at org.apache.jackrabbit.core.RepositoryImpl.shutdown(RepositoryImpl.java:959) at org.apache.jackrabbit.core.TransientRepository.stopRepository(TransientRepository.java:271) at org.apache.jackrabbit.core.TransientRepository.loggedOut(TransientRepository.java:423) at org.apache.jackrabbit.core.SessionImpl.notifyLoggedOut(SessionImpl.java:574) at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:1097) at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:403) at RC5.main(RC5.java:91) 30.03.2008 11:25:27 *INFO * RepositoryImpl: workspace 'default' has been shutdown (RepositoryImpl.java, line 1846) 30.03.2008 11:25:27 *INFO * DerbyPersistenceManager: Database '/apache-tomcat-6.0.16/rep-mantex.co.uk/version/db' shutdown. (DerbyPersistenceManager.java, line 334) 30.03.2008 11:25:27 *ERROR* ConnectionRecoveryManager: failed to close connection, reason: No current connection., state/code: 08003/40000 (ConnectionRecoveryManager.java, line 453) 30.03.2008 11:25:27 *DEBUG* ConnectionRecoveryManager: dump: (ConnectionRecoveryManager.java, line 455) java.sql.SQLException: No current connection. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.getAutoCommit(Unknown Source) at org.apache.jackrabbit.core.persistence.bundle.util.ConnectionRecoveryManager.close(ConnectionRecoveryManager.java:314) at org.apache.jackrabbit.core.persistence.bundle.BundleDbPersistenceManager.close(BundleDbPersistenceManager.java:926) at org.apache.jackrabbit.core.persistence.bundle.DerbyPersistenceManager.close(DerbyPersistenceManager.java:337) at org.apache.jackrabbit.core.version.VersionManagerImpl.close(VersionManagerImpl.java:201) at org.apache.jackrabbit.core.RepositoryImpl.doShutdown(RepositoryImpl.java:1011) at org.apache.jackrabbit.core.RepositoryImpl.shutdown(RepositoryImpl.java:959) at org.apache.jackrabbit.core.TransientRepository.stopRepository(TransientRepository.java:271) at org.apache.jackrabbit.core.TransientRepository.loggedOut(TransientRepository.java:423) at org.apache.jackrabbit.core.SessionImpl.notifyLoggedOut(SessionImpl.java:574) at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:1097) at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:403) at RC5.main(RC5.java:91) 30.03.2008 11:25:27 *INFO * RepositoryImpl: Repository has been shutdown (RepositoryImpl.java, line 1044) 30.03.2008 11:25:27 *INFO * TransientRepository: Transient repository shut down (TransientRepository.java, line 272) 30.03.2008 11:51:55 *DEBUG* TransientRepository: Initializing transient repository (TransientRepository.java, line 260) 30.03.2008 11:51:55 *INFO * RepositoryImpl: Starting repository... (RepositoryImpl.java, line 234) 30.03.2008 11:51:56 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/repository (LocalFileSystem.java, line 166) 30.03.2008 11:51:57 *INFO * NodeTypeRegistry: no custom node type definitions found (NodeTypeRegistry.java, line 836) 30.03.2008 11:51:57 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/version (LocalFileSystem.java, line 166) 30.03.2008 11:52:01 *INFO * ConnectionRecoveryManager: Database: Apache Derby / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 345) 30.03.2008 11:52:01 *INFO * ConnectionRecoveryManager: Driver: Apache Derby Embedded JDBC Driver / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 346) 30.03.2008 11:52:07 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@f0b7f8 size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:52:07 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@90832e size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:52:07 *INFO * RepositoryImpl: initializing workspace 'default'... (RepositoryImpl.java, line 1733) 30.03.2008 11:52:07 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default (LocalFileSystem.java, line 166) 30.03.2008 11:52:07 *INFO * ConnectionRecoveryManager: Database: Apache Derby / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 345) 30.03.2008 11:52:07 *INFO * ConnectionRecoveryManager: Driver: Apache Derby Embedded JDBC Driver / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 346) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=1 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=2 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=3 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=4 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=5 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=6 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=7 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=8 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=9 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=10 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=11 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=12 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=13 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=14 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=15 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=16 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=17 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=18 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=19 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=20 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=21 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=22 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=23 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=24 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=25 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=26 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=27 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=28 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=29 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=30 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=31 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=32 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=33 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=34 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=35 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=36 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=37 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=38 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=39 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=40 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=41 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=42 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=43 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:09 *DEBUG* AbstractVISProvider: item added to cache. size=44 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=45 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=46 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=47 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=48 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=49 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=50 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=51 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=52 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=53 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=54 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=55 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=56 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=57 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=58 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=59 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=60 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=61 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=62 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=63 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=64 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=65 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=66 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=67 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=68 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=69 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=70 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=71 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=72 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=73 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=74 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=75 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=76 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=77 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=78 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=79 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=80 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=81 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=82 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=83 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=84 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=85 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=86 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=87 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=88 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=89 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=90 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=91 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=92 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *DEBUG* AbstractVISProvider: item added to cache. size=93 (AbstractVISProvider.java, line 334) 30.03.2008 11:52:10 *INFO * RepositoryImpl: workspace 'default' initialized (RepositoryImpl.java, line 1736) 30.03.2008 11:52:11 *WARN * BeanConfig: org.apache.jackrabbit.core.query.lucene.SearchIndex does not support 'extractorPoolSize '; the setting is ignored. (BeanConfig.java, line 120) 30.03.2008 11:52:11 *DEBUG* JackrabbitTextExtractor: JackrabbitTextExtractor(org.apache.jackrabbit.extractor.MsWordTextExtractor,org.apache.jackrabbit.extractor.MsExcelTextExtractor,org.apache.jackrabbit.extractor.MsPowerPointTextExtractor,org.apache.jackrabbit.extractor.PdfTextExtractor,org.apache.jackrabbit.extractor.OpenOfficeTextExtractor,org.apache.jackrabbit.extractor.RTFTextExtractor,org.apache.jackrabbit.extractor.HTMLTextExtractor,org.apache.jackrabbit.extractor.XMLTextExtractor) (JackrabbitTextExtractor.java, line 108) 30.03.2008 11:52:12 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index (LocalFileSystem.java, line 166) 30.03.2008 11:52:12 *DEBUG* IndexMerger: index added: name=_0, numDocs=96 (IndexMerger.java, line 162) 30.03.2008 11:52:12 *DEBUG* CachingIndexReader: initialized 96 DocIds in 123 ms, 1% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 11:52:12 *DEBUG* AbstractIndex: closing IndexWriter. (AbstractIndex.java, line 226) 30.03.2008 11:52:12 *DEBUG* CachingIndexReader: initialized 0 DocIds in 1 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 11:52:12 *DEBUG* Recovery: RedoLog is empty, no recovery needed. (Recovery.java, line 80) 30.03.2008 11:52:12 *INFO * SearchIndex: Index initialized: /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index Version: 2 (SearchIndex.java, line 460) 30.03.2008 11:52:12 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@165c7f6 size=1, 1264/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:52:12 *DEBUG* JackrabbitTextExtractor: JackrabbitTextExtractor(org.apache.jackrabbit.extractor.MsWordTextExtractor,org.apache.jackrabbit.extractor.MsExcelTextExtractor,org.apache.jackrabbit.extractor.MsPowerPointTextExtractor,org.apache.jackrabbit.extractor.PdfTextExtractor,org.apache.jackrabbit.extractor.OpenOfficeTextExtractor,org.apache.jackrabbit.extractor.RTFTextExtractor,org.apache.jackrabbit.extractor.HTMLTextExtractor,org.apache.jackrabbit.extractor.XMLTextExtractor) (JackrabbitTextExtractor.java, line 108) 30.03.2008 11:52:13 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index (LocalFileSystem.java, line 166) 30.03.2008 11:52:13 *DEBUG* IndexMerger: index added: name=_0, numDocs=2 (IndexMerger.java, line 162) 30.03.2008 11:52:13 *DEBUG* CachingIndexReader: initialized 2 DocIds in 2 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 11:52:13 *DEBUG* AbstractIndex: closing IndexWriter. (AbstractIndex.java, line 226) 30.03.2008 11:52:13 *DEBUG* CachingIndexReader: initialized 0 DocIds in 0 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 11:52:13 *DEBUG* Recovery: RedoLog is empty, no recovery needed. (Recovery.java, line 80) 30.03.2008 11:52:13 *INFO * SearchIndex: Index initialized: /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index Version: 2 (SearchIndex.java, line 460) 30.03.2008 11:52:13 *INFO * RepositoryImpl: Repository started (RepositoryImpl.java, line 342) 30.03.2008 11:52:13 *INFO * TransientRepository: Transient repository initialized (TransientRepository.java, line 262) 30.03.2008 11:52:13 *DEBUG* TransientRepository: Opening a new session (TransientRepository.java, line 333) 30.03.2008 11:52:13 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@3fbbfc size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:52:13 *INFO * TransientRepository: Session opened (TransientRepository.java, line 337) 30.03.2008 11:52:13 *INFO * RC5: Got session. Workspace is default (RC5.java, line 40) 30.03.2008 11:52:14 *DEBUG* QueryImpl: Executing query: + Root node + Select properties: * + PathQueryNode + LocationStepQueryNode: NodeTest={}reviews Descendants=false Index=0 (QueryImpl.java, line 105) 30.03.2008 11:52:14 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@10c0f66 size=1, 1264/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 11:52:14 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 11:52:14 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 11:52:14 *DEBUG* QueryResultImpl: getResults(2147483647) limit=0 (QueryResultImpl.java, line 273) 30.03.2008 11:52:14 *DEBUG* QueryResultImpl: query executed in 230 ms (QueryResultImpl.java, line 293) 30.03.2008 11:52:14 *DEBUG* QueryResultImpl: retrieved ScoreNodes in 0 ms (QueryResultImpl.java, line 314) 30.03.2008 11:52:14 *DEBUG* QueryImpl: executed in 0.61 s. (/reviews[0]) (QueryImpl.java, line 184) 30.03.2008 11:52:14 *DEBUG* RC5: /reviews node not found - creating it (RC5.java, line 69) 30.03.2008 11:52:14 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 11:52:14 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 11:52:14 *DEBUG* RC5: Attempting to create node with path reviews (RC5.java, line 154) 30.03.2008 11:52:14 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 750) 30.03.2008 11:52:14 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 689) 30.03.2008 11:52:15 *DEBUG* ItemManager: created item 2bd0e7c0-154d-4abe-966b-5a508664b05a (ItemManager.java, line 750) 30.03.2008 11:52:15 *DEBUG* ItemManager: caching item 2bd0e7c0-154d-4abe-966b-5a508664b05a (ItemManager.java, line 689) 30.03.2008 11:52:15 *DEBUG* ItemManager: created item 2bd0e7c0-154d-4abe-966b-5a508664b05a/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 11:52:15 *DEBUG* ItemManager: caching item 2bd0e7c0-154d-4abe-966b-5a508664b05a/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 11:52:15 *DEBUG* RC5: Attempting to save node reviews (RC5.java, line 161) 30.03.2008 11:52:15 *DEBUG* AbstractBundlePersistenceManager: stored bundle 2bd0e7c0-154d-4abe-966b-5a508664b05a (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 11:52:15 *DEBUG* AbstractBundlePersistenceManager: stored bundle cafebabe-cafe-babe-cafe-babecafebabe (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 11:52:15 *DEBUG* SharedItemStateManager: persisting change log {#addedStates=2, #modifiedStates=1, #deletedStates=0, #modifiedRefs=0} took 570ms (SharedItemStateManager.java, line 729) 30.03.2008 11:52:15 *DEBUG* ObservationDispatcher: notifying 3 synchronous listeners. (ObservationDispatcher.java, line 196) 30.03.2008 11:52:15 *DEBUG* SearchManager: onEvent: indexing started (SearchManager.java, line 344) 30.03.2008 11:52:15 *DEBUG* SearchManager: onEvent: indexing finished in 56 ms. (SearchManager.java, line 459) 30.03.2008 11:52:15 *DEBUG* ObservationDispatcher: got EventStateCollection (ObservationDispatcher.java, line 140) 30.03.2008 11:52:15 *DEBUG* ObservationDispatcher: event delivery to 1 consumers started... (ObservationDispatcher.java, line 141) 30.03.2008 11:52:15 *DEBUG* ObservationDispatcher: event delivery finished. (ObservationDispatcher.java, line 152) 30.03.2008 11:52:15 *INFO * JackUtils: / (JackUtils.java, line 13) 30.03.2008 11:52:15 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 11:52:15 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 11:52:15 *INFO * JackUtils: /jcr:primaryType = rep:root (JackUtils.java, line 32) 30.03.2008 11:52:15 *DEBUG* ItemManager: created item deadbeef-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 11:52:15 *DEBUG* ItemManager: caching item deadbeef-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 11:52:15 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 750) 30.03.2008 11:52:15 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 689) 30.03.2008 11:52:16 *INFO * JackUtils: /jcr:system (JackUtils.java, line 13) 30.03.2008 11:52:16 *INFO * JackUtils: /reviews (JackUtils.java, line 13) 30.03.2008 11:52:16 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 11:52:16 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 11:52:16 *INFO * JackUtils: /reviews/jcr:primaryType = nt:unstructured (JackUtils.java, line 32) 30.03.2008 11:52:16 *INFO * JackUtils: /reviews[2] (JackUtils.java, line 13) 30.03.2008 11:52:16 *DEBUG* ItemManager: created item 2bd0e7c0-154d-4abe-966b-5a508664b05a/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 11:52:16 *DEBUG* ItemManager: caching item 2bd0e7c0-154d-4abe-966b-5a508664b05a/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 11:52:16 *INFO * JackUtils: /reviews[2]/jcr:primaryType = nt:unstructured (JackUtils.java, line 32) 30.03.2008 11:52:16 *DEBUG* RC5: Attempting to save session... (RC5.java, line 79) 30.03.2008 11:52:16 *DEBUG* RC5: Attempting to log out... (RC5.java, line 89) 30.03.2008 11:52:16 *DEBUG* ItemManager: invalidated item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 761) 30.03.2008 11:52:16 *DEBUG* ItemManager: removing item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType from cache (ItemManager.java, line 702) 30.03.2008 11:52:16 *DEBUG* ItemManager: invalidated item 2bd0e7c0-154d-4abe-966b-5a508664b05a (ItemManager.java, line 761) 30.03.2008 11:52:16 *DEBUG* ItemManager: removing item 2bd0e7c0-154d-4abe-966b-5a508664b05a from cache (ItemManager.java, line 702) 30.03.2008 11:52:16 *DEBUG* ItemManager: invalidated item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 761) 30.03.2008 11:52:16 *DEBUG* ItemManager: removing item cafebabe-cafe-babe-cafe-babecafebabe from cache (ItemManager.java, line 702) 30.03.2008 11:52:16 *INFO * TransientRepository: Session closed (TransientRepository.java, line 415) 30.03.2008 11:52:16 *DEBUG* TransientRepository: Shutting down transient repository (TransientRepository.java, line 270) 30.03.2008 11:52:16 *INFO * RepositoryImpl: Shutting down repository... (RepositoryImpl.java, line 971) 30.03.2008 11:52:16 *DEBUG* IndexMerger: dispose IndexMerger (IndexMerger.java, line 218) 30.03.2008 11:52:16 *INFO * IndexMerger: IndexMerger terminated (IndexMerger.java, line 347) 30.03.2008 11:52:16 *DEBUG* IndexMerger: quit sent (IndexMerger.java, line 232) 30.03.2008 11:52:16 *DEBUG* IndexMerger: IndexMerger thread stopped (IndexMerger.java, line 245) 30.03.2008 11:52:16 *DEBUG* IndexMerger: merge queue size: 0 (IndexMerger.java, line 247) 30.03.2008 11:52:16 *INFO * SearchIndex: Index closed: /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index (SearchIndex.java, line 639) 30.03.2008 11:52:16 *INFO * RepositoryImpl: shutting down workspace 'default'... (RepositoryImpl.java, line 1840) 30.03.2008 11:52:16 *INFO * ObservationDispatcher: Notification of EventListeners stopped. (ObservationDispatcher.java, line 106) 30.03.2008 11:52:16 *DEBUG* IndexMerger: dispose IndexMerger (IndexMerger.java, line 218) 30.03.2008 11:52:16 *INFO * IndexMerger: IndexMerger terminated (IndexMerger.java, line 347) 30.03.2008 11:52:16 *DEBUG* IndexMerger: quit sent (IndexMerger.java, line 232) 30.03.2008 11:52:16 *DEBUG* IndexMerger: IndexMerger thread stopped (IndexMerger.java, line 245) 30.03.2008 11:52:16 *DEBUG* IndexMerger: merge queue size: 0 (IndexMerger.java, line 247) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: closing IndexReader. (AbstractIndex.java, line 296) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: Inverted document in 61 ms (AbstractIndex.java, line 195) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: committing IndexWriter. (AbstractIndex.java, line 333) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: merging segments _ram_0 (1 docs) into _0 (1 docs) (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: now checkpoint "segments_2" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.fnm": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.fdx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.fdt": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.tii": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.tis": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.frq": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.prx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: deleteCommits: now remove commit "segments_1" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "segments_1": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "segments_1" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: now checkpoint "segments_3" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: IncRef "_0.cfs": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: deleteCommits: now remove commit "segments_2" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "_0.fnm": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "_0.fnm" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "_0.fdx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "_0.fdx" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "_0.fdt": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "_0.fdt" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "_0.tii": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "_0.tii" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "_0.tis": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "_0.tis" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "_0.frq": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "_0.frq" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "_0.prx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "_0.prx" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: DecRef "segments_2": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@89e2f1 main: delete "segments_2" (AbstractIndex.java, line 583) 30.03.2008 11:52:16 *DEBUG* IndexMerger: index added: name=_1, numDocs=1 (IndexMerger.java, line 162) 30.03.2008 11:52:16 *DEBUG* MultiIndex: Committed in-memory index in 365ms. (MultiIndex.java, line 999) 30.03.2008 11:52:16 *INFO * SearchIndex: Index closed: /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index (SearchIndex.java, line 639) 30.03.2008 11:52:16 *INFO * DerbyPersistenceManager: Database '/apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/db' shutdown. (DerbyPersistenceManager.java, line 334) 30.03.2008 11:52:16 *ERROR* ConnectionRecoveryManager: failed to close connection, reason: No current connection., state/code: 08003/40000 (ConnectionRecoveryManager.java, line 453) 30.03.2008 11:52:16 *DEBUG* ConnectionRecoveryManager: dump: (ConnectionRecoveryManager.java, line 455) java.sql.SQLException: No current connection. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.getAutoCommit(Unknown Source) at org.apache.jackrabbit.core.persistence.bundle.util.ConnectionRecoveryManager.close(ConnectionRecoveryManager.java:314) at org.apache.jackrabbit.core.persistence.bundle.BundleDbPersistenceManager.close(BundleDbPersistenceManager.java:926) at org.apache.jackrabbit.core.persistence.bundle.DerbyPersistenceManager.close(DerbyPersistenceManager.java:337) at org.apache.jackrabbit.core.RepositoryImpl$WorkspaceInfo.doDispose(RepositoryImpl.java:1890) at org.apache.jackrabbit.core.RepositoryImpl$WorkspaceInfo.dispose(RepositoryImpl.java:1841) at org.apache.jackrabbit.core.RepositoryImpl.doShutdown(RepositoryImpl.java:1005) at org.apache.jackrabbit.core.RepositoryImpl.shutdown(RepositoryImpl.java:959) at org.apache.jackrabbit.core.TransientRepository.stopRepository(TransientRepository.java:271) at org.apache.jackrabbit.core.TransientRepository.loggedOut(TransientRepository.java:423) at org.apache.jackrabbit.core.SessionImpl.notifyLoggedOut(SessionImpl.java:574) at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:1097) at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:403) at RC5.main(RC5.java:91) 30.03.2008 11:52:16 *INFO * RepositoryImpl: workspace 'default' has been shutdown (RepositoryImpl.java, line 1846) 30.03.2008 11:52:16 *INFO * DerbyPersistenceManager: Database '/apache-tomcat-6.0.16/rep-mantex.co.uk/version/db' shutdown. (DerbyPersistenceManager.java, line 334) 30.03.2008 11:52:16 *ERROR* ConnectionRecoveryManager: failed to close connection, reason: No current connection., state/code: 08003/40000 (ConnectionRecoveryManager.java, line 453) 30.03.2008 11:52:16 *DEBUG* ConnectionRecoveryManager: dump: (ConnectionRecoveryManager.java, line 455) java.sql.SQLException: No current connection. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.getAutoCommit(Unknown Source) at org.apache.jackrabbit.core.persistence.bundle.util.ConnectionRecoveryManager.close(ConnectionRecoveryManager.java:314) at org.apache.jackrabbit.core.persistence.bundle.BundleDbPersistenceManager.close(BundleDbPersistenceManager.java:926) at org.apache.jackrabbit.core.persistence.bundle.DerbyPersistenceManager.close(DerbyPersistenceManager.java:337) at org.apache.jackrabbit.core.version.VersionManagerImpl.close(VersionManagerImpl.java:201) at org.apache.jackrabbit.core.RepositoryImpl.doShutdown(RepositoryImpl.java:1011) at org.apache.jackrabbit.core.RepositoryImpl.shutdown(RepositoryImpl.java:959) at org.apache.jackrabbit.core.TransientRepository.stopRepository(TransientRepository.java:271) at org.apache.jackrabbit.core.TransientRepository.loggedOut(TransientRepository.java:423) at org.apache.jackrabbit.core.SessionImpl.notifyLoggedOut(SessionImpl.java:574) at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:1097) at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:403) at RC5.main(RC5.java:91) 30.03.2008 11:52:16 *INFO * RepositoryImpl: Repository has been shutdown (RepositoryImpl.java, line 1044) 30.03.2008 11:52:16 *INFO * TransientRepository: Transient repository shut down (TransientRepository.java, line 272) 30.03.2008 12:04:57 *DEBUG* TransientRepository: Initializing transient repository (TransientRepository.java, line 260) 30.03.2008 12:04:57 *INFO * RepositoryImpl: Starting repository... (RepositoryImpl.java, line 234) 30.03.2008 12:04:57 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/repository (LocalFileSystem.java, line 166) 30.03.2008 12:04:58 *INFO * NodeTypeRegistry: no custom node type definitions found (NodeTypeRegistry.java, line 836) 30.03.2008 12:04:58 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/version (LocalFileSystem.java, line 166) 30.03.2008 12:05:03 *INFO * ConnectionRecoveryManager: Database: Apache Derby / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 345) 30.03.2008 12:05:03 *INFO * ConnectionRecoveryManager: Driver: Apache Derby Embedded JDBC Driver / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 346) 30.03.2008 12:05:09 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@f0b7f8 size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 12:05:09 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@90832e size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 12:05:09 *INFO * RepositoryImpl: initializing workspace 'default'... (RepositoryImpl.java, line 1733) 30.03.2008 12:05:09 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default (LocalFileSystem.java, line 166) 30.03.2008 12:05:09 *INFO * ConnectionRecoveryManager: Database: Apache Derby / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 345) 30.03.2008 12:05:09 *INFO * ConnectionRecoveryManager: Driver: Apache Derby Embedded JDBC Driver / 10.2.1.6 - (452058) (ConnectionRecoveryManager.java, line 346) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=1 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=2 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=3 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=4 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=5 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=6 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=7 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=8 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=9 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=10 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=11 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=12 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=13 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=14 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=15 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=16 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=17 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=18 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=19 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=20 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=21 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=22 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=23 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=24 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=25 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=26 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=27 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=28 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=29 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=30 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=31 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=32 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=33 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=34 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=35 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=36 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=37 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=38 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=39 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=40 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=41 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=42 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=43 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=44 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=45 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=46 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=47 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=48 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=49 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=50 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=51 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=52 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=53 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=54 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=55 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=56 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=57 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=58 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=59 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=60 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=61 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=62 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=63 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=64 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=65 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=66 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=67 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=68 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=69 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=70 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=71 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=72 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=73 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=74 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=75 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=76 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=77 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=78 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:11 *DEBUG* AbstractVISProvider: item added to cache. size=79 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=80 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=81 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=82 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=83 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=84 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=85 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=86 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=87 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=88 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=89 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=90 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=91 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=92 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *DEBUG* AbstractVISProvider: item added to cache. size=93 (AbstractVISProvider.java, line 334) 30.03.2008 12:05:12 *INFO * RepositoryImpl: workspace 'default' initialized (RepositoryImpl.java, line 1736) 30.03.2008 12:05:13 *WARN * BeanConfig: org.apache.jackrabbit.core.query.lucene.SearchIndex does not support 'extractorPoolSize '; the setting is ignored. (BeanConfig.java, line 120) 30.03.2008 12:05:13 *DEBUG* JackrabbitTextExtractor: JackrabbitTextExtractor(org.apache.jackrabbit.extractor.MsWordTextExtractor,org.apache.jackrabbit.extractor.MsExcelTextExtractor,org.apache.jackrabbit.extractor.MsPowerPointTextExtractor,org.apache.jackrabbit.extractor.PdfTextExtractor,org.apache.jackrabbit.extractor.OpenOfficeTextExtractor,org.apache.jackrabbit.extractor.RTFTextExtractor,org.apache.jackrabbit.extractor.HTMLTextExtractor,org.apache.jackrabbit.extractor.XMLTextExtractor) (JackrabbitTextExtractor.java, line 108) 30.03.2008 12:05:13 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index (LocalFileSystem.java, line 166) 30.03.2008 12:05:14 *DEBUG* IndexMerger: index added: name=_0, numDocs=96 (IndexMerger.java, line 162) 30.03.2008 12:05:14 *DEBUG* CachingIndexReader: initialized 96 DocIds in 124 ms, 1% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 12:05:14 *DEBUG* AbstractIndex: closing IndexWriter. (AbstractIndex.java, line 226) 30.03.2008 12:05:14 *DEBUG* CachingIndexReader: initialized 0 DocIds in 1 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 12:05:14 *DEBUG* Recovery: RedoLog is empty, no recovery needed. (Recovery.java, line 80) 30.03.2008 12:05:14 *INFO * SearchIndex: Index initialized: /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index Version: 2 (SearchIndex.java, line 460) 30.03.2008 12:05:14 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@165c7f6 size=1, 1264/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 12:05:14 *DEBUG* JackrabbitTextExtractor: JackrabbitTextExtractor(org.apache.jackrabbit.extractor.MsWordTextExtractor,org.apache.jackrabbit.extractor.MsExcelTextExtractor,org.apache.jackrabbit.extractor.MsPowerPointTextExtractor,org.apache.jackrabbit.extractor.PdfTextExtractor,org.apache.jackrabbit.extractor.OpenOfficeTextExtractor,org.apache.jackrabbit.extractor.RTFTextExtractor,org.apache.jackrabbit.extractor.HTMLTextExtractor,org.apache.jackrabbit.extractor.XMLTextExtractor) (JackrabbitTextExtractor.java, line 108) 30.03.2008 12:05:14 *INFO * LocalFileSystem: LocalFileSystem initialized at path /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index (LocalFileSystem.java, line 166) 30.03.2008 12:05:14 *DEBUG* IndexMerger: index added: name=_0, numDocs=2 (IndexMerger.java, line 162) 30.03.2008 12:05:14 *DEBUG* IndexMerger: index added: name=_1, numDocs=1 (IndexMerger.java, line 162) 30.03.2008 12:05:14 *DEBUG* CachingIndexReader: initialized 2 DocIds in 1 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 12:05:14 *DEBUG* CachingIndexReader: initialized 1 DocIds in 0 ms, 100% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 12:05:14 *DEBUG* AbstractIndex: closing IndexWriter. (AbstractIndex.java, line 226) 30.03.2008 12:05:14 *DEBUG* CachingIndexReader: initialized 0 DocIds in 0 ms, 0% foreign parents (CachingIndexReader.java, line 270) 30.03.2008 12:05:14 *DEBUG* Recovery: RedoLog is empty, no recovery needed. (Recovery.java, line 80) 30.03.2008 12:05:14 *INFO * SearchIndex: Index initialized: /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index Version: 2 (SearchIndex.java, line 460) 30.03.2008 12:05:14 *INFO * RepositoryImpl: Repository started (RepositoryImpl.java, line 342) 30.03.2008 12:05:14 *INFO * TransientRepository: Transient repository initialized (TransientRepository.java, line 262) 30.03.2008 12:05:14 *DEBUG* TransientRepository: Opening a new session (TransientRepository.java, line 333) 30.03.2008 12:05:14 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@4ed904 size=1, 664/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 12:05:15 *INFO * TransientRepository: Session opened (TransientRepository.java, line 337) 30.03.2008 12:05:15 *INFO * RC5: Got session. Workspace is default (RC5.java, line 40) 30.03.2008 12:05:16 *DEBUG* QueryImpl: Executing query: + Root node + Select properties: * + PathQueryNode + LocationStepQueryNode: NodeTest={}reviews Descendants=false Index=0 (QueryImpl.java, line 105) 30.03.2008 12:05:16 *DEBUG* MLRUItemStateCache: org.apache.jackrabbit.core.state.MLRUItemStateCache@c6f734 size=1, 1564/4194304 (MLRUItemStateCache.java, line 148) 30.03.2008 12:05:16 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 12:05:16 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 12:05:16 *DEBUG* QueryResultImpl: getResults(2147483647) limit=0 (QueryResultImpl.java, line 273) 30.03.2008 12:05:16 *DEBUG* QueryResultImpl: query executed in 233 ms (QueryResultImpl.java, line 293) 30.03.2008 12:05:16 *DEBUG* QueryResultImpl: retrieved ScoreNodes in 0 ms (QueryResultImpl.java, line 314) 30.03.2008 12:05:16 *DEBUG* QueryImpl: executed in 0.61 s. (/reviews[0]) (QueryImpl.java, line 184) 30.03.2008 12:05:16 *DEBUG* RC5: /reviews node not found - creating it (RC5.java, line 70) 30.03.2008 12:05:16 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 12:05:16 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 12:05:16 *DEBUG* RC5: Attempting to create node with path reviews (RC5.java, line 155) 30.03.2008 12:05:16 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 750) 30.03.2008 12:05:16 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 689) 30.03.2008 12:05:16 *DEBUG* ItemManager: created item fbca685e-e7ca-4f0f-8fcd-998a8ecee490 (ItemManager.java, line 750) 30.03.2008 12:05:16 *DEBUG* ItemManager: caching item fbca685e-e7ca-4f0f-8fcd-998a8ecee490 (ItemManager.java, line 689) 30.03.2008 12:05:16 *DEBUG* ItemManager: created item fbca685e-e7ca-4f0f-8fcd-998a8ecee490/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 12:05:16 *DEBUG* ItemManager: caching item fbca685e-e7ca-4f0f-8fcd-998a8ecee490/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 12:05:16 *DEBUG* RC5: Attempting to save node reviews (RC5.java, line 162) 30.03.2008 12:05:17 *DEBUG* AbstractBundlePersistenceManager: stored bundle fbca685e-e7ca-4f0f-8fcd-998a8ecee490 (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 12:05:17 *DEBUG* AbstractBundlePersistenceManager: stored bundle cafebabe-cafe-babe-cafe-babecafebabe (AbstractBundlePersistenceManager.java, line 704) 30.03.2008 12:05:17 *DEBUG* SharedItemStateManager: persisting change log {#addedStates=2, #modifiedStates=1, #deletedStates=0, #modifiedRefs=0} took 588ms (SharedItemStateManager.java, line 729) 30.03.2008 12:05:17 *DEBUG* ObservationDispatcher: notifying 3 synchronous listeners. (ObservationDispatcher.java, line 196) 30.03.2008 12:05:17 *DEBUG* SearchManager: onEvent: indexing started (SearchManager.java, line 344) 30.03.2008 12:05:17 *DEBUG* SearchManager: onEvent: indexing finished in 56 ms. (SearchManager.java, line 459) 30.03.2008 12:05:17 *DEBUG* ObservationDispatcher: got EventStateCollection (ObservationDispatcher.java, line 140) 30.03.2008 12:05:17 *DEBUG* ObservationDispatcher: event delivery to 1 consumers started... (ObservationDispatcher.java, line 141) 30.03.2008 12:05:17 *DEBUG* ObservationDispatcher: event delivery finished. (ObservationDispatcher.java, line 152) 30.03.2008 12:05:17 *INFO * JackUtils: / (JackUtils.java, line 13) 30.03.2008 12:05:17 *DEBUG* ItemManager: created item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 12:05:17 *DEBUG* ItemManager: caching item cafebabe-cafe-babe-cafe-babecafebabe/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 12:05:17 *INFO * JackUtils: /jcr:primaryType = rep:root (JackUtils.java, line 32) 30.03.2008 12:05:17 *DEBUG* ItemManager: created item deadbeef-cafe-babe-cafe-babecafebabe (ItemManager.java, line 750) 30.03.2008 12:05:17 *DEBUG* ItemManager: caching item deadbeef-cafe-babe-cafe-babecafebabe (ItemManager.java, line 689) 30.03.2008 12:05:17 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 750) 30.03.2008 12:05:17 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8 (ItemManager.java, line 689) 30.03.2008 12:05:17 *INFO * JackUtils: /jcr:system (JackUtils.java, line 13) 30.03.2008 12:05:17 *DEBUG* ItemManager: created item 2bd0e7c0-154d-4abe-966b-5a508664b05a (ItemManager.java, line 750) 30.03.2008 12:05:17 *DEBUG* ItemManager: caching item 2bd0e7c0-154d-4abe-966b-5a508664b05a (ItemManager.java, line 689) 30.03.2008 12:05:17 *INFO * JackUtils: /reviews (JackUtils.java, line 13) 30.03.2008 12:05:17 *DEBUG* ItemManager: created item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 12:05:17 *DEBUG* ItemManager: caching item 3254ecdd-7bd9-465b-be35-513a3cb3f5e8/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 12:05:17 *INFO * JackUtils: /reviews/jcr:primaryType = nt:unstructured (JackUtils.java, line 32) 30.03.2008 12:05:17 *INFO * JackUtils: /reviews[2] (JackUtils.java, line 13) 30.03.2008 12:05:17 *DEBUG* ItemManager: created item 2bd0e7c0-154d-4abe-966b-5a508664b05a/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 12:05:17 *DEBUG* ItemManager: caching item 2bd0e7c0-154d-4abe-966b-5a508664b05a/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 12:05:17 *INFO * JackUtils: /reviews[2]/jcr:primaryType = nt:unstructured (JackUtils.java, line 32) 30.03.2008 12:05:17 *INFO * JackUtils: /reviews[3] (JackUtils.java, line 13) 30.03.2008 12:05:17 *DEBUG* ItemManager: created item fbca685e-e7ca-4f0f-8fcd-998a8ecee490/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 750) 30.03.2008 12:05:17 *DEBUG* ItemManager: caching item fbca685e-e7ca-4f0f-8fcd-998a8ecee490/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 689) 30.03.2008 12:05:17 *INFO * JackUtils: /reviews[3]/jcr:primaryType = nt:unstructured (JackUtils.java, line 32) 30.03.2008 12:05:17 *DEBUG* RC5: Attempting to save session... (RC5.java, line 80) 30.03.2008 12:05:17 *DEBUG* RC5: Attempting to log out... (RC5.java, line 90) 30.03.2008 12:05:17 *DEBUG* ItemManager: invalidated item fbca685e-e7ca-4f0f-8fcd-998a8ecee490/{http://www.jcp.org/jcr/1.0}primaryType (ItemManager.java, line 761) 30.03.2008 12:05:17 *DEBUG* ItemManager: removing item fbca685e-e7ca-4f0f-8fcd-998a8ecee490/{http://www.jcp.org/jcr/1.0}primaryType from cache (ItemManager.java, line 702) 30.03.2008 12:05:17 *DEBUG* ItemManager: invalidated item fbca685e-e7ca-4f0f-8fcd-998a8ecee490 (ItemManager.java, line 761) 30.03.2008 12:05:17 *DEBUG* ItemManager: removing item fbca685e-e7ca-4f0f-8fcd-998a8ecee490 from cache (ItemManager.java, line 702) 30.03.2008 12:05:17 *DEBUG* ItemManager: invalidated item 2bd0e7c0-154d-4abe-966b-5a508664b05a (ItemManager.java, line 761) 30.03.2008 12:05:17 *DEBUG* ItemManager: removing item 2bd0e7c0-154d-4abe-966b-5a508664b05a from cache (ItemManager.java, line 702) 30.03.2008 12:05:17 *DEBUG* ItemManager: invalidated item cafebabe-cafe-babe-cafe-babecafebabe (ItemManager.java, line 761) 30.03.2008 12:05:17 *DEBUG* ItemManager: removing item cafebabe-cafe-babe-cafe-babecafebabe from cache (ItemManager.java, line 702) 30.03.2008 12:05:17 *INFO * TransientRepository: Session closed (TransientRepository.java, line 415) 30.03.2008 12:05:17 *DEBUG* TransientRepository: Shutting down transient repository (TransientRepository.java, line 270) 30.03.2008 12:05:17 *INFO * RepositoryImpl: Shutting down repository... (RepositoryImpl.java, line 971) 30.03.2008 12:05:17 *DEBUG* IndexMerger: dispose IndexMerger (IndexMerger.java, line 218) 30.03.2008 12:05:17 *INFO * IndexMerger: IndexMerger terminated (IndexMerger.java, line 347) 30.03.2008 12:05:17 *DEBUG* IndexMerger: quit sent (IndexMerger.java, line 232) 30.03.2008 12:05:17 *DEBUG* IndexMerger: IndexMerger thread stopped (IndexMerger.java, line 245) 30.03.2008 12:05:17 *DEBUG* IndexMerger: merge queue size: 0 (IndexMerger.java, line 247) 30.03.2008 12:05:17 *INFO * SearchIndex: Index closed: /apache-tomcat-6.0.16/rep-mantex.co.uk/repository/index (SearchIndex.java, line 639) 30.03.2008 12:05:17 *INFO * RepositoryImpl: shutting down workspace 'default'... (RepositoryImpl.java, line 1840) 30.03.2008 12:05:17 *INFO * ObservationDispatcher: Notification of EventListeners stopped. (ObservationDispatcher.java, line 106) 30.03.2008 12:05:17 *DEBUG* IndexMerger: dispose IndexMerger (IndexMerger.java, line 218) 30.03.2008 12:05:17 *INFO * IndexMerger: IndexMerger terminated (IndexMerger.java, line 347) 30.03.2008 12:05:17 *DEBUG* IndexMerger: quit sent (IndexMerger.java, line 232) 30.03.2008 12:05:17 *DEBUG* IndexMerger: IndexMerger thread stopped (IndexMerger.java, line 245) 30.03.2008 12:05:17 *DEBUG* IndexMerger: merge queue size: 0 (IndexMerger.java, line 247) 30.03.2008 12:05:17 *DEBUG* AbstractIndex: closing IndexReader. (AbstractIndex.java, line 296) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: Inverted document in 49 ms (AbstractIndex.java, line 195) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: committing IndexWriter. (AbstractIndex.java, line 333) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: merging segments _ram_0 (1 docs) into _0 (1 docs) (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: now checkpoint "segments_2" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.fnm": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.fdx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.fdt": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.tii": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.tis": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.frq": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.prx": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: deleteCommits: now remove commit "segments_1" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "segments_1": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "segments_1" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: now checkpoint "segments_3" [isCommit = true] (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: IncRef "_0.cfs": pre-incr count is 0 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: deleteCommits: now remove commit "segments_2" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "_0.fnm": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "_0.fnm" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "_0.fdx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "_0.fdx" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "_0.fdt": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "_0.fdt" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "_0.tii": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "_0.tii" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "_0.tis": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "_0.tis" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "_0.frq": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "_0.frq" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "_0.prx": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "_0.prx" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: DecRef "segments_2": pre-decr count is 1 (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* AbstractIndex: org.apache.lucene.index.IndexFileDeleter@2515 main: delete "segments_2" (AbstractIndex.java, line 583) 30.03.2008 12:05:18 *DEBUG* IndexMerger: index added: name=_2, numDocs=1 (IndexMerger.java, line 162) 30.03.2008 12:05:18 *DEBUG* MultiIndex: Committed in-memory index in 362ms. (MultiIndex.java, line 999) 30.03.2008 12:05:18 *INFO * SearchIndex: Index closed: /apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/index (SearchIndex.java, line 639) 30.03.2008 12:05:18 *INFO * DerbyPersistenceManager: Database '/apache-tomcat-6.0.16/rep-mantex.co.uk/workspaces/default/db' shutdown. (DerbyPersistenceManager.java, line 334) 30.03.2008 12:05:18 *ERROR* ConnectionRecoveryManager: failed to close connection, reason: No current connection., state/code: 08003/40000 (ConnectionRecoveryManager.java, line 453) 30.03.2008 12:05:18 *DEBUG* ConnectionRecoveryManager: dump: (ConnectionRecoveryManager.java, line 455) java.sql.SQLException: No current connection. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.getAutoCommit(Unknown Source) at org.apache.jackrabbit.core.persistence.bundle.util.ConnectionRecoveryManager.close(ConnectionRecoveryManager.java:314) at org.apache.jackrabbit.core.persistence.bundle.BundleDbPersistenceManager.close(BundleDbPersistenceManager.java:926) at org.apache.jackrabbit.core.persistence.bundle.DerbyPersistenceManager.close(DerbyPersistenceManager.java:337) at org.apache.jackrabbit.core.RepositoryImpl$WorkspaceInfo.doDispose(RepositoryImpl.java:1890) at org.apache.jackrabbit.core.RepositoryImpl$WorkspaceInfo.dispose(RepositoryImpl.java:1841) at org.apache.jackrabbit.core.RepositoryImpl.doShutdown(RepositoryImpl.java:1005) at org.apache.jackrabbit.core.RepositoryImpl.shutdown(RepositoryImpl.java:959) at org.apache.jackrabbit.core.TransientRepository.stopRepository(TransientRepository.java:271) at org.apache.jackrabbit.core.TransientRepository.loggedOut(TransientRepository.java:423) at org.apache.jackrabbit.core.SessionImpl.notifyLoggedOut(SessionImpl.java:574) at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:1097) at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:403) at RC5.main(RC5.java:92) 30.03.2008 12:05:18 *INFO * RepositoryImpl: workspace 'default' has been shutdown (RepositoryImpl.java, line 1846) 30.03.2008 12:05:18 *INFO * DerbyPersistenceManager: Database '/apache-tomcat-6.0.16/rep-mantex.co.uk/version/db' shutdown. (DerbyPersistenceManager.java, line 334) 30.03.2008 12:05:18 *ERROR* ConnectionRecoveryManager: failed to close connection, reason: No current connection., state/code: 08003/40000 (ConnectionRecoveryManager.java, line 453) 30.03.2008 12:05:18 *DEBUG* ConnectionRecoveryManager: dump: (ConnectionRecoveryManager.java, line 455) java.sql.SQLException: No current connection. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source) at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.getAutoCommit(Unknown Source) at org.apache.jackrabbit.core.persistence.bundle.util.ConnectionRecoveryManager.close(ConnectionRecoveryManager.java:314) at org.apache.jackrabbit.core.persistence.bundle.BundleDbPersistenceManager.close(BundleDbPersistenceManager.java:926) at org.apache.jackrabbit.core.persistence.bundle.DerbyPersistenceManager.close(DerbyPersistenceManager.java:337) at org.apache.jackrabbit.core.version.VersionManagerImpl.close(VersionManagerImpl.java:201) at org.apache.jackrabbit.core.RepositoryImpl.doShutdown(RepositoryImpl.java:1011) at org.apache.jackrabbit.core.RepositoryImpl.shutdown(RepositoryImpl.java:959) at org.apache.jackrabbit.core.TransientRepository.stopRepository(TransientRepository.java:271) at org.apache.jackrabbit.core.TransientRepository.loggedOut(TransientRepository.java:423) at org.apache.jackrabbit.core.SessionImpl.notifyLoggedOut(SessionImpl.java:574) at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:1097) at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:403) at RC5.main(RC5.java:92) 30.03.2008 12:05:18 *INFO * RepositoryImpl: Repository has been shutdown (RepositoryImpl.java, line 1044) 30.03.2008 12:05:18 *INFO * TransientRepository: Transient repository shut down (TransientRepository.java, line 272)