topic Re: reindexing causes exception in job ftsIndexerJobDetail in Alfresco Archive

reindexing causes exception in job ftsIndexerJobDetail

haroonzc — Thu, 05 Jul 2007 16:21:56 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

kevinr — Thu, 05 Jul 2007 16:48:02 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

haroonzc — Thu, 05 Jul 2007 19:11:57 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

callermd — Sun, 08 Jul 2007 22:48:02 GMT

We have the same exact issue after the DB upgrade.

Re: reindexing causes exception in job ftsIndexerJobDetail

gcoleman — Mon, 20 Aug 2007 23:09:03 GMT

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.

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Tue, 21 Aug 2007 15:40:34 GMT

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/…?

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Tue, 21 Aug 2007 16:07:04 GMT

Can you post the startup logs as well, please?

Re: reindexing causes exception in job ftsIndexerJobDetail

gcoleman — Wed, 22 Aug 2007 03:20:31 GMT

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

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

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Wed, 22 Aug 2007 08:07:42 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

gcoleman — Wed, 22 Aug 2007 08:28:35 GMT

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.

Re: reindexing causes exception in job ftsIndexerJobDetail

gcoleman — Wed, 22 Aug 2007 08:32:22 GMT


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
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Wed, 22 Aug 2007 08:34:48 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Wed, 22 Aug 2007 08:38:24 GMT

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?

Re: reindexing causes exception in job ftsIndexerJobDetail

gcoleman — Wed, 22 Aug 2007 08:47:35 GMT

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.

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Wed, 22 Aug 2007 08:48:06 GMT

Hi,
Please turn on debugging for:

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

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Wed, 22 Aug 2007 08:49:45 GMT

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.

Re: reindexing causes exception in job ftsIndexerJobDetail

gcoleman — Wed, 22 Aug 2007 08:50:11 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

gcoleman — Wed, 22 Aug 2007 08:51:19 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

dcrossma — Wed, 22 Aug 2007 22:53:14 GMT

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

Re: reindexing causes exception in job ftsIndexerJobDetail

derek — Thu, 23 Aug 2007 10:26:05 GMT

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