Error Deploying Alfresco to JBoss AS + Portal [SOLVED]

[trupoet]

So I'm trying to install Alfresco on an already installed and working JBoss AS 4.0.3 SP1 + JBoss Portal 2.2 SP3 on Centos 4.

I follow directions and setup the database like so:

mysql < db_setup.sql
mysqladmin flush-tables
mysqladmin flush-privileges

then I drop the war from the community-war-1.3 into the $JBOSS_HOME/server/default/deploy directory (tried it hot or cold) and it starts loading up.

For some reason it hangs after loading SQLErrorCodes. Just to see what happened, I left it like that last night and came back this morning and found that 3 HOURS later it had finally moved on and loaded the rest of the server.

Any ideas? Also shows that it was trying to connect to port 8100 for some reason and failed before this, not sure if thats related.

EDIT: Also, while it hangs here, I see java taking up 99% cpu usage in top.

The last few lines of the jboss_console.out are as follows:

11:17:02,361 INFO  [STDOUT] Aug 25, 2006 11:17:02 AM net.sf.joott.uno.UnoConnection connect
INFO: connecting using "socket,host=localhost,port=8100,tcpNoDelay=1"…
11:17:02,487 INFO  [STDOUT] Aug 25, 2006 11:17:02 AM net.sf.joott.uno.UnoConnection connect
SEVERE: connection failed: com.sun.star.connection.NoConnectException: java.net.ConnectException: Connection refused
11:17:02,608 INFO  [STDOUT] Aug 25, 2006 11:17:02 AM net.sf.joott.uno.UnoConnection connect
INFO: connecting using "socket,host=localhost,port=8100,tcpNoDelay=1"…
11:17:02,611 INFO  [STDOUT] Aug 25, 2006 11:17:02 AM net.sf.joott.uno.UnoConnection connect
SEVERE: connection failed: com.sun.star.connection.NoConnectException: java.net.ConnectException: Connection refused
11:17:02,656 INFO  [DictionaryDAO] Loading model from alfresco/model/jcrModel.xml
11:17:02,668 INFO  [DictionaryDAO] Registered model jcr:jcrmodel
11:17:02,668 INFO  [DictionaryDAO] Registered namespace 'http://www.jcp.org/jcr/1.0' (prefix 'jcr')
11:17:02,668 INFO  [DictionaryDAO] Registered namespace 'http://www.jcp.org/jcr/nt/1.0' (prefix 'nt')
11:17:02,668 INFO  [DictionaryDAO] Registered namespace 'http://www.jcp.org/jcr/mix/1.0' (prefix 'mix')
11:17:02,668 INFO  [DictionaryDAO] Registered namespace 'http://www.jcp.org/jcr/sv/1.0' (prefix 'sv')
11:17:02,668 INFO  [DictionaryDAO] Registered namespace 'http://www.w3.org/XML/1998/namespace' (prefix 'xml')
11:17:03,727 INFO  [XmlBeanDefinitionReader] Loading XML bean definitions from class path resource [org/springframework/jdbc/support/sql-error-codes.xml]
11:17:03,754 INFO  [SQLErrorCodesFactory] SQLErrorCodes loaded: [DB2, HSQL, MS-SQL, MySQL, Oracle, Informix, PostgreSQL, Sybase]

[trupoet]

Adding onto this, I found that the $JBOSS_HOME/server/default/log/server.log contained DEBUG statements and they had really really long lines but here ist he beginning and end of one of them:

2006-08-25 13:44:26,955 DEBUG [org.springframework.transaction.support.TransactionSynchronizationManager] Retrieved value [TransactionSychronizationImpl[ txnId=1156538296366:a2bec579-3479-11db-963a-ab0bf0f3dec3, daos=1, integrity=1, indexers=1, resources={workspace://SpacesStore/4bc07537-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/4bc07537-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/c8ac3e86-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/c8ac3e86-3479-11db-963a-ab0bf0f3dec3, TransactionalCache.TxnData.permissionsAccessTransactionalCache=org.alfresco.repo.cache.TransactionalCache$TransactionData@77521871, workspace://SpacesStore/0573c8bf-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/0573c8bf-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/3e8501b6-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/3e8501b6-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/f457bfad-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/f457bfad-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/bcfb89b3-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/bcfb89b3-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/a3e5b94c-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/a3e5b94c-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/e64944b9-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/e64944b9-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/a593694d-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/a593694d-3479-11db-963a-ab0bf0f3dec3, IntegrityChecker.EventSet={IntegrityEvent[ name=org.alfresco.repo.node.integrity.AssocTargetMultiplicity
….

0f3dec3=workspace://SpacesStore/b26d34d1-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/adb949b0-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/adb949b0-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/0f7a9e22-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/0f7a9e22-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/59dde448-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/59dde448-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/fc6c3aee-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/fc6c3aee-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/3218c515-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/3218c515-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/68873fa9-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/68873fa9-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/263f0474-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/263f0474-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/a7c368ae-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/a7c368ae-3479-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/1a68ed53-347a-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/1a68ed53-347a-11db-963a-ab0bf0f3dec3, workspace://SpacesStore/ed2d564c-3479-11db-963a-ab0bf0f3dec3=workspace://SpacesStore/ed2d564c-3479-11db-963a-ab0bf0f3dec3, TransactionalCache.TxnData.userToAuthorityTransactionalCache=org.alfresco.repo.cache.TransactionalCache$TransactionData@b1ae4cc}]] for key [txnSynch] bound to thread [main]

[trupoet]

Also tried stracing it via:

strace -f -o jboss.st /etc/init.d/jboss start

and it seems to mostly be calling the system call futex

Stuff like the following over and over and the whole time JBoss is just sitting there on the SQLErrorCodes saying it loaded them.


24174 futex(0x40ac3de8, FUTEX_WAKE, 1)  = 0
24174 clock_gettime(CLOCK_REALTIME, {1156538925, 385247000}) = 0
24174 futex(0x2aadf963a4, FUTEX_WAIT, 1, {0, 49973000}) = -1 ETIMEDOUT (Connection timed out)
24174 futex(0x40ac3de8, FUTEX_WAKE, 1)  = 0
24174 clock_gettime(CLOCK_REALTIME, {1156538925, 436251000}) = 0
24174 futex(0x2aadf963a4, FUTEX_WAIT, 1, {0, 49974000}) = -1 ETIMEDOUT (Connection timed out)
24174 futex(0x40ac3de8, FUTEX_WAKE, 1)  = 0
24174 clock_gettime(CLOCK_REALTIME, {1156538925, 487270000}) = 0
24174 futex(0x2aadf963a4, FUTEX_WAIT, 1, {0, 49976000}) = -1 ETIMEDOUT (Connection timed out)
24174 futex(0x40ac3de8, FUTEX_WAKE, 1)  = 0
24174 clock_gettime(CLOCK_REALTIME, {1156538925, 538212000}) = 0
24174 futex(0x2aadf963a4, FUTEX_WAIT, 1, {0, 49975000}) = -1 ETIMEDOUT (Connection timed out)
24174 futex(0x40ac3de8, FUTEX_WAKE, 1)  = 0
24174 clock_gettime(CLOCK_REALTIME, {1156538925, 589204000}) = 0
24174 futex(0x2aadf963a4, FUTEX_WAIT, 1, {0, 49975000}) = -1 ETIMEDOUT (Connection timed out)
24174 futex(0x40ac3de8, FUTEX_WAKE, 1)  = 0
24174 clock_gettime(CLOCK_REALTIME, {1156538925, 640175000}) = 0
24174 futex(0x2aadf963a4, FUTEX_WAIT, 1, {0, 49976000} <unfinished …>
24166 mprotect(0x2a95ee0000, 4096, PROT_READ) = 0


Anyone have any idea what is going on?

[trupoet]

FYI I finally figured out why this was hanging.

It was writing so many debug messages to the server.log that it was taking 3 hours to write them all and continue.

Ended up actually having to change the default log4j root context in the run.jar (for JBoss AS) to be WARN instead of DEBUG.

That seemed to fix it.

[kevinr]

That is a common issue with JBoss, there are >10 other forum posts were we  have helped people change the bizare default logging settings - for our bundles we  have preset the logging to a sensible set of values. I have no idea why JBoss/Spring/Hibernate et al generate so much 'INFO' (haha) level log by default - it's not helpful at all!

The problem was not obvious in your case, looking more like a DB/connection issue, glad to hear you solved it anyway.

Thanks,

Kevin