AnsweredAssumed Answered

problem with alfresco module wcmquickstart

Question asked by punk on May 9, 2012
Latest reply on Mar 10, 2015 by ofnavarro
Hello I've upgraded from the version 3.4.e to the version 4.0.d and I have an exception in my alfresco.log.
This exception is thrown every 10-30 minutes, not in a regular way.
Here is my complete alfresco.log


10:16:18,454 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
10:16:18,533 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
10:16:28,189 WARN [org.alfresco.util.AbstractTriggerBean] Job ehCacheTracerJob is not active/enabled
10:16:31,548 INFO [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
10:16:31,548 INFO [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
10:16:39,142 INFO [org.alfresco.repo.domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.MySQLInnoDBDialect.
10:16:40,908 INFO [org.alfresco.repo.domain.schema.SchemaBootstrap] No changes were made to the schema.
10:16:41,236 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Search' subsystem, ID: [Search, managed, solr]
10:16:41,579 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Search' subsystem, ID: [Search, managed, solr] complete
10:16:41,970 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
10:16:42,111 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
10:16:42,111 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
10:16:43,095 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
10:16:43,204 INFO [org.alfresco.repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: C:\Alfresco-com40d\alf_data
10:16:43,204 INFO [org.alfresco.repo.admin.patch.PatchExecuter] Checking for patches to apply …
10:16:44,408 INFO [org.alfresco.repo.admin.patch.PatchExecuter] No patches were required.
10:16:44,423 INFO [org.alfresco.repo.module.ModuleServiceImpl] Found 1 module(s).
10:16:44,470 INFO [org.alfresco.repo.module.ModuleServiceImpl] Starting module 'org_alfresco_module_wcmquickstart' version 1.0.
10:16:44,486 DEBUG [org.alfresco.repo.module.ModuleComponentHelper] Started module 'ModuleDetails[{module.version=1.0, module.description=Web Quick Start, module.id=org_alfresco_module_wcmquickstart, module.repo.version.max=999, module.title=Web Quick Start, module.repo.version.min=3.3, module.installState=INSTALLED, module.installDate=2012-05-07T16:22:27.260+02:00}]' including 0components.
10:16:44,501 DEBUG [org.alfresco.repo.module.ModuleComponentHelper] Installed module found in distribution: org_alfresco_module_wcmquickstart
10:16:44,501 WARN [org.alfresco.repo.module.ModuleServiceImpl] A previously-installed module 'org.alfresco.module.quickr' (version 1.0) is not present in your distribution.
10:16:44,517 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'fileServers' subsystem, ID: [fileServers, default]
10:16:45,189 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
10:16:45,376 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
10:16:45,376 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, passthru1]
10:16:45,533 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, passthru1] complete
10:16:45,533 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Authentication' subsystem, ID: [Authentication, managed, ldap1]
10:16:45,751 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Authentication' subsystem, ID: [Authentication, managed, ldap1] complete
10:16:45,814 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
10:16:45,814 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'imap' subsystem, ID: [imap, default]
10:16:45,954 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'imap' subsystem, ID: [imap, default] complete
10:16:45,954 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, outbound]
10:16:46,079 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, outbound] complete
10:16:46,079 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'email' subsystem, ID: [email, inbound]
10:16:46,392 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'email' subsystem, ID: [email, inbound] complete
10:16:46,392 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'googledocs' subsystem, ID: [googledocs, default]
10:16:46,470 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
10:16:46,470 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Subscriptions' subsystem, ID: [Subscriptions, default]
10:16:46,486 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Subscriptions' subsystem, ID: [Subscriptions, default] complete
10:16:46,486 INFO [org.alfresco.repo.usage.UserUsageTrackingComponent] Disabled - clear non-missing user usages …
10:16:46,501 INFO [org.alfresco.repo.usage.UserUsageTrackingComponent] Found 0 users to clear
10:16:46,501 INFO [org.alfresco.repo.usage.UserUsageTrackingComponent] … cleared non-missing usages for 0 users
10:16:46,501 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
10:16:46,595 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Synchronizing users and groups with user registry 'ldap1'
10:16:46,611 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Retrieving groups changed since 7-mag-2012 14.57.46 from user registry 'ldap1'
10:16:46,658 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 Group Analysis: Commencing batch of 0 entries
10:16:46,658 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 Group Analysis: Completed batch of 0 entries
10:16:46,658 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Retrieving users changed since 17-apr-2012 10.23.06 from user registry 'ldap1'
10:16:46,673 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Commencing batch of 0 entries
10:16:46,673 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] ldap1 User Creation and Association: Completed batch of 0 entries
10:16:46,736 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] Finished synchronizing users and groups with user registry 'ldap1'
10:16:46,736 INFO [org.alfresco.repo.security.sync.ChainingUserRegistrySynchronizer] 0 user(s) and 0 group(s) processed
10:16:46,751 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
10:16:46,892 INFO [org.alfresco.service.descriptor.DescriptorService] Alfresco JVM - v1.6.0_26-b03; maximum heap size 4551,125MB
10:16:46,908 INFO [org.alfresco.service.descriptor.DescriptorService] Alfresco started (Community). Current version: 4.0.0 (4003) schema 5.025. Originally installed version: 3.4.0 (e 3419) schema 4.113.
10:16:46,908 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'ActivitiesFeed' subsystem, ID: [ActivitiesFeed, default]
10:16:46,986 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'ActivitiesFeed' subsystem, ID: [ActivitiesFeed, default] complete
10:16:46,986 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Starting 'Replication' subsystem, ID: [Replication, default]
10:16:47,001 INFO [org.alfresco.repo.management.subsystems.ChildApplicationContextFactory] Startup of 'Replication' subsystem, ID: [Replication, default] complete
10:17:00,642 WARN [org.springframework.extensions.webscripts.DeclarativeRegistry] Unable to register script classpath:webscripts/org/springframework/extensions/cmis/content.get.desc.xml due to error: 04090000 Web Script document org/springframework/extensions/cmis/content.get.desc.xml is attempting to define the url '/cmis/content:GET' already defined by org/alfresco/cmis/client/content.get.desc.xml
10:17:00,642 INFO [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 476 Web Scripts (+1 failed), 744 URLs
10:17:00,642 INFO [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 2 Package Description Documents (+0 failed)
10:17:00,642 INFO [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 1 Schema Description Documents (+0 failed)
10:17:00,642 INFO [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Repository Web Script Container (in 8638.66ms)
10:17:00,704 INFO [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
10:17:00,704 INFO [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
10:23:40,392 WARN [org.alfresco.web.app.servlet.AuthenticationHelper] Unable to login as Guest: 04090149 Accesso Negato. Non si dispone di permessi appropriati per eseguire questa operazione.
11:06:00,126 ERROR [org.quartz.core.JobRunShell] Job DEFAULT.org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean#59d6e3d2 threw an unhandled Exception:
org.springframework.scheduling.quartz.JobMethodInvocationFailedException: Invocation of method 'run' on target class [class org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor] failed; nested exception is org.alfresco.repo.search.impl.lucene.LuceneQueryParserException: 04090234
at org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:273)
at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:563)
Caused by: org.alfresco.repo.search.impl.lucene.LuceneQueryParserException: 04090234
at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.executeQuery(SolrQueryHTTPClient.java:364)
at org.alfresco.repo.search.impl.solr.SolrQueryLanguage.executeQuery(SolrQueryLanguage.java:49)
at org.alfresco.repo.search.impl.solr.SolrSearchService.query(SolrSearchService.java:348)
at org.alfresco.repo.search.impl.solr.SolrSearchService.query(SolrSearchService.java:152)
at org.alfresco.repo.search.SearcherComponent.query(SearcherComponent.java:67)
at org.alfresco.repo.search.AbstractSearcherComponent.query(AbstractSearcherComponent.java:53)
at sun.reflect.GeneratedMethodAccessor637.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy13.query(Unknown Source)
at org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor$1$1.execute(DynamicCollectionProcessor.java:114)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:388)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:259)
at org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor$1.doWork(DynamicCollectionProcessor.java:107)
at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:519)
at org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor.run(DynamicCollectionProcessor.java:102)
at sun.reflect.GeneratedMethodAccessor913.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
at org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:264)
… 3 more
Caused by: java.net.SocketException: Software caused connection abort: recv failed
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:798)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:755)
at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
at org.apache.commons.httpclient.HttpParser.readRawLine(HttpParser.java:78)
at org.apache.commons.httpclient.HttpParser.readLine(HttpParser.java:106)
at org.apache.commons.httpclient.HttpConnection.readLine(HttpConnection.java:1116)
at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager$HttpConnectionAdapter.readLine(MultiThreadedHttpConnectionManager.java:1413)
at org.apache.commons.httpclient.HttpMethodBase.readStatusLine(HttpMethodBase.java:1973)
at org.apache.commons.httpclient.HttpMethodBase.readResponse(HttpMethodBase.java:1735)
at org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:1098)
at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:398)
at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.executeQuery(SolrQueryHTTPClient.java:318)
… 26 more
11:06:00,142 ERROR [org.quartz.core.ErrorLogger] Job (DEFAULT.org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean#59d6e3d2 threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception. [See nested exception: org.springframework.scheduling.quartz.JobMethodInvocationFailedException: Invocation of method 'run' on target class [class org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor] failed; nested exception is org.alfresco.repo.search.impl.lucene.LuceneQueryParserException: 04090234 ]
at org.quartz.core.JobRunShell.run(JobRunShell.java:227)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:563)
Caused by: org.springframework.scheduling.quartz.JobMethodInvocationFailedException: Invocation of method 'run' on target class [class org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor] failed; nested exception is org.alfresco.repo.search.impl.lucene.LuceneQueryParserException: 04090234
at org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:273)
at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
… 1 more
Caused by: org.alfresco.repo.search.impl.lucene.LuceneQueryParserException: 04090234
at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.executeQuery(SolrQueryHTTPClient.java:364)
at org.alfresco.repo.search.impl.solr.SolrQueryLanguage.executeQuery(SolrQueryLanguage.java:49)
at org.alfresco.repo.search.impl.solr.SolrSearchService.query(SolrSearchService.java:348)
at org.alfresco.repo.search.impl.solr.SolrSearchService.query(SolrSearchService.java:152)
at org.alfresco.repo.search.SearcherComponent.query(SearcherComponent.java:67)
at org.alfresco.repo.search.AbstractSearcherComponent.query(AbstractSearcherComponent.java:53)
at sun.reflect.GeneratedMethodAccessor637.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy13.query(Unknown Source)
at org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor$1$1.execute(DynamicCollectionProcessor.java:114)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:388)
at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:259)
at org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor$1.doWork(DynamicCollectionProcessor.java:107)
at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:519)
at org.alfresco.module.org_alfresco_module_wcmquickstart.jobs.DynamicCollectionProcessor.run(DynamicCollectionProcessor.java:102)
at sun.reflect.GeneratedMethodAccessor913.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
at org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:264)
… 3 more
Caused by: java.net.SocketException: Software caused connection abort: recv failed
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:798)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:755)
at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
at org.apache.commons.httpclient.HttpParser.readRawLine(HttpParser.java:78)
at org.apache.commons.httpclient.HttpParser.readLine(HttpParser.java:106)
at org.apache.commons.httpclient.HttpConnection.readLine(HttpConnection.java:1116)
at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager$HttpConnectionAdapter.readLine(MultiThreadedHttpConnectionManager.java:1413)
at org.apache.commons.httpclient.HttpMethodBase.readStatusLine(HttpMethodBase.java:1973)
at org.apache.commons.httpclient.HttpMethodBase.readResponse(HttpMethodBase.java:1735)
at org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:1098)
at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:398)
at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
at org.alfresco.repo.search.impl.solr.SolrQueryHTTPClient.executeQuery(SolrQueryHTTPClient.java:318)
… 26 more


All seems to work fine,I do not use the module web quick start even if I have installed it.

How can I investigate this problem?

Thank you in advance.

Outcomes