Artifactory 5.11 fails to start up due to Access failure

Question

My artifactory instance has been running for months but it has completely stopped working since the last update (to 5.11).

When I try to start it up I see the following errors in the logs...

     /\
    /  \   ___ ___ ___  ___ ___
   / /\ \ / __/ __/ _ \/ __/ __|
  / ____ \ (_| (_|  __/\__ \__ \
 /_/    \_\___\___\___||___/___/
Access Version:  3.3.2
Access Revision: 30302900    


2018-05-15 08:57:43.904  INFO 32571 --- [ost-startStop-1] o.j.a.s.startup.AccessHomeFinderImpl     : Using JFrog Access home at '/var/opt/jfrog/artifactory/access' resolved from: System property (Artifactory)
2018-05-15 08:57:44.132 ERROR 32571 --- [ost-startStop-1] o.s.boot.SpringApplication               : Application startup failed    

java.lang.IllegalArgumentException: Unknown value:
    at org.jfrog.access.util.EnumUtils.lambda$fromValue$0(EnumUtils.java:30) ~[access-common-api-3.3.2.jar:na]
    at java.util.Optional.orElseThrow(Optional.java:290) ~[na:1.8.0_161]
    at org.jfrog.access.util.EnumUtils.fromValue(EnumUtils.java:70) ~[access-common-api-3.3.2.jar:na]
    at org.jfrog.access.util.EnumUtils.fromValue(EnumUtils.java:30) ~[access-common-api-3.3.2.jar:na]
    at org.jfrog.access.server.home.migration.EnvironmentVersion.fromVersionString(EnvironmentVersion.java:62) ~[access-server-core-3.3.2.jar:na]
    at org.jfrog.access.server.home.migration.EnvironmentConfig.readEnvVersionFile(EnvironmentConfig.java:72) ~[access-server-core-3.3.2.jar:na]
    at org.jfrog.access.server.home.migration.EnvironmentConfig.getConfigVersion(EnvironmentConfig.java:46) ~[access-server-core-3.3.2.jar:na]
    at org.jfrog.access.migration.ConfigMigrationRunner.migrateIfNeeded(ConfigMigrationRunner.java:37) ~[access-common-core-3.3.2.jar:na]
    at org.jfrog.access.server.startup.AccessServerStartupFacadeImpl.migrateEnvironment(AccessServerStartupFacadeImpl.java:48) ~[access-server-core-3.3.2.jar:na]
    at org.jfrog.access.server.startup.AccessServerStartupFacadeImpl.prepareEnvironment(AccessServerStartupFacadeImpl.java:30) ~[access-server-core-3.3.2.jar:na]
    at org.jfrog.access.context.AccessApplicationContextInitializer.prepareEnvironment(AccessApplicationContextInitializer.java:48) ~[access-application-3.3.2.jar:3.3.2]
    at org.jfrog.access.context.AccessApplicationContextInitializer.prepareEnvironment(AccessApplicationContextInitializer.java:26) ~[access-application-3.3.2.jar:3.3.2]
    at org.jfrog.app.context.JFrogApplicationContextInitializer.initialize(JFrogApplicationContextInitializer.java:69) ~[jfrog-application-1.5.2.jar:na]
    at org.springframework.boot.SpringApplication.applyInitializers(SpringApplication.java:567) ~[spring-boot-1.5.6.RELEASE.jar:1.5.6.RELEASE]
    at org.springframework.boot.SpringApplication.prepareContext(SpringApplication.java:338) ~[spring-boot-1.5.6.RELEASE.jar:1.5.6.RELEASE]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:301) ~[spring-boot-1.5.6.RELEASE.jar:1.5.6.RELEASE]
    at org.springframework.boot.web.support.SpringBootServletInitializer.run(SpringBootServletInitializer.java:151) [spring-boot-1.5.6.RELEASE.jar:1.5.6.RELEASE]
    at org.springframework.boot.web.support.SpringBootServletInitializer.createRootApplicationContext(SpringBootServletInitializer.java:131) [spring-boot-1.5.6.RELEASE.jar:1.5.6.RELEASE]
    at org.springframework.boot.web.support.SpringBootServletInitializer.onStartup(SpringBootServletInitializer.java:86) [spring-boot-1.5.6.RELEASE.jar:1.5.6.RELEASE]
    at org.springframework.web.SpringServletContainerInitializer.onStartup(SpringServletContainerInitializer.java:169) [spring-web-4.3.10.RELEASE.jar:4.3.10.RELEASE]
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5196) [catalina.jar:8.5.23]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150) [catalina.jar:8.5.23]
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:752) [catalina.jar:8.5.23]
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:728) [catalina.jar:8.5.23]
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:734) [catalina.jar:8.5.23]
    at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:630) [catalina.jar:8.5.23]
    at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1842) [catalina.jar:8.5.23]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_161]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_161]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_161]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_161]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_161]    

May 15, 2018 8:57:44 AM org.apache.catalina.core.ContainerBase addChildInternal
SEVERE: ContainerBase.addChild: start:
org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/access]]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:167)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:752)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:728)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:734)
    at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:630)
    at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1842)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalArgumentException: Unknown value:
    at org.jfrog.access.util.EnumUtils.lambda$fromValue$0(EnumUtils.java:30)
    at java.util.Optional.orElseThrow(Optional.java:290)
    at org.jfrog.access.util.EnumUtils.fromValue(EnumUtils.java:70)
    at org.jfrog.access.util.EnumUtils.fromValue(EnumUtils.java:30)
    at org.jfrog.access.server.home.migration.EnvironmentVersion.fromVersionString(EnvironmentVersion.java:62)
    at org.jfrog.access.server.home.migration.EnvironmentConfig.readEnvVersionFile(EnvironmentConfig.java:72)
    at org.jfrog.access.server.home.migration.EnvironmentConfig.getConfigVersion(EnvironmentConfig.java:46)
    at org.jfrog.access.migration.ConfigMigrationRunner.migrateIfNeeded(ConfigMigrationRunner.java:37)
    at org.jfrog.access.server.startup.AccessServerStartupFacadeImpl.migrateEnvironment(AccessServerStartupFacadeImpl.java:48)
    at org.jfrog.access.server.startup.AccessServerStartupFacadeImpl.prepareEnvironment(AccessServerStartupFacadeImpl.java:30)
    at org.jfrog.access.context.AccessApplicationContextInitializer.prepareEnvironment(AccessApplicationContextInitializer.java:48)
    at org.jfrog.access.context.AccessApplicationContextInitializer.prepareEnvironment(AccessApplicationContextInitializer.java:26)
    at org.jfrog.app.context.JFrogApplicationContextInitializer.initialize(JFrogApplicationContextInitializer.java:69)
    at org.springframework.boot.SpringApplication.applyInitializers(SpringApplication.java:567)
    at org.springframework.boot.SpringApplication.prepareContext(SpringApplication.java:338)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:301)
    at org.springframework.boot.web.support.SpringBootServletInitializer.run(SpringBootServletInitializer.java:151)
    at org.springframework.boot.web.support.SpringBootServletInitializer.createRootApplicationContext(SpringBootServletInitializer.java:131)
    at org.springframework.boot.web.support.SpringBootServletInitializer.onStartup(SpringBootServletInitializer.java:86)
    at org.springframework.web.SpringServletContainerInitializer.onStartup(SpringServletContainerInitializer.java:169)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5196)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    ... 10 more    

May 15, 2018 8:57:44 AM org.apache.catalina.startup.HostConfig deployDescriptor
SEVERE: Error deploying configuration descriptor [/opt/jfrog/artifactory/tomcat/conf/Catalina/localhost/access.xml]
java.lang.IllegalStateException: ContainerBase.addChild: start: org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/access]]
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:756)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:728)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:734)
    at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:630)
    at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1842)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)    

May 15, 2018 8:57:44 AM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deployment of configuration descriptor [/opt/jfrog/artifactory/tomcat/conf/Catalina/localhost/access.xml] has finished in [6,262] ms
2018-05-15 08:57:44 [ARTIFACTORY] [INFO ] Starting Artifactory [artifactory.home=/var/opt/jfrog/artifactory].
2018-05-15 08:57:44,833 [art-init] [INFO ] (o.a.w.s.ArtifactoryContextConfigListener:265) -

This then causes Artifactory to fail because it cant find the access server

2018-05-15 08:58:03,475 [art-init] [INFO ] (o.a.s.a.ArtifactoryAccessClientConfigStore:556) - Using Access Server URL: http://localhost:8040/access (bundled) source: detected
2018-05-15 08:58:03,959 [art-init] [INFO ] (o.a.s.a.AccessServiceImpl:290) - Waiting for access server...
2018-05-15 08:58:04,678 [art-init] [WARN ] (o.j.a.c.AccessClientHttpException:39) - Unrecognized ErrorsModel by Access. Original message: Failed on executing /api/v1/system/ping, with response: Not Found
2018-05-15 08:58:06,697 [art-init] [WARN ] (o.j.a.c.AccessClientHttpException:39) - Unrecognized ErrorsModel by Access. Original message: Failed on executing /api/v1/system/ping, with response: Not Found
...
2018-05-15 08:59:35,043 [art-init] [ERROR] (o.a.w.s.ArtifactoryContextConfigListener:92) - Application could not be initialized: Waiting for access server to respond timed-out
java.lang.reflect.InvocationTargetException: null
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at org.artifactory.webapp.servlet.ArtifactoryContextConfigListener.configure(ArtifactoryContextConfigListener.java:207)
    at org.artifactory.webapp.servlet.ArtifactoryContextConfigListener.access$200(ArtifactoryContextConfigListener.java:63)
    at org.artifactory.webapp.servlet.ArtifactoryContextConfigListener$1.run(ArtifactoryContextConfigListener.java:88)
Caused by: org.springframework.beans.factory.BeanInitializationException: Failed to initialize bean 'org.artifactory.security.access.AccessService'.; nested exception is java.lang.IllegalStateException: Waiting for access server to respond timed-out
    at org.artifactory.spring.ArtifactoryApplicationContext.refresh(ArtifactoryApplicationContext.java:250)
    at org.artifactory.spring.ArtifactoryApplicationContext.<init>(ArtifactoryApplicationContext.java:133)
    ... 7 common frames omitted
Caused by: java.lang.IllegalStateException: Waiting for access server to respond timed-out
    at org.artifactory.security.access.AccessServiceImpl.waitForAccessServer(AccessServiceImpl.java:305)
    at org.artifactory.security.access.AccessServiceImpl.initAccessService(AccessServiceImpl.java:265)
    at org.artifactory.security.access.AccessServiceImpl.initIfNeeded(AccessServiceImpl.java:250)
    at org.artifactory.security.access.AccessServiceImpl.init(AccessServiceImpl.java:244)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.artifactory.storage.fs.lock.aop.LockingAdvice.invoke(LockingAdvice.java:76)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy41.init(Unknown Source)
    at org.artifactory.spring.ArtifactoryApplicationContext.refresh(ArtifactoryApplicationContext.java:248)
    ... 8 common frames omitted
2018-05-15 09:01:16,534 [http-nio-8081-exec-1] [ERROR] (o.a.w.s.ArtifactoryFilter:213) - Artifactory failed to initialize: Context is null

I have not been able to find anything about the Access error and none of the posts similar to the Artifactory error (like this https://www.jfrog.com/jira/browse/RTFACT-14477) have helped.

Any assistance would be greatly appreciated.

Answer 1

To resolve this issue, please delete the db.lck + dbex.lck files from the $ARTIFACTORY_HOME/data/derby/ folder.

Answer 2

What version of Artifactory have you upgraded from? Is this a Zip installation? Have you changed/removed any content in the $ARTIFACTORY_HOME/access/ folder? Specifically the $ARTIFACTORY_HOME/access/data/access.env.version. Can you confirm this file is there the same it was prior to the upgrade?

Looks like it was touched by someone. Can you change the content of the file to "4" (1byte, with no space or a blank line afterwards), then restart and see if there is any change.