Index unrecoverable error

[upforsin]

Hello,

since a couple of days, I'm getting an "Index tracking batch hit an unrecoverable error " log in the SOLR 6.6.5 (search services 1.3.0.1).

2021-02-11 22:49:31.749 WARN (SolrTrackingPool-alfresco-ContentTracker-2) [ ] o.a.s.t.AbstractWorkerRunnable Index tracking batch hit an unrecoverable error
org.alfresco.error.AlfrescoRuntimeException: 01121205 GetTextContentResponse return status is 500
	at org.alfresco.solr.client.SOLRAPIClient.getTextContent(SOLRAPIClient.java:1119)
	at org.alfresco.solr.SolrInformationServer.addContentPropertyToDocUsingAlfrescoRepository(SolrInformationServer.java:3387)
	at org.alfresco.solr.SolrInformationServer.addContentToDoc(SolrInformationServer.java:3374)
	at org.alfresco.solr.SolrInformationServer.updateContentToIndexAndCache(SolrInformationServer.java:3306)
	at org.alfresco.solr.tracker.ContentTracker$ContentIndexWorkerRunnable.doWork(ContentTracker.java:154)
	at org.alfresco.solr.tracker.AbstractWorkerRunnable.run(AbstractWorkerRunnable.java:45)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

In the alfresco.log I can also see the error, it is printed after org/alfresco/repository/solr/nodeContent.get webscript is executed.

2021-02-11 23:07:00,546 DEBUG [org.springframework.extensions.webscripts.AbstractRuntime] [https-jsse-nio-8443-exec-18] Web Script org/alfresco/repository/solr/nodeContent.get executed in 11.518096ms
2021-02-11 23:07:00,546 ERROR [org.springframework.extensions.webscripts.AbstractRuntime] [https-jsse-nio-8443-exec-18] Exception from executeScript: 01110232 Exception in Transaction.
org.alfresco.error.AlfrescoRuntimeException: 01110232 Exception in Transaction.
	at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:536)
	at org.alfresco.repo.web.scripts.RepositoryContainer.transactionedExecute(RepositoryContainer.java:587)
	at org.alfresco.repo.web.scripts.RepositoryContainer.transactionedExecuteAs(RepositoryContainer.java:656)
	at org.alfresco.repo.web.scripts.RepositoryContainer.executeScriptInternal(RepositoryContainer.java:355)
	at org.alfresco.repo.web.scripts.RepositoryContainer.executeScript(RepositoryContainer.java:308)
	at org.springframework.extensions.webscripts.AbstractRuntime.executeScript(AbstractRuntime.java:399)
	at org.springframework.extensions.webscripts.AbstractRuntime.executeScript(AbstractRuntime.java:210)
	at org.springframework.extensions.webscripts.servlet.WebScriptServlet.service(WebScriptServlet.java:132)
	at org.alfresco.repo.web.scripts.AlfrescoWebScriptServlet.service(AlfrescoWebScriptServlet.java:43)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.alfresco.module.aosmodule.service.ContextRootFilter.doFilter(ContextRootFilter.java:93)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.alfresco.web.scripts.servlet.X509ServletFilterBase.doFilter(X509ServletFilterBase.java:144)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.alfresco.web.app.servlet.GlobalLocalizationFilter.doFilter(GlobalLocalizationFilter.java:68)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.alfresco.web.app.servlet.ClearSecurityContextFilter.doFilter(ClearSecurityContextFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NoSuchMethodError: org.apache.commons.io.IOUtils.toString(Ljava/io/InputStream;Ljava/nio/charset/Charset;)Ljava/lang/String;
	at org.apache.tika.parser.pkg.ZipContainerDetector.detectOpenDocument(ZipContainerDetector.java:182)
	at org.apache.tika.parser.pkg.ZipContainerDetector.detectZipFormat(ZipContainerDetector.java:134)
	at org.apache.tika.parser.pkg.ZipContainerDetector.detect(ZipContainerDetector.java:88)
	at org.apache.tika.detect.CompositeDetector.detect(CompositeDetector.java:84)
	at org.alfresco.repo.content.MimetypeMap.detectType(MimetypeMap.java:721)
	at org.alfresco.repo.content.MimetypeMap.detectType(MimetypeMap.java:671)
	at org.alfresco.repo.content.MimetypeMap.getMimetypeIfNotMatches(MimetypeMap.java:788)
	at org.alfresco.repo.content.transform.AbstractContentTransformer2.transform(AbstractContentTransformer2.java:338)
	at org.alfresco.repo.web.scripts.solr.NodeContentGet.execute(NodeContentGet.java:214)
	at org.alfresco.repo.web.scripts.RepositoryContainer$3.execute(RepositoryContainer.java:512)
	at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:450)
	... 42 more

Do you have any idea what can cause this issue? For now, everything seems to be working as usual but it produces tens of thousands of logs per day and I'm concerned that something might stop working.

I tried the full reindex, I called action=FIX API, nothing helps. In the SOLR report, everything seems to be alright.

I noticed that this error is printed dozen times every 20 minutes

[sufo]

This seems to be about full-text search (content indexing). Solr tries to get text representation of content to index it. Seems that it is trying to process some zip file. Did you enable transformer.Archive.includeContents=true?
https://docs.alfresco.com/search-enterprise1.3/concepts/search-fts-config.html (bottom of the page)

[upforsin]

@sufo thank you for the answer but no, the only transformer-related properties I have are about maxSourceSizeKBytes.

But you might be right, maybe it is about a less known, "some kind of an archive" file extension. Do you know how can I check which file is causing the issue?

[sufo]

Provided, that you are running repo on Tomcat, you should have localhost_access_log files in your logs directory. Search there for urls like this /alfresco/s/api/solr/textContent?nodeId=xxx which have 500 (error) at second to last position.
Something like this:

192.168.7.18 - - [12/Feb/2021:15:45:40 +0000] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1613144730001&toTime=1613151930001&maxResults=2000 HTTP/1.1" 500 127

The nodeId is sys:node-dbid so you have to find out the noderef from it. Use node browser FTS query: DBID:xxx

[upforsin]

@sufo well, I did not know about that, thank you.

All  .odt  files (Mimetype: OpenDocument Text (OpenOffice 2.0)) are throwing 500 error. Some of them can not be previewed, some of them can. I'm quite confused now 

[sufo]

Are you running docker istallation? Check if the alfresco-libreoffice container is running.
Another test: Upload new .odt document and see if you see pdf preview in its details.

[upforsin · Accepted solution]

@sufo There seems to be an issue with .odt files - none of the newly uploaded files can be previewed. I don't use Docker (manual installation).

I can see soffice.bin is running and the previews of i.e. the .docx or .doc files are working.

Anyway, thanks for helping me to solve this out. Now at least I know that this is mostly only about previewing files.

EDIT. I've found the issue. It was about the custom AMP which had a batik-bridge dependency. After removing the batik-bridge dependency (I tried version 1.13 and 1.14) it works again!

So once more, be aware of the org.apache.xmlgraphics.batik-bridge in your Alfresco projects!

And thank you @sufo for your time, you helped me a lot

EDIT2. Seems like batik-bridge is breaking some commons-io dependency. Adding commons-io dependency also fixed the issue.

[EddieMay]

Hi @upforsin 

Great that you got your problem resolved & thanks for accepting the solution and adding the extra information - really useful to ther users.

Kind regards,

[upforsin · Accepted solution]

Well.. to be honest, I do not think that it is the right solution. It looks like there is a mismatch between commons-io versions.

I need the batik-bridge library for JasperReports library, so for now I strictly added commons-io version 2.4 dependency (it looks like some of the components require at least version 2.3). It also fixed the issue but I'm worried that it broke something else. 

@EddieMay do you know which apache commons-io version should I add? Which version is used by Alfresco components?

[EddieMay]

Hi @upforsin 

It's looking like 2.4. There's also this to check against.

HTH