Alfresco loading very slowly in Tomcat

[stefan776]

Hi,
I am experiencing severe problems in getting Alfreso to run on Tomcat in a CentOS VM. Tomcat will take about 45 mins to load Alfresco, during this time the whole server becomes very unresponsive (command line lag etc) and even once the app is up and running it is almost unusable due to sluggish performance.
Alfresco is not running in a production environment, so it is not under any load due to heavy user traffic.  The Share app is not deployed and Tomcat is not running any other applications besides Alfresco.

I suspect that its a problem with the JVM and looking at the output in the garbage-collection log seems to somewhat confirm this (GC can take up to 8 mins! during startup), however I cannot seem to pinpoint the culprit.
I already tried twiddling the knobs of the JVM by setting various GC optimization flags and increasing/decreasing heap sizes, but all to no avail.

RAM and disk space is ample on this machine, so if anyone has run into similar problems or perhaps give me some pointers to looks elsewhere I would highly appreciate it.

Thanks,
- Stefan

Here is my set up:
Centos 5.5. 64 bit

$ uname -a
Linux bimini 2.6.18-194.17.1.el5 #1 SMP Wed Sep 29 12:50:31 EDT 2010 x86_64 x86_64 x86_64 GNU/Linux
$ cat /etc/issue
CentOS release 5.5 (Final)
Kernel \r on an \m
‍‍‍‍‍‍‍

8 GB of RAM

$  free -m
             total       used       free     shared    buffers     cached
Mem:          7983       7857        126          0         97        612
-/+ buffers/cache:       7147        835
Swap:          767          0        767
‍‍‍‍‍‍‍

On this VM, I'm running
- Apache Tomcat 6.0.29 - binaries from the official project site
- MySQL 5.0.77 - installed via YUM
- Apache webserver 2.2.3 - installed via YUM
- Sun Java SDK 1.6.0_21 - installed from the official RPMs

# java -version
java version "1.6.0_21"
Java(TM) SE Runtime Environment (build 1.6.0_21-b06)
Java HotSpot(TM) 64-Bit Server VM (build 17.0-b16, mixed mode)
‍‍‍‍‍‍

Tomcat startup options

# ps aux | grep tomcat
tomcat   13714  1.7 22.0 4905876 1801088 ?     Sl   Oct21  16:47 /opt/java/bin/java -Djava.util.logging.config.file=/opt/tomcat6/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.library.path=/usr/local/apr/lib -server -Xss1M -Xms2G -Xmx4G -XX:MaxPermSize=256M -XX:NewSize=1G -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xdebug -verbose:gc -Xloggc:/var/log/tomcat6/gc.log -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.password.file=/opt/tomcat6/conf/jmx-password.txt -Dcom.sun.management.jmxremote.access.file=/opt/tomcat6/conf/jmx-access.txt -Dcom.sun.management.jmxremote.ssl=false -Djava.endorsed.dirs=/opt/tomcat6/endorsed -classpath /opt/tomcat6/bin/bootstrap.jar -Dcatalina.base=/opt/tomcat6 -Dcatalina.home=/opt/tomcat6 -Djava.io.tmpdir=/opt/tomcat6/temp org.apache.catalina.startup.Bootstrap start
‍‍‍‍

Tomcat log

Oct 21, 2010 4:41:25 PM org.apache.catalina.core.AprLifecycleListener init
INFO: Loaded APR based Apache Tomcat Native library 1.1.20.
Oct 21, 2010 4:41:25 PM org.apache.catalina.core.AprLifecycleListener init
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Oct 21, 2010 4:41:26 PM org.apache.coyote.http11.Http11AprProtocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
Oct 21, 2010 4:41:26 PM org.apache.coyote.ajp.AjpAprProtocol init
INFO: Initializing Coyote AJP/1.3 on ajp-8009
Oct 21, 2010 4:41:26 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 2507 ms
Oct 21, 2010 4:41:27 PM org.apache.catalina.mbeans.JmxRemoteLifecycleListener createServer
INFO: The JMX Remote Listener has configured the registry on port 9,004 and the server on port 9,005 for the Platform server
Oct 21, 2010 4:41:27 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Oct 21, 2010 4:41:27 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.29
Oct 21, 2010 4:41:27 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor manager.xml
Oct 21, 2010 4:41:28 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor host-manager.xml
Oct 21, 2010 4:41:28 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor alfresco.xml
Oct 21, 2010 4:42:43 PM org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate definition has been ignored.
Oct 21, 2010 5:32:53 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory ROOT
Oct 21, 2010 5:32:56 PM org.apache.coyote.http11.Http11AprProtocol start
INFO: Starting Coyote HTTP/1.1 on http-8080
Oct 21, 2010 5:32:57 PM org.apache.coyote.ajp.AjpAprProtocol start
INFO: Starting Coyote AJP/1.3 on ajp-8009
Oct 21, 2010 5:32:57 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 3090508 ms
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Alfresco log

16:44:35,233 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
16:44:35,340 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
16:44:35,487 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/apache-tomcat-6.0.29/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
16:44:35,488 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/apache-tomcat-6.0.29/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
16:44:35,495 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/apache-tomcat-6.0.29/shared/classes/alfresco-global.properties]
16:44:37,217 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
16:47:56,316 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/apache-tomcat-6.0.29/shared/classes/alfresco/extension/subsystems/Authentication/ldap/ldap1/ldap-authentication.properties]
16:55:53,359 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
16:55:53,817 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
17:06:12,514 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
17:06:36,383 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] No changes were made to the schema.
17:06:38,884 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
17:06:57,317 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:06:58,830 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
17:08:06,636 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
17:08:08,914 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:08:30,013 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
17:08:30,036 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
17:08:33,122 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:08:48,143 WARN  [org.alfresco.util.OpenOfficeConnectionTester] An initial OpenOffice connection could not be established.
17:08:48,921 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
17:09:27,729 INFO  [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /opt/alfresco/data
17:09:31,269 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
17:10:04,834 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] No patches were required.
17:10:05,751 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Found 0 module(s).
17:10:06,170 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [fileServers, default]
17:10:09,071 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:10:24,415 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
17:10:24,415 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [imap, default]
17:10:26,258 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:10:31,417 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [imap, default] complete
17:10:31,418 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, outbound]
17:10:33,249 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:10:36,299 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, outbound] complete
17:10:36,300 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, inbound]
17:10:38,067 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:10:41,841 WARN  [org.springframework.beans.GenericTypeAwarePropertyDescriptor] Invalid JavaBean property 'blockedSenders' being accessed! Ambiguous write methods found next to actually used [public void org.alfresco.email.server.EmailServer.setBlockedSenders(java.util.List)]: [public void org.alfresco.email.server.EmailServer.setBlockedSenders(java.lang.String)]
17:10:41,841 WARN  [org.springframework.beans.GenericTypeAwarePropertyDescriptor] Invalid JavaBean property 'allowedSenders' being accessed! Ambiguous write methods found next to actually used [public void org.alfresco.email.server.EmailServer.setAllowedSenders(java.util.List)]: [public void org.alfresco.email.server.EmailServer.setAllowedSenders(java.lang.String)]
17:10:44,104 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, inbound] complete
17:10:44,104 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'googledocs' subsystem, ID: [googledocs, default]
17:10:47,110 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:10:54,047 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
17:10:54,074 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Enabled - calculate missing user usages …
17:11:44,072 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Found 0 users to recalculate
17:11:44,217 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] … calculated missing usages for 0 users
17:11:44,217 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
17:11:45,636 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:11:49,540 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
17:11:51,743 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:12:00,657 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
17:12:00,661 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, ldap1]
17:12:03,768 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:22:28,462 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, ldap1] complete
17:22:28,573 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Synchronizing users and groups with user registry 'ldap1'
17:22:29,549 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Retrieving all groups from user registry 'ldap1'
17:22:33,008 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 Group Analysis: Commencing batch of 0 entries
17:22:33,047 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 Group Analysis: Completed batch of 0 entries
17:22:34,008 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Retrieving users changed since Oct 18, 2010 10:44:55 AM from user registry 'ldap1'
17:22:34,237 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Commencing batch
17:22:52,592 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Processed 21 entries. Rate: 1 per second. 0 failures detected.
17:22:52,621 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Completed batch
17:22:55,514 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Finished synchronizing users and groups with user registry 'ldap1'
17:22:55,561 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] -1 user(s) and 0 group(s) processed
17:22:57,527 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
17:23:02,366 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_21-b06; maximum heap size 3640.938MB
17:23:02,410 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco started (Community): Current version 3.4.0 (a 3169) schema 4111 - Originally installed version 3.4.0 (a 3169) schema 4111
17:23:02,444 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Replication' subsystem, ID: [Replication, default]
17:23:07,233 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
17:23:07,721 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Replication' subsystem, ID: [Replication, default] complete
17:32:13,786 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 369 Web Scripts (+0 failed), 610 URLs
17:32:13,874 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 2 Package Description Documents (+0 failed)
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

GC log

5.086: [GC [PSYoungGen: 31457K->2336K(917504K)] 31457K->2336K(1966080K), 0.13131 30 secs] [Times: user=0.04 sys=0.00, real=0.13 secs]
5.217: [Full GC (System) [PSYoungGen: 2336K->0K(917504K)] [PSOldGen: 0K->2254K(1 048576K)] 2336K->2254K(1966080K) [PSPermGen: 11079K->11079K(22464K)], 0.0911970 secs] [Times: user=0.03 sys=0.01, real=0.09 secs]
325.108: [GC [PSYoungGen: 786432K->28932K(917504K)] 788686K->31187K(1966080K), 3 4.7933390 secs] [Times: user=6.22 sys=2.36, real=34.79 secs]
966.788: [GC [PSYoungGen: 815364K->88832K(917504K)] 817619K->91086K(1966080K), 2 62.1270430 secs] [Times: user=26.19 sys=7.41, real=262.09 secs]
1969.726: [GC [PSYoungGen: 875264K->131050K(1267008K)] 877518K->166572K(2315584K ), 433.2836330 secs] [Times: user=39.04 sys=54.64, real=433.29 secs]
‍‍‍‍‍‍‍

alfresco-global.properties

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

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

#
# Sample database connection properties
#————-
db.name=alfresco
db.username=alfresco
db.password=XXXXXXX
db.host=localhost
db.port=3306

#
# External locations
#————-
# ooo.exe=soffice
ooo.enabled=false
img.root=/usr
swf.exe=/usr/local/bin/pdf2swf

#
# MySQL connection
#————-
db.driver=org.gjt.mm.mysql.Driver
db.url=jdbc:mysql://${db.host}:${db.port}/${db.name}

#
# PostgreSQL connection (requires postgresql-8.2-504.jdbc3.jar or equivalent)
#
#db.driver=org.postgresql.Driver
#db.url=jdbc:postgresql://localhost:5432/alfresco

#
# Index Recovery Mode
#————-
#index.recovery.mode=AUTO

#
# Outbound Email Configuration
#————-
#mail.host=
#mail.port=25
#mail.username=anonymous
#mail.password=
#mail.encoding=UTF-8
#[email protected]
#mail.smtp.auth=false

#
# Alfresco Email Service and Email Server
#————-

# Enable/Disable the inbound email service.  The service could be used by processes other than
# the Email Server (e.g. direct RMI access) so this flag is independent of the Email Service.
#————-
email.inbound.enabled=false
#email.inbound.enabled=true

# Email Server properties
#————-
email.server.enabled=false

# A comma separated list of email REGEX patterns of allowed senders.
# If there are any values in the list then all sender email addresses
# must match. For example:
#   .*\@alfresco\.com, .*\@alfresco\.org
# Allow anyone:
#————-
#email.server.allowed.senders=.*

#
# The default authentication chain
# To configure external authentication subsystems see:
# http://wiki.alfresco.com/wiki/Alfresco_Authentication_Subsystems
#————-
# authentication.chain=mnet1:mnet,alfrescoNtlm1:alfrescoNtlm,ldap1:ldap
authentication.chain=alfrescoNtlm1:alfrescoNtlm,ldap1:ldap

#
# URL Generation Parameters (The ${localname} token is replaced by the local server name)
#————-
#alfresco.context=alfresco
#alfresco.host=${localname}
#alfresco.port=8080
#alfresco.protocol=http
#
#share.context=share
#share.host=${localname}
#share.port=8080
#share.protocol=http

#imap.server.enabled=true
#imap.server.port=143
#imap.server.host=localhost

#
# RMI Services
# To make your RMI services available from other machines you will need to change
# alfresco.rmi.services.host from "localhost".
alfresco.rmi.services.port=50500

# FTP
ftp.enabled=false
# CIFS
cifs.enabled=false
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[derek]

Take a JStack of the server while the alfresco.war is starting.
jps
jstack <pid>

Cut out all the threads that are just sitting around and identify which threads are busy and find out what they are doing.  There are some crazy waits in there where I would not expect any time to be taken, so perhaps it's doing something silly like generating DEBUG log messages before throwing them away (normally only a problem with incorrect JBoss settings).

I scanned the config and details and couldn't find anything that looks odd - if anything that machine should be starting up in 30s tops!

[stefan776]

Thanks Derek.
I did some remote profiling via JMX, JVisualVM and JConsole during startup of Tomcat/Alfresco and couldn't find anything in the output that would hint at the problem.
Since then we moved Alfresco to a different virtual machine of a similar build and its working there without problems. The average startup time is now 30 seconds and the web client is very fast to respond.
So in conclusion I am ruling this out to be a problem with Java or Alfresco.
Our server admins are having a look at both VMs right now, if they get to the bottom of it then I will give an update here.

[stefan776]

Just a quick follow-up - our sysadmins got to the bottom of it and fixed it. It all boiled down to the misconfiguration of a single VM setting.
From their feedback:

http://kb.vmware.com/selfservice/microsites/search.do?language=en_US&cmd=displayKC&externalId=100347...
for the VM, go to Edit / Resources Tab / Memory  and make sure Resource Allocation “unlimited” box is checked (on).

Flipping this "unlimited" switch to ON resolved all our performance troubles with Java/Tomcat/Alfresco. The start-up time for Tomcat6 with Alfresco deployed is on average 30 seconds now.