Bitnami Alfresco Failing to Start

Over the past two days I have been working on getting a very old instance of Bitnami Alfresco Community Server to actually start. Unfortunately for the most parts the logs were not providing anything useful. After a bit of cleanup of Tomcat Caching I was able to finally get proper logging and a solution to the problem without having to upgrade the AWS instance.

First, the ‘alfresco.log’ log was owned by root so the tomcat user could not write to it which prevented much troubleshooting outside of hope, dreams crossing fingers and a bit of strace. But anyone who has ever straced java can tell you it’s almost useless unless of course you have time to scour tens of thousands of lines of system calls; which lets be honest, none of us do.

Moving forward I started seeing logs like:

Caused by: java.lang.OutOfMemoryError: Java heap space
  at java.util.Arrays.copyOfRange(Arrays.java:2694)
  at java.lang.String.<init>(String.java:203)
  at java.lang.String.toUpperCase(String.java:2664)
  at org.apache.ibatis.executor.resultset.FastResultSetHandler.loadMappedAndUnmappedColumnNames(FastResultSetHandler.java:270)
  at org.apache.ibatis.executor.resultset.NestedResultSetHandler.getRowValue(NestedResultSetHandler.java:90)
  at org.apache.ibatis.executor.resultset.NestedResultSetHandler.applyNestedResultMappings(NestedResultSetHandler.java:125)
  at org.apache.ibatis.executor.resultset.NestedResultSetHandler.getRowValue(NestedResultSetHandler.java:96)
  at org.apache.ibatis.executor.resultset.NestedResultSetHandler.handleRowValues(NestedResultSetHandler.java:65)
  at org.apache.ibatis.executor.resultset.FastResultSetHandler.handleResultSet(FastResultSetHandler.java:121)
  at org.apache.ibatis.executor.resultset.FastResultSetHandler.handleResultSets(FastResultSetHandler.java:98)
  at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:40)
  at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:55)
  at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:41)
  at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:120)
  at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:75)
  at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:75)
  at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:69)
  at sun.reflect.GeneratedMethodAccessor214.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:606)
  at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:338)
  at com.sun.proxy.$Proxy6.selectList(Unknown Source)
  at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:189)
  at org.alfresco.repo.domain.node.ibatis.NodeDAOImpl.selectNodesByUuids(NodeDAOImpl.java:437)
  at org.alfresco.repo.domain.node.AbstractNodeDAOImpl.cacheNodes(AbstractNodeDAOImpl.java:4586)
  at org.alfresco.repo.domain.node.AbstractNodeDAOImpl.cacheNodes(AbstractNodeDAOImpl.java:4562)
  at org.alfresco.repo.domain.node.AbstractNodeDAOImpl$ChildAssocRefBatchingQueryCallback.done(AbstractNodeDAOImpl.java:3385)
  at org.alfresco.repo.domain.node.ibatis.NodeDAOImpl.selectChildAssocs(NodeDAOImpl.java:1108)
  at org.alfresco.repo.domain.node.AbstractNodeDAOImpl.getChildAssocs(AbstractNodeDAOImpl.java:3417)
  at org.alfresco.repo.node.db.DbNodeServiceImpl.getChildAssocs(DbNodeServiceImpl.java:1882)
  at org.alfresco.repo.node.db.DbNodeServiceImpl.getChildAssocs(DbNodeServiceImpl.java:1826)
  at org.alfresco.repo.node.db.DbNodeServiceImpl.getChildAssocs(DbNodeServiceImpl.java:1814)

This lead me to an obvious memory issue while troubleshooting the start up of the Alfresco service. Checking the environment variables for the running process I saw it only had 512M allocated to the process shown below:

# cat /proc/$(ps auwx | grep jsvc | head -1 | awk '{print $2}')/environ | sed 's/\x0/\n/g' | grep JAVA_OPTS
JAVA_OPTS=-XX:MaxPermSize=512m -Xms256m -Xmx512m -Djava.awt.headless=true -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager

There was nearly 4G of ram available on this box and the only application running was Alfresco on top of Tomcat; so whomever setup the server never actually configured Java to use enough memory to perform properly. So this ended up being a relatively easy fix by just increasing the memory in the JAVA_OPTS variable. You can do this in one of the following files:

  • /opt/bitnami/apache-tomcat/scripts/ctl.sh
  • /opt/bitnami/apache-tomcat/bin/setenv.sh

Write a Comment

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.