AnsweredAssumed Answered

Alfresco startup fails from within cron job

Question asked by noobie on Dec 13, 2010
Latest reply on Dec 14, 2010 by noobie
Hi everybody!

we have some strange problem with (re)starting alfresco from within a cron job. From the console ('/etc/init.d/alfresto start') everything works just fine, but doing the 'same' thing from within a cron job '/alfresco' fails to start up. 'console' (dash) and 'cron' are run from the same account of course. Here are the logs:

alfresco.log when starting from console (works fine for now..):
12:17:03,583 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
12:17:03,585 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
12:17:03,585 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
12:17:03,585 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_wcmquickstart/alfresco-global.properties]
12:17:03,585 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
12:17:03,585 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_dod5015/alfresco-global.properties]
12:17:03,586 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/alfresco-3.4.a/tomcat/shared/classes/alfresco-global.properties]
12:17:03,656 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:21,571 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[])]
12:17:22,585 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
12:17:22,587 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
12:17:26,649 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
12:17:26,958 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] No changes were made to the schema.
12:17:27,006 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
12:17:27,027 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:27,111 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
12:17:29,273 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
12:17:29,289 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:29,409 ERROR [org.alfresco.repo.content.transform.magick.AbstractImageMagickContentTransformerWorker] ImageMagickContentTransformerWorker not available: 11130000 Failed to perform ImageMagick transformation:
Execution result:
   os:         Linux
   command:    [/opt/alfresco-3.4.a/common/bin/convert, /opt/alfresco-3.4.a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_1409072694986652239.gif[0], /opt/alfresco-3.4.a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_target_496577744566706719.png]
   succeeded:  false
   exit code:  1
   out:       
   err:        .convert.bin: no decode delegate for this image format `/opt/alfresco-3.4.a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_1409072694986652239.gif' @ constitute.c/ReadImage/526.
.convert.bin: missing an image filename `/opt/alfr
12:17:29,421 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
12:17:29,421 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
12:17:29,434 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:30,103 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
12:17:34,009 INFO  [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /var/alfresco-3.4.a/alf_data
12:17:34,322 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
12:17:34,741 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] No patches were required.
12:17:34,750 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Found 4 module(s).
12:17:34,795 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_wcmquickstart' version 1.0.
12:17:35,343 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_dod5015' version 1.0.
12:17:35,401 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.vti' version 1.2.
12:17:35,424 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.quickr' version 1.0.
12:17:35,434 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [fileServers, default]
12:17:35,445 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:35,655 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, passthru1]
12:17:35,664 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:36,115 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, passthru1] complete
12:17:36,116 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
12:17:36,172 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:36,222 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
12:17:36,271 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
12:17:36,271 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [imap, default]
12:17:36,289 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:36,482 INFO  [org.alfresco.repo.imap.AlfrescoImapServer] IMAP service started on host:port 192.168.1.2:1143.
12:17:36,487 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [imap, default] complete
12:17:36,493 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, outbound]
12:17:36,505 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:36,563 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, outbound] complete
12:17:36,563 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, inbound]
12:17:36,578 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:36,627 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)]
12:17:36,627 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)]
12:17:36,707 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, inbound] complete
12:17:36,707 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'googledocs' subsystem, ID: [googledocs, default]
12:17:36,792 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:37,024 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
12:17:37,033 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Enabled - calculate missing user usages …
12:17:37,060 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Found 0 users to recalculate
12:17:37,060 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] … calculated missing usages for 0 users
12:17:37,060 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
12:17:37,114 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:37,433 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
12:17:37,475 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_18-b07; maximum heap size 455,125MB
12:17:37,475 WARN  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - WARNING - maximum heap size 455,125MB is less than recommended 512MB
12:17:37,475 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco started (Community): Current version 3.4.0 (a 3169) schema 4111 - Originally installed version 3.3.0 (g 2860) schema 4100
12:17:37,476 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Replication' subsystem, ID: [Replication, default]
12:17:37,496 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:37,544 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Replication' subsystem, ID: [Replication, default] complete
12:17:40,061 INFO  [org.alfresco.module.vti.VtiServer] Vti server started successfully on port: 7070
12:17:51,580 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 443 Web Scripts (+0 failed), 694 URLs
12:17:51,580 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 2 Package Description Documents (+0 failed)
12:17:51,580 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 1 Schema Description Documents (+0 failed)
12:17:51,581 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Repository Web Script Container (in 7002.4673ms)
12:17:51,582 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
12:17:51,583 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
12:17:51,668 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
12:17:51,710 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:17:51,797 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default] complete
12:18:27,365 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
12:18:27,366 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'wcm_deployment_receiver' subsystem, ID: [wcm_deployment_receiver, default]
12:18:27,422 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'googledocs' subsystem, ID: [googledocs, default]
12:18:27,422 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'googledocs' subsystem, ID: [googledocs, default]
12:18:27,422 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'email' subsystem, ID: [email, inbound]
12:18:27,423 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'email' subsystem, ID: [email, inbound]
12:18:27,447 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'Replication' subsystem, ID: [Replication, default]
12:18:27,450 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'Replication' subsystem, ID: [Replication, default]
12:18:27,454 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'Synchronization' subsystem, ID: [Synchronization, default]
12:18:27,454 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'Synchronization' subsystem, ID: [Synchronization, default]
12:18:27,454 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'fileServers' subsystem, ID: [fileServers, default]
12:18:27,458 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'fileServers' subsystem, ID: [fileServers, default]
12:18:27,460 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'OOoDirect' subsystem, ID: [OOoDirect, default]
12:18:27,461 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'OOoDirect' subsystem, ID: [OOoDirect, default]
12:18:27,462 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'email' subsystem, ID: [email, outbound]
12:18:27,465 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'email' subsystem, ID: [email, outbound]
12:18:27,466 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'imap' subsystem, ID: [imap, default]
12:18:27,466 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'imap' subsystem, ID: [imap, default]
12:18:27,488 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'thirdparty' subsystem, ID: [thirdparty, default]
12:18:27,489 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'thirdparty' subsystem, ID: [thirdparty, default]
12:18:27,497 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'Authentication' subsystem, ID: [Authentication, managed, passthru1]
12:18:27,498 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'Authentication' subsystem, ID: [Authentication, managed, passthru1]
12:18:27,499 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
12:18:27,499 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
12:18:27,499 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopping 'sysAdmin' subsystem, ID: [sysAdmin, default]
12:18:27,500 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Stopped 'sysAdmin' subsystem, ID: [sysAdmin, default]

alfresco.log when starting from cron ('/share' prompts for login but fails with 'remote server may be unavailable', '/alfresco' returns HTTP/404..):
12:20:16,563 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
12:20:16,565 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
12:20:16,573 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/tests/alfresco-global.properties]
12:20:16,573 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_wcmquickstart/alfresco-global.properties]
12:20:16,573 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/test/alfresco-global.properties]
12:20:16,573 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from file [/opt/alfresco-3.4.a/tomcat/webapps/alfresco/WEB-INF/classes/alfresco/module/org_alfresco_module_dod5015/alfresco-global.properties]
12:20:16,573 INFO  [org.alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/alfresco-3.4.a/tomcat/shared/classes/alfresco-global.properties]
12:20:16,637 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:29,972 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[])]
12:20:30,905 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
12:20:30,907 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
12:20:33,833 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
12:20:34,084 INFO  [org.alfresco.repo.domain.schema.SchemaBootstrap] No changes were made to the schema.
12:20:34,139 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
12:20:34,148 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:34,199 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
12:20:36,050 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
12:20:36,065 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:36,183 ERROR [org.alfresco.repo.content.transform.magick.AbstractImageMagickContentTransformerWorker] ImageMagickContentTransformerWorker not available: 11130000 Failed to perform ImageMagick transformation:
Execution result:
   os:         Linux
   command:    [/opt/alfresco-3.4.a/common/bin/convert, /opt/alfresco-3.4.a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_3411934348772026932.gif[0], /opt/alfresco-3.4.a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_target_3025769665125275503.png]
   succeeded:  false
   exit code:  1
   out:       
   err:        .convert.bin: no decode delegate for this image format `/opt/alfresco-3.4.a/tomcat/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_3411934348772026932.gif' @ constitute.c/ReadImage/526.
.convert.bin: missing an image filename `/opt/alfr
12:20:36,189 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
12:20:36,189 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
12:20:36,197 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:36,673 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
12:20:40,707 INFO  [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /var/alfresco-3.4.a/alf_data
12:20:40,994 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
12:20:41,513 INFO  [org.alfresco.repo.admin.patch.PatchExecuter] No patches were required.
12:20:41,533 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Found 4 module(s).
12:20:41,580 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_wcmquickstart' version 1.0.
12:20:42,105 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_dod5015' version 1.0.
12:20:42,163 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.vti' version 1.2.
12:20:42,202 INFO  [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org.alfresco.module.quickr' version 1.0.
12:20:42,211 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [fileServers, default]
12:20:42,220 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:42,427 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, passthru1]
12:20:42,437 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:42,743 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, passthru1] complete
12:20:42,743 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
12:20:42,758 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:42,824 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
12:20:42,906 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
12:20:42,906 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [imap, default]
12:20:42,920 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:43,121 INFO  [org.alfresco.repo.imap.AlfrescoImapServer] IMAP service started on host:port 192.168.1.2:1143.
12:20:43,145 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [imap, default] complete
12:20:43,145 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, outbound]
12:20:43,159 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:43,215 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, outbound] complete
12:20:43,215 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, inbound]
12:20:43,226 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:43,282 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)]
12:20:43,282 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)]
12:20:43,382 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, inbound] complete
12:20:43,382 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'googledocs' subsystem, ID: [googledocs, default]
12:20:43,419 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:43,693 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
12:20:43,707 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Enabled - calculate missing user usages …
12:20:43,713 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] Found 0 users to recalculate
12:20:43,713 INFO  [org.alfresco.repo.usage.UserUsageTrackingComponent] … calculated missing usages for 0 users
12:20:43,713 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
12:20:43,727 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:44,102 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
12:20:44,132 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_18-b07; maximum heap size 455.125MB
12:20:44,132 WARN  [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - WARNING - maximum heap size 455.125MB is less than recommended 512MB
12:20:44,132 INFO  [org.alfresco.service.descriptor.DescriptorService] Alfresco started (Community): Current version 3.4.0 (a 3169) schema 4111 - Originally installed version 3.3.0 (g 2860) schema 4100
12:20:44,133 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Replication' subsystem, ID: [Replication, default]
12:20:44,148 INFO  [org.alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
12:20:44,161 INFO  [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Replication' subsystem, ID: [Replication, default] complete
12:20:50,495 INFO  [org.alfresco.module.vti.VtiServer] Vti server started successfully on port: 7070
12:20:55,584 ERROR [org.springframework.web.context.ContextLoader] Context initialization failed
org.alfresco.service.cmr.repository.DuplicateChildNodeNameException: Duplicate child name not allowed: Internal Target
   at org.alfresco.repo.domain.node.AbstractNodeDAOImpl$3.execute(AbstractNodeDAOImpl.java:2261)
   at org.alfresco.repo.domain.node.AbstractNodeDAOImpl$3.execute(AbstractNodeDAOImpl.java:2251)
   at org.alfresco.ibatis.RetryingCallbackHelper.doWithRetry(RetryingCallbackHelper.java:107)
   at org.alfresco.repo.domain.node.AbstractNodeDAOImpl.newChildAssocImpl(AbstractNodeDAOImpl.java:2268)
   at org.alfresco.repo.domain.node.AbstractNodeDAOImpl.newNode(AbstractNodeDAOImpl.java:890)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.createNode(DbNodeServiceImpl.java:308)
   at sun.reflect.GeneratedMethodAccessor336.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.tenant.MultiTNodeServiceInterceptor.invoke(MultiTNodeServiceInterceptor.java:104)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
   at $Proxy7.createNode(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor336.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.alfresco.repo.service.StoreRedirectorProxyFactory$RedirectorInvocationHandler.invoke(StoreRedirectorProxyFactory.java:215)
   at $Proxy8.createNode(Unknown Source)
   at org.alfresco.repo.node.MLPropertyInterceptor.invoke(MLPropertyInterceptor.java:276)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:183)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:183)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
   at $Proxy7.createNode(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor336.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 net.sf.acegisecurity.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:80)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at net.sf.acegisecurity.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:80)
   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.createNode(Unknown Source)
   at org.alfresco.repo.transfer.TransferServiceImpl2.createTransferTarget(TransferServiceImpl2.java:245)
   at org.alfresco.repo.transfer.TransferServiceImpl2.createAndSaveTransferTarget(TransferServiceImpl2.java:199)
   at org.alfresco.module.org_alfresco_module_wcmquickstart.publish.PublishBootstrap$Lifecycle$1.doWork(PublishBootstrap.java:90)
   at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:508)
   at org.alfresco.module.org_alfresco_module_wcmquickstart.publish.PublishBootstrap$Lifecycle.onBootstrap(PublishBootstrap.java:74)
   at org.springframework.extensions.surf.util.AbstractLifecycleBean.onApplicationEvent(AbstractLifecycleBean.java:56)
   at org.alfresco.module.org_alfresco_module_wcmquickstart.publish.PublishBootstrap.onApplicationEvent(PublishBootstrap.java:63)
   at org.alfresco.module.org_alfresco_module_wcmquickstart.publish.PublishBootstrap.onApplicationEvent(PublishBootstrap.java:36)
   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)

Seemingly the major difference between them is the 'DuplicateChildNodeNameException "Internal Target"' - but where does it come from? Google didn't quite help me. Why does it work just fine from console but fail from cron? I've set SHELL and PATH in crontab to the same values as shown on console (as by 'echo $PATH' and 'echo $SHELL') but that doesn't make no difference either. Of course cron doesn't provide a TTY, does that make a difference for the startup code?

Any other ideas? Where else should I dig for information?

Thanks in advance!

Outcomes