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.

‍‍‍‍‍‍‍

[kevinr]

You have missing content! The DB says that content exists in alf_data but it is missing. Have you delete items in alf_data or modifed the DB by hand using SQL or similar? Just wondering as you shouldn't get into that situation without them going out-of-sync some how…

I'll raise an issue so that the reindexer can ignore missing content and raise a big ERROR on the console when it finds some but still continue with the process.
http://issues.alfresco.com/browse/AR-1582

Thanks,

Kevin

[haroonzc]

Thanks for the quick reply.

Our problem seems with creating new contents rather than accessing old. We may have lost some thing, we don't know, did not change any thing on disk just did a DB upgrade to Alfresco 2.1.

Above error where newly created file has error message in contents happens when we create a new document in certain spaces. Not every where. Any idea how we can fix it or try to resymch DB adn disk contents? Since we can read contents, I can copy every thing over and try to fix problem adn then import old contents. But I am not sure how can we fix it?

Thanks

[callermd]

We have the same exact issue after the DB upgrade.

[gcoleman]

We also have this issue after upgrading from 1.4 to 2.1

The error happens every hour but the afected node is different each time.
As you can see in haroonzc's message the  date / time represented by the  directory structure (store://2007/7/5/9/3/) is the same as time the error is generated (09:03:52). This is also true in our case.

[derek]

How are you updating (saving) the file, i.e. are you using CIFS, FTP or the Web Client?
Are the physical binaries present on the system at the location 2007/…?

[derek]

Can you post the startup logs as well, please?

[gcoleman]

There error does not occur when updating or saving a file it occurs at regular intervals. I don't really know what file it is related to. The binaries do not exist nor is there any node in the database with that UUID.

It is all a bit complicated but this is the sequence of events so far:

1. We were running 1.4
2. Our users are imported regularly from our LDAP tree.
3. We have a rogue user whose details have not been imported properly. (I suspect that he logged in before his details were imported).
4. We upgraded to 2.1
5. We start getting these ftsIndexerJobDetail errors as well as LDAP import errors. The LDAP error occurs always when importing the rogue user.
6. I cannot delete the rogue user from the web interface so I delete him from the database.
7. The LDAP errors go away but the ftsIndexerJobDetail error persists.
8. I notice that I cannot delete the rogue user's home space using the web interface so I delete it from the database (it was empty when I deleted it).
9. We rebuild the Lucene indexes
10. Still the ftsIndexerJobDetail error persists and in fact now it is more frequent.

This is the startup log.
I am not really concerned about the netBios/samba error because I know what causes this (a clash with an other application) and have tested it with the other application not running.

INFO: Deploying web application archive alfresco.war
19:16:58,009 WARN  [remoting.rmi.RmiRegistryFactoryBean] Could not detect RMI re gistry - creating new one
19:17:01,831 WARN  [alfresco.util.OpenOfficeConnectionTester] A connection to Op enOffice could not be established.
19:17:47,662 INFO  [domain.schema.SchemaBootstrap] No changes were made to the s chema.
19:17:54,415 INFO  [repo.admin.ConfigurationChecker] The Alfresco root data dire ctory ('dir.root') is: /data/alfresco
19:17:56,983 INFO  [admin.patch.PatchExecuter] Checking for patches to apply …
19:17:57,225 INFO  [repo.module.ModuleServiceImpl] Found 0 module(s).
19:17:57,576 INFO  [service.descriptor.DescriptorService] Alfresco JVM - v1.5.0_ 11-b03; maximum heap size 933.750MB
19:17:57,576 ERROR [smb.protocol.netbios] NetBIOSNameServer setup error:
java.net.BindException: Address already in use
        at java.net.PlainDatagramSocketImpl.bind0(Native Method)
        at
java.net.PlainDatagramSocketImpl.bind(PlainDatagramSocketImpl.java:82
)
        at java.net.DatagramSocket.bind(DatagramSocket.java:368)
        at java.net.DatagramSocket.<init>(DatagramSocket.java:210)
        at java.net.DatagramSocket.<init>(DatagramSocket.java:261)
        at java.net.DatagramSocket.<init>(DatagramSocket.java:234)
        at
org.alfresco.filesys.netbios.server.NetBIOSNameServer.openSocket(NetB
IOSNameServer.java:1084)
        at
org.alfresco.filesys.netbios.server.NetBIOSNameServer.run(NetBIOSName
Server.java:1556)
        at java.lang.Thread.run(Thread.java:595)
19:17:57,578 INFO  [service.descriptor.DescriptorService] Alfresco started (Comm unity Network): Current version 2.1.0 (R1 443) schema 62 - Installed version 1.4 .0 (build-105) schema 21
19:17:57,593 ERROR [alfresco.smb.protocol] Server error : 
java.net.BindException: Address already in use
        at java.net.PlainSocketImpl.socketBind(Native Method)
        at java.net.PlainSocketImpl.bind(PlainSocketImpl.java:359)
        at java.net.ServerSocket.bind(ServerSocket.java:319)
        at java.net.ServerSocket.<init>(ServerSocket.java:185)
        at java.net.ServerSocket.<init>(ServerSocket.java:141)
        at
org.alfresco.filesys.smb.server.SessionSocketHandler.initialize(Sessi
onSocketHandler.java:257)
        at
org.alfresco.filesys.smb.server.NetBIOSSessionSocketHandler.createSes
sionHandlers(NetBIOSSessionSocketHandler.java:165)
        at
org.alfresco.filesys.smb.server.SMBServer.run(SMBServer.java:495)
        at java.lang.Thread.run(Thread.java:595)
19:18:09,477 ERROR [quartz.core.JobRunShell] Job DEFAULT.ftsIndexerJobDetail thr ew an unhandled Exception: 
org.alfresco.service.cmr.repository.ContentIOException: Failed to open stream on to channel: 
   accessor:
ContentAccessor[ contentUrl=store://2007/8/21/19/18/6ef3582e-4fc7-1
1dc-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.indexProper
ty(ADMLuceneIndexerImpl.java:893)
        at
org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.createDocum
ents(ADMLuceneIndexerImpl.java:547)
        at
org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.updateFullT
extSearch(ADMLuceneIndexerImpl.java:1286)
        at
org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.in
dex(FullTextSearchIndexerImpl.java:188)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
java:39)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
sorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflecti
on(AopUtils.java:281)
        at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJo
inpoint(ReflectiveMethodInvocation.java:187)
        at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:154)
        at
org.springframework.transaction.interceptor.TransactionInterceptor.in
voke(TransactionInterceptor.java:107)
        at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:176)
        at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynami
cAopProxy.java:210)
        at $Proxy50.index(Unknown Source)
        at
org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSInd
exerJob.java:52)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool $WorkerThread.run(SimpleThreadPool.j
ava:529)
Caused by: java.lang.UnsupportedOperationException: The content never exists
        at
org.alfresco.repo.content.EmptyContentReader.getDirectReadableChannel
(EmptyContentReader.java:59)
        at
org.alfresco.repo.content.AbstractContentReader.getReadableChannel(Ab
stractContentReader.java:226)
        at
org.alfresco.repo.content.AbstractContentReader.getContentInputStream
(AbstractContentReader.java:330)
        … 18 more
19:18:09,485 ERROR [quartz.core.ErrorLogger] Job (DEFAULT.ftsIndexerJobDetail th rew an exception.
org.quartz.SchedulerException: Job threw an unhandled exception. [See nested exc
eption: org.alfresco.service.cmr.repository.ContentIOException: Failed to open s tream onto channel: 
   accessor:
ContentAccessor[ contentUrl=store://2007/8/21/19/18/6ef3582e-4fc7-1
1dc-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.j
ava:529)
Caused by: org.alfresco.service.cmr.repository.ContentIOException:
Failed to ope
n stream onto channel: 
   accessor:
ContentAccessor[ contentUrl=store://2007/8/21/19/18/6ef3582e-4fc7-1
1dc-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.indexProper
ty(ADMLuceneIndexerImpl.java:893)
        at
org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.createDocum
ents(ADMLuceneIndexerImpl.java:547)
        at
org.alfresco.repo.search.impl.lucene.ADMLuceneIndexerImpl.updateFullT
extSearch(ADMLuceneIndexerImpl.java:1286)
        at
org.alfresco.repo.search.impl.lucene.fts.FullTextSearchIndexerImpl.in
dex(FullTextSearchIndexerImpl.java:188)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
java:39)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
sorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflecti
on(AopUtils.java:281)
        at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJo
inpoint(ReflectiveMethodInvocation.java:187)
        at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:154)
        at
org.springframework.transaction.interceptor.TransactionInterceptor.in
voke(TransactionInterceptor.java:107)
        at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:176)
        at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynami
cAopProxy.java:210)
        at $Proxy50.index(Unknown Source)
        at
org.alfresco.repo.search.impl.lucene.fts.FTSIndexerJob.execute(FTSInd
exerJob.java:52)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        … 1 more
Caused by: java.lang.UnsupportedOperationException: The content never exists
        at
org.alfresco.repo.content.EmptyContentReader.getDirectReadableChannel
(EmptyContentReader.java:59)
        at
org.alfresco.repo.content.AbstractContentReader.getReadableChannel(Ab
stractContentReader.java:226)
        at
org.alfresco.repo.content.AbstractContentReader.getContentInputStream
(AbstractContentReader.java:330)
        … 18 more

‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[derek]

Hi,
There's bug in the index code that causes the failure, when it should be able to handle the case.  There's definitely some content missing and I can't account for that, perhaps it is in the contentstore.deleted folder or in a backup somewhere.  In the meantime, create a file at the location 2007/8/21/19/18/6ef3582e-4fc7-11dc-8a60-73aa86343014.bin.  Make it a plain-text UTF-8 file that contains the letters "NICM" only.  Then the indexer will at least find the file and index it under the acronym normally reserved for missing content.
Regards

[gcoleman]

But the point is, every time it throws that error, the location (2007/8/21/19/18/6ef3582e-4fc7-11dc-8a60-73aa86343014.bin) is different and the time represented by the directory is same as the time the error is thrown. I don't doubt that something is missing, but i don't think the error is actually reporting what the missing file is.

I will send some more logs to demonstrate what I mean.