File upload fails and Alfresco becomes unusable

[acommons]

Version Information: Alfresco 3.4.d running on RHEL 5.5 Xen para-virtualized CentOS 5.5.

While uploading a number of files into a Document Library the upload freezes and one of the files displays as having caused an error (orange background to file name). I stopped the upload reasonably cleanly - I was able to remove one of the uploaded files from the list since the button to do this was still enabled and this enabled to OK button. From this point on the site is basically unusable with every click producing the message:

Could not load module template from '/share/service/modules/header/sites'.

There is also the message "Could not retrieve tags" is also displayed under the Tags heading in the left sidebar. Trying to refresh results in a timeout because it appears Tomcat has now died.

Stopping everything, deleting the stuck catalina.pid and restarting does not help. The only way out seems to be uninstall and reinstall (which I've done once and I'm now facing doing it again) which is a bit terminal with respect to site content.

Whilst Alfresco looks absolutely fantastic it also seems too fragile to use at present.

Is 3.4.c more stable?

cheers
=======================alfresco.log================================
21:08:18,499 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
21:08:18,502 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
21:08:18,503 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_dod5015/alfresco-global.properties]
21:08:18,503 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_wcmquickstart/alfresco-global.properties]
21:08:18,503 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
21:08:18,503 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
21:08:18,503 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco-global.properties]
21:08:18,582 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:08:18,751 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:08:18,789 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:08:18,819 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:08:18,820 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:08:38,943 WARN  [org.springframework.beans.GenericTypeAwarePropertyDescriptor] Invalid JavaBean property 'serviceBeans' being accessed! Ambiguous write methods found next to actually used [public void org.apache.cxf.jaxrs.JAXRSServerFactoryBean.setServiceBeans(java.util.List)]: [public void org.apache.cxf.jaxrs.JAXRSServerFactoryBean.setServiceBeans(java.lang.Object[])]
21:08:39,589 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
21:08:39,592 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
21:08:46,131 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
21:08:46,277 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-4312797126930180753.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-RepoTables.sql).
21:08:46,401 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-4853591520928347538.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-LockTables.sql).
21:08:46,416 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-2712741527890982085.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-ContentTables.sql).
21:08:46,429 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-36948632071574636.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-PropertyValueTables.sql).
21:08:46,448 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-5419410997047913158.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-AuditTables.sql).
21:08:46,458 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-8996020654978964693.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-AvmTables.sql).
21:08:46,579 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-1913432175954055715.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-ActivityTables.sql).
21:08:46,587 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-8814579308407578844.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-UsageTables.sql).
21:08:46,644 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-7598180353724224681.sql (Generated).
21:08:47,107 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-7193479080674097134.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoPostCreate-JBPM-Extra.sql).
21:08:47,109 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] All executed statements:  /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-All_Statements-8675237334532340669.sql.
21:08:47,666 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Normalized schema dumped to file /opt/alfresco-3.4.d/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-7474241440069436345.xml.
21:08:47,675 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
21:08:47,694 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:08:47,694 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:08:47,695 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:08:47,695 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:08:47,695 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:08:47,770 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
21:08:47,896 WARN  [org.alfresco.repo.dictionary.DictionaryRepositoryBootstrap] StoreRef 'workspace://SpacesStore' does not exist
21:08:48,933 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
21:08:48,950 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:08:48,951 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:08:48,952 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:08:48,952 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:08:48,953 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:08:49,681 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
21:08:49,682 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
21:08:49,704 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:08:49,704 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:08:49,705 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:08:49,705 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:08:49,706 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:08:50,064 WARN  [org.alfresco.util.OpenOfficeConnectionTester] An initial OpenOffice connection could not be established.
21:08:50,088 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
21:09:03,586 INFO  [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /opt/alfresco-3.4.d/alf_data
21:09:03,611 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
21:09:04,681 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]    Applying patch 'patch.wcmFolders' (Ensures the existance of the WCM specific 'Web Projects' and 'Web Forms' folders.).
21:09:04,757 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]    Applying patch 'patch.wcmDeployed' (null).
21:09:04,780 WARN  [org.alfresco.repo.admin.patch.PatchExecuter] Patch description is not available: Patch[ id=patch.wcmDeployed, description=patch.wcmDeployed.description, fixesFromSchema=0, fixesToSchema=4113, targetSchema=10000]
21:09:04,832 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.4-UsageTables
RESULT:
Script completed
=====================================
21:09:04,833 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.0-ActivityTables
RESULT:
Script completed
=====================================
21:09:04,833 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.2-LockTables
RESULT:
Script completed
=====================================
21:09:04,833 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.2-ContentTables
RESULT:
Script completed
=====================================
21:09:04,833 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.2-PropertyValueTables
RESULT:
Script completed
=====================================
21:09:04,833 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.2-AvmTables
RESULT:
Script completed
=====================================
21:09:04,833 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.2-AuditTables
RESULT:
Script completed
=====================================
21:09:04,834 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.3-JBPM-Extra
RESULT:
Script completed
=====================================
21:09:04,834 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.wcmFolders
RESULT:
The Web Projects folder was successfully created: workspace://SpacesStore/07e2553f-5c7e-40a5-985a-853d4c5a11b7
The Web Forms folder was successfully created: workspace://SpacesStore/07e2553f-5c7e-40a5-985a-853d4c5a11b7
=====================================
21:09:04,834 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.wcmDeployed
RESULT:
Imported view into bootstrap location: /app:company_home (workspace://SpacesStore/11dfbd23-9a01-4d79-845b-5dcdf86282b4)
=====================================
21:09:04,848 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Found 4 module(s).
21:09:04,899 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Installing module 'org_alfresco_module_wcmquickstart' version 1.0.
21:09:04,961 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Installing module 'org_alfresco_module_dod5015' version 1.0.
21:09:05,199 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Installing module 'org.alfresco.module.vti' version 1.2.
21:09:05,237 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Installing module 'org.alfresco.module.quickr' version 1.0.
21:09:05,372 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [fileServers, default]
21:09:05,449 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:05,450 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:05,451 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:05,451 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:05,451 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:05,727 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
21:09:05,749 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:05,750 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:05,750 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:05,750 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:05,750 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:05,865 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
21:09:10,881 ERROR [org.alfresco.fileserver] Failed to get local domain/workgroup name, using default of WORKGROUP
21:09:10,881 ERROR [org.alfresco.fileserver] (This may be due to firewall settings or incorrect <broadcast> setting)
21:09:11,001 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
21:09:11,001 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [imap, default]
21:09:11,041 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:11,042 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:11,042 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:11,042 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:11,042 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:11,116 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [imap, default] complete
21:09:11,116 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, outbound]
21:09:11,128 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:11,128 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:11,129 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:11,129 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:11,129 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:11,204 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, outbound] complete
21:09:11,204 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, inbound]
21:09:11,220 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:11,221 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:11,221 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:11,221 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:11,221 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:11,268 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)]
21:09:11,268 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)]
21:09:11,339 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, inbound] complete
21:09:11,339 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'googledocs' subsystem, ID: [googledocs, default]
21:09:11,366 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:11,367 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:11,367 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:11,368 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:11,368 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:11,720 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
21:09:11,732 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Enabled - calculate missing user usages …
21:09:11,748 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Found 0 users to recalculate
21:09:11,748 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] … calculated missing usages for 0 users
21:09:11,748 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
21:09:11,851 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:11,851 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:11,851 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:11,851 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:11,853 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:11,950 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
21:09:12,193 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_18-b07; maximum heap size 682.688MB
21:09:12,194 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco started (Community): Current version 3.4.0 (d 3370) schema 4113 - Originally installed version 3.4.0 (d 3370) schema 4113
21:09:12,236 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Replication' subsystem, ID: [Replication, default]
21:09:12,255 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:12,255 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:12,255 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:12,255 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:12,255 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:12,268 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Replication' subsystem, ID: [Replication, default] complete
21:09:15,073 INFO  [org.alfresco.module.vti.VtiServer] Vti server started successfully on port: 7070
21:09:29,591 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 449 Web Scripts (+0 failed), 700 URLs
21:09:29,591 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 2 Package Description Documents (+0 failed)
21:09:29,591 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 1 Schema Description Documents (+0 failed)
21:09:29,594 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Repository Web Script Container (in 11572.05ms)
21:09:29,606 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:09:29,608 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
21:09:29,794 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
21:09:29,814 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:09:29,814 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:09:29,815 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:09:29,815 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:09:29,815 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:09:29,899 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default] complete
21:09:39,265 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 309 Web Scripts (+0 failed), 319 URLs
21:09:39,267 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 8 Package Description Documents (+0 failed)
21:09:39,267 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 0 Schema Description Documents (+0 failed)
21:09:39,535 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Spring Surf Container Web Script Container (in 2139.1929ms)
21:09:39,587 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:09:39,684 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
21:09:39,916 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:09:39,921 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
21:09:40,083 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:09:40,089 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
21:31:10,769 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
21:31:10,771 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
21:31:10,922 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'googledocs' subsystem, ID: [googledocs, default]
21:31:10,923 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'googledocs' subsystem, ID: [googledocs, default]
21:31:10,923 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'email' subsystem, ID: [email, inbound]
21:31:10,924 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'email' subsystem, ID: [email, inbound]
21:31:10,973 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'Replication' subsystem, ID: [Replication, default]
21:31:10,973 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'Replication' subsystem, ID: [Replication, default]
21:31:10,980 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'Synchronization' subsystem, ID: [Synchronization, default]
21:31:10,981 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'Synchronization' subsystem, ID: [Synchronization, default]
21:31:10,981 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'fileServers' subsystem, ID: [fileServers, default]
21:32:27,477 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
21:32:27,480 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
21:32:27,481 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_dod5015/alfresco-global.properties]
21:32:27,481 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_wcmquickstart/alfresco-global.properties]
21:32:27,481 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
21:32:27,481 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
21:32:27,481 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco-global.properties]
21:32:27,556 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:32:27,732 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:32:27,773 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:32:27,804 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:32:27,805 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:32:46,981 WARN  [org.springframework.beans.GenericTypeAwarePropertyDescriptor] Invalid JavaBean property 'serviceBeans' being accessed! Ambiguous write methods found next to actually used [public void org.apache.cxf.jaxrs.JAXRSServerFactoryBean.setServiceBeans(java.util.List)]: [public void org.apache.cxf.jaxrs.JAXRSServerFactoryBean.setServiceBeans(java.lang.Object[])]
21:55:02,041 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
21:55:02,044 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
21:55:02,045 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_dod5015/alfresco-global.properties]
21:55:02,045 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_wcmquickstart/alfresco-global.properties]
21:55:02,045 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
21:55:02,045 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.d/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
21:55:02,045 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco-global.properties]
21:55:02,118 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:02,287 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:02,328 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:02,359 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:02,360 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:21,324 WARN  [org.springframework.beans.GenericTypeAwarePropertyDescriptor] Invalid JavaBean property 'serviceBeans' being accessed! Ambiguous write methods found next to actually used [public void org.apache.cxf.jaxrs.JAXRSServerFactoryBean.setServiceBeans(java.util.List)]: [public void org.apache.cxf.jaxrs.JAXRSServerFactoryBean.setServiceBeans(java.lang.Object[])]
21:55:22,082 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
21:55:22,085 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
21:55:28,149 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
21:55:28,490 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] No changes were made to the schema.
21:55:28,580 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
21:55:28,597 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:28,597 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:28,598 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:28,598 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:28,598 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:28,671 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
21:55:29,992 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
21:55:30,009 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:30,010 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:30,011 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:30,012 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:30,012 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:30,720 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
21:55:30,721 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
21:55:30,739 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:30,739 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:30,740 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:30,740 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:30,740 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:31,087 WARN  [org.alfresco.util.OpenOfficeConnectionTester] An initial OpenOffice connection could not be established.
21:55:31,115 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
21:55:31,720 INFO  [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /opt/alfresco-3.4.d/alf_data
21:55:31,768 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
21:55:32,903 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] No patches were required.
21:55:32,922 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Found 4 module(s).
21:55:33,023 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_wcmquickstart' version 1.0.
21:55:33,090 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_dod5015' version 1.0.
21:55:33,175 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.vti' version 1.2.
21:55:33,233 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.quickr' version 1.0.
21:55:33,261 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [fileServers, default]
21:55:33,281 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:33,282 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:33,283 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:33,284 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:33,284 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:33,595 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
21:55:33,615 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:33,616 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:33,616 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:33,616 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:33,616 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:33,744 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
21:55:38,763 ERROR [org.alfresco.fileserver] Failed to get local domain/workgroup name, using default of WORKGROUP
21:55:38,763 ERROR [org.alfresco.fileserver] (This may be due to firewall settings or incorrect <broadcast> setting)
21:55:38,848 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
21:55:38,848 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [imap, default]
21:55:38,879 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:38,880 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:38,880 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:38,881 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:38,881 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:38,962 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [imap, default] complete
21:55:38,962 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, outbound]
21:55:38,979 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:38,980 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:38,980 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:38,981 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:38,981 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:39,051 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, outbound] complete
21:55:39,052 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, inbound]
21:55:39,070 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:39,071 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:39,071 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:39,071 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:39,072 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:39,125 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)]
21:55:39,125 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)]
21:55:39,165 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, inbound] complete
21:55:39,165 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'googledocs' subsystem, ID: [googledocs, default]
21:55:39,198 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:39,199 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:39,200 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:39,200 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:39,200 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:39,555 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
21:55:39,556 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Enabled - calculate missing user usages …
21:55:39,603 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Found 0 users to recalculate
21:55:39,603 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] … calculated missing usages for 0 users
21:55:39,603 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
21:55:39,694 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:39,694 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:39,695 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:39,695 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:39,695 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:39,792 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
21:55:39,854 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_18-b07; maximum heap size 682.688MB
21:55:39,859 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco started (Community): Current version 3.4.0 (d 3370) schema 4113 - Originally installed version 3.4.0 (d 3370) schema 4113
21:55:39,861 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Replication' subsystem, ID: [Replication, default]
21:55:39,925 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:55:39,926 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:55:39,926 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:55:39,926 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:55:39,926 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:55:39,942 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Replication' subsystem, ID: [Replication, default] complete
21:55:44,924 INFO  [org.alfresco.module.vti.VtiServer] Vti server started successfully on port: 7070
21:55:46,810 INFO  [org.alfresco.repo.activities.feed.FeedTaskProcessor] >>> Generated 4 activity feed entries for 1 activity posts (in 458 msecs)
21:56:00,933 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 449 Web Scripts (+0 failed), 700 URLs
21:56:00,933 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 2 Package Description Documents (+0 failed)
21:56:00,934 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 1 Schema Description Documents (+0 failed)
21:56:00,936 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Repository Web Script Container (in 11386.603ms)
21:56:00,947 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:56:00,949 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
21:56:01,142 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
21:56:01,164 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/version.properties]
21:56:01,164 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
21:56:01,165 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/domain/cache-strategies.properties]
21:56:01,165 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/module/org.alfresco.module.vti/context/vti.properties]
21:56:01,165 INFO  [org.alfresco.config.FixedPropertyPlaceholderConfigurer] Loading properties file from URL [file:/opt/alfresco-3.4.d/tomcat/shared/classes/alfresco/extension/custom-vti.properties]
21:56:01,311 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default] complete
21:56:13,480 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 309 Web Scripts (+0 failed), 319 URLs
21:56:13,482 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 8 Package Description Documents (+0 failed)
21:56:13,482 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 0 Schema Description Documents (+0 failed)
21:56:13,738 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Spring Surf Container Web Script Container (in 2083.323ms)
21:56:13,783 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:56:13,914 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
21:56:14,067 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:56:14,073 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
21:56:14,263 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
21:56:14,269 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js

[gnyce]

The catalina.out entries you posted weren't especially helpful.  Is it possible you are hitting a bug with uploading a specific PDF file?  After you reinstall and start Alfresco for the first time, find where it keeps the PDFBox1.2.1 and FontBox1.2.2 jar files.  Replace those files with PDFBox1.3.1 and FontBox 1.3.1 jar files… Google is your friend to help you find them.  Make sure you move the existing 2 jar files elsewhere… dont' rename the newer files.   Stop/start Alfresco… then try your upload test again (same set of files)… see if you run into the same thing.

[acommons]

I suspect the bug is associated with a particular PDF file. I think I know which one and I think it is repeatable. So I can try out the newer versions of PDFbox and FontBox as you have suggested.

What concerns me more is the effect this error has on Alfresco. The fact that it maims itself really worries me. I would really like to know how to recover from the broken state rather than blowing everything away. I would prefer that it never maimed itself in the first place regardless of the error, the possibility of hours of work going down the tubes at the drop of a hat is not comforting.

cheers

[acommons]

I downloaded the 1.5.0 versions of PDFBox and FontBox from apache.org and replaced the 1.2.1 versions in Alfresco (note that the names are lowercase in the file system) and so far it seems to have solved the problem. I went for the 1.5.0 rather than the 1.3.1 versions on the assumption that there would be more bug fixes but this may also introduce more incompatibilities.

I'm not marking this solved just yet because I have no idea if replacing these jars with newer versions introduces other problems, only time and blundering around will tell.

Thanks for the suggestion 

cheers

[ahalil]

Hi I recently came across this problem and the fix mentioned worked.

acommons - I agree with you that this just masks the issue however I managed to remove the bad upload by going via CIFS and deleting. Hope this helps anyone else who's come across this and wondered how to remove the bad PDF without having to delete a whole site!

[jambrosino]

I had a similar problem.
Running Alfresco Community 3.4d on Ubuntu 10.04 LTS. As with other contributors in this thread, it appeared that just certain pdf files were causing Tomcat, and of course, Alfresco to crash. I followed the instructions to replace FontBox & PDFBox, and that solved the crashing, but the uploaded file and its containing folder remained unusable unless I deleted the file through FTP.

I tried upgrading/replacing Java as outlined in other threads, and while Alfresco worked fine, it didn't help the pdf problem.

Finally, I looked more closely at the .pdfs themselves. The offending files had had security applied. Not a user password to prevent actually opening the file, but either encryption to prevent them being text searched, or copy or print protection, with no user password applied. If I removed the protection via Adobe Acrobat, the files worked fine when uploaded to Alfresco Share.

Obviously, if you've only uploaded a couple of pdfs it's easy to find the culprit, but if you have dozens, it's not so easy. Adobe Acrobat Professional allows you to batch process files to remove the encryption, tutorial here - http://blogs.adobe.com/acrobatforlifesciences/2010/04/removing_security_from_pdfs_in/

You can batch process entire folders, if a file has security applied, it will remove it, if a file doesn't, it won't matter if it's processed. While Acrobat Pro isn't cheap (I don't know if these features are available on any of the Foxit products) it certainly saved a lot of time in terms of getting things back up and running.

[wali]

Dear team,
i am using alfresco 3.4d and i facing the issue with Rule and Email.
i have created a rule on folder to send email whenever document uploaded but the rule doesn't work for user except administrator account..

what i noticed that there is an issue with template loading for the user.users doesn't have permission to access the email template..
below is the error log.

User:wali ERROR [action.executer.MailActionExecuter] Failed to send email to [wali]
org.springframework.mail.MailPreparationException: Could not prepare mail; nested exception is org.alfresco.service.cmr.repository.TemplateException: 06070027 06070026 Access Denied.  You do not have the appropriate permissions to perform this operation.
   at org.springframework.mail.javamail.JavaMailSenderImpl.send(JavaMailSenderImpl.java:368)
   at org.springframework.mail.javamail.JavaMailSenderImpl.send(JavaMailSenderImpl.java:345)
   at org.alfresco.repo.action.executer.MailActionExecuter.executeImpl(MailActionExecuter.java:439)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:133)
   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.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:65)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
   at $Proxy265.execute(Unknown Source)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:749)
   at org.alfresco.repo.action.executer.CompositeActionExecuter.executeImpl(CompositeActionExecuter.java:66)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:133)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:749)
   at org.alfresco.repo.action.ActionServiceImpl.executeActionImpl(ActionServiceImpl.java:675)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:540)
   at sun.reflect.GeneratedMethodAccessor579.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:307)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
   at org.alfresco.repo.security.permissions.impl.AlwaysProceedMethodInterceptor.invoke(AlwaysProceedMethodInterceptor.java:34)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:44)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.alfresco.repo.audit.AuditMethodInterceptor.proceedWithAudit(AuditMethodInterceptor.java:217)
   at org.alfresco.repo.audit.AuditMethodInterceptor.proceed(AuditMethodInterceptor.java:184)
   at org.alfresco.repo.audit.AuditMethodInterceptor.invoke(AuditMethodInterceptor.java:137)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
   at $Proxy37.executeAction(Unknown Source)
   at org.alfresco.repo.rule.RuleServiceImpl.executeRule(RuleServiceImpl.java:1165)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRule(RuleServiceImpl.java:1133)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRulesImpl(RuleServiceImpl.java:1092)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRules(RuleServiceImpl.java:1065)
   at org.alfresco.repo.rule.RuleTransactionListener.beforeCommit(RuleTransactionListener.java:57)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.doBeforeCommit(AlfrescoTransactionSupport.java:732)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.doBeforeCommit(AlfrescoTransactionSupport.java:712)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.beforeCommit(AlfrescoTransactionSupport.java:672)
   at org.springframework.transaction.support.TransactionSynchronizationUtils.triggerBeforeCommit(TransactionSynchronizationUtils.java:95)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCommit(AbstractPlatformTransactionManager.java:927)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:737)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:394)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:472)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:403)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:253)
   at org.alfresco.repo.action.AsynchronousActionExecutionQueueImpl$ActionExecutionWrapper$1.doWork(AsynchronousActionExecutionQueueImpl.java:452)
   at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:508)
   at org.alfresco.repo.action.AsynchronousActionExecutionQueueImpl$ActionExecutionWrapper.run(AsynchronousActionExecutionQueueImpl.java:455)
   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)
Caused by: org.alfresco.service.cmr.repository.TemplateException: 06070027 06070026 Access Denied.  You do not have the appropriate permissions to perform this operation.
   at org.alfresco.repo.processor.TemplateServiceImpl.processTemplate(TemplateServiceImpl.java:183)
   at org.alfresco.repo.processor.TemplateServiceImpl.processTemplate(TemplateServiceImpl.java:194)
   at org.alfresco.repo.action.executer.MailActionExecuter$1.prepare(MailActionExecuter.java:397)
   at org.springframework.mail.javamail.JavaMailSenderImpl.send(JavaMailSenderImpl.java:353)
   … 57 more
Caused by: org.alfresco.repo.security.permissions.AccessDeniedException: 06070026 Access Denied.  You do not have the appropriate permissions to perform this operation.
   at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:48)

[wali]

Dear Team,
please let me know if there is any solution for this..