1 Reply Latest reply on Feb 5, 2009 6:11 AM by Sohil Shah

    Problem after uploading multiple archives

    gressho Newbie

      Hello,

      we are trying to upload image archives to JBossPortal 2.7.1 (single node, backed by Oracle 11g). Our archives are simply zip-files with gif's inside, stored in a directory. This works fine some times but then the portal won't react any more. I attach some lengthy log files.
      First there are timeouts acquiring a lock, then it get's more serious:


      INFO | jvm 1 | 2009/02/04 16:08:52 | 16:08:52,386 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:09:30 | 16:09:30,424 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:10:00 | 16:10:00,242 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:10:34 | 16:10:34,408 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:14:43 | 16:14:43,472 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:15:12 | 16:15:12,491 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:16:13 | 16:16:13,790 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:17:19 | 16:17:19,559 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:18:07 | 16:18:07,568 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:18:24 | 16:18:24,810 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:19:48 | 16:19:48,413 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:21:04 | 16:21:04,608 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:21:46 | 16:21:46,383 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:23:37 | 16:23:37,667 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:24:01 | 16:24:01,336 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:24:27 | 16:24:27,550 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:24:34 | 16:24:34,051 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:25:21 | 16:25:21,119 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/04 16:25:55 | 16:25:55,539 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/04 16:26:37 | 16:26:37,941 INFO [AsyncStoreArchiveCommand] Async Processing finished..................
      INFO | jvm 1 | 2009/02/05 09:52:08 | 09:52:08,081 ERROR [STDERR] 05.02.2009 09:52:08 org.jboss.portletbridge.AjaxPortletBridge doFacesRequest
      INFO | jvm 1 | 2009/02/05 09:52:08 | INFO: Start bridge render request processing for portlet IdentityUserPortlet
      INFO | jvm 1 | 2009/02/05 09:52:08 | 09:52:08,111 ERROR [STDERR] 05.02.2009 09:52:08 org.jboss.portletbridge.AjaxPortletBridge doFacesRequest
      INFO | jvm 1 | 2009/02/05 09:52:08 | INFO: Finish rendering portletbridge for namespace jbpns_2fdefault_2fdefault_2fIdentityUserPortletWindowsnpbj
      INFO | jvm 1 | 2009/02/05 09:54:39 | 09:54:39,581 ERROR [STDERR] 05.02.2009 09:54:39 org.jboss.portletbridge.AjaxPortletBridge doFacesRequest
      INFO | jvm 1 | 2009/02/05 09:54:39 | INFO: Start bridge render request processing for portlet IdentityUserPortlet
      INFO | jvm 1 | 2009/02/05 09:54:39 | 09:54:39,615 ERROR [STDERR] 05.02.2009 09:54:39 org.jboss.portletbridge.AjaxPortletBridge doFacesRequest
      INFO | jvm 1 | 2009/02/05 09:54:39 | INFO: Finish rendering portletbridge for namespace jbpns_2fdefault_2fdefault_2fIdentityUserPortletWindowsnpbj
      INFO | jvm 1 | 2009/02/05 09:54:53 | 09:54:53,224 ERROR [STDERR] 05.02.2009 09:54:53 org.jboss.portletbridge.AjaxPortletBridge doFacesRequest
      INFO | jvm 1 | 2009/02/05 09:54:53 | INFO: Start bridge render request processing for portlet AdminPortlet
      INFO | jvm 1 | 2009/02/05 09:54:53 | 09:54:53,590 ERROR [STDERR] 05.02.2009 09:54:53 org.jboss.portletbridge.AjaxPortletBridge doFacesRequest
      INFO | jvm 1 | 2009/02/05 09:54:53 | INFO: Finish rendering portletbridge for namespace jbpns_2fadmin_2fdefault_2fAdminPortletWindowsnpbj
      INFO | jvm 1 | 2009/02/05 10:00:41 | 10:00:41,438 INFO [AsyncStoreArchiveCommand] Async Processing started....................
      INFO | jvm 1 | 2009/02/05 10:01:26 | 10:01:26,303 ERROR [JCRCMS] org.jboss.portal.cms.impl.jcr.JCRCMS@2f7fe7
      INFO | jvm 1 | 2009/02/05 10:01:26 | java.lang.RuntimeException: org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/version_ref/e54d884a-86b0-4ab4-b125-b5041e598cb6, caller=GlobalTransaction:<null>:75, lock=write owner=GlobalTransaction:<null>:74 (activeReaders=0, activeWriter=Thread[Thread-440,5,jboss], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.cms.hibernate.state.JBossCachePersistenceManager.load(JBossCachePersistenceManager.java:1127)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.state.SharedItemStateManager.getNodeReferences(SharedItemStateManager.java:313)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.version.VersionItemStateProvider.getNodeReferences(VersionItemStateProvider.java:134)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.state.SharedItemStateManager.getNodeReferences(SharedItemStateManager.java:320)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.state.SharedItemStateManager.updateReferences(SharedItemStateManager.java:1339)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.state.SharedItemStateManager$Update.begin(SharedItemStateManager.java:551)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.state.SharedItemStateManager.beginUpdate(SharedItemStateManager.java:843)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.state.XAItemStateManager.prepare(XAItemStateManager.java:146)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.TransactionContext.prepare(TransactionContext.java:138)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.jackrabbit.core.XASessionImpl.prepare(XASessionImpl.java:324)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.cms.impl.jcr.JackRabbitTransaction.commit(JackRabbitTransaction.java:119)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.cms.impl.jcr.JCRCMS.execute(JCRCMS.java:501)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at sun.reflect.GeneratedMethodAccessor583.invoke(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at java.lang.reflect.Method.invoke(Method.java:597)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at $Proxy236.execute(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.cms.ui.admin.CMSAdminPortlet.internalProcessAction(CMSAdminPortlet.java:1260)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.cms.ui.admin.CMSAdminPortlet.processAction(CMSAdminPortlet.java:890)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portlet.JBossPortlet.processAction(JBossPortlet.java:392)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.impl.jsr168.PortletContainerImpl$Invoker.doFilter(PortletContainerImpl.java:557)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.impl.jsr168.api.FilterChainImpl.doFilter(FilterChainImpl.java:109)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portlet.filter.JBossPortletFilter.doFilter(JBossPortletFilter.java:59)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.impl.jsr168.api.FilterChainImpl.doFilter(FilterChainImpl.java:109)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.impl.jsr168.api.FilterChainImpl.doFilter(FilterChainImpl.java:72)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.impl.jsr168.PortletContainerImpl.dispatch(PortletContainerImpl.java:505)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.container.ContainerPortletDispatcher.invoke(ContainerPortletDispatcher.java:42)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.TransactionInterceptor.org$jboss$portal$core$aspects$portlet$TransactionInterceptor$invokeRequired$aop(TransactionInterceptor.java:117)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.TransactionInterceptor$invokeRequired_N7979132061380150447.invokeNext(TransactionInterceptor$invokeRequired_N7979132061380150447.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.TransactionInterceptor$invokeRequired_N7979132061380150447.invokeNext(TransactionInterceptor$invokeRequired_N7979132061380150447.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.TransactionInterceptor$invokeRequired_N7979132061380150447.invokeNext(TransactionInterceptor$invokeRequired_N7979132061380150447.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.TransactionInterceptor.invokeRequired(TransactionInterceptor.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.TransactionInterceptor.invoke(TransactionInterceptor.java:74)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.HeaderInterceptor.invoke(HeaderInterceptor.java:49)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.EventPayloadInterceptor.invoke(EventPayloadInterceptor.java:196)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.RequestAttributeConversationInterceptor.invoke(RequestAttributeConversationInterceptor.java:119)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.SignOutInterceptor.invoke(SignOutInterceptor.java:43)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.AjaxInterceptor.invoke(AjaxInterceptor.java:49)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.portlet.BackwardCompatibilityInterceptor.invoke(BackwardCompatibilityInterceptor.java:46)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.bridge.BridgeInterceptor.invoke(BridgeInterceptor.java:49)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.PortletSessionSynchronizationInterceptor.invoke(PortletSessionSynchronizationInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.ContextTrackerInterceptor.invoke(ContextTrackerInterceptor.java:48)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.ContextDispatcherInterceptor.access$001(ContextDispatcherInterceptor.java:49)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.ContextDispatcherInterceptor$1.doCallback(ContextDispatcherInterceptor.java:123)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.web.command.CommandDispatcher$CallbackCommand.execute(CommandDispatcher.java:74)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at sun.reflect.GeneratedMethodAccessor809.invoke(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at java.lang.reflect.Method.invoke(Method.java:597)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.web.command.CommandServlet.doGet(CommandServlet.java:130)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.web.command.CommandServlet.doPost(CommandServlet.java:161)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:654)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:557)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:481)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.web.command.CommandServlet.include(CommandServlet.java:79)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.web.command.CommandDispatcher.include(CommandDispatcher.java:50)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.web.jboss.JBossWebContext.include(JBossWebContext.java:66)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.web.impl.DefaultServletContainer.include(DefaultServletContainer.java:190)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.impl.spi.AbstractServerContext.dispatch(AbstractServerContext.java:69)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.ContextDispatcherInterceptor.invoke(ContextDispatcherInterceptor.java:77)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.SecureTransportInterceptor.invoke(SecureTransportInterceptor.java:69)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.ValveInterceptor.invoke(ValveInterceptor.java:75)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.container.ContainerPortletInvoker.invoke(ContainerPortletInvoker.java:116)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.state.producer.ProducerPortletInvoker.invoke(ProducerPortletInvoker.java:221)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.portlet.state.ProducerPortletInvoker.org$jboss$portal$core$impl$portlet$state$ProducerPortletInvoker$invoke$aop(ProducerPortletInvoker.java:53)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.portlet.state.ProducerPortletInvoker$invoke_N8654503705355129869.invokeNext(ProducerPortletInvoker$invoke_N8654503705355129869.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.portlet.state.ProducerPortletInvoker$invoke_N8654503705355129869.invokeNext(ProducerPortletInvoker$invoke_N8654503705355129869.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.portlet.state.ProducerPortletInvoker$invoke_N8654503705355129869.invokeNext(ProducerPortletInvoker$invoke_N8654503705355129869.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.portlet.state.ProducerPortletInvoker.invoke(ProducerPortletInvoker.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.federation.impl.FederatedPortletInvokerService.invoke(FederatedPortletInvokerService.java:145)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.federation.impl.FederatingPortletInvokerService.invoke(FederatingPortletInvokerService.java:149)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.model.instance.InstanceInvoker.invoke(InstanceInvoker.java:42)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.PortalSessionSynchronizationInterceptor.invoke(PortalSessionSynchronizationInterceptor.java:93)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.model.instance.InstanceSecurityInterceptor.invoke(InstanceSecurityInterceptor.java:93)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.PortletInvokerInterceptor.invoke(PortletInvokerInterceptor.java:82)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.aspects.portlet.ConsumerCacheInterceptor.invoke(ConsumerCacheInterceptor.java:229)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.model.instance.InstanceContainerImpl.org$jboss$portal$core$impl$model$instance$InstanceContainerImpl$invoke$aop(InstanceContainerImpl.java:408)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.model.instance.InstanceContainerImpl$invoke_N8654503705355129869.invokeNext(InstanceContainerImpl$invoke_N8654503705355129869.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.model.instance.InstanceContainerImpl$invoke_N8654503705355129869.invokeNext(InstanceContainerImpl$invoke_N8654503705355129869.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.model.instance.InstanceContainerImpl$invoke_N8654503705355129869.invokeNext(InstanceContainerImpl$invoke_N8654503705355129869.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.model.instance.InstanceContainerImpl.invoke(InstanceContainerImpl.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.model.instance.AbstractInstance.invoke(AbstractInstance.java:231)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.portlet.ControllerPortletControllerContext.internalInvoke(ControllerPortletControllerContext.java:255)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.portlet.ControllerPortletControllerContext.invoke(ControllerPortletControllerContext.java:208)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.controller.PortletRequestHandler.invoke(PortletRequestHandler.java:332)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.controller.PortletRequestHandler.invoke(PortletRequestHandler.java:58)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.controller.RequestHandler.handle(RequestHandler.java:64)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.portlet.controller.PortletController.process(PortletController.java:179)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.model.portal.command.action.InvokePortletWindowActionCommand.execute(InvokePortletWindowActionCommand.java:183)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerCommand$1.invoke(ControllerCommand.java:68)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.node.EventBroadcasterInterceptor.invoke(EventBroadcasterInterceptor.java:124)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.PageCustomizerInterceptor.invoke(PageCustomizerInterceptor.java:134)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.PolicyEnforcementInterceptor.invoke(PolicyEnforcementInterceptor.java:78)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.node.PortalNodeInterceptor.invoke(PortalNodeInterceptor.java:81)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.BackwardCompatibilityInterceptor.invoke(BackwardCompatibilityInterceptor.java:48)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.ControlInterceptor.invoke(ControlInterceptor.java:56)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.NavigationalStateInterceptor.invoke(NavigationalStateInterceptor.java:42)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ajax.AjaxInterceptor.invoke(AjaxInterceptor.java:55)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.controller.ResourceAcquisitionInterceptor.invoke(ResourceAcquisitionInterceptor.java:50)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerInterceptor.invoke(ControllerInterceptor.java:40)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:157)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.ControllerContext.execute(ControllerContext.java:134)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.Controller.processCommand(Controller.java:279)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.controller.Controller.handle(Controller.java:261)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.RequestControllerDispatcher.invoke(RequestControllerDispatcher.java:51)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.cms.aspect.IdentityBindingInterceptor.invoke(IdentityBindingInterceptor.java:47)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.aspects.server.ContentTypeInterceptor.invoke(ContentTypeInterceptor.java:68)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.PortalContextPathInterceptor.invoke(PortalContextPathInterceptor.java:45)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.LocaleInterceptor.invoke(LocaleInterceptor.java:96)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.UserInterceptor.invoke(UserInterceptor.java:196)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.aspects.server.SignOutInterceptor.invoke(SignOutInterceptor.java:98)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.impl.api.user.UserEventBridgeTriggerInterceptor.invoke(UserEventBridgeTriggerInterceptor.java:65)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.IdentityCacheInterceptor.invoke(IdentityCacheInterceptor.java:68)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.TransactionInterceptor.org$jboss$portal$core$aspects$server$TransactionInterceptor$invoke$aop(TransactionInterceptor.java:49)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.TransactionInterceptor$invoke_N5143606530999904530.invokeNext(TransactionInterceptor$invoke_N5143606530999904530.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$RequiresNew.invoke(TxInterceptor.java:253)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.TransactionInterceptor$invoke_N5143606530999904530.invokeNext(TransactionInterceptor$invoke_N5143606530999904530.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.aspects.tx.TxInterceptor$RequiresNew.invoke(TxInterceptor.java:262)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.TransactionInterceptor$invoke_N5143606530999904530.invokeNext(TransactionInterceptor$invoke_N5143606530999904530.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.core.aspects.server.TransactionInterceptor.invoke(TransactionInterceptor.java)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.aspects.LockInterceptor$InternalLock.invoke(LockInterceptor.java:69)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.aspects.LockInterceptor.invoke(LockInterceptor.java:130)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:157)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.portal.server.servlet.PortalServlet.service(PortalServlet.java:252)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:524)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
      INFO | jvm 1 | 2009/02/05 10:01:26 | at java.lang.Thread.run(Thread.java:619)


      INFO | jvm 1 | 2009/02/05 10:17:16 | 10:17:16,392 ERROR [FileCreateCommand] org.jboss.portal.cms.impl.jcr.command.FileCreateCommand@28c873
      INFO | jvm 1 | 2009/02/05 10:17:16 | org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:83)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.FileCreateCommand.execute(FileCreateCommand.java:75)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCompositeCommand.execute(JCRCompositeCommand.java:49)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCommandContext.execute(JCRCommandContext.java:73)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.addFile(StoreArchiveCommand.java:159)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.execute(StoreArchiveCommand.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS$1.invoke(JCRCMS.java:121)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ApprovalWorkflowInterceptor.invoke(ApprovalWorkflowInterceptor.java:105)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ACLInterceptor.invoke(ACLInterceptor.java:254)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:157)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS.execute(JCRCMS.java:491)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.GeneratedMethodAccessor583.invoke(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.reflect.Method.invoke(Method.java:597)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.util.JMXInvocationHandler.invoke(JMXInvocationHandler.java:287)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at $Proxy645.execute(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.AsyncStoreArchiveCommand$AsyncProcessor.run(AsyncStoreArchiveCommand.java:163)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.Thread.run(Thread.java:619)
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:118)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:63)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 30 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.createItemInstance(ItemManager.java:566)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:395)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddChildNode(NodeImpl.java:770)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:718)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:665)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.addNode(NodeImpl.java:1987)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:106)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 31 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | 10:17:16,393 ERROR [StoreArchiveCommand] org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand@2ae14e
      INFO | jvm 1 | 2009/02/05 10:17:16 | org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.FileCreateCommand.execute(FileCreateCommand.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCompositeCommand.execute(JCRCompositeCommand.java:49)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCommandContext.execute(JCRCommandContext.java:73)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.addFile(StoreArchiveCommand.java:159)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.execute(StoreArchiveCommand.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS$1.invoke(JCRCMS.java:121)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ApprovalWorkflowInterceptor.invoke(ApprovalWorkflowInterceptor.java:105)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ACLInterceptor.invoke(ACLInterceptor.java:254)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:157)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS.execute(JCRCMS.java:491)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.GeneratedMethodAccessor583.invoke(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.reflect.Method.invoke(Method.java:597)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.util.JMXInvocationHandler.invoke(JMXInvocationHandler.java:287)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at $Proxy645.execute(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.AsyncStoreArchiveCommand$AsyncProcessor.run(AsyncStoreArchiveCommand.java:163)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.Thread.run(Thread.java:619)
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:83)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.FileCreateCommand.execute(FileCreateCommand.java:75)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 29 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:118)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:63)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 30 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.createItemInstance(ItemManager.java:566)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:395)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddChildNode(NodeImpl.java:770)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:718)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:665)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.addNode(NodeImpl.java:1987)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:106)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 31 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | 10:17:16,408 ERROR [FileCreateCommand] org.jboss.portal.cms.impl.jcr.command.FileCreateCommand@1a2ac90
      INFO | jvm 1 | 2009/02/05 10:17:16 | org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:83)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.FileCreateCommand.execute(FileCreateCommand.java:75)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCompositeCommand.execute(JCRCompositeCommand.java:49)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCommandContext.execute(JCRCommandContext.java:73)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.addFile(StoreArchiveCommand.java:159)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.execute(StoreArchiveCommand.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS$1.invoke(JCRCMS.java:121)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ApprovalWorkflowInterceptor.invoke(ApprovalWorkflowInterceptor.java:105)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ACLInterceptor.invoke(ACLInterceptor.java:254)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:157)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS.execute(JCRCMS.java:491)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.GeneratedMethodAccessor583.invoke(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.reflect.Method.invoke(Method.java:597)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.util.JMXInvocationHandler.invoke(JMXInvocationHandler.java:287)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at $Proxy645.execute(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.AsyncStoreArchiveCommand$AsyncProcessor.run(AsyncStoreArchiveCommand.java:163)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.Thread.run(Thread.java:619)
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:118)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:63)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 30 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.createItemInstance(ItemManager.java:566)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:395)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddChildNode(NodeImpl.java:770)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:718)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:665)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.addNode(NodeImpl.java:1987)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:106)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 31 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | 10:17:16,409 ERROR [StoreArchiveCommand] org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand@2ae14e
      INFO | jvm 1 | 2009/02/05 10:17:16 | org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.FileCreateCommand.execute(FileCreateCommand.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCompositeCommand.execute(JCRCompositeCommand.java:49)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCommandContext.execute(JCRCommandContext.java:73)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.addFile(StoreArchiveCommand.java:159)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.execute(StoreArchiveCommand.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS$1.invoke(JCRCMS.java:121)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ApprovalWorkflowInterceptor.invoke(ApprovalWorkflowInterceptor.java:105)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ACLInterceptor.invoke(ACLInterceptor.java:254)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:157)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS.execute(JCRCMS.java:491)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.GeneratedMethodAccessor583.invoke(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.reflect.Method.invoke(Method.java:597)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.util.JMXInvocationHandler.invoke(JMXInvocationHandler.java:287)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at $Proxy645.execute(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.AsyncStoreArchiveCommand$AsyncProcessor.run(AsyncStoreArchiveCommand.java:163)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.Thread.run(Thread.java:619)
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:83)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.FileCreateCommand.execute(FileCreateCommand.java:75)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 29 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:118)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:63)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 30 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.createItemInstance(ItemManager.java:566)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:395)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddChildNode(NodeImpl.java:770)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:718)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.internalAddNode(NodeImpl.java:665)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.NodeImpl.addNode(NodeImpl.java:1987)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:106)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 31 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | 10:17:16,435 ERROR [FileCreateCommand] org.jboss.portal.cms.impl.jcr.command.FileCreateCommand@1e7ed58
      INFO | jvm 1 | 2009/02/05 10:17:16 | org.jboss.portal.cms.CMSException: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:83)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.FileCreateCommand.execute(FileCreateCommand.java:75)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCompositeCommand.execute(JCRCompositeCommand.java:49)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCommandContext.execute(JCRCommandContext.java:73)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.addFile(StoreArchiveCommand.java:159)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.StoreArchiveCommand.execute(StoreArchiveCommand.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS$1.invoke(JCRCMS.java:121)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ApprovalWorkflowInterceptor.invoke(ApprovalWorkflowInterceptor.java:105)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.interceptors.ACLInterceptor.invoke(ACLInterceptor.java:254)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.CMSInterceptor.invoke(CMSInterceptor.java:36)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:115)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:157)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.JCRCMS.execute(JCRCMS.java:491)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.GeneratedMethodAccessor583.invoke(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.reflect.Method.invoke(Method.java:597)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.mx.util.JMXInvocationHandler.invoke(JMXInvocationHandler.java:287)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at $Proxy645.execute(Unknown Source)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.command.AsyncStoreArchiveCommand$AsyncProcessor.run(AsyncStoreArchiveCommand.java:163)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at java.lang.Thread.run(Thread.java:619)
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: org.jboss.portal.cms.CMSException: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createFolder(ResourceUtil.java:118)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.jboss.portal.cms.impl.jcr.util.ResourceUtil.createParentHierarchy(ResourceUtil.java:63)
      INFO | jvm 1 | 2009/02/05 10:17:16 | ... 30 more
      INFO | jvm 1 | 2009/02/05 10:17:16 | Caused by: javax.jcr.ItemNotFoundException: e7aa3ddd-276c-43a4-b7c6-bc844132c297
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.createItemInstance(ItemManager.java:566)
      INFO | jvm 1 | 2009/02/05 10:17:16 | at org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:395)


        • 1. Re: Problem after uploading multiple archives
          Sohil Shah Master

          Try increasing the JBoss cache lock timeout. You can do this for the JBoss Cache configuration under portal-cms.sar/META-INF/jboss-service.xml on the cms.pm.cache:service=TreeCache mbean

           <!--
           Number of milliseconds to wait until all responses for a
           synchronous call have been received.
           -->
           <attribute name="SyncReplTimeout">120000</attribute>
          
           <!-- Max number of milliseconds to wait for a lock acquisition -->
           <attribute name="LockAcquisitionTimeout">120000</attribute>
          


          in this case, the values have been bumped from its default values of 20 s and 15 s respectively to 2 min each

          See if this helps and adjust your wait times based on the size of your archives. Bigger the archive (in terms of number of files it carries, longer the timeout needed)

          Thanks