All user logins being rejected. startInternal error listenerStart

[o_p_davey]

Hi all,

I set up Alfresco around July last year and configured it to use MySQL instead of the standard postgres on Windows Server 2008. It was used lightly at first but went untouched for a short while. Last week, we ran out of disk space on the server and I noticed there were many logfiles in the tomcat log directory (which I found odd since it was not used much). Anyway, I removed the logs and changed the conf to bring the logging level down a little. However, no-one is able to log on to Alfresco. The response is always:

Your authentication details have not been recognized or Alfresco may not be available at this time.

From reverse-engineering the database, I can see that the password hash for admin is '209c6174da490caeb422f3fa5a7ae634' (admin)

When trying to access localhost:8080/alfresco, the response is:

HTTP Status 404 - /alfresco

type Status report

message /alfresco

description The requested resource is not available.
‍‍‍‍‍‍‍‍‍

The access logs are filled mostly with:

"POST /alfresco/service/api/solr/modelsdiff HTTP/1.1" 404 1023‍

Catalina logs report the following on startup:

Feb 02, 2015 9:59:09 AM org.apache.catalina.core.AprLifecycleListener init
INFO: Loaded APR based Apache Tomcat Native library 1.1.29 using APR version 1.4.8.
Feb 02, 2015 9:59:09 AM org.apache.catalina.core.AprLifecycleListener init
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Feb 02, 2015 9:59:10 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 1.0.1e 11 Feb 2013)
Feb 02, 2015 9:59:10 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8080"]
Feb 02, 2015 9:59:10 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8009"]
Feb 02, 2015 9:59:10 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8443"]
Feb 02, 2015 9:59:11 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 2556 ms
Feb 02, 2015 9:59:11 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Feb 02, 2015 9:59:11 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.53
Feb 02, 2015 9:59:11 AM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor C:\Alfresco\tomcat\conf\Catalina\localhost\solr.xml
Feb 02, 2015 9:59:11 AM org.apache.catalina.startup.SetContextPropertiesRule begin
WARNING: [SetContextPropertiesRule]{Context} Setting property 'debug' to '0' did not find a matching property.
Feb 02, 2015 9:59:29 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive C:\Alfresco\tomcat\webapps\alfresco.war
Feb 02, 2015 10:01:27 AM org.apache.catalina.core.StandardContext startInternal
SEVERE: Error listenerStart
Feb 02, 2015 10:01:27 AM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [/alfresco] startup failed due to previous errors
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Any guidance on how to get Alfresco back up and running would be much appreciated.

Thanks

[mlagneaux]

Hi,

You can't login since Alfresco webapp is not started. On Windows, Catalina logs are not really usefull since you just find logs about Tomcat startup (no logs about webapps startup).
You should have an alfresco.log file. It should be in the repository from which you run Tomcat (perhaps [TOMCAT_HOME]/bin). This log file will be better to understand your problem.

Could you give us this alfresco.log file ?

Access logs about POST requests to /alfresco/service/api/solr/modelsdiff are generated by SolR. SolR makes request to Alfresco on a regular basis to ask which transactions it has to index. Since Alfresco is down, those requests end with a 404 error.

[o_p_davey]

I have the alfresco.log file in C:\Alfresco (not the Tomcat home) which shows a few errors. It looks like the error breaking it is related to the app:dictionary node, but I will post all (with warnings), just in case.

10:25:16,445 WARN  [org.alfresco.util.RuntimeSystemPropertiesSetter] [localhost-startStop-1] Could not find alfresco-jmxrmi.password on classpath
‍‍‍

…

10:26:17,425 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
10:26:17,565 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
10:26:20,498 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
10:26:20,545 ERROR [org.alfresco.repo.content.transform.RuntimeExecutableContentTransformerWorker] [localhost-startStop-1] Failed to start a runtime executable content transformer: 
Execution result: 
   os:         Windows Server 2008 R2
   command:    ./bin/pdf2swf -V
   succeeded:  false
   exit code:  1
   out:        
   err:        Cannot run program "./bin/pdf2swf": CreateProcess error=2, The system cannot find the file specified
10:26:21,309 ERROR [org.alfresco.repo.content.transform.magick.AbstractImageMagickContentTransformerWorker] [localhost-startStop-1] ImageMagickContentTransformerWorker not available: 01030001 Failed to perform ImageMagick transformation: 
Execution result: 
   os:         Windows Server 2008 R2
   command:    ./ImageMagick/bin/convert C:\Alfresco\tomcat\temp\Alfresco\ImageMagickContentTransformerWorker_init_source_608472856053835526.gif C:\Alfresco\tomcat\temp\Alfresco\ImageMagickContentTransformerWorker_init_target_7912363757482311446.png
   succeeded:  false
   exit code:  410
   out:        
   err:        Cannot run program "./ImageMagick/bin/convert": CreateProcess error=2, The system cannot find the file specified
10:26:21,325 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
10:26:21,325 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
10:26:21,605 ERROR [org.alfresco.util.exec.RuntimeExecBootstrapBean] [localhost-startStop-1] Bootstrap command failed: 
Execution result: 
   os:         Windows Server 2008 R2
   command:    soffice -accept=socket,host=127.0.0.1,port=8100;urp;StarOffice.ServiceManager -env:UserInstallation=file:///C:/Alfresco/alf_data/oouser -headless -nocrashreport -nofirststartwizard -nologo -norestore
   succeeded:  false
   exit code:  2
   out:        
   err:        Cannot run program "soffice": CreateProcess error=2, The system cannot find the file specified
10:26:22,682 WARN  [org.alfresco.util.OpenOfficeConnectionTester] [localhost-startStop-1] An initial OpenOffice connection could not be established.
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

…

11:05:32,152 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
11:05:32,542 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
11:05:32,636 ERROR [org.springframework.web.context.ContextLoader] [localhost-startStop-1] Context initialization failed
org.alfresco.error.AlfrescoRuntimeException: 01030032 Failed to find 'app:dictionary' node
   at org.alfresco.repo.action.scheduled.ScheduledPersistedActionServiceImpl.locatePersistanceFolder(ScheduledPersistedActionServiceImpl.java:141)
   at org.alfresco.repo.action.scheduled.ScheduledPersistedActionServiceImpl$ScheduledPersistedActionServiceBootstrap$1$1.execute(ScheduledPersistedActionServiceImpl.java:497)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:454)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:323)
   at org.alfresco.repo.action.scheduled.ScheduledPersistedActionServiceImpl$ScheduledPersistedActionServiceBootstrap$1.doWork(ScheduledPersistedActionServiceImpl.java:502)
   at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:548)
   at org.alfresco.repo.action.scheduled.ScheduledPersistedActionServiceImpl$ScheduledPersistedActionServiceBootstrap.onBootstrap(ScheduledPersistedActionServiceImpl.java:489)
   at org.springframework.extensions.surf.util.AbstractLifecycleBean.onApplicationEvent(AbstractLifecycleBean.java:56)
   at org.alfresco.repo.management.SafeApplicationEventMulticaster.multicastEventInternal(SafeApplicationEventMulticaster.java:209)
   at org.alfresco.repo.management.SafeApplicationEventMulticaster.multicastEvent(SafeApplicationEventMulticaster.java:180)
   at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:303)
   at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:911)
   at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:428)
   at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:276)
   at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:197)
   at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:47)
   at org.alfresco.web.app.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:63)
   at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4973)
   at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5467)
   at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
   at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901)
   at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877)
   at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:632)
   at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1073)
   at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1857)
   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
   at java.util.concurrent.FutureTask.run(FutureTask.java:262)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   at java.lang.Thread.run(Thread.java:745)

‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Appreciate the help

[rjohnson]

Basically Alfresco is not starting and without that you will not be able to log in even though share will present a login page.

I think the java "dump" that follows what you posted from your log will give a clue as to the issue.