reindexing causes exception in job ftsIndexerJobDetail

[haroonzc]

We have a problem with our installation and some one suggested to rebuild index as a work around we did that and during that job threw following exception

09:03:52,122 ERROR [org.quartz.core.ErrorLogger] Job (DEFAULT.ftsIndexerJobDetail threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception. [See nested exception: org.alfresco.service.cmr.repository.ContentIOException: Failed to ope
n stream onto channel: 
   accessor: ContentAccessor[ contentUrl=store://2007/7/5/9/3/2d4bcaba-2af8-11dc-9392-5390c16435ee.bin, mimetype=null, size=0, encoding=UTF-8, locale=en_US]]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
Caused by: org.alfresco.service.cmr.repository.ContentIOException: Failed to open stream onto channel: 
   accessor: ContentAccessor[ contentUrl=store://2007/7/5/9/3/2d4bcaba-2af8-11dc-9392-5390c16435ee.bin, mimetype=null, size=0, encoding=UTF-8, locale=en_US]
        at org.alfresco.repo.content.AbstractContentReader.getContentInputStream(AbstractContentReader.java:337)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.indexProperty(ADMLuceneIndexerImpl.java:893)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.createDocuments(ADMLuceneIndexerImpl.java:547)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.updateFullTextSearch(ADMLuceneIndexerImpl.java:1286)
        at org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.index(FullTextSearchIndexerImpl.java:188)
        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:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
        at $Proxy9.index(Unknown Source)
        at org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSIndexerJob.java:52)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

It causes some of the nodes to become un accessable, e.g. I tried to save a file and it told n\me folder is read only but files was created anyhow with following contents

The node's content is missing: 
   node: workspace://SpacesStore/996579b7-2b04-11dc-9392-5390c16435ee 
   reader: null  
Please contact your system administrator.

‍‍‍‍‍‍‍

[gcoleman]

17:20:08,953 ERROR [quartz.core.JobRunShell] Job DEFAULT.ftsIndexerJobDetail threw an unhandled Exception: 
org.alfresco.service.cmr.repository.ContentIOException: Failed to open stream onto channel: 
   accessor: ContentAccessor[ contentUrl=store://2007/8/22/17/20/1d19fa75-5080-11dc-8a60-73aa86343014.bin, mimetype=null, size=0, encoding=UTF-8, locale=en_AU]
        at org.alfresco.repo.content.AbstractContentReader.getContentInputStream(AbstractContentReader.java:337)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.indexProperty(ADMLuceneIndexerImpl.java:893)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.createDocuments(ADMLuceneIndexerImpl.java:547)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.updateFullTextSearch(ADMLuceneIndexerImpl.java:1286)
        at org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.index(FullTextSearchIndexerImpl.java:188)
        at sun.reflect.GeneratedMethodAccessor602.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
        at $Proxy50.index(Unknown Source)
        at org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSIndexerJob.java:52)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

and

18:20:06,386 ERROR [quartz.core.ErrorLogger] Job (DEFAULT.ftsIndexerJobDetail threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception. [See nested exception: org.alfresco.service.cmr.repository.ContentIOException: Failed to open stream onto c
hannel: 
   accessor: ContentAccessor[ contentUrl=store://2007/8/22/18/20/7d541928-5088-11dc-8a60-73aa86343014.bin, mimetype=null, size=0, encoding=UTF-8, locale=en_AU]]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
Caused by: org.alfresco.service.cmr.repository.ContentIOException: Failed to open stream onto channel: 
   accessor: ContentAccessor[ contentUrl=store://2007/8/22/18/20/7d541928-5088-11dc-8a60-73aa86343014.bin, mimetype=null, size=0, encoding=UTF-8, locale=en_AU]
        at org.alfresco.repo.content.AbstractContentReader.getContentInputStream(AbstractContentReader.java:337)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.indexProperty(ADMLuceneIndexerImpl.java:893)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.createDocuments(ADMLuceneIndexerImpl.java:547)
        at org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.updateFullTextSearch(ADMLuceneIndexerImpl.java:1286)
        at org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.index(FullTextSearchIndexerImpl.java:188)
        at sun.reflect.GeneratedMethodAccessor602.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
        at $Proxy50.index(Unknown Source)
        at org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSIndexerJob.java:52)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        … 1 more
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[derek]

Is there anything at any of the reported locations, for starters?
Which clients are using the system when the errors occur?

[derek]

Somewhere some code is pushing incorrect metadata into the DB.  A null mimetype is unusual as well.  So, what is the system doing at the time of these errors?

[gcoleman]

There is nothing at any of those locations.

This error happens every hour even when no-one is using the system.

It  must be a quartz job which happens every hour.

[derek]

Hi,
Please turn on debugging for:

org.alfresco.repo.content.filestore
org.alfresco.repo.content.RoutingContentService‍‍

[derek]

Which quartz job?  Since the mimetype is null for these, and there is no actual content present, the cm:content property must be being set using a String value.  So an import is the most likely cause, but it's a guess.

[gcoleman]

Sorry this will have to happen tomorrow. I have to go and I can't restart the system anyway.

[gcoleman]

The LDAP import sounds the most likely since that is the only quartz job I know about.

[dcrossma]

Hi Derek,

Greg(gcoleman) will be out of the office for a few days so I am trying to take off where he finished.I think the debugging requested earlier is turned on, though not sure if I need to add anything else to the log4j.properties file.

I agree with greg, if the error is a result of a quartz job it is most likely the ldap import. This is certainly the only scheduled job that i am aware of.

Is there anything else I can send you to assist?

Cheers Dave

[derek]

Hi,
The system should be logging content access and creation now.  The logs leading up to the next failure will be useful.