cancel
Showing results for 
Search instead for 
Did you mean: 

Alfresco installation Problem in Ubuntu - Log included.

anonymousc
Champ in-the-making
Champ in-the-making
I have installed Alfresco in Ubuntu, but when I try to start alfresco, I get:

root@ubuntusvr:/opt/Alfresco# /opt/Alfresco/alfresco.sh start
Using CATALINA_BASE:   /opt/Alfresco/tomcat
Using CATALINA_HOME:   /opt/Alfresco/tomcat
Using CATALINA_TMPDIR: /opt/Alfresco/tomcat/temp
Using JRE_HOME:       /usr/lib/jvm/java-6-sun;

I don't see any server times showing that the server was started in xxxxxxxms which I see when I run the Windows version of Alfresco.

Is this a confirmation that Alfresco has started? There are no processes running in port 8080. I have checked database access using 127.0.0.1, localhost, hostname, they all work. The database exists, but the there are no tables. I am trying to install/run the Lab version. Please help me understand the log so I can fix this.

17:27:57,297 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
17:28:36,019 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 67 Web Scripts (+0 failed), 71 URLs
17:28:36,044 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 3962.5708ms)
17:29:46,430 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 101 Web Scripts (+0 failed), 105 URLs
17:29:46,435 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 70227.82ms)
17:29:48,016 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
17:36:08,795 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
17:36:54,009 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
17:38:36,390 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 67 Web Scripts (+0 failed), 71 URLs
17:38:36,474 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 17692.742ms)
17:38:57,522 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 67 Web Scripts (+0 failed), 71 URLs
17:38:57,608 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 13422.671ms)
17:39:30,968 ERROR [org.alfresco.repo.content.transform.magick.AbstractImageMagickContentTransformer] ImageMagickContentTransformer not available: Failed to perform ImageMagick transformation:
Execution result:
   os:         Linux
   command:    [./ImageMagick/bin/convert, /opt/alfresco/tomcat/temp/Alfresco/ImageMagickContentTransformer_init_source_3893013690754879385.gif, /opt/alfresco/tomcat/temp/Alfresco/ImageMagickContentTransformer_init_target_6546576239020779931.png]
   succeeded:  false
   exit code:  1
   out:
   err:        Cannot run program "./ImageMagick/bin/convert": java.io.IOException: error=2, No such file or directory
17:39:58,714 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 101 Web Scripts (+0 failed), 105 URLs
17:39:58,748 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 81517.89ms)
17:40:01,000 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
17:40:56,507 INFO  [org.alfresco.config.xml.XMLConfigService$PropertyConfigurer] Loading properties file from class path resource [alfresco/file-servers.properties]
17:41:30,275 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 101 Web Scripts (+0 failed), 105 URLs
17:41:30,347 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 151993.48ms)
17:41:34,212 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework

Please Help.

Thanks
AC
8 REPLIES 8

gronfelt
Champ in-the-making
Champ in-the-making
The error message indicates that you have not set up the right path to imagemagick. You do that in <alfresco dir>/tomcat/shared/classes/alfresco/extension/custom-repository.properties.

However, I believe that Alfresco should start anyway, even if there's a problem with imagemagick. If Alfresco is started you should see a line in the log stating something like
INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco started (Labs): Current version 3.2.0 (_dev 1979) schema 2015 - Installed version 3.2.0 (_dev 1979) schema 2015

You could also check if Alfresco is running with ps:
ps -ef |grep Alfresco

Are there any error messages in catalina.out (located under tomcat/logs/)?

anonymousc
Champ in-the-making
Champ in-the-making
Alfresco is not running according to ps.

Does this info help at all:
root@ubuntusvr:/opt/alfresco/tomcat/shared/classes/alfresco/extension# /opt/alfresco/alf_start.sh
sh: Can't open @@ALFRESCO_DIR@@/alfresco.sh

Also, the catalina.out file has been duplicated, there are now 3 of them, one is catalina.out, and the other 2 have dates as suffices, like catalina.2009-06-25.log. The following is the text from catalina.2009-06-25.log

25-Jun-2009 10:18:38 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
25-Jun-2009 10:18:38 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 10558 ms
25-Jun-2009 10:18:39 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
25-Jun-2009 10:18:39 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
25-Jun-2009 10:18:39 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive share.war
25-Jun-2009 10:19:50 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive studio.war
25-Jun-2009 10:21:17 PM org.apache.coyote.http11.Http11Protocol init
SEVERE: Error initializing endpoint
java.net.BindException: Address already in use<null>:8080
   at org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:502)
   at org.apache.coyote.http11.Http11Protocol.init(Http11Protocol.java:176)
   at org.apache.catalina.connector.Connector.initialize(Connector.java:1058)
   at org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
   at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:530)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:550)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:412)
25-Jun-2009 10:21:18 PM org.apache.catalina.startup.Catalina load
SEVERE: Catalina.start
LifecycleException:  Protocol handler initialization failed: java.net.BindException: Address already in use<null>:8080
   at org.apache.catalina.connector.Connector.initialize(Connector.java:1060)
   at org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
   at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:530)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:550)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:412)
25-Jun-2009 10:21:18 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 13654 ms
25-Jun-2009 10:21:19 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
25-Jun-2009 10:21:20 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
25-Jun-2009 10:21:20 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive share.war
25-Jun-2009 10:21:47 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive alfresco.war
25-Jun-2009 10:22:15 PM org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate definition has been ignored.
25-Jun-2009 10:22:45 PM org.apache.coyote.http11.Http11Protocol init
SEVERE: Error initializing endpoint
java.net.BindException: Address already in use<null>:8080
   at org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:502)
   at org.apache.coyote.http11.Http11Protocol.init(Http11Protocol.java:176)
   at org.apache.catalina.connector.Connector.initialize(Connector.java:1058)
   at org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
   at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:530)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:550)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:412)
25-Jun-2009 10:22:46 PM org.apache.catalina.startup.Catalina load
SEVERE: Catalina.start
LifecycleException:  Protocol handler initialization failed: java.net.BindException: Address already in use<null>:8080
   at org.apache.catalina.connector.Connector.initialize(Connector.java:1060)
   at org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
   at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:530)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:550)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:412)
25-Jun-2009 10:22:46 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 19296 ms
25-Jun-2009 10:22:48 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
25-Jun-2009 10:22:48 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
25-Jun-2009 10:22:48 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive share.war
25-Jun-2009 10:22:51 PM org.apache.coyote.http11.Http11Protocol init
SEVERE: Error initializing endpoint
java.net.BindException: Address already in use<null>:8080
   at org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:502)
   at org.apache.coyote.http11.Http11Protocol.init(Http11Protocol.java:176)
   at org.apache.catalina.connector.Connector.initialize(Connector.java:1058)
   at org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
   at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:530)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:550)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:412)
25-Jun-2009 10:22:51 PM org.apache.catalina.startup.Catalina load
SEVERE: Catalina.start
LifecycleException:  Protocol handler initialization failed: java.net.BindException: Address already in use<null>:8080
   at org.apache.catalina.connector.Connector.initialize(Connector.java:1060)
   at org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
   at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:530)
   at org.apache.catalina.startup.Catalina.load(Catalina.java:550)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:412)
25-Jun-2009 10:22:51 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 18733 ms
25-Jun-2009 10:22:53 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
25-Jun-2009 10:22:53 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
25-Jun-2009 10:22:54 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive share.war
25-Jun-2009 10:24:03 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive studio.war
25-Jun-2009 10:25:32 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive studio.war
25-Jun-2009 10:25:40 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive studio.war
25-Jun-2009 10:27:54 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive alfresco.war
25-Jun-2009 10:28:26 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive alfresco.war
25-Jun-2009 10:28:29 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive alfresco.war
25-Jun-2009 10:28:50 PM org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate definition has been ignored.
25-Jun-2009 10:28:52 PM org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate definition has been ignored.

Should the Alfresco folder be loer case or upper case, that is /opt/alfresco/ or /opt/Alfresco

Thanks. I need to figure out the proper way to install Alfresco, I will then have to start over and recreate the proper steps once I fugure them out. I am installing in Ubuntu Server. I hope I answered all your questions.

mikeh
Star Contributor
Star Contributor
java.net.BindException: Address already in use<null>:8080
Shutdown anything already listening on port 8080

Mike

gronfelt
Champ in-the-making
Champ in-the-making
Alfresco is not running according to ps.

Does this info help at all:
root@ubuntusvr:/opt/alfresco/tomcat/shared/classes/alfresco/extension# /opt/alfresco/alf_start.sh
sh: Can't open @@ALFRESCO_DIR@@/alfresco.sh

The problem is that the script tries to run "@@ALFRESCO_DIR@@/alfresco.sh", which is a path that the operating system can't make any sense of. The "@@ALFRESCO_DIR@@" part is supposed to be exchanged with the actual install directory during install, but unfortunately that didn't work with the Linux installer in Alfresco Labs 3 Stable.

So you need to exchange "@@ALFRESCO_DIR@@" with your proper install directory (in your case "/opt/alfresco/") in alfresco.sh and alf_start.sh.

(However, as far as I know alf_start.sh does nothing at all but run alfresco.sh, so you might as well just make the change in alfresco.sh and then run "alfresco.sh start" to start Alfresco).

Like Mike points out the error message in catalina.out says that port 8080, which tomcat want's to bind to, is already used by another process, perhaps an earlier instance of tomcat that's still running. You can use "netstat -pn|grep 8080" to find out which process it is.

anonymousc
Champ in-the-making
Champ in-the-making
Hi MikeH and gronfelt. I checked what was locking up port 8080 and got the following:

root@ubuntusvr:/# netstat -antp | grep 8080
tcp6       0      0 :::8080                 :::*                    LISTEN      3216/java

By the way, I fixed that "@@ALFRESCO_DIR@@/alfresco.sh" path issue in alf_start.sh. The path was already correct in alfresco.sh, which is what I have been using all along to try and launch alfresco.

So, Alfresco is not running, and Java is locking up port 8080. Any ideas?

Thanks,
AC

gronfelt
Champ in-the-making
Champ in-the-making
Try "ps -ef|grep 3216", that should hopefully give you more information about the java process running.

Was this machine installed specifically to run Alfresco? Or is it used for other purposes also? I don't think that a normal Ubuntu installation would be running anything on port 8080 by default, so if your'e not running any other servers on the machine my best guess would be that it's a left-over process from an earlier attemt to run Alfresco.

anonymousc
Champ in-the-making
Champ in-the-making
Okay, there has been some new development since my last post. I did not make any changes since I was still waiting for a response from you.

I was reading through some posts and there were making references to a server config file at /opt/alfresco/tomcat/conf/server.xml. Then checked out the file and found a line:

<Server port="8005" shutdown="SHUTDOWN">

Without putting much deduction/analysis into it, then sent my browser to http://<my_alfresco_server_ip>:8005/share. I then ran a tail -f on both the catalina.out file and the alfresco log file. Alfresco finally loaded, though with some errors.

I can  now see the Alfresco Share login screen, though it rejects my logins with admin/admin with

"The remote server may be unavailable or your authentication details have not been recognized."

I get an "HTTP Status 404 -" description The requested resource () is not available. when I try to access http://ip_address:8080/alfresco

Here are the logs for catalina.out and the alfresco.log file.

Catalina.out:

28-Jun-2009 12:45:14 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
28-Jun-2009 12:45:15 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 10495 ms
28-Jun-2009 12:45:15 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
28-Jun-2009 12:45:15 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
28-Jun-2009 12:45:16 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive share.war
12:46:26,254  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
28-Jun-2009 12:46:26 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive studio.war
12:47:00,296  INFO  [web.scripts.DeclarativeRegistry] Registered 67 Web Scripts (+0 failed), 71 URLs
12:47:00,310  INFO  [web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 3878.2065ms)
12:48:10,406  INFO  [web.scripts.DeclarativeRegistry] Registered 101 Web Scripts (+0 failed), 105 URLs
12:48:10,407  INFO  [web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 69909.07ms)
12:48:12,020  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
28-Jun-2009 12:48:12 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive alfresco.war
28-Jun-2009 12:48:27 PM org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate definition has been ignored.
12:52:11,360  ERROR [transform.magick.AbstractImageMagickContentTransformer] ImageMagickContentTransformer not available: Failed to perform ImageMagick transformation:
Execution result:
   os:         Linux
   command:    [/usr/bin/bin/convert, /opt/alfresco/tomcat/temp/Alfresco/ImageMagickContentTransformer_init_source_1330639902139558618.gif, /opt/alfresco/tomcat/temp/Alfresco/ImageMagickContentTransformer_init_target_6784922338443639070.png]
   succeeded:  false
   exit code:  1
   out:       
   err:        Cannot run program "/usr/bin/bin/convert": java.io.IOException: error=2, No such file or directory
12:52:41,158  INFO  [config.xml.XMLConfigService$PropertyConfigurer] Loading properties file from class path resource [alfresco/file-servers.properties]
12:53:40,970  ERROR [web.context.ContextLoader] Context initialization failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'luceneIndexBackupComponent' defined in class path resource [alfresco/core-services-context.xml]: Invocation of init method failed; nested exception is org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
Caused by: org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
Caused by: org.hibernate.exception.GenericJDBCException: Cannot open connection
   at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
   at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)
   at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
   at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:119)
   at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:57)
   at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1326)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:510)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:350)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:262)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:219)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.begin(SpringAwareUserTransaction.java:415)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:309)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:227)
   at org.alfresco.repo.search.impl.lucene.AbstractLuceneIndexerAndSearcherFactory$LuceneIndexBackupComponent.afterPropertiesSet(AbstractLuceneIndexerAndSearcherFactory.java:1467)
   at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1201)
   at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1171)
   at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
   at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:251)
   at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:156)
   at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:248)
   at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:160)
   at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:287)
   at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:352)
   at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:244)
   at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:187)
   at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:49)
   at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3843)
   at org.apache.catalina.core.StandardContext.start(StandardContext.java:4342)
   at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:791)
   at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
   at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:525)
   at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:830)
   at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:719)
   at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:490)
   at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1149)
   at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:311)
   at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
   at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
   at org.apache.catalina.core.StandardHost.start(StandardHost.java:719)
   at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
   at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443)
   at org.apache.catalina.core.StandardService.start(StandardService.java:516)
   at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
   at org.apache.catalina.startup.Catalina.start(Catalina.java:578)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:288)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413)
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (Communications link failure

Last packet sent to the server was 0 ms ago.)
   at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:855)
   at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:540)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
   at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
   … 48 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 0 ms ago.
   at sun.reflect.GeneratedConstructorAccessor71.newInstance(Unknown Source)
   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
   at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
   at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
   at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1074)
   at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2103)
   at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:718)
   at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:46)
   at sun.reflect.GeneratedConstructorAccessor68.newInstance(Unknown Source)
   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
   at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
   at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
   at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:302)
   at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:282)
   at org.apache.commons.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:37)
   at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:290)
   at org.apache.commons.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:877)
   at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:851)
   … 51 more
Caused by: java.net.ConnectException: Connection refused
   at java.net.PlainSocketImpl.socketConnect(Native Method)
   at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
   at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
   at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
   at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
   at java.net.Socket.connect(Socket.java:519)
   at java.net.Socket.connect(Socket.java:469)
   at java.net.Socket.<init>(Socket.java:366)
   at java.net.Socket.<init>(Socket.java:209)
   at com.mysql.jdbc.StandardSocketFactory.connect(StandardSocketFactory.java:253)
   at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:280)
   at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2026)
   … 63 more
28-Jun-2009 12:53:41 PM org.apache.catalina.core.StandardContext start
SEVERE: Error listenerStart
28-Jun-2009 12:53:41 PM org.apache.catalina.core.StandardContext start
SEVERE: Context [/alfresco] startup failed due to previous errors
log4j:ERROR LogMananger.repositorySelector was null likely due to error in class reloading, using NOPLoggerRepository.
log4j:WARN No appenders could be found for logger (org.alfresco.util.transaction.SpringAwareUserTransaction.trace).
log4j:WARN Please initialize the log4j system properly.
28-Jun-2009 12:54:02 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-8080
28-Jun-2009 12:54:03 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 528045 ms

Alfresco.log:

12:46:26,254 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
12:47:00,296 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 67 Web Scripts (+0 failed), 71 URLs
12:47:00,310 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 3878.2065ms)
12:48:10,406 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 101 Web Scripts (+0 failed), 105 URLs
12:48:10,407 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 69909.07ms)
12:48:12,020 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
12:52:11,360 ERROR [org.alfresco.repo.content.transform.magick.AbstractImageMagickContentTransformer] ImageMagickContentTransformer not available: Failed to perform ImageMagick transformation:
Execution result:
   os:         Linux
   command:    [/usr/bin/bin/convert, /opt/alfresco/tomcat/temp/Alfresco/ImageMagickContentTransformer_init_source_1330639902139558618.gif, /opt/alfresco/tomcat/temp/Alfresco/ImageMagickContentTransformer_init_target_6784922338443639070.png]
   succeeded:  false
   exit code:  1
   out:       
   err:        Cannot run program "/usr/bin/bin/convert": java.io.IOException: error=2, No such file or directory
12:52:41,158 INFO  [org.alfresco.config.xml.XMLConfigService$PropertyConfigurer] Loading properties file from class path resource [alfresco/file-servers.properties]
12:53:40,970 ERROR [org.springframework.web.context.ContextLoader] Context initialization failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'luceneIndexBackupComponent' defined in class path resource [alfresco/core-services-context.xml]: Invocation of init method failed; nested exception is org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
Caused by: org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection
Caused by: org.hibernate.exception.GenericJDBCException: Cannot open connection
   at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
   at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)
   at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
   at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:119)
   at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:57)
   at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1326)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:510)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:350)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:262)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:219)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.begin(SpringAwareUserTransaction.java:415)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:309)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:227)
   at org.alfresco.repo.search.impl.lucene.AbstractLuceneIndexerAndSearcherFactory$LuceneIndexBackupComponent.afterPropertiesSet(AbstractLuceneIndexerAndSearcherFactory.java:1467)
   at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1201)
   at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1171)
   at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
   at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:251)
   at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:156)
   at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:248)
   at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:160)
   at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:287)
   at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:352)
   at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:244)
   at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:187)
   at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:49)
   at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3843)
   at org.apache.catalina.core.StandardContext.start(StandardContext.java:4342)
   at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:791)
   at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
   at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:525)
   at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:830)
   at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:719)
   at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:490)
   at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1149)
   at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:311)
   at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
   at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
   at org.apache.catalina.core.StandardHost.start(StandardHost.java:719)
   at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
   at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443)
   at org.apache.catalina.core.StandardService.start(StandardService.java:516)
   at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
   at org.apache.catalina.startup.Catalina.start(Catalina.java:578)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:288)
   at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413)
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (Communications link failure

Last packet sent to the server was 0 ms ago.)
   at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:855)
   at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:540)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
   at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
   … 48 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 0 ms ago.
   at sun.reflect.GeneratedConstructorAccessor71.newInstance(Unknown Source)
   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
   at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
   at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
   at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1074)
   at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2103)
   at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:718)
   at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:46)
   at sun.reflect.GeneratedConstructorAccessor68.newInstance(Unknown Source)
   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
   at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
   at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
   at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:302)
   at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:282)
   at org.apache.commons.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:37)
   at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:290)
   at org.apache.commons.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:877)
   at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:851)
   … 51 more
Caused by: java.net.ConnectException: Connection refused
   at java.net.PlainSocketImpl.socketConnect(Native Method)
   at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
   at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
   at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
   at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
   at java.net.Socket.connect(Socket.java:519)
   at java.net.Socket.connect(Socket.java:469)
   at java.net.Socket.<init>(Socket.java:366)
   at java.net.Socket.<init>(Socket.java:209)
   at com.mysql.jdbc.StandardSocketFactory.connect(StandardSocketFactory.java:253)
   at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:280)
   at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2026)
   … 63 more

If I run nano /opt/alfresco/alfresco.lo, I still see "… 63 more".

Please help. Thanks, for your help, and for taking time to go trough these huge logs.
AC

gronfelt
Champ in-the-making
Champ in-the-making
The shutdown port is, as the name implies, used to shut down Tomcat, by sending the shutdown string to that port. That port is normally nothing that you need to worry about.

Your log files indicate that there´s an issue with your database connection, you should veryify that the database settings in custom-repository.properties and custom-hibernate-dialect.properties are correct and that your database server is up and running and has an alfresco database and user.