[Artifactory-developers] [JIRA jfrog] Created: (RTFACT-212) After clear installation + stop & restart Tomcat JackRabbit storage corrupts

[<ji...@jf...>]

After clear installation  + stop & restart Tomcat JackRabbit storage corrup=
ts
---------------------------------------------------------------------------=
--

                 Key: RTFACT-212
                 URL: http://www.jfrog.org/jira//browse/RTFACT-212
             Project: Artifactory
          Issue Type: Bug
          Components: Artifact Storage
    Affects Versions: 1.2.2
         Environment: Artifactory version 1.2.2-rc1
Java Version: 1.5.0_11
Tomcat: 5.5.23
            Reporter: Jan Novotn=C3=BD
         Assigned To: Yoav Landman
            Priority: Blocker


Recently I havent been able to keep Artifactory alive more than a few hours=
.
I found out, that on clear installation (with empty artifactory home - only=
 with default /etc directory) when I first start Tomcat everything goes ok.=
 When I stop it - it seems that locks are not cleared properly on Derby or =
Jackrabbit level?!

Tomcat shuts down properly by shutdown.sh script.

When I start Tomcat next time in log I can found this:

catalina.out:

2007-08-01 10:58:28,673 [WARN ] core.util.RepositoryLock  - Existing lock f=
ile /www/p_prj/p_java/artifactory-home/data/jcr/.lock detected. Repository =
was not shut down properly.
2007-08-01 10:58:28,675 [ERROR] repo.spring.CentralConfigFactoryBean  - Fai=
led to load configuration from '/www/p_prj/p_java/artifactory-home/etc/arti=
factory.config.xml'.
java.lang.RuntimeException: Faild to config jcr repo.
=09at org.artifactory.jcr.JcrHelper.<init>(JcrHelper.java:93)
=09at org.artifactory.repo.CentralConfig.afterPropertiesSet(CentralConfig.j=
ava:131)
=09at org.artifactory.repo.spring.CentralConfigFactoryBean.afterPropertiesS=
et(CentralConfigFactoryBean.java:84)
=09at org.springframework.beans.factory.support.AbstractAutowireCapableBean=
Factory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1175)
=09at org.springframework.beans.factory.support.AbstractAutowireCapableBean=
Factory.initializeBean(AbstractAutowireCapableBeanFactory.java:1145)
=09at org.springframework.beans.factory.support.AbstractAutowireCapableBean=
Factory.createBean(AbstractAutowireCapableBeanFactory.java:427)
=09at org.springframework.beans.factory.support.AbstractBeanFactory$1.getOb=
ject(AbstractBeanFactory.java:251)
=09at org.springframework.beans.factory.support.DefaultSingletonBeanRegistr=
y.getSingleton(DefaultSingletonBeanRegistry.java:144)
=09at org.springframework.beans.factory.support.AbstractBeanFactory.getBean=
(AbstractBeanFactory.java:248)
=09at org.springframework.beans.factory.support.AbstractBeanFactory.getBean=
(AbstractBeanFactory.java:160)
=09at org.springframework.beans.factory.support.DefaultListableBeanFactory.=
preInstantiateSingletons(DefaultListableBeanFactory.java:276)
=09at org.springframework.context.support.AbstractApplicationContext.refres=
h(AbstractApplicationContext.java:360)
=09at org.artifactory.webapp.servlet.ArtifactoryContextConfigurer.contextIn=
itialized(ArtifactoryContextConfigurer.java:45)
=09at org.apache.catalina.core.StandardContext.listenerStart(StandardContex=
t.java:3764)
=09at org.apache.catalina.core.StandardContext.start(StandardContext.java:4=
216)
=09at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase=
.java:760)
=09at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:74=
0)
=09at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:544)
=09at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.jav=
a:920)
=09at org.apache.catalina.startup.HostConfig.deployDirectories(HostConfig.j=
ava:883)
=09at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:492=
)
=09at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1138)
=09at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java=
:311)
=09at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(Lifecycl=
eSupport.java:120)
=09at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1022)
=09at org.apache.catalina.core.StandardHost.start(StandardHost.java:736)
=09at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1014)
=09at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443=
)
=09at org.apache.catalina.core.StandardService.start(StandardService.java:4=
48)
=09at org.apache.catalina.core.StandardServer.start(StandardServer.java:700=
)
=09at org.apache.catalina.startup.Catalina.start(Catalina.java:552)
=09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
=09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.=
java:39)
=09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces=
sorImpl.java:25)
=09at java.lang.reflect.Method.invoke(Method.java:585)
=09at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:295)
=09at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:433)
Caused by: javax.jcr.RepositoryException: The repository home /www/p_prj/p_=
java/artifactory-home/data/jcr appears to be already locked by the current =
process.
=09at org.apache.jackrabbit.core.util.RepositoryLock.acquire(RepositoryLock=
.java:146)
=09at org.apache.jackrabbit.core.RepositoryImpl.<init>(RepositoryImpl.java:=
229)
=09at org.apache.jackrabbit.core.RepositoryImpl.create(RepositoryImpl.java:=
521)
=09at org.artifactory.jcr.JcrHelper.<init>(JcrHelper.java:91)
=09... 36 more=20

I will attach full logs listing.

In derby.log I can found:

----------------------------------------------------------------
2007-08-01 08:58:57.078 GMT:
 Booting Derby version The Apache Software Foundation - Apache Derby - 10.2=
.2.0 - (485682): instance c013800d-0114-20a6-3448-000001858410
on database directory /www/p_prj/p_java/artifactory-home/data/jcr/db =20

Database Class Loader started - derby.database.classpath=3D''
2007-08-01 08:58:58.349 GMT Thread[Finalizer,8,system] (XID =3D 810), (SESS=
IONID =3D 2), (DATABASE =3D /www/p_prj/p_java/artifactory-home/data/jcr/db)=
, (DRDAID =3D null), Cleanup action starting
2007-08-01 08:58:58.349 GMT Thread[Finalizer,8,system] (XID =3D 810), (SESS=
IONID =3D 2), (DATABASE =3D /www/p_prj/p_java/artifactory-home/data/jcr/db)=
, (DRDAID =3D null), Failed Statement is: null
java.lang.NullPointerException
=09at org.apache.derby.iapi.services.monitor.Monitor.newInstanceFromIdentif=
ier(Unknown Source)
=09at org.apache.derby.iapi.services.io.FormatIdInputStream.readObject(Unkn=
own Source)
=09at org.apache.derby.iapi.services.io.ArrayInputStream.readObject(Unknown=
 Source)
=09at org.apache.derby.impl.store.raw.log.Scan.getNextRecordBackward(Unknow=
n Source)
=09at org.apache.derby.impl.store.raw.log.Scan.getNextRecord(Unknown Source=
)
=09at org.apache.derby.impl.store.raw.log.FileLogger.undo(Unknown Source)
=09at org.apache.derby.impl.store.raw.xact.Xact.abort(Unknown Source)
=09at org.apache.derby.impl.store.access.RAMTransaction.abort(Unknown Sourc=
e)
=09at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.doRol=
lback(Unknown Source)
=09at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.userR=
ollback(Unknown Source)
=09at org.apache.derby.impl.jdbc.TransactionResourceImpl.rollback(Unknown S=
ource)
=09at org.apache.derby.impl.jdbc.EmbedConnection.close(Unknown Source)
=09at org.apache.derby.impl.jdbc.EmbedConnection.finalize(Unknown Source)
=09at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
=09at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
=09at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
=09at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)
Cleanup action completed
2007-08-01 08:58:58.360 GMT Thread[Finalizer,8,system] Cleanup action start=
ing
java.lang.NullPointerException
=09at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source)
=09at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Unknown Source)
=09at org.apache.derby.impl.jdbc.Util.javaException(Unknown Source)
=09at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException=
(Unknown Source)
=09at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Un=
known Source)
=09at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown So=
urce)
=09at org.apache.derby.impl.jdbc.EmbedConnection.close(Unknown Source)
=09at org.apache.derby.impl.jdbc.EmbedConnection.finalize(Unknown Source)
=09at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
=09at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
=09at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
=09at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)
2007-08-01 08:58:58.360 GMT Thread[Finalizer,8,system] Equally severe excep=
tion raised during cleanup (ignored) null
java.lang.NullPointerException
=09at org.apache.derby.impl.sql.compile.CompilerContextImpl.initRequiredPri=
v(Unknown Source)
=09at org.apache.derby.impl.sql.compile.CompilerContextImpl.resetContext(Un=
known Source)
=09at org.apache.derby.impl.sql.compile.CompilerContextImpl.cleanupOnError(=
Unknown Source)
=09at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(=
Unknown Source)
=09at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Un=
known Source)
=09at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown So=
urce)
=09at org.apache.derby.impl.jdbc.EmbedConnection.close(Unknown Source)
=09at org.apache.derby.impl.jdbc.EmbedConnection.finalize(Unknown Source)
=09at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
=09at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
=09at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
=09at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)
Cleanup action completed=20

--=20
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: htt=
p://www.jfrog.org/jira//secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira