AnsweredAssumed Answered

Community 3.4.a: A valid SecureContext was not provided...

Question asked by lboschi on Nov 8, 2010
Latest reply on Sep 9, 2011 by raweck
Hi,
I have tried to install Alfresco Community 3.4.a on linux, upgrading from 3.3.g, but failed, and I need some help to solve this situation.
My procedure is as follows:
- installed 3.4.a from bundle and modified/added configuration files
- stopped 3.3.g
- started 3.4.a, using a test DB/repository (an empty one): successfull
- after stopping the previous alfresco instance, I modified the config to use the production DB/repository
- started again 3.4.a, but got the following error:

10:24:51,593 ERROR [org.springframework.web.context.ContextLoader] Context initialization failed
net.sf.acegisecurity.AuthenticationCredentialsNotFoundException: A valid SecureContext was not provided in the RequestContext
        at net.sf.acegisecurity.intercept.AbstractSecurityInterceptor.credentialsNotFound(AbstractSecurityInterceptor.java:477)
        at net.sf.acegisecurity.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:355)
        at net.sf.acegisecurity.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:77)
        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.proceed(AuditMethodInterceptor.java:160)
        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.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 $Proxy7.getChildAssocs(Unknown Source)
        at org.alfresco.repo.rule.RuleServiceImpl.getRule(RuleServiceImpl.java:699)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRule(RuleServiceImpl.java:1123)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRulesImpl(RuleServiceImpl.java:1085)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRules(RuleServiceImpl.java:1058)
        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:347)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:251)
        at org.alfresco.repo.module.ModuleStarter.onBootstrap(ModuleStarter.java:68)
        at org.springframework.extensions.surf.util.AbstractLifecycleBean.onApplicationEvent(AbstractLifecycleBean.java:56)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97)
        at org.alfresco.repo.management.SafeApplicationEventMulticaster.multicastEvent(SafeApplicationEventMulticaster.java:78)
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:294)
        at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:858)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:419)
        at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:261)
        at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:192)
        at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:47)
        at org.alfresco.web.app.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:63)
        at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3972)
        at org.apache.catalina.core.StandardContext.start(StandardContext.java:4467)
        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:546)
        at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:637)
        at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:563)
        at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:498)
        at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277)
        at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:321)
        at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
        at org.apache.catalina.core.StandardHost.start(StandardHost.java:785)
        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:519)
        at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
        at org.apache.catalina.startup.Catalina.start(Catalina.java:581)
        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:289)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)

The server is Ubuntu 8.04.4 LTS - Linux 2.6.24-28-server #1 SMP Thu Sep 16 15:43:17 UTC 2010 i686 GNU/Linux.
Alfresco is running on one machine only (no clustering).
MySQL 5.0.51.

When the exception came out, I was just watching the logs, during the webapp startup, not browsing alfresco.

This is the content of my alfresco-global.properties:


# TEST REPOSITORY
#dir.root=/opt/tomcat6-alfresco34a/alf_data
# PRODUCTION REPOSITORY
dir.shared.root=/var/www/example.com/alf_data_nfs_pro
dir.local.root=/opt/tomcat6-alfresco34a/alf_data_local
dir.root=${dir.shared.root}

web.application.context.url=http://example.com:8080/alfresco

### database connection properties ###
db.driver=org.gjt.mm.mysql.Driver
db.username=alfresco
db.password=XXXXXXXXXXXXXX
# TEST DB
#db.name=alfresco32r2
# PR0DUCTION DB
db.name=alfresco
db.url=jdbc:mysql://mysql.xxxx.xx/${db.name}

### RMI service ports ###
alfresco.rmi.services.port=50500
avm.rmi.service.port=0
avmsync.rmi.service.port=0
attribute.rmi.service.port=0
authentication.rmi.service.port=0
repo.rmi.service.port=0
action.rmi.service.port=0
deployment.rmi.service.port=0

### External executable locations ###
ooo.exe=/opt/tomcat6-alfresco34a/openoffice/program/soffice.bin
img.root=/opt/tomcat6-alfresco34a/common
img.dyn=${img.root}/lib
img.exe=${img.root}/bin/convert
swf.exe=/opt/tomcat6-alfresco34a/common/bin/pdf2swf
#jodconverter.enabled=true
#jodconverter.officeHome=/opt/tomcat6-alfresco34a/openoffice/program/soffice.bin
#jodconverter.portNumbers=8101

### Initial admin password ###
alfresco_user_store.adminpassword=975fxxxxxxxxxxxxxxxxxxxxxx

#
# Outbound Email Configuration
mail.host=localhost
mail.port=25
mail.username=anonymous
mail.password=
mail.encoding=UTF-8
mail.from.default=kms@support.example.com
mail.smtp.auth=false

authentication.chain=alfrescoNtlm1:alfrescoNtlm,passthru1:passthru,ldap1:ldap-ad

######### custom-repository.properties ###############

repo.remote.url=http://example.com:8080/alfresco

# The location for lucene index files
dir.indexes=${dir.local.root}/lucene-indexes
# The location for index backups
dir.indexes.backup=${dir.local.root}/backup-lucene-indexes

index.recovery.mode=AUTO

This is the complete log of the first startup with production DB/repository:

10:09:00,071 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
10:09:00,074 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
10:09:00,074 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_dod5015/alfresco-global.properties]
10:09:00,075 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_wcmquickstart/alfresco-global.properties]
10:09:00,075 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
10:09:00,075 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
10:09:00,075 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco-global.properties]
10:09:00,141 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:09:05,969 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/alfrescoNtlm/alfrescoNtlm1/ntlm-filter.properties]
10:09:05,969 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/alfrescoNtlm/alfrescoNtlm1/alfresco-authentication.properties]
10:09:05,972 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/passthru/passthru1/ntlm-filter.properties]
10:09:05,972 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/passthru/passthru1/passthru-authentication-context.properties]
10:09:05,976 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/ldap-ad/ldap1/ldap-ad-authentication.properties]
10:09:11,882 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/OOoDirect/default/default/custom-openoffice-transform.properties]
10:09:12,130 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/fileServers/default/default/custom-file-servers.properties]
10:09:12,162 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Synchronization/default/default/custom-synchronization.properties]
10:09:20,716 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
10:09:20,719 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
10:09:28,145 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
10:09:32,484 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-9077753941049347393.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.3/org.hibernate.dialect.MySQLInnoDBDialect/modify-index-permission_id.sql).
10:09:32,806 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-4916736592256609474.sql (Copied from classpath:alfresco/dbscripts/upgrade/2.2/org.hibernate.dialect.MySQLInnoDBDialect/AddFKIndexes.sql).
10:09:32,994 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-2376392279336334613.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.3/org.hibernate.dialect.MySQLInnoDBDialect/fix-Repo-seqs.sql).
10:09:33,000 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-427574424575666961.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.3/org.hibernate.dialect.MySQLInnoDBDialect/fix-AVM-seqs.sql).
10:09:33,018 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-3670325768383177555.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoPostCreate-JBPM-Extra.sql).
10:09:33,025 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-155341032327112623.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.3/org.hibernate.dialect.MySQLInnoDBDialect/node-prop-serializable.sql).
10:09:33,031 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-6397975274860777338.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.4/org.hibernate.dialect.MySQLInnoDBDialect/property-unique-ctx-value.sql).
10:09:33,349 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Executing database script /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-4822439300340855442.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.4/org.hibernate.dialect.MySQLInnoDBDialect/child-assoc-indexes.sql).
10:09:42,172 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] All executed statements:  /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-All_Statements-4423545819197658230.sql.
10:09:43,595 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Normalized schema (pre-bootstrap)  dumped to file /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-5217338924517823241-Startup.xml.
10:09:43,595 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Normalized schema (post-bootstrap) dumped to file /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-8263569703794313331.xml.
10:09:43,607 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
10:09:43,635 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:09:43,651 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
10:09:45,927 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
10:09:45,960 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:09:46,607 ERROR [org.alfresco.repo.content.transform.magick.AbstractImageMagickContentTransformerWorker] ImageMagickContentTransformerWorker not available: 10050000 Failed to perform ImageMagick transformation:
Execution result:
   os:         Linux
   command:    [/opt/tomcat6-alfresco34a/common/bin/convert, /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_8585406213058594320.gif[0], /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_target_2611968150738930037.png]
   succeeded:  false
   exit code:  1
   out:       
   err:        .convert.bin: no decode delegate for this image format `/opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_8585406213058594320.gif' @ constitute.c/ReadImage/526.
.convert.bin: missing an image filename `/opt
10:09:46,613 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
10:09:46,613 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
10:09:46,643 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:09:47,237 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
10:09:49,600 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] Iniziato il recupero Indice: 45.289 % della transazione
10:10:47,403 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 10 % completata.
10:11:18,039 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 20 % completata.
10:11:43,694 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 30 % completata.
10:12:18,567 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 40 % completata.
10:12:46,387 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 50 % completata.
10:13:21,384 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 60 % completata.
10:13:48,148 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 70 % completata.
10:14:27,841 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 80 % completata.
10:14:46,534 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 90 % completata.
10:23:30,082 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] 100 % completata.
10:23:35,961 INFO  [org.alfresco.repo.node.index.FullIndexRecoveryComponent] Recupero indice completato
10:23:36,161 WARN  [org.alfresco.repo.node.index.AVMFullIndexRecoveryComponent]     Index for avm store sitestore is out of date
10:23:36,161 INFO  [org.alfresco.repo.node.index.AVMFullIndexRecoveryComponent] Rebuilding indexes for 1 AVM Stores
10:23:36,161 INFO  [org.alfresco.repo.node.index.AVMFullIndexRecoveryComponent]     Auto recovering index for sitestore
10:23:36,168 INFO  [org.alfresco.repo.node.index.AVMFullIndexRecoveryComponent]   Reindex   100% complete
10:23:36,168 INFO  [org.alfresco.repo.node.index.AVMFullIndexRecoveryComponent] Finished rebuilding indexes for AVM Stores
10:23:56,349 INFO  [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /var/www/example.com/alf_data_nfs_pro
10:23:56,529 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
10:23:57,167 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.fixAuthoritiesCrcValues' (Fixes authority CRC32 values to match UTF-8 encoding.).
10:23:57,191 INFO  [org.alfresco.repo.admin.patch.impl.FixAuthoritiesCrcValuesPatch] FixAuthorityCrcValuesPatch: Commencing batch of 0 entries
10:23:57,193 INFO  [org.alfresco.repo.admin.patch.impl.FixAuthoritiesCrcValuesPatch] FixAuthorityCrcValuesPatch: Completed batch of 0 entries
10:23:57,196 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.updateMimetypes1' (Fix mimetypes for Excel and Powerpoint.).
10:24:22,374 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.migrateAttrTenants' (Migrate old Tenant attributes).
10:24:22,380 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.migrateAttrAVMLocks' (Migrate old AVM Lock attributes).
10:24:22,420 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.migrateAttrPropBackedBeans' (Migrate old Property-Backed Bean component attributes).
10:24:22,425 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.migrateAttrChainingURS' (Migrate old Chaining User Registry Synchronizer attributes).
10:24:22,456 INFO  [org.alfresco.repo.admin.patch.impl.MigrateAttrChainingURSPatch] Processed 2 Chaining URS attrs in 0 secs
10:24:22,459 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.migrateAttrDelete' (Delete old attributes (if any) after they have been migrated).
10:24:22,460 INFO  [org.alfresco.repo.domain.patch.ibatis.PatchDAOImpl] Deleted 0 rows from alf_list_attribute_entries
10:24:22,462 INFO  [org.alfresco.repo.domain.patch.ibatis.PatchDAOImpl] Deleted 6 rows from alf_map_attribute_entries
10:24:22,462 INFO  [org.alfresco.repo.domain.patch.ibatis.PatchDAOImpl] Deleted 2 rows from alf_global_attributes
10:24:22,463 INFO  [org.alfresco.repo.domain.patch.ibatis.PatchDAOImpl] Deleted 8 rows from alf_attributes
10:24:22,473 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.replication.replication_actions' (Creates the Replication Actions folder.).
10:24:23,718 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
10:24:23,800 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:24:24,003 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
10:24:24,003 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, passthru1]
10:24:24,038 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:24:24,152 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, passthru1] complete
10:24:24,153 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, ldap1]
10:24:24,203 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:24:24,562 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, ldap1] complete
10:24:26,011 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.transfer.targetrulefolder' (Creates the transfer target rule folder for the default transfer group.).
10:24:27,284 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.transfer.targetrule' (Creates the transfer target rule for the default transfer group.).
10:24:31,139 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.actions.scheduledfolder' (Creates the scheduled actions folder in the Data Dictionary.).
10:24:31,268 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.updateMimetypes2' (null).
10:24:45,687 WARN  [org.alfresco.repo.admin.patch.PatchExecuter] Patch description is not available: Patch[ id=patch.updateMimetypes2, description=patch.updateMimetypes2.description, fixesFromSchema=0, fixesToSchema=4110, targetSchema=4111]
10:24:46,657 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]        Applying patch 'patch.wcmDeployed' (null).
10:24:46,685 WARN  [org.alfresco.repo.admin.patch.PatchExecuter] Patch description is not available: Patch[ id=patch.wcmDeployed, description=patch.wcmDeployed.description, fixesFromSchema=0, fixesToSchema=4111, targetSchema=10000]
10:24:47,591 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.2-AddFKIndexes
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.fixAuthoritiesCrcValues
RESULT:
Fixed CRC32 values for UTF-8 encoding for 0 authorities.  See file /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/longLife_patches/FixAuthorityCrcValuesPatch.log for details.
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.updateMimetypes1
RESULT:
Updating mimetypes.
        Updated 2.782 content references with mimetype 'application/vnd.excel' to use 'application/vnd.ms-excel'.
        Indexed 2.723 nodes in store 'workspace://SpacesStore'.
        Indexed 2.729 nodes in store 'archive://SpacesStore'.
        Updated 190 content references with mimetype 'application/vnd.powerpoint' to use 'application/vnd.ms-powerpoint'.
        Indexed 157 nodes in store 'workspace://SpacesStore'.
        Indexed 160 nodes in store 'archive://SpacesStore'.
        Finished updating mimetypes.
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.3-modify-index-permission_id
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.3-Fix-AVM-Seqs
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.3-Fix-Repo-Seqs
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.4-child-assoc-indexes
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.4-property-unique-ctx-value
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.3-JBPM-Extra
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.db-V3.3-Node-Prop-Serializable
RESULT:
Script completed
=====================================
10:24:47,592 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.migrateAttrDelete
RESULT:
Old attributes were deleted (if any)
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.migrateAttrTenants
RESULT:
Processed 0 attributes
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.migrateAttrAVMLocks
RESULT:
Processed 0 attributes
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.migrateAttrChainingURS
RESULT:
Processed 2 attributes
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.migrateAttrPropBackedBeans
RESULT:
Processed 0 attributes (0 properties)
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.replication.replication_actions
RESULT:
Imported view into bootstrap location: /app:company_home/app:dictionary (workspace://SpacesStore/7a285bbb-8102-4ee6-9609-7a4eb890c2dd)
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.transfer.targetrule
RESULT:
Imported view into bootstrap location: /app:company_home/app:dictionary/app:transfers/app:transfer_groups/cm:default/rule:ruleFolder (workspace://SpacesStore/7a285bbb-8102-4ee6-9609-7a4eb890c2dd)
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.transfer.targetrulefolder
RESULT:
Imported view into bootstrap location: /app:company_home/app:dictionary/app:transfers/app:transfer_groups/cm:default (workspace://SpacesStore/7a285bbb-8102-4ee6-9609-7a4eb890c2dd)
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.actions.scheduledfolder
RESULT:
Imported view into bootstrap location: /app:company_home/app:dictionary (workspace://SpacesStore/7a285bbb-8102-4ee6-9609-7a4eb890c2dd)
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.updateMimetypes2
RESULT:
Updating mimetypes.
        Updated 0 content references with mimetype 'application/vnd.excel' to use 'application/vnd.ms-excel'.
        Indexed 2.723 nodes in store 'workspace://SpacesStore'.
        Indexed 2.729 nodes in store 'archive://SpacesStore'.
        Updated 0 content references with mimetype 'application/vnd.powerpoint' to use 'application/vnd.ms-powerpoint'.
        Indexed 157 nodes in store 'workspace://SpacesStore'.
        Indexed 160 nodes in store 'archive://SpacesStore'.
        Finished updating mimetypes.
=====================================
10:24:47,593 INFO  [org.alfresco.repo.admin.patch.PatchExecuter]
=== Applied patch                 ===
ID: patch.wcmDeployed
RESULT:
Imported view into bootstrap location: /app:company_home (workspace://SpacesStore/7a285bbb-8102-4ee6-9609-7a4eb890c2dd)
=====================================
10:24:50,329 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Found 3 module(s).
10:24:50,722 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Installing module 'org_alfresco_module_wcmquickstart' version 1.0.
10:24:50,776 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Installing module 'org_alfresco_module_dod5015' version 1.0.
10:24:51,393 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.vti' version 1.2.
10:24:51,593 ERROR [org.springframework.web.context.ContextLoader] Context initialization failed
net.sf.acegisecurity.AuthenticationCredentialsNotFoundException: A valid SecureContext was not provided in the RequestContext
        at net.sf.acegisecurity.intercept.AbstractSecurityInterceptor.credentialsNotFound(AbstractSecurityInterceptor.java:477)
        at net.sf.acegisecurity.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:355)
        at net.sf.acegisecurity.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:77)
        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.proceed(AuditMethodInterceptor.java:160)
        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.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 $Proxy7.getChildAssocs(Unknown Source)
        at org.alfresco.repo.rule.RuleServiceImpl.getRule(RuleServiceImpl.java:699)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRule(RuleServiceImpl.java:1123)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRulesImpl(RuleServiceImpl.java:1085)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRules(RuleServiceImpl.java:1058)
        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:347)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:251)
        at org.alfresco.repo.module.ModuleStarter.onBootstrap(ModuleStarter.java:68)
        at org.springframework.extensions.surf.util.AbstractLifecycleBean.onApplicationEvent(AbstractLifecycleBean.java:56)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97)
        at org.alfresco.repo.management.SafeApplicationEventMulticaster.multicastEvent(SafeApplicationEventMulticaster.java:78)
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:294)
        at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:858)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:419)
        at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:261)
        at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:192)
        at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:47)
        at org.alfresco.web.app.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:63)
        at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3972)
        at org.apache.catalina.core.StandardContext.start(StandardContext.java:4467)
        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:546)
        at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:637)
        at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:563)
        at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:498)
        at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277)
        at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:321)
        at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
        at org.apache.catalina.core.StandardHost.start(StandardHost.java:785)
        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:519)
        at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
        at org.apache.catalina.startup.Catalina.start(Catalina.java:581)
        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:289)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
10:25:09,627 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 301 Web Scripts (+0 failed), 309 URLs
10:25:09,629 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 8 Package Description Documents (+0 failed)
10:25:09,629 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 0 Schema Description Documents (+0 failed)
10:25:09,902 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Spring Surf Container Web Script Container (in 3317.43ms)
10:25:10,244 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:25:10,367 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
10:25:10,530 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:25:10,537 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
10:25:10,708 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:25:10,714 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js

This is the complete log of the last startup with test DB/repository:
09:59:17,602 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
09:59:17,605 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
09:59:17,606 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_dod5015/alfresco-global.properties]
09:59:17,606 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_wcmquickstart/alfresco-global.properties]
09:59:17,606 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
09:59:17,606 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
09:59:17,606 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco-global.properties]
09:59:17,671 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:23,523 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/alfrescoNtlm/alfrescoNtlm1/ntlm-filter.properties]
09:59:23,524 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/alfrescoNtlm/alfrescoNtlm1/alfresco-authentication.properties]
09:59:23,527 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/passthru/passthru1/ntlm-filter.properties]
09:59:23,527 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/passthru/passthru1/passthru-authentication-context.properties]
09:59:23,531 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Authentication/ldap-ad/ldap1/ldap-ad-authentication.properties]
09:59:29,684 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/OOoDirect/default/default/custom-openoffice-transform.properties]
09:59:30,407 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/fileServers/default/default/custom-file-servers.properties]
09:59:30,438 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/tomcat6-alfresco34a/tomcat/shared/classes/alfresco/extension/subsystems/Synchronization/default/default/custom-synchronization.properties]
09:59:39,130 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
09:59:39,133 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
09:59:49,559 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
09:59:49,864 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] No changes were made to the schema.
09:59:49,926 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
09:59:49,945 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:49,961 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
09:59:51,722 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
09:59:51,762 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:51,922 ERROR [org.alfresco.repo.content.transform.magick.AbstractImageMagickContentTransformerWorker] ImageMagickContentTransformerWorker not available: 10050000 Failed to perform ImageMagick transformation:
Execution result:
   os:         Linux
   command:    [/opt/tomcat6-alfresco34a/common/bin/convert, /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_4814594278650236927.gif[0], /opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_target_6714541041032116870.png]
   succeeded:  false
   exit code:  1
   out:       
   err:        .convert.bin: no decode delegate for this image format `/opt/tomcat6-alfresco34a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_4814594278650236927.gif' @ constitute.c/ReadImage/526.
.convert.bin: missing an image filename `/opt
09:59:51,928 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
09:59:51,928 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
09:59:51,948 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:53,540 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
09:59:54,216 INFO  [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /opt/tomcat6-alfresco34a/alf_data
09:59:54,277 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
09:59:55,314 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] No patches were required.
09:59:55,330 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Found 3 module(s).
09:59:55,429 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_wcmquickstart' version 1.0.
09:59:55,815 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_dod5015' version 1.0.
09:59:55,892 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.vti' version 1.2.
09:59:55,928 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [fileServers, default]
09:59:55,966 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:56,413 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
09:59:56,443 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:56,615 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
09:59:56,615 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, passthru1]
09:59:56,639 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:56,731 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, passthru1] complete
09:59:56,732 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, ldap1]
09:59:56,761 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:57,102 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, ldap1] complete
09:59:57,173 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
09:59:57,173 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [imap, default]
09:59:57,217 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:57,309 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [imap, default] complete
09:59:57,310 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, outbound]
09:59:57,332 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:57,417 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, outbound] complete
09:59:57,418 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, inbound]
09:59:57,441 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:57,525 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)]
09:59:57,526 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)]
09:59:57,550 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, inbound] complete
09:59:57,550 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'googledocs' subsystem, ID: [googledocs, default]
09:59:57,593 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
09:59:59,991 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
09:59:59,997 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Enabled - calculate missing user usages …
10:00:00,077 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Found 0 users to recalculate
10:00:00,077 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] … calculated missing usages for 0 users
10:00:00,077 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
10:00:00,133 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:00:00,328 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Synchronizing users and groups with user registry 'ldap1'
10:00:00,353 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Retrieving groups changed since 29-ott-2010 17.39.04 from user registry 'ldap1'
10:00:00,773 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 Group Analysis: Commencing batch of 0 entries
10:00:00,777 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 Group Analysis: Completed batch of 0 entries
10:00:00,788 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Retrieving users changed since 5-nov-2010 9.30.15 from user registry 'ldap1'
10:00:00,829 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Commencing batch of 1 entries
10:00:00,936 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Processed 1 entries out of 1. 100% complete. Rate: 9 per second. 0 failures detected.
10:00:00,936 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Completed batch of 1 entries
10:00:00,973 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Finished synchronizing users and groups with user registry 'ldap1'
10:00:00,973 INFO  [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] 1 user(s) and 0 group(s) processed
10:00:00,998 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
10:00:01,095 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_18-b07; maximum heap size 494,938MB
10:00:01,095 WARN  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - WARNING - maximum heap size 494,938MB is less than recommended 512MB
10:00:01,096 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
10:00:01,098 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Replication' subsystem, ID: [Replication, default]
10:00:01,119 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:00:01,129 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Replication' subsystem, ID: [Replication, default] complete
10:00:10,069 INFO  [org.alfresco.module.vti.VtiServer] Vti server started successfully on port: 7070
10:00:24,519 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 443 Web Scripts (+0 failed), 694 URLs
10:00:24,519 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 2 Package Description Documents (+0 failed)
10:00:24,519 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 1 Schema Description Documents (+0 failed)
10:00:24,522 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Repository Web Script Container (in 14231.169ms)
10:00:24,522 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:00:24,526 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
10:00:24,792 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
10:00:24,827 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
10:00:24,943 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default] complete
10:00:36,816 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 301 Web Scripts (+0 failed), 309 URLs
10:00:36,818 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 8 Package Description Documents (+0 failed)
10:00:36,818 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 0 Schema Description Documents (+0 failed)
10:00:36,993 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Spring Surf Container Web Script Container (in 2660.3997m
s)
10:00:37,089 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:00:37,221 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
10:00:37,473 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:00:37,482 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
10:00:37,718 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:00:37,725 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js

Thank you for any help or hint.

Luciano

Outcomes