Hyland Community
Help
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 

3.2 New Install and GC overhead limit exceeded

sergisat
Champ in-the-making
Champ in-the-making

‎07-08-2009 03:27 AM

Hello, my new dev server is Ubuntu Server 9.04 64 bits in a virtual machine:

4vcpus
16GB RAM
java version "1.6.0_13"
Java(TM) SE Runtime Environment (build 1.6.0_13-b03)
Java HotSpot(TM) 64-Bit Server VM (build 11.3-b02, mixed mode)
Mysql in another server

New installation of Alfresco-Community-3.2-Linux-x86-Install, I try to copy files from 5 pc's over CIFS and after 15 minutes I get this errors:


INFO: Server startup in 268752 ms
09:04:35,454  ERROR [hibernate.transaction.JDBCTransaction] JDBC rollback failed
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Connection.close() has already been called. Invalid operation in this state.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        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.Util.getInstance(Util.java:381)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
        at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3032)
        at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4606)
        at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:328)
        at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.rollback(PoolingDataSource.java:312)
        at org.hibernate.transaction.JDBCTransaction.rollbackAndResetAutoCommit(JDBCTransaction.java:183)
        at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:162)
        at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:597)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.doRollbackOnCommitException(AbstractPlatformTransactionManager.java:803)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:697)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:632)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:314)
        at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:467)
        at org.alfresco.filesys.alfresco.AlfrescoDiskDriver.endTransaction(AlfrescoDiskDriver.java:227)
        at org.alfresco.jlan.server.SrvSession.endTransaction(SrvSession.java:523)
        at org.alfresco.jlan.smb.server.SMBSrvSession.sendResponseSMB(SMBSrvSession.java:1574)
        at org.alfresco.jlan.smb.server.NTProtocolHandler.procNTCreateAndX(NTProtocolHandler.java:5820)
        at org.alfresco.jlan.smb.server.NTProtocolHandler.runProtocol(NTProtocolHandler.java:306)
        at org.alfresco.jlan.smb.server.SMBSrvSession.runHandler(SMBSrvSession.java:1354)
        at org.alfresco.jlan.smb.server.SMBSrvSession.processPacket(SMBSrvSession.java:1446)
        at org.alfresco.jlan.smb.server.nio.NIOCIFSThreadRequest.runRequest(NIOCIFSThreadRequest.java:106)
        at org.alfresco.jlan.server.thread.ThreadRequestPool$ThreadWorker.run(ThreadRequestPool.java:141)
        at java.lang.Thread.run(Thread.java:619)
09:04:42,710  WARN  [jdbc.support.SQLErrorCodesFactory] Error while extracting database product name - falling back to empty error codes
org.springframework.jdbc.support.MetaDataAccessException: Error while extracting DatabaseMetaData; nested exception is java.sql.SQLException: Connection com.mysql.jdbc.JDBC4Connection@44f7bb41 is closed.
Caused by: java.sql.SQLException: Connection com.mysql.jdbc.JDBC4Connection@44f7bb41 is closed.
        at org.apache.commons.dbcp.DelegatingConnection.checkOpen(DelegatingConnection.java:354)
        at org.apache.commons.dbcp.DelegatingConnection.getMetaData(DelegatingConnection.java:310)
        at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.getMetaData(PoolingDataSource.java:234)
        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.hibernate.jdbc.BorrowedConnectionProxy.invoke(BorrowedConnectionProxy.java:50)
        at $Proxy5.getMetaData(Unknown Source)
        at org.springframework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:189)
        at org.springframework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:224)
        at org.springframework.jdbc.support.SQLErrorCodesFactory.getErrorCodes(SQLErrorCodesFactory.java:215)
        at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.setDataSource(SQLErrorCodeSQLExceptionTranslator.java:133)
        at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.<init>(SQLErrorCodeSQLExceptionTranslator.java:98)
        at org.springframework.orm.hibernate3.HibernateTransactionManager.getDefaultJdbcExceptionTranslator(HibernateTransactionManager.java:741)
        at org.springframework.orm.hibernate3.HibernateTransactionManager.convertHibernateAccessException(HibernateTransactionManager.java:715)
        at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:604)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.doRollbackOnCommitException(AbstractPlatformTransactionManager.java:803)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:697)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:632)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:314)
        at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:467)
        at org.alfresco.filesys.alfresco.AlfrescoDiskDriver.endTransaction(AlfrescoDiskDriver.java:227)
        at org.alfresco.jlan.server.SrvSession.endTransaction(SrvSession.java:523)
        at org.alfresco.jlan.smb.server.SMBSrvSession.sendResponseSMB(SMBSrvSession.java:1574)
        at org.alfresco.jlan.smb.server.NTProtocolHandler.procNTCreateAndX(NTProtocolHandler.java:5820)
        at org.alfresco.jlan.smb.server.NTProtocolHandler.runProtocol(NTProtocolHandler.java:306)
        at org.alfresco.jlan.smb.server.SMBSrvSession.runHandler(SMBSrvSession.java:1354)
        at org.alfresco.jlan.smb.server.SMBSrvSession.processPacket(SMBSrvSession.java:1446)
        at org.alfresco.jlan.smb.server.nio.NIOCIFSThreadRequest.runRequest(NIOCIFSThreadRequest.java:106)
        at org.alfresco.jlan.server.thread.ThreadRequestPool$ThreadWorker.run(ThreadRequestPool.java:141)
        at java.lang.Thread.run(Thread.java:619)
09:04:42,711  ERROR [orm.hibernate3.HibernateTransactionManager] Commit exception overridden by rollback exception
java.lang.OutOfMemoryError: GC overhead limit exceeded
09:04:56,753  ERROR [repo.transaction.AlfrescoTransactionSupport] After completion (rolled-back) TransactionalCache exception
org.alfresco.error.AlfrescoRuntimeException: 06080174 Failed to add txn caches to manager
        at org.alfresco.repo.cache.TransactionalCache.getTransactionData(TransactionalCache.java:221)
        at org.alfresco.repo.cache.TransactionalCache.afterRollback(TransactionalCache.java:643)
        at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.afterCompletion(AlfrescoTransactionSupport.java:824)
        at org.springframework.transaction.support.TransactionSynchronizationUtils.invokeAfterCompletion(TransactionSynchronizationUtils.java:133)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.invokeAfterCompletion(AbstractPlatformTransactionManager.java:904)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerAfterCompletion(AbstractPlatformTransactionManager.java:879)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:782)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:730)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:332)
        at org.alfresco.util.transaction.SpringAwareUserTransaction.completeTransactionAfterThrowing(SpringAwareUserTransaction.java:562)
        at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:532)
        at org.alfresco.filesys.alfresco.AlfrescoDiskDriver.endTransaction(AlfrescoDiskDriver.java:216)
        at org.alfresco.jlan.server.SrvSession.endTransaction(SrvSession.java:523)
        at org.alfresco.jlan.smb.server.SMBSrvSession.processPacket(SMBSrvSession.java:1514)
        at org.alfresco.jlan.smb.server.nio.NIOCIFSThreadRequest.runRequest(NIOCIFSThreadRequest.java:106)
        at org.alfresco.jlan.server.thread.ThreadRequestPool$ThreadWorker.run(ThreadRequestPool.java:141)
        at java.lang.Thread.run(Thread.java:619)
Caused by: net.sf.ehcache.ObjectExistsException: Cache org.alfresco.storeAndNodeIdTransactionalCache_bd188298-f852-4ed9-973e-f19254ae888e_updates already exists
        at net.sf.ehcache.CacheManager.addCacheNoCheck(CacheManager.java:689)
        at net.sf.ehcache.CacheManager.addCache(CacheManager.java:683)
        at net.sf.ehcache.CacheManager.addCache(CacheManager.java:640)
        at org.alfresco.repo.cache.TransactionalCache.getTransactionData(TransactionalCache.java:216)
        … 16 more
Exception in thread "DefaultScheduler_QuartzSchedulerThread" java.lang.OutOfMemoryError: GC overhead limit exceeded
Exception in thread "NetBIOS Name Server" java.lang.OutOfMemoryError: GC overhead limit exceeded
Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError: GC overhead limit exceeded
Exception in thread "FileStateReaper" java.lang.OutOfMemoryError: GC overhead limit exceeded
09:21:14,767  ERROR [transaction.SpringAwareUserTransaction.trace] Detected first UserTransaction which is being garbage collected without a commit() or rollback()
09:21:14,767  ERROR [transaction.SpringAwareUserTransaction.trace] Logging of transaction call stack is now enabled and will affect performance
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

My alfresco.sh is:

#!/bin/sh
# Start or stop Alfresco server
# Set the following to where Tomcat is installed
ALF_HOME=/opt/Alfresco
cd "$ALF_HOME"
APPSERVER="${ALF_HOME}/tomcat"
export JAVA_HOME="/usr"
# Set any default JVM values
#export JAVA_OPTS='-Xms128m -Xmx512m -XX:MaxPermSize=128m -server'
export JAVA_OPTS='-Xms512m -Xmx1024m -XX:MaxPermSize=1024m -server'
export JAVA_OPTS="${JAVA_OPTS} -Dalfresco.home=${ALF_HOME} -Dcom.sun.management.jmxremote"
# Following only needed for Sun JVMs before to 1.5 update 8
#export JAVA_OPTS="${JAVA_OPTS} -XX:CompileCommand=exclude,org/apache/lucene/index/IndexReader\$1,doBody -XX:CompileCommand=exclude,org/
alfresco/repo/search/impl/lucene/index/IndexInfo\$Merger,mergeIndexes -XX:CompileCommand=exclude,org/alfresco/repo/search/impl/lucene/in
dex/IndexInfo\$Merger,mergeDeletions"
#
if [ "$1" = "start" ]; then
  "${APPSERVER}/bin/startup.sh"
#  if [ -r ./virtual_start.sh ]; then
#    sh ./virtual_start.sh
#  fi
#  if [ -r "$ALF_HOME"/start_oo.sh ]; then
#    sh "$ALF_HOME"/start_oo.sh
#  fi
elif [ "$1" = "stop" ]; then
  "${APPSERVER}/bin/shutdown.sh"
#  if [ -r ./virtual_start.sh ]; then
#    sh ./virtual_stop.sh
#  fi
#  if [ -r "$ALF_HOME"/start_oo.sh ]; then
#    killall soffice.bin
#  fi
fi
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

My /opt/Alfresco/tomcat/shared/classes/alfresco-global.properties

###############################
## Common Alfresco Properties #
###############################

#
# Sample custom content and index data location
#————-
#dir.root=/opt/Alfresco/alf_data
dir.root=/mnt/alfresco

#
# Sample database connection properties
#————-
db.name=alfrescopru32
db.username=alfrescopru32
db.password=password
db.host=server_name_mysql
db.port=3306

#
# External locations
#————-
#ooo.exe=/opt/Alfresco/program/soffice
#img.root=/usr/local
#swf.exe=/opt/Alfresco/bin/pdf2swf

#Modificaciones para ImageMagick
img.root=/usr

#Modificacion para pdf2swf (swftools)
swf.exe=/usr/bin/pdf2swf

#
# MySQL connection
#————-
db.driver=org.gjt.mm.mysql.Driver
#db.url=jdbc:mysql://${db.host}:${db.port}/${db.name}
db.url=jdbc:mysql://server_name_mysql:3306/alfrescopru32
hibernate.dialect=org.hibernate.dialect.MySQLInnoDBDialect
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍
Labels:
0 Kudos
32 REPLIES 32

zaizi
Champ in-the-making
Champ in-the-making

‎07-08-2009 06:01 AM

It should be

export JAVA_OPTS='-Xms512m -Xmx1024m -XX:MaxPermSize=128m -server'‍
0 Kudos

dc41
Champ in-the-making
Champ in-the-making

‎07-08-2009 10:23 AM

I too am having this problem on an Ubuntu 9.04 box as documented here. I tried the JAVA_OPTS settings above, but I still get the reindexer errors followed by the GC overhead limit error after 40% complete.

I wonder if there's a library in Ubuntu 9.04 that needs to be updated?
0 Kudos

dc41
Champ in-the-making
Champ in-the-making

‎07-08-2009 01:06 PM

After googling GC Overhead Limit exceeded, I saw that many postings were related to VirtualBox. I have VirtualBox installed, but Alfresco is running on the real machine… not a virtual one. Just for giggles, I started up a VM and then tried to start Alfresco 3.2. It to 50% reindexing and then kind of stalled with little or no processor usage. I stopped and closed VM. Alfresco's Java instance immediately sped up, used more memory, and then the errors started again.

I'm too ignorant to know what that all means, but I think it points to a memory usage/garbage collection problem, right? Any advice would be appreciated. I really need to get this server back up.

Thanks!
0 Kudos

mrogers
Star Contributor
Star Contributor

‎07-08-2009 03:06 PM

Have you set your memory settings as Zazi suggests above?
0 Kudos

dc41
Champ in-the-making
Champ in-the-making

‎07-08-2009 03:22 PM

Have you set your memory settings as Zazi suggests above?

Yes… it runs to 40% complete, and then starts throwing the error.

I found an IRC log from a Java chat room from last January. Someone was having this same problem with this own program using a 64bit version of JVM. He took out a piece that is sending data to a DB via a JDBC (layer 3) batch insert statement and said his heap profile looks much more normal. I've emailed him asking if he found the cause/solution.
0 Kudos

dc41
Champ in-the-making
Champ in-the-making

‎07-09-2009 12:19 AM

I found an IRC log from a Java chat room from last January. Someone was having this same problem with this own program using a 64bit version of JVM. He took out a piece that is sending data to a DB via a JDBC (layer 3) batch insert statement and said his heap profile looks much more normal. I've emailed him asking if he found the cause/solution.

Here's the programmer's response:

That error means that the JVM keeps running garbage collection, and each
time, it gets some memory back, but never enough to compensate for what
you are consistently trying to allocate.  After a certain number of GCs
where too little memory was gotten back, it will throw that error.
The only real option is to either run a memory profiler on your
application and find some places where you can reduce your memory usage,
or allocate a larger initial heap size for the JVM.  While you can
disable that error, disabling it won't really help the underlying
problem of too much object generation and too little memory available.

I hope that helps someone smarter than me figure this thing out. I've tried allocating a larger initial heap size, but that didn't work. Any chance this is a bug that wasn't discovered in the beta process? Tomorrow I'll double the ram in the machine, but I don't have high hopes.
0 Kudos

sergisat
Champ in-the-making
Champ in-the-making

‎07-09-2009 05:44 AM

After changed JAVA_OPTS:


export JAVA_OPTS='-Xms512m -Xmx1024m -XX:MaxPermSize=128m -server'
export JAVA_OPTS="${JAVA_OPTS} -Dalfresco.home=${ALF_HOME} -Dcom.sun.management.jmxremote"
‍‍‍‍

My MySQL server is vmware ESX 3.5 virtual machine:
8GB RAM
Centos 5.3 2.6.18-128.1.16.el5PAE
MySQL server version 5.1.34-community

This is my /etc/my.cnf:

[client]
port        = 3306
socket      = /var/run/mysqld/mysqld.sock
default-character-set=utf8

[mysql]
character-sets-dir=/usr/share/mysql/charsets
default-character-set=utf8

[mysqld]
init_connect='SET collation_connection = utf8_general_ci'
init_connect='SET NAMES utf8'
default-character-set=utf8
character-set-server = utf8
collation-server = utf8_general_ci
default-storage-engine=innodb

# Number of threads to keep available for use
# Not really important for our situation where we use webobjects applications with persistent connections
# But since it is a dedicated MySQL server, let's decide to keep at least 8 alive
thread_cache_size = 8

# This is buffer allocated by threads for sorting. Improves performance
# of ORDER BY and GROUP BY operations
sort_buffer_size = 16M

innodb_additional_mem_pool_size = 20M

#Eliminate Double Buffering
innodb_flush_method=O_DIRECT

# The size of the cache to hold the SQL statements for the binary log
# during a transaction. If you often use big, multi-statement
# transactions you can increase this value to get more performance. All
# statements from transactions are buffered in the binary log cache and
# are being written to the binary log at once after the COMMIT.  If the
# transaction is larger than this value, temporary file on disk is used
# instead.  This buffer is allocated per connection on first update
# statement in transaction
binlog_cache_size = 1M

# Maximum allowed size for a single HEAP (in memory) table. This option
# is a protection against the accidential creation of a very large HEAP
# table which could otherwise use up all memory resources.
max_heap_table_size = 64M

# This buffer is used for the optimization of full JOINs (JOINs without
# indexes). Such JOINs are very bad for performance in most cases
# anyway, but setting this variable to a large value reduces the
# performance impact. See the "Select_full_join" status variable for a
# count of full JOINs. Allocated per thread if full join is found
join_buffer_size = 8M

# Query cache is used to cache SELECT results and later return them
# without actual executing the same query once again. Having the query
# cache enabled may result in significant speed improvements, if your
# have a lot of identical queries and rarely changing tables. See the
# "Qcache_lowmem_prunes" status variable to check if the current value
# is high enough for your load.
# Note: In case your tables change very often or if your queries are
# textually different every time, the query cache may result in a
# slowdown instead of a performance improvement.
query_cache_size = 64M

# Only cache result sets that are smaller than this limit. This is to
# protect the query cache of a very large result set overwriting all
# other query results.
query_cache_limit = 2M

# Maximum size for internal (in-memory) temporary tables. If a table
# grows larger than this value, it is automatically converted to disk
# based table This limitation is for a single table. There can be many
# of them.
tmp_table_size = 64M

# InnoDB, unlike MyISAM, uses a buffer pool to cache both indexes and
# row data. The bigger you set this the less disk I/O is needed to
# access data in tables. On a dedicated database server you may set this
# parameter up to 80% of the machine physical memory size. Do not set it
# too large, though, because competition of the physical memory may
# cause paging in the operating system.  Note that on 32bit systems you
# might be limited to 2-3.5G of user level memory per process, so do not
# set it too high.
innodb_buffer_pool_size = 2G

# Number of threads allowed inside the InnoDB kernel. The optimal value
# depends highly on the application, hardware as well as the OS
# scheduler properties. A too high value may lead to thread thrashing.
innodb_thread_concurrency = 16

# The size of the buffer InnoDB uses for buffering log data. As soon as
# it is full, InnoDB will have to flush it to disk. As it is flushed
# once per second anyway, it does not make sense to have it very large
# (even with long transactions).
innodb_log_buffer_size = 8M

# Size of each log file in a log group. You should set the combined size
# of log files to about 25%-100% of your buffer pool size to avoid
# unneeded buffer pool flush activity on log file overwrite. However,
# note that a larger logfile size will increase the time needed for the
# recovery process.
innodb_log_file_size = 256M

# How long an InnoDB transaction should wait for a lock to be granted
# before being rolled back. InnoDB automatically detects transaction
# deadlocks in its own lock table and rolls back the transaction. If you
# use the LOCK TABLES command, or other transaction-safe storage engines
# than InnoDB in the same transaction, then a deadlock may arise which
# InnoDB cannot notice. In cases like this the timeout is useful to
# resolve the situation.
innodb_lock_wait_timeout = 120

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

I get very poor performance in Alfresco, if I try to copy files (around 10Gb) with CIFS from 5 pc's this is more and more slowly.

This is my catalina.out now:

09-jul-2009 9:37:21 org.apache.coyote.http11.Http11Protocol init
INFO: Inicializando Coyote HTTP/1.1 en puerto http-8080
09-jul-2009 9:37:22 org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 1010 ms
09-jul-2009 9:37:22 org.apache.catalina.core.StandardService start
INFO: Arrancando servicio Catalina
09-jul-2009 9:37:22 org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
09-jul-2009 9:37:28 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.
09:37:34,957  INFO  [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
09:37:34,972  INFO  [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
09:37:34,973  INFO  [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/Alfresco/tomcat/shared/classes/alfresco-global.properties]
09:37:35,122  INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:37:56,852  INFO  [domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
09:38:02,754  INFO  [domain.schema.SchemaBootstrap] No changes were made to the schema.
09:38:09,183 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [default]
09:38:09,234 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:38:12,236 User:System WARN  [alfresco.util.OpenOfficeConnectionTester] An initial OpenOffice connection could not be established.
09:38:12,238 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [default] complete
09:38:12,532 User:System INFO  [repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /mnt/alfresco
09:38:12,840 User:System INFO  [admin.patch.PatchExecuter] Checking for patches to apply …
09:38:13,302 User:System INFO  [admin.patch.PatchExecuter] No patches were required.
09:38:13,309 User:System INFO  [repo.module.ModuleServiceImpl] Found 0 module(s).
09:38:13,332 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [default]
09:38:13,442 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:38:13,958 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [managed, alfrescoNtlm1]
09:38:14,005 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:38:14,682 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [managed, alfrescoNtlm1] complete
09:38:19,708 User:System ERROR [org.alfresco.fileserver] Failed to get local domain/workgroup name, using default of WORKGROUP
09:38:19,709 User:System ERROR [org.alfresco.fileserver] (This may be due to firewall settings or incorrect <broadcast> setting)
09:38:20,838 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [default] complete
09:38:20,838 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [default]
09:38:20,889 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:38:20,944 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [default] complete
09:38:20,945 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [default]
09:38:20,974 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:38:21,022 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [default] complete
09:38:21,304 User:System INFO  [service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_13-b03; maximum heap size 910,250MB
09:38:21,305 User:System INFO  [service.descriptor.DescriptorService] Alfresco started (Community): Current version 3.2.0 (2039) schema 2019 - Installed version 3.2.0 (2039) schema 2019
09:38:36,999 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'wcm_deployment_receiver' subsystem, ID: [default]
09:38:37,081 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:38:37,210 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'wcm_deployment_receiver' subsystem, ID: [default] complete
09-jul-2009 9:38:38 org.apache.catalina.startup.HostConfig deployWAR
INFO: Despliegue del archivo share.war de la aplicaci�n web
09:38:43,490  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
09-jul-2009 9:38:43 org.apache.catalina.startup.HostConfig deployWAR
INFO: Despliegue del archivo mobile.war de la aplicaci�n web
09:38:44,747  INFO  [alfresco.config.JBossEnabledWebApplicationContext] Refreshing org.alfresco.config.JBossEnabledWebApplicationContext@61d1c8a2: display name [Root WebApplicationContext]; startup date [Thu Jul 09 09:38:44 CEST 2009]; root of context hierarchy
09:38:44,993  INFO  [alfresco.config.JBossEnabledWebApplicationContext] Bean factory for application context [org.alfresco.config.JBossEnabledWebApplicationContext@61d1c8a2]: org.springframework.beans.factory.support.DefaultListableBeanFactory@3e727a27
09:38:46,031  INFO  [web.scripts.DeclarativeRegistry] Registered 24 Web Scripts (+0 failed), 26 URLs
09:38:46,045  INFO  [web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 213.2292ms)
09:38:46,269  INFO  [web.scripts.DeclarativeRegistry] Registered 42 Web Scripts (+0 failed), 44 URLs
09:38:46,282  INFO  [web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 233.42644ms)
09:38:46,316  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
09-jul-2009 9:38:46 org.apache.catalina.startup.HostConfig deployWAR
INFO: Despliegue del archivo studio.war de la aplicaci�n web
09:39:00,190  INFO  [alfresco.util.OpenOfficeConnectionTester] The OpenOffice connection was re-established.
09:41:49,652  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
09-jul-2009 9:41:50 org.apache.coyote.http11.Http11Protocol start
INFO: Arrancando Coyote HTTP/1.1 en puerto http-8080
09-jul-2009 9:41:50 org.apache.catalina.startup.Catalina start
INFO: Server startup in 268116 ms
10:19:33,292  ERROR [content.transform.PoiHssfContentTransformer] org.apache.poi.hssf.record.RecordFormatException: Unhandled Continue Record
10:21:03,036  ERROR [content.transform.PoiHssfContentTransformer] org.apache.poi.hssf.record.RecordFormatException: Unhandled Continue Record
11:23:20,687  WARN  [activities.feed.AbstractFeedGenerator] Still busy …
11:45:05,803  ERROR [transaction.SpringAwareUserTransaction.trace] Detected first UserTransaction which is being garbage collected without a commit() or rollback()
11:45:19,569  ERROR [transaction.SpringAwareUserTransaction.trace] Logging of transaction call stack is now enabled and will affect performance
11:45:19,569  ERROR [activities.feed.AbstractFeedGenerator] Exception during generation of feeds
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 1 ms ago.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        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:2120)
        at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:723)
        at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:46)
        at sun.reflect.GeneratedConstructorAccessor501.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:38)
        at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:294)
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:974)
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:96)
        at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880)
        at sun.reflect.GeneratedMethodAccessor382.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
        at org.alfresco.util.AutoCommitInterceptor.invoke(AutoCommitInterceptor.java:41)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy65.getConnection(Unknown Source)
        at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:113)
        at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy.getConnection(TransactionAwareDataSourceProxy.java:109)
        at com.ibatis.sqlmap.engine.transaction.external.ExternalTransaction.init(ExternalTransaction.java:53)
        at com.ibatis.sqlmap.engine.transaction.external.ExternalTransaction.getConnection(ExternalTransaction.java:90)
        at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeQueryForObject(MappedStatement.java:120)
        at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:518)
        at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:493)
        at com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.queryForObject(SqlMapSessionImpl.java:106)
        at com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.queryForObject(SqlMapSessionImpl.java:110)
        at com.ibatis.sqlmap.engine.impl.SqlMapClientImpl.queryForObject(SqlMapClientImpl.java:86)
        at org.alfresco.repo.domain.activities.ibatis.ActivityPostDAOImpl.getMaxActivitySeq(ActivityPostDAOImpl.java:59)
        at org.alfresco.repo.activities.feed.local.LocalFeedGenerator.generate(LocalFeedGenerator.java:65)
        at org.alfresco.repo.activities.feed.AbstractFeedGenerator.execute(AbstractFeedGenerator.java:143)
        at org.alfresco.repo.activities.feed.FeedGeneratorJob.execute(FeedGeneratorJob.java:56)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 0 ms ago.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        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.MysqlIO.reuseAndReadPacket(MysqlIO.java:3009)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2895)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3438)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:911)
        at com.mysql.jdbc.MysqlIO.secureAuth411(MysqlIO.java:3953)
        at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1276)
        at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2048)
        … 39 more
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2455)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2906)
        … 45 more
11:46:40,677  ERROR [transaction.SpringAwareUserTransaction.trace] UserTransaction being garbage collected without a commit() or rollback(). NOTE: Prior to transaction call stack logging.
11:46:40,677  ERROR [transaction.SpringAwareUserTransaction.trace] UserTransaction being garbage collected without a commit() or rollback(). NOTE: Prior to transaction call stack logging.
11:46:40,678  ERROR [transaction.SpringAwareUserTransaction.trace] UserTransaction being garbage collected without a commit() or rollback(). NOTE: Prior to transaction call stack logging.
Exception in thread "DefaultScheduler_QuartzSchedulerThread" java.lang.OutOfMemoryError: PermGen space
09-jul-2009 11:52:59 org.apache.coyote.http11.Http11Processor process
GRAVE: Error processing request
java.lang.OutOfMemoryError: PermGen space
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍
0 Kudos

sergisat
Champ in-the-making
Champ in-the-making

‎07-09-2009 08:00 AM

After playing wit JAVA_OPTS:


export JAVA_OPTS="-Xmx3G -Xms1G -XX:NewSize=512M -XX:MaxPermSize=1G -XX:PermSize=512m -server -verbose:gc"
export JAVA_OPTS="${JAVA_OPTS} -Dalfresco.home=${ALF_HOME} -Dcom.sun.management.jmxremote"
‍‍‍‍

This is my log now:

INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
09-jul-2009 13:01:46 org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate defin
ition has been ignored.
13:01:55,333  INFO  [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.pr
operties]
13:01:55,350  INFO  [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transa
ction.properties]
13:01:55,351  INFO  [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/Alfresco/tomcat/shared/class
es/alfresco-global.properties]
13:01:55,522  INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfre
sco-shared.properties]
[GC 393216K->13905K(983040K), 0.1131090 secs]
[GC 407121K->34739K(983040K), 0.1756100 secs]
[GC 151609K->44625K(983040K), 0.2083150 secs]
[Full GC 44625K->44266K(983040K), 0.7308310 secs]
[GC 437482K->69490K(1376256K), 0.1311230 secs]
13:02:18,065  INFO  [domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
13:02:19,568  INFO  [domain.schema.SchemaBootstrap] No changes were made to the schema.
13:02:32,828 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [default]
13:02:32,878 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alf
resco/alfresco-shared.properties]
13:02:37,785 User:System WARN  [alfresco.util.OpenOfficeConnectionTester] An initial OpenOffice connection could not be established.
13:02:37,836 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [default] c
omplete
13:02:39,757 User:System INFO  [repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /mnt/alfresco
13:02:40,127 User:System INFO  [admin.patch.PatchExecuter] Checking for patches to apply …
13:02:41,637 User:System INFO  [admin.patch.PatchExecuter] No patches were required.
13:02:41,650 User:System INFO  [repo.module.ModuleServiceImpl] Found 0 module(s).
13:02:41,691 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [default]
13:02:41,852 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alf
resco/alfresco-shared.properties]
13:02:42,560 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [managed,
 alfrescoNtlm1]
13:02:42,616 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alf
resco/alfresco-shared.properties]
13:02:43,386 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [manage
d, alfrescoNtlm1] complete
13:02:48,410 User:System ERROR [org.alfresco.fileserver] Failed to get local domain/workgroup name, using default of WORKGROUP
13:02:48,411 User:System ERROR [org.alfresco.fileserver] (This may be due to firewall settings or incorrect <broadcast> setting)
13:02:48,556 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [default]
complete
13:02:48,556 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [default]
13:02:48,597 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alf
resco/alfresco-shared.properties]
13:02:48,862 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [default] complet
e
13:02:48,863 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [default
]
13:02:48,965 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alf
resco/alfresco-shared.properties]
13:02:48,977 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [defau
lt] complete
13:02:49,073 User:System INFO  [service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_13-b03; maximum heap size 2730,688MB
13:02:49,074 User:System INFO  [service.descriptor.DescriptorService] Alfresco started (Community): Current version 3.2.0 (2039) schema
2019 - Installed version 3.2.0 (2039) schema 2019
[GC 855922K->163912K(1376256K), 1.4500980 secs]
13:03:00,320  INFO  [alfresco.util.OpenOfficeConnectionTester] The OpenOffice connection was re-established.
13:03:17,877 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Starting 'wcm_deployment_receiver' subsystem, ID:
[default]
13:03:17,976 User:System INFO  [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alf
resco/alfresco-shared.properties]
13:03:18,117 User:System INFO  [management.subsystems.ChildApplicationContextFactory] Startup of 'wcm_deployment_receiver' subsystem, ID
: [default] complete
09-jul-2009 13:03:19 org.apache.catalina.startup.HostConfig deployWAR
INFO: Despliegue del archivo share.war de la aplicaci�n web
13:03:25,291  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
09-jul-2009 13:03:25 org.apache.catalina.startup.HostConfig deployWAR
INFO: Despliegue del archivo mobile.war de la aplicaci�n web
13:03:26,658  INFO  [alfresco.config.JBossEnabledWebApplicationContext] Refreshing org.alfresco.config.JBossEnabledWebApplicationContext
@24534011: display name [Root WebApplicationContext]; startup date [Thu Jul 09 13:03:26 CEST 2009]; root of context hierarchy
13:03:26,955  INFO  [alfresco.config.JBossEnabledWebApplicationContext] Bean factory for application context [org.alfresco.config.JBossE
nabledWebApplicationContext@24534011]: org.springframework.beans.factory.support.DefaultListableBeanFactory@1de646e8
13:03:28,288  INFO  [web.scripts.DeclarativeRegistry] Registered 24 Web Scripts (+0 failed), 26 URLs
13:03:28,303  INFO  [web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 227.33084ms)
13:03:28,481  INFO  [web.scripts.DeclarativeRegistry] Registered 42 Web Scripts (+0 failed), 44 URLs
13:03:28,496  INFO  [web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 188.75458ms)
13:03:28,537  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
09-jul-2009 13:03:28 org.apache.catalina.startup.HostConfig deployWAR
INFO: Despliegue del archivo studio.war de la aplicaci�n web
[GC 950344K->194384K(1387520K), 0.3763030 secs]
13:06:32,893  INFO  [web.site.FrameworkHelper] Successfully Initialized Web Framework
09-jul-2009 13:06:33 org.apache.coyote.http11.Http11Protocol start
INFO: Arrancando Coyote HTTP/1.1 en puerto http-8080
09-jul-2009 13:06:33 org.apache.catalina.startup.Catalina start
INFO: Server startup in 292734 ms
[GC 992080K->244966K(1438144K), 0.4093830 secs]
[GC 1042662K->323849K(1320512K), 0.5948080 secs]
[GC 985353K->326065K(1379328K), 1.3267460 secs]
[GC 987569K->317383K(1360064K), 0.2418590 secs]
[GC 990087K->307910K(1375296K), 0.1149750 secs]
[GC 980614K->321617K(1390336K), 0.1373440 secs]
[GC 1014481K->329553K(1392896K), 0.1294060 secs]
[GC 1022417K->327694K(1392320K), 0.0541640 secs]
[GC 1026126K->334148K(1395328K), 0.0859140 secs]
[GC 1032580K->328859K(1393728K), 0.0176540 secs]
[GC 1036251K->334317K(1396480K), 0.0489290 secs]
[GC 1041709K->342545K(1396608K), 0.0861350 secs]
[GC 1067025K->344128K(1400960K), 0.0867880 secs]
[GC 1068608K->346696K(1410304K), 0.0652750 secs]
[GC 1097160K->434762K(1414528K), 0.2676600 secs]
[GC 1185226K->456041K(1408640K), 0.2849630 secs]
[GC 1189353K->493412K(1359616K), 0.3034790 secs]
[GC 1226724K->558882K(1357376K), 0.6589750 secs]
[GC 1223970K->525446K(1288448K), 0.2806230 secs]
[GC 1190534K->537069K(1379200K), 0.2622990 secs]
[GC 1198573K->554021K(1288704K), 0.2802800 secs]
[GC 1215525K->563992K(1379968K), 0.2723700 secs]
[GC 1225304K->505246K(1212160K), 0.1004310 secs]
[GC 1166558K->544612K(1383744K), 0.1355660 secs]
[GC 1215332K->605705K(1374336K), 0.2825350 secs]
[Full GC[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor12]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor11]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor13]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor10]
[Unloading class sun.reflect.GeneratedConstructorAccessor356]
 605705K->498341K(1803648K), 3.0110160 secs]
[GC 1169061K->585728K(1814848K), 0.2165850 secs]
[GC 1270208K->601075K(1810880K), 0.2515580 secs]
[GC 1285555K->624717K(1821760K), 0.2705290 secs]
[GC 1323405K->629993K(1822080K), 0.2584110 secs]
[GC 1328681K->603746K(1825920K), 0.1741130 secs]
[GC 1315938K->626485K(1827712K), 0.1725570 secs]
[GC 1338677K->703285K(1827200K), 0.3835100 secs]
[GC 1421237K->714551K(1788352K), 0.3839530 secs]
[GC 1432503K->712702K(1834368K), 0.3151740 secs]
[GC 1423486K->729214K(1757696K), 0.3584900 secs]
[GC 1439998K->755472K(1827392K), 0.4240560 secs]
[GC 1466192K->734464K(1827456K), 0.2226950 secs]
[GC 1445184K->708956K(1832000K), 0.1222240 secs]
[GC 1428335K->731863K(1833984K), 0.1212050 secs]
[GC 1452247K->839198K(1821952K), 0.3526580 secs]
[GC 1548702K->870153K(1806784K), 0.3746750 secs]
[GC 1579657K->834212K(1827520K), 0.2695560 secs]
[GC 1524196K->845153K(1729856K), 0.2442580 secs]
[GC 1535137K->899803K(1806272K), 0.3292290 secs]
[GC 1586459K->893790K(1809600K), 0.2391630 secs]
[GC 1580446K->985934K(1814784K), 0.4122360 secs]
[GC 1685582K->975053K(1827712K), 0.3230220 secs]
[GC 1674701K->993335K(1815616K), 0.2816930 secs]
[GC 1696247K->1000403K(1823296K), 0.2754810 secs]
[GC 1703315K->979562K(1834048K), 0.1957000 secs]
[Full GC 979562K->647822K(2068864K), 2.9899080 secs]
[GC 1368526K->685401K(2070528K), 0.1043720 secs]
[GC 1406105K->683752K(2066304K), 0.0955630 secs]
[GC 1397736K->757544K(1987712K), 0.2613230 secs]
[GC 1471528K->788197K(2067072K), 0.3241930 secs]
[GC 1506533K->819670K(2066112K), 0.3647730 secs]
[GC 1538006K->838388K(2066048K), 0.4006320 secs]
[GC 1551220K->784503K(1941056K), 0.1550610 secs]
[GC 1497335K->813928K(2072320K), 0.2793720 secs]
[GC 1529320K->819189K(1954752K), 0.2892520 secs]
[GC 1534581K->821374K(2068928K), 0.2832930 secs]
[GC 1540222K->818462K(2065472K), 0.2442470 secs]
[GC 1537310K->824086K(2074752K), 0.2419800 secs]
[GC 1556822K->820227K(2072192K), 0.2291810 secs]
[GC 1552963K->831186K(2080960K), 0.2756400 secs]
[GC 1580114K->838421K(2080192K), 0.3095950 secs]
[GC 1587349K->823793K(2090240K), 0.2105460 secs]
[GC 1588593K->801108K(2087552K), 0.0828130 secs]
[GC 1565908K->802254K(2100992K), 0.0767710 secs]
[GC 1578958K->803553K(1975296K), 0.0696100 secs]
[GC 1580257K->805359K(2102144K), 0.0709330 secs]
[GC 1584367K->807234K(1978432K), 0.0658320 secs]
[GC 1586242K->807916K(2102592K), 0.0570780 secs]
[GC 1592812K->808394K(2099072K), 0.0512830 secs]
[GC 1593290K->834869K(2101696K), 0.2755000 secs]
[GC 1635893K->892213K(2102720K), 0.4256310 secs]
[GC 1693237K->927949K(2117312K), 0.3913560 secs]
[GC 1743053K->897293K(2117056K), 0.0659890 secs]
[GC 1712397K->921286K(2112384K), 0.1697650 secs]
[GC 1745414K->941743K(2116480K), 0.2716900 secs]
[GC 1765871K->934930K(2121536K), 0.2258750 secs]
[GC 1777042K->910429K(2128000K), 0.1061480 secs]
[GC 1752541K->911311K(2133824K), 0.0676160 secs]
[GC 1766671K->912676K(2137536K), 0.0640000 secs]
[GC 1768036K->916139K(2135808K), 0.0705670 secs]
[GC 1779499K->915055K(2140224K), 0.0600700 secs]
[GC 1778415K->917846K(2140608K), 0.0684050 secs]
[GC 1792150K->918266K(2145472K), 0.0978070 secs]
[GC 1792570K->989977K(2125504K), 0.3498940 secs]
[GC 1847449K->930880K(2141440K), 0.1194870 secs]
[GC 1788352K->999237K(2120384K), 0.4079450 secs]
[GC 1840299K->1021051K(2133248K), 0.4261430 secs]
[GC 1862139K->1060956K(2131840K), 0.4103070 secs]
[GC 1906780K->1058553K(2091072K), 0.3387540 secs]
[GC 1904377K->1054950K(2136320K), 0.2354270 secs]
[GC 1900390K->1066827K(2134528K), 0.2893270 secs]
[GC 1912267K->1072339K(2133696K), 0.2850640 secs]
[GC 1916115K->1093579K(2111040K), 0.3092630 secs]
[GC 1937355K->1085611K(2129152K), 0.2919360 secs]
[GC 1916715K->1056221K(2039744K), 0.1260490 secs]
[GC 1887325K->1056994K(2127104K), 0.1056900 secs]
[GC 1889058K->1056174K(2126144K), 0.0658850 secs]
[GC 1888238K->1065156K(2127744K), 0.0870860 secs]
[GC 1903364K->1068454K(2128576K), 0.1082360 secs]
[GC 1906662K->1068688K(2131840K), 0.0781160 secs]
[GC 1916368K->1080000K(2132352K), 0.1095190 secs]
[GC 1927680K->1149620K(2118336K), 0.3809850 secs]
[GC 1987764K->1163691K(2131776K), 0.4379860 secs]
[GC 2001835K->1167359K(2120640K), 0.2443450 secs]
[Full GC 1167359K->419568K(1927424K), 3.5918950 secs]
[GC 1262576K->483730K(1935424K), 0.2845340 secs]
[GC 1326738K->436169K(1944064K), 0.0807310 secs]
[GC 1283081K->446657K(1862592K), 0.1412170 secs]
[GC 1293569K->479357K(1938624K), 0.2694120 secs]
[GC 1327357K->511435K(1937664K), 0.3404740 secs]
[GC 1359435K->492293K(1943232K), 0.1992200 secs]
[GC 1346117K->491728K(1943360K), 0.1573310 secs]
[GC 1345552K->490219K(1947072K), 0.1184190 secs]
[GC 1352619K->500689K(1945728K), 0.1197160 secs]
[GC 1363089K->500132K(1952576K), 0.1079700 secs]
[GC 1373156K->563221K(1950528K), 0.3588060 secs]
[GC 1436245K->586637K(1930688K), 0.3741700 secs]
[GC 1429005K->604988K(1921664K), 0.3150330 secs]
[GC 1447356K->644098K(1901248K), 0.3548650 secs]
[GC 1437186K->657701K(1882176K), 0.3190170 secs]
[GC 1450789K->622617K(1911616K), 0.1679560 secs]
[GC 1402969K->622902K(1800128K), 0.0939090 secs]
[GC 1403254K->627107K(1905536K), 0.0984790 secs]
[GC 1408547K->634516K(1904448K), 0.0902920 secs]
[GC 1415956K->644194K(1911104K), 0.1233150 secs]
[GC 1439778K->654646K(1911680K), 0.1551780 secs]
[GC 1450230K->659946K(1918592K), 0.1521310 secs]
[GC 1471338K->669687K(1918720K), 0.1233420 secs]
[GC 1481079K->671686K(1927040K), 0.1020620 secs]
[GC 1500742K->674508K(1926336K), 0.0946380 secs]
[GC 1503564K->684397K(1936192K), 0.1248050 secs]
[GC 1533229K->732229K(1936384K), 0.2809940 secs]
[GC 1581061K->756890K(1930048K), 0.3319850 secs]
[GC 1592218K->789149K(1918656K), 0.3401220 secs]
[GC 1624477K->767008K(1932544K), 0.1925820 secs]
[GC 1586016K->762298K(1839616K), 0.1497510 secs]
[GC 1581306K->773769K(1926144K), 0.1219390 secs]
[GC 1597257K->771147K(1921664K), 0.0804520 secs]
[GC 1594635K->789280K(1935744K), 0.1136410 secs]
[GC 1632480K->796372K(1933760K), 0.1247110 secs]
[GC 1639572K->807142K(1944000K), 0.1502890 secs]
[GC 1667430K->810980K(1941824K), 0.1255580 secs]
[GC 1671268K->817348K(1954688K), 0.1189210 secs]
[GC 1693828K->832077K(1952384K), 0.1426600 secs]
[GC 1708557K->876242K(1950208K), 0.3168480 secs]
[GC 1754450K->904424K(1945792K), 0.4054150 secs]
[GC 1782632K->939913K(1911616K), 0.4439440 secs]
[GC 1764105K->904173K(1931584K), 0.2005310 secs]
[GC 1728365K->903542K(1920192K), 0.1356020 secs]
[GC 1732982K->908060K(1928512K), 0.1164030 secs]
[GC 1737500K->914467K(1931200K), 0.1196150 secs]
[GC 1758115K->921755K(1936960K), 0.1096320 secs]
[GC 1765403K->932012K(1935680K), 0.1346790 secs]
[GC 1787436K->934241K(1942016K), 0.0910670 secs]
[GC 1789665K->947450K(1942144K), 0.1105950 secs]
[GC 1815674K->975582K(1948480K), 0.2343280 secs]
[GC 1843806K->1040598K(1912768K), 0.4490440 secs]
[GC 1873622K->1079591K(1973440K), 0.5100910 secs]
[Full GC 1079591K->792668K(2347136K), 4.1800440 secs]
[GC 1625692K->877432K(2333824K), 0.3540810 secs]
[GC 1702264K->891421K(2343040K), 0.4812230 secs]
[GC 1716253K->946415K(2334208K), 0.3407210 secs]
[GC 1765743K->979621K(2313088K), 0.3406610 secs]
[GC 1798949K->964782K(2337856K), 0.2858160 secs]
[GC 1774190K->944323K(2332800K), 0.1067630 secs]
[GC 1753731K->957404K(2335424K), 0.1262780 secs]
[GC 1769180K->952834K(2333056K), 0.1069520 secs]
[GC 1764610K->955026K(2338240K), 0.0761740 secs]
[GC 1773074K->1013604K(2336512K), 0.2704600 secs]
[GC 1831652K->1037515K(2336000K), 0.3635650 secs]
[GC 1852235K->1049198K(2285376K), 0.3816110 secs]
[GC 1863918K->1067620K(2336064K), 0.3965820 secs]
[GC 1880292K->1085252K(2287616K), 0.3942470 secs]
[GC 1897924K->1053348K(2338304K), 0.1647480 secs]
[GC 1866852K->1062814K(2244032K), 0.1688220 secs]
[GC 1876318K->1069785K(2336832K), 0.1670470 secs]
[GC 1886617K->1073979K(2333504K), 0.1245220 secs]
[GC 1890811K->1093755K(2338880K), 0.1897640 secs]
[GC 1924027K->1093146K(2337920K), 0.1672880 secs]
[GC 1923418K->1100234K(2350400K), 0.1887160 secs]
[GC 1948426K->1116898K(2349760K), 0.1396230 secs]
[GC 1965090K->1163372K(2352704K), 0.3427250 secs]
[GC 2019948K->1199633K(2353600K), 0.4297440 secs]
[GC 2056208K->1219200K(2343936K), 0.4423340 secs]
[GC 2058880K->1239816K(2322752K), 0.4955300 secs]
[GC 2079496K->1264276K(2334656K), 0.4801770 secs]
[GC 2076316K->1249329K(2339712K), 0.2386710 secs]
[GC 2067505K->1237662K(2337664K), 0.1447770 secs]
[GC 2060510K->1280758K(2338880K), 0.2854510 secs]
[GC 2103607K->1320260K(2341440K), 0.4366300 secs]
[GC 2148740K->1336608K(2343360K), 0.4667010 secs]
[GC 2165088K->1344630K(2341824K), 0.1622430 secs]
[GC 2179382K->1357398K(2343424K), 0.2173520 secs]
[GC 2192150K->1358098K(2350656K), 0.1452390 secs]
[GC 2204498K->1359503K(2351168K), 0.1032280 secs]
[GC 2205903K->1414318K(2353920K), 0.2701100 secs]
[GC 2264494K->1461020K(2340672K), 0.4188380 secs]
[Full GC[Unloading class sun.reflect.GeneratedMethodAccessor91]
[Unloading class sun.reflect.GeneratedConstructorAccessor64]
[Unloading class sun.reflect.GeneratedMethodAccessor242]
[Unloading class sun.reflect.GeneratedConstructorAccessor108]
[Unloading class sun.reflect.GeneratedConstructorAccessor58]
[Unloading class sun.reflect.GeneratedMethodAccessor98]
[Unloading class sun.reflect.GeneratedMethodAccessor173]
[Unloading class sun.reflect.GeneratedMethodAccessor55]
[Unloading class sun.reflect.GeneratedConstructorAccessor100]
[Unloading class sun.reflect.GeneratedMethodAccessor75]
[Unloading class sun.reflect.GeneratedMethodAccessor49]
[Unloading class sun.reflect.GeneratedMethodAccessor50]
[Unloading class sun.reflect.GeneratedMethodAccessor60]
[Unloading class sun.reflect.GeneratedMethodAccessor56]
[Unloading class sun.reflect.GeneratedConstructorAccessor89]
[Unloading class sun.reflect.GeneratedConstructorAccessor67]
[Unloading class sun.reflect.GeneratedMethodAccessor122]
[Unloading class sun.reflect.GeneratedConstructorAccessor66]
[Unloading class sun.reflect.GeneratedConstructorAccessor112]
[Unloading class sun.reflect.GeneratedConstructorAccessor79]
[Unloading class sun.reflect.GeneratedConstructorAccessor80]
[Unloading class sun.reflect.GeneratedMethodAccessor119]
[Unloading class sun.reflect.GeneratedConstructorAccessor77]
[Unloading class sun.reflect.GeneratedConstructorAccessor119]
[Unloading class sun.reflect.GeneratedConstructorAccessor88]
[Unloading class sun.reflect.GeneratedMethodAccessor77]
[Unloading class sun.reflect.GeneratedConstructorAccessor63]
[Unloading class sun.reflect.GeneratedConstructorAccessor73]
[Unloading class sun.reflect.GeneratedConstructorAccessor102]
[Unloading class sun.reflect.GeneratedMethodAccessor48]
[Unloading class sun.reflect.GeneratedMethodAccessor84]
[Unloading class sun.reflect.GeneratedMethodAccessor96]
[Unloading class sun.reflect.GeneratedMethodAccessor89]
[Unloading class sun.reflect.GeneratedConstructorAccessor68]
[Unloading class sun.reflect.GeneratedConstructorAccessor85]
[Unloading class sun.reflect.GeneratedConstructorAccessor92]
[Unloading class sun.reflect.GeneratedMethodAccessor67]
[Unloading class sun.reflect.GeneratedMethodAccessor123]
[Unloading class sun.reflect.GeneratedConstructorAccessor116]
[Unloading class sun.reflect.GeneratedMethodAccessor46]
[Unloading class sun.reflect.GeneratedConstructorAccessor76]
[Unloading class sun.reflect.GeneratedMethodAccessor88]
[Unloading class sun.reflect.GeneratedConstructorAccessor109]
[Unloading class sun.reflect.GeneratedConstructorAccessor105]
[Unloading class sun.reflect.GeneratedMethodAccessor73]
[Unloading class sun.reflect.GeneratedMethodAccessor72]
[Unloading class sun.reflect.GeneratedMethodAccessor47]
[Unloading class sun.reflect.GeneratedMethodAccessor124]
[Unloading class sun.reflect.GeneratedConstructorAccessor97]
[Unloading class sun.reflect.GeneratedConstructorAccessor104]
[Unloading class sun.reflect.GeneratedConstructorAccessor99]
[Unloading class sun.reflect.GeneratedMethodAccessor95]
[Unloading class sun.reflect.GeneratedConstructorAccessor48]
[Unloading class sun.reflect.GeneratedConstructorAccessor60]
[Unloading class sun.reflect.GeneratedMethodAccessor64]
[Unloading class sun.reflect.GeneratedConstructorAccessor296]
[Unloading class sun.reflect.GeneratedMethodAccessor171]
[Unloading class sun.reflect.GeneratedConstructorAccessor98]
[Unloading class sun.reflect.GeneratedMethodAccessor71]
[Unloading class sun.reflect.GeneratedConstructorAccessor71]
[Unloading class sun.reflect.GeneratedConstructorAccessor107]
[Unloading class sun.reflect.GeneratedConstructorAccessor120]
[Unloading class sun.reflect.GeneratedMethodAccessor127]
[Unloading class sun.reflect.GeneratedMethodAccessor59]
[Unloading class sun.reflect.GeneratedConstructorAccessor118]
[Unloading class sun.reflect.GeneratedConstructorAccessor18]
[Unloading class sun.reflect.GeneratedConstructorAccessor70]
[Unloading class sun.reflect.GeneratedMethodAccessor66]
[Unloading class sun.reflect.GeneratedMethodAccessor121]
[Unloading class sun.reflect.GeneratedMethodAccessor76]
[Unloading class sun.reflect.GeneratedMethodAccessor79]
[Unloading class sun.reflect.GeneratedConstructorAccessor96]
[Unloading class sun.reflect.GeneratedMethodAccessor57]
[Unloading class sun.reflect.GeneratedMethodAccessor69]
[Unloading class sun.reflect.GeneratedMethodAccessor125]
[Unloading class sun.reflect.GeneratedConstructorAccessor62]
[Unloading class sun.reflect.GeneratedMethodAccessor65]
[Unloading class sun.reflect.GeneratedMethodAccessor86]
[Unloading class sun.reflect.GeneratedMethodAccessor54]
[Unloading class sun.reflect.GeneratedConstructorAccessor90]
[Unloading class sun.reflect.GeneratedConstructorAccessor114]
[Unloading class sun.reflect.GeneratedConstructorAccessor94]
[Unloading class sun.reflect.GeneratedMethodAccessor61]
[Unloading class sun.reflect.GeneratedMethodAccessor97]
[Unloading class sun.reflect.GeneratedConstructorAccessor69]
[Unloading class sun.reflect.GeneratedConstructorAccessor95]
[Unloading class sun.reflect.GeneratedMethodAccessor70]
[Unloading class sun.reflect.GeneratedConstructorAccessor101]
[Unloading class sun.reflect.GeneratedMethodAccessor51]
[Unloading class sun.reflect.GeneratedConstructorAccessor78]
[Unloading class sun.reflect.GeneratedMethodAccessor63]
[Unloading class sun.reflect.GeneratedConstructorAccessor72]
[Unloading class sun.reflect.GeneratedConstructorAccessor106]
[Unloading class sun.reflect.GeneratedMethodAccessor172]
[Unloading class sun.reflect.GeneratedConstructorAccessor93]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor3]
[Unloading class sun.reflect.GeneratedConstructorAccessor91]
[Unloading class sun.reflect.GeneratedMethodAccessor85]
[Unloading class sun.reflect.GeneratedConstructorAccessor115]
[Unloading class sun.reflect.GeneratedMethodAccessor92]
[Unloading class sun.reflect.GeneratedMethodAccessor58]
[Unloading class sun.reflect.GeneratedConstructorAccessor117]
[Unloading class sun.reflect.GeneratedMethodAccessor90]
[Unloading class sun.reflect.GeneratedMethodAccessor62]
[Unloading class sun.reflect.GeneratedConstructorAccessor325]
[Unloading class sun.reflect.GeneratedMethodAccessor68]
[Unloading class sun.reflect.GeneratedMethodAccessor241]
[Unloading class sun.reflect.GeneratedMethodAccessor93]
[Unloading class sun.reflect.GeneratedConstructorAccessor61]
[Unloading class sun.reflect.GeneratedConstructorAccessor110]
[Unloading class sun.reflect.GeneratedMethodAccessor94]
[Unloading class sun.reflect.GeneratedMethodAccessor81]
[Unloading class sun.reflect.GeneratedMethodAccessor74]
[Unloading class sun.reflect.GeneratedMethodAccessor78]
[Unloading class sun.reflect.GeneratedMethodAccessor87]
[Unloading class sun.reflect.GeneratedMethodAccessor80]
 1461020K->1031349K(2613312K), 5.2032390 secs]
[GC 1881525K->1114770K(2603776K), 0.3889460 secs]
[GC 1930642K->1126600K(2564736K), 0.4147510 secs]
[GC 1942472K->1135218K(2614720K), 0.3228050 secs]
[GC 1953970K->1118971K(2522560K), 0.1569400 secs]
[GC 1937723K->1135046K(2611456K), 0.1484010 secs]
[GC 1955910K->1141051K(2609344K), 0.1155660 secs]
[GC 1961915K->1178232K(2611328K), 0.2299220 secs]
[GC 2009208K->1169848K(2612928K), 0.1476430 secs]
[GC 2000824K->1182322K(2620608K), 0.1498120 secs]
[GC 2028338K->1201103K(2621696K), 0.1870620 secs]
[GC 2047119K->1255955K(2618944K), 0.3407730 secs]
[GC 2103443K->1295456K(2614144K), 0.4185410 secs]
[GC 2142944K->1335523K(2594240K), 0.4399770 secs]
[GC 2140003K->1365133K(2575808K), 0.4691320 secs]
[GC 2169613K->1410398K(2581376K), 0.3675490 secs]
[GC 2183390K->1449486K(2549760K), 0.3309950 secs]
[GC 2222478K->1456660K(2590656K), 0.2580860 secs]
[GC 2224852K->1483407K(2497088K), 0.3052910 secs]
[GC 2251599K->1466800K(2578496K), 0.1591680 secs]
[GC 2234032K->1467226K(2579456K), 0.1085910 secs]
[GC 2234458K->1488352K(2586944K), 0.1427950 secs]
[GC 2270112K->1501752K(2590464K), 0.1810870 secs]
[GC 2283512K->1516659K(2590656K), 0.1933700 secs]
[GC 2309427K->1533708K(2594176K), 0.1846040 secs]
[GC 2326476K->1543849K(2597248K), 0.2414790 secs]
[GC 2352297K->1544323K(2600576K), 0.1691560 secs]
[GC 2352771K->1578943K(2606656K), 0.3013100 secs]
[GC 2404479K->1591638K(2610560K), 1.0620860 secs]
[GC 2417168K->1582202K(2619840K), 0.1253540 secs]
[GC 2424250K->1581918K(2619264K), 0.0931300 secs]
[GC 2423966K->1593919K(2624960K), 0.0760280 secs]
[GC 2446207K->1615131K(2626752K), 0.1705900 secs]
[GC 2467419K->1626872K(2625728K), 0.1759930 secs]
[GC 2489272K->1634881K(2627392K), 0.1995620 secs]
[GC 2497281K->1671008K(2636032K), 0.3742490 secs]
[GC 2546336K->1706271K(2618752K), 0.3925480 secs]
[GC 2581599K->1726854K(2629632K), 0.3593710 secs]
[Full GC[Unloading class sun.reflect.GeneratedMethodAccessor355]
[Unloading class sun.reflect.GeneratedMethodAccessor366]
[Unloading class sun.reflect.GeneratedConstructorAccessor328]
[Unloading class sun.reflect.GeneratedMethodAccessor368]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor4]
[Unloading class sun.reflect.GeneratedMethodAccessor357]
[Unloading class sun.reflect.GeneratedMethodAccessor300]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor9]
[Unloading class sun.reflect.GeneratedMethodAccessor356]
[Unloading class sun.reflect.GeneratedMethodAccessor381]
[Unloading class sun.reflect.GeneratedMethodAccessor299]
[Unloading class sun.reflect.GeneratedMethodAccessor52]
[Unloading class sun.reflect.GeneratedMethodAccessor301]
[Unloading class sun.reflect.GeneratedMethodAccessor379]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor14]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor2]
[Unloading class sun.reflect.GeneratedMethodAccessor367]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor5]
[Unloading class sun.reflect.GeneratedConstructorAccessor16]
[Unloading class sun.reflect.GeneratedMethodAccessor358]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor15]
[Unloading class sun.reflect.GeneratedConstructorAccessor65]
[Unloading class sun.reflect.GeneratedMethodAccessor380]
[Unloading class sun.reflect.GeneratedConstructorAccessor358]
[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor1]
 1726854K->1380465K(3047360K), 6.0492030 secs]
[GC 2240456K->1422272K(2998592K), 0.2278440 secs]
[GC 2282304K->1438654K(3053696K), 0.2795920 secs]
[GC 2306110K->1434211K(3049920K), 0.1568490 secs]
[GC 2301667K->1438932K(3055168K), 0.1133600 secs]
[GC 2313236K->1467832K(3054144K), 0.2065680 secs]
[GC 2342136K->1442618K(3058880K), 0.0639470 secs]
[GC 2324282K->1447434K(3058496K), 0.2268410 secs]
[GC 2329098K->1533028K(3026624K), 0.4988150 secs]
[GC 2383588K->1562929K(3046272K), 0.4755540 secs]
[GC 2413489K->1554030K(3039232K), 0.1830070 secs]
[GC 2409070K->1606741K(3044992K), 0.3174910 secs]
[GC 2461781K->1617218K(3049472K), 0.3784490 secs]
[GC 2473154K->1643227K(3011712K), 0.3549970 secs]
[GC 2499163K->1669030K(3042944K), 0.4387600 secs]
[GC 2517926K->1697485K(3015744K), 0.4445550 secs]
[GC 2546381K->1717253K(3037056K), 0.4331290 secs]
[GC 2553605K->1735955K(3039168K), 0.4396060 secs]
[GC 2572044K->1756526K(3037952K), 0.4328670 secs]
[GC 2593070K->1788778K(3007680K), 0.4508840 secs]
[GC 2625322K->1814703K(3032512K), 0.4756760 secs]
[GC 2641967K->1842567K(2998336K), 0.4164480 secs]
[GC 2669831K->1851850K(3038144K), 0.3681520 secs]
[GC 2681226K->1859863K(2968448K), 0.3221620 secs]
[GC 2689239K->1876664K(3033024K), 0.3273440 secs]
[GC 2708280K->1925732K(3030784K), 0.4796050 secs]
[GC 2757348K->1963832K(3028416K), 0.6599570 secs]
[GC 2790584K->1996501K(3014208K), 0.6597220 secs]
[GC 2823253K->2031396K(3013696K), 0.6536910 secs]
[GC 2831012K->2055198K(2982336K), 0.5818510 secs]
[GC 2854814K->2088179K(3015232K), 0.6091510 secs]
[GC 2880627K->2076573K(2938432K), 0.4571540 secs]
[GC 2869021K->2126327K(3017344K), 0.4452960 secs]
[GC 2921207K->2182228K(2997952K), 0.5297220 secs]
[Full GC 2182228K->1558341K(2998400K), 7.5474500 secs]
[GC 2353221K->1667014K(2997952K), 0.4257600 secs]
[GC 2434374K->1711774K(2971328K), 0.5518440 secs]
[GC 2479134K->1759010K(2991936K), 0.4515800 secs]
[GC 2508450K->1773667K(2920832K), 0.4816250 secs]
[GC 2523107K->1802367K(3000832K), 0.5563780 secs]
[GC 2561791K->1849466K(2995072K), 0.4927700 secs]
[GC 2608890K->1890505K(3001024K), 0.5006560 secs]
[GC 2655753K->1877723K(3001600K), 0.2941190 secs]
[GC 2642971K->1901309K(3005312K), 0.2871200 secs]
[GC 2668477K->1939309K(2933376K), 0.2527090 secs]
[GC 2706477K->1932529K(3000000K), 0.1878150 secs]
[GC 2699889K->1943329K(2999808K), 0.1726890 secs]
[GC 2710689K->1970452K(3004864K), 0.2219190 secs]
[GC 2748692K->1992630K(3007424K), 0.2427980 secs]
[GC 2770870K->2064093K(3005312K), 0.4378470 secs]
[GC 2843357K->2121572K(2983616K), 0.4974330 secs]
[GC 2900836K->2176813K(2987968K), 0.5188090 secs]
[Full GC 2176813K->1961138K(2987968K), 6.8797910 secs]
[GC 2709682K->2068240K(2952832K), 0.3533950 secs]
[GC 2816784K->2123629K(2984832K), 0.4613500 secs]
[GC 2857325K->2178746K(2941376K), 0.4429720 secs]
[Full GC[Unloading class sun.reflect.GeneratedConstructorAccessor372]
[Unloading class sun.reflect.GeneratedConstructorAccessor314]
[Unloading class sun.reflect.GeneratedConstructorAccessor373]
 2178746K->2066240K(2941376K), 6.4231260 secs]
[Full GC 2799936K->2051858K(2941376K), 6.4785260 secs]
[Full GC 2785554K->1959377K(2941376K), 8.2228150 secs]
[GC 2693073K->2013949K(2987712K), 0.1862710 secs]
[GC 2744189K->2040692K(2908736K), 0.2125790 secs]
[GC 2770932K->2061929K(2977280K), 0.2352990 secs]
[GC 2791465K->2088153K(2977984K), 0.3455110 secs]
[GC 2817689K->2119126K(2946496K), 0.6414340 secs]
[GC 2807382K->2142539K(2965568K), 0.6381180 secs]
[GC 2830795K->2162810K(2902208K), 0.7754990 secs]
[GC 2787706K->2181193K(2892736K), 0.8996820 secs]
[GC 2806089K->2200589K(2887936K), 0.8615990 secs]
[GC 2767117K->2200720K(2853888K), 0.7816180 secs]
[GC 2767248K->2206787K(2867200K), 0.7036090 secs]
[GC 2722755K->2205276K(2807872K), 0.7765220 secs]
[GC 2721244K->2220132K(2847360K), 0.7803870 secs]
[GC 2695396K->2229434K(2791360K), 0.7148750 secs]
[GC 2704698K->2222907K(2833664K), 0.8097960 secs]
[GC 2660667K->2230551K(2754944K), 0.8840330 secs]
[GC 2668311K->2271924K(2792512K), 1.1191620 secs]
[GC 2654644K->2269502K(2733056K), 1.1093090 secs]
[GC 2652222K->2283214K(2792256K), 1.2078760 secs]
[GC 2632782K->2293319K(2656384K), 1.2592270 secs]
[Full GC 2293319K->2208165K(2656384K), 6.5564210 secs]
[Full GC 2446712K->2209370K(2656384K), 6.2004260 secs]
[Full GC 2446712K->2228835K(2656384K), 6.2028480 secs]
[Full GC 2446712K->2116141K(2656384K), 8.1862680 secs]
[Full GC 2446719K->2137520K(2656384K), 6.3699460 secs]
[Full GC 2446719K->2139310K(2656384K), 6.2534580 secs]
[Full GC 2446719K->2142111K(2656384K), 6.2803170 secs]
[Full GC 2446719K->2139516K(2656384K), 8.1434010 secs]
[Full GC 2446719K->2162403K(2656384K), 6.5643480 secs]
[Full GC 2446719K->2170040K(2656384K), 6.3810590 secs]
[Full GC 2446719K->2175809K(2656384K), 6.3440730 secs]
[Full GC 2446719K->2158241K(2656384K), 8.6094460 secs]
[Full GC 2446719K->2175328K(2656384K), 6.3818720 secs]
[Full GC 2446719K->2183827K(2656384K), 7.2058950 secs]
[Full GC 2446719K->2192344K(2656384K), 6.4249000 secs]
[Full GC 2446712K->2180947K(2656384K), 8.8668510 secs]
[Full GC 2446719K->2209402K(2656384K), 6.8512360 secs]
[Full GC 2446719K->2212242K(2656384K), 6.5069630 secs]
[Full GC 2446719K->2208984K(2656384K), 6.4505680 secs]
[Full GC 2446719K->2191914K(2656384K), 8.0026250 secs]
[Full GC 2446719K->2213844K(2656384K), 6.5842280 secs]
[Full GC 2446719K->2221810K(2656384K), 6.4821610 secs]
[Full GC 2446719K->2228134K(2656384K), 6.5481800 secs]
[Full GC 2446719K->2211321K(2656384K), 7.8732270 secs]
[Full GC 2446719K->2239330K(2656384K), 6.8347490 secs]
[Full GC 2446719K->2240009K(2656384K), 6.5203270 secs]
[Full GC 2446719K->2240910K(2656384K), 6.7759940 secs]
[Full GC 2446719K->2228386K(2656384K), 8.1556370 secs]
[Full GC 2446719K->2248860K(2656384K), 6.5532600 secs]
[Full GC 2446719K->2248984K(2656384K), 6.5135120 secs]
[Full GC 2446719K->2248287K(2656384K), 6.5015670 secs]
[Full GC 2446719K->2235232K(2656384K), 8.3445330 secs]
[Full GC 2446719K->2254634K(2656384K), 6.7678240 secs]
[Full GC 2446719K->2258790K(2656384K), 6.5398830 secs]
[Full GC 2446242K->2262364K(2656384K), 6.4846150 secs]
[Full GC 2446719K->2245979K(2656384K), 8.4831160 secs]
[Full GC 2446719K->2272558K(2656384K), 6.5129930 secs]
[Full GC 2446719K->2270893K(2656384K), 6.6019010 secs]
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

I see a lot of FULL GC, what's happening?

Whats is my configuration problem?

Thanks
0 Kudos

dc41
Champ in-the-making
Champ in-the-making

‎07-09-2009 06:56 PM

Okay, I added another 2GB RAM and am experiencing the same problem. At no time did it have to resort to the swap file. I'll keep playing with this, but I'm shooting in the dark. Any suggestions, anyone?
15:10:51,825 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
15:10:51,827 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
15:10:51,827 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/Alfresco/tomcat/shared/classes/alfresco-global.properties]
15:10:52,024 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
15:11:16,488 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
15:11:21,996 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] No changes were made to the schema.
15:11:42,782 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] Index recovery started: 302,394 transactions.
15:13:14,687 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent]    10 % complete.
15:14:20,771 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent]    20 % complete.
15:15:22,138 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent]    30 % complete.
15:17:24,211 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent]    40 % complete.
15:25:31,936 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent]    50 % complete.
15:59:53,970 ERROR [org.alfresco.repo.node.index.AbstractReindexComponent.threads] Reindexer   589 failed with error: 06090000 Exception in Transaction..
16:09:42,459 ERROR [org.alfresco.repo.node.index.AbstractReindexComponent.threads] Reindexer   591 failed with error: 06090001 Exception in Transaction..
16:09:42,459 ERROR [org.hibernate.transaction.JDBCTransaction] JDBC rollback failed
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Connection.close() has already been called. Invalid operation in this state.
   at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
   at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
   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.Util.getInstance(Util.java:381)
   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
   at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3032)
   at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4606)
   at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:328)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.rollback(PoolingDataSource.java:312)
   at org.hibernate.transaction.JDBCTransaction.rollbackAndResetAutoCommit(JDBCTransaction.java:183)
   at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:162)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:597)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:753)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:730)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:332)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.completeTransactionAfterThrowing(SpringAwareUserTransaction.java:562)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:532)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:387)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.run(AbstractReindexComponent.java:780)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
   at java.lang.Thread.run(Thread.java:619)
16:10:07,277 ERROR [org.alfresco.repo.node.index.AbstractReindexComponent.threads] Reindexer   592 failed with error: 06090002 Exception in Transaction..
16:10:23,141 ERROR [org.alfresco.repo.node.index.AbstractReindexComponent.threads] Reindexer   593 failed with error: 06090003 Exception in Transaction..
16:11:28,996 WARN  [org.springframework.jdbc.support.SQLErrorCodesFactory] Error while extracting database product name - falling back to empty error codes
org.springframework.jdbc.support.MetaDataAccessException: Error while extracting DatabaseMetaData; nested exception is java.sql.SQLException: Connection com.mysql.jdbc.JDBC4Connection@5b4a77e8 is closed.
Caused by: java.sql.SQLException: Connection com.mysql.jdbc.JDBC4Connection@5b4a77e8 is closed.
   at org.apache.commons.dbcp.DelegatingConnection.checkOpen(DelegatingConnection.java:354)
   at org.apache.commons.dbcp.DelegatingConnection.getMetaData(DelegatingConnection.java:310)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.getMetaData(PoolingDataSource.java:234)
   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.hibernate.jdbc.BorrowedConnectionProxy.invoke(BorrowedConnectionProxy.java:50)
   at $Proxy5.getMetaData(Unknown Source)
   at org.springframework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:189)
   at org.springframework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:224)
   at org.springframework.jdbc.support.SQLErrorCodesFactory.getErrorCodes(SQLErrorCodesFactory.java:215)
   at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.setDataSource(SQLErrorCodeSQLExceptionTranslator.java:133)
   at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.<init>(SQLErrorCodeSQLExceptionTranslator.java:98)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.getDefaultJdbcExceptionTranslator(HibernateTransactionManager.java:741)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.convertHibernateAccessException(HibernateTransactionManager.java:715)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:604)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:753)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:730)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:332)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.completeTransactionAfterThrowing(SpringAwareUserTransaction.java:562)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:532)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:387)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.run(AbstractReindexComponent.java:780)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
   at java.lang.Thread.run(Thread.java:619)
16:11:57,085 ERROR [org.alfresco.util.transaction.SpringAwareUserTransaction] Application exception overridden by rollback exception
java.lang.Exception
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:532)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:387)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.run(AbstractReindexComponent.java:780)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
   at java.lang.Thread.run(Thread.java:619)
16:11:57,086 ERROR [org.alfresco.repo.transaction.RetryingTransactionHelper] Rollback failure.  Normal retry behaviour will resume.
org.springframework.jdbc.UncategorizedSQLException: Hibernate flushing: Cannot release connection; uncategorized SQLException for SQL [???]; SQL state [null]; error code [0]; Already closed.; nested exception is java.sql.SQLException: Already closed.
Caused by: java.sql.SQLException: Already closed.
   at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:84)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:181)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.closeConnection(LocalDataSourceConnectionProvider.java:95)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:451)
   at org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:406)
   at org.hibernate.jdbc.ConnectionManager.afterTransaction(ConnectionManager.java:293)
   at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:225)
   at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:174)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:597)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:753)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:730)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:332)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.completeTransactionAfterThrowing(SpringAwareUserTransaction.java:562)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:532)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:387)
   at org.alfresco.repo.node.index.AbstractReindexComponent$ReindexWorkerRunnable.run(AbstractReindexComponent.java:780)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
   at java.lang.Thread.run(Thread.java:619)
16:11:57,086 ERROR [org.alfresco.repo.node.index.AbstractReindexComponent.threads] Reindexer   594 failed with error: 06090004 Exception in Transaction..
16:33:19,177 ERROR [org.springframework.orm.hibernate3.HibernateTransactionManager] Commit exception overridden by rollback exception
java.lang.OutOfMemoryError: Java heap space
16:34:11,470 ERROR [org.alfresco.repo.node.index.AbstractReindexComponent.threads] Reindexer   597 failed with error: 06090005 Exception in Transaction..
16:34:18,770 ERROR [org.alfresco.repo.node.index.AbstractReindexComponent.threads] Reindexer   598 failed with error: 06090006 Exception in Transaction..
16:39:26,206 ERROR [org.springframework.web.context.ContextLoader] Context initialization failed
org.alfresco.error.AlfrescoRuntimeException: 06090008 Reindex failure for org.alfresco.repo.node.index.FullIndexRecoveryComponent
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:271)
   at org.alfresco.repo.node.index.IndexRecoveryBootstrapBean.onBootstrap(IndexRecoveryBootstrapBean.java:35)
   at org.alfresco.util.AbstractLifecycleBean.onApplicationEvent(AbstractLifecycleBean.java:62)
   at org.springframework.context.event.SimpleApplicationEventMulticaster$1.run(SimpleApplicationEventMulticaster.java:77)
   at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:49)
   at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:75)
   at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:246)
   at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:617)
   at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:355)
   at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:246)
   at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:189)
   at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:49)
   at org.alfresco.web.app.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:69)
   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.deployDescriptor(HostConfig.java:627)
   at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:553)
   at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:488)
   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.alfresco.error.AlfrescoRuntimeException: 06090007 Exception in Transaction.
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:403)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:252)
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:262)
   … 36 more
Caused by: java.lang.OutOfMemoryError: Java heap space
16:39:31,643 INFO  [org.alfresco.config.JBossEnabledWebApplicationContext] Refreshing org.alfresco.config.JBossEnabledWebApplicationContext@4a2d2ca9: display name [Root WebApplicationContext]; startup date [Thu Jul 09 16:39:31 MDT 2009]; root of context hierarchy
16:39:32,105 INFO  [org.alfresco.config.JBossEnabledWebApplicationContext] Bean factory for application context [org.alfresco.config.JBossEnabledWebApplicationContext@4a2d2ca9]: org.springframework.beans.factory.support.DefaultListableBeanFactory@2a9b33ab
16:39:33,321 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 24 Web Scripts (+0 failed), 26 URLs
16:39:33,388 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised Presentation Web Script Container (in 300.8043ms)
16:39:33,541 INFO  [org.alfresco.web.scripts.DeclarativeRegistry] Registered 42 Web Scripts (+0 failed), 44 URLs
16:39:33,554 INFO  [org.alfresco.web.scripts.AbstractRuntimeContainer] Initialised WebFramework Web Script Container (in 160.9139ms)
16:39:33,588 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
16:42:37,305 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
16:42:41,015 INFO  [org.alfresco.web.site.FrameworkHelper] Successfully Initialized Web Framework
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍
0 Kudos
Getting started

Tags

Find what you came for

We want to make your experience in Hyland Connect as valuable as possible, so we put together some helpful links.

Copyright © 2025 Khoros, LLC