[Alfresco 5.0.d] 100% CPU usage and Read timed out error

[jonnypa]

Hi,

in a production environment (Alfresco 5.0.d, SOLR4, 8 Core, 20 GB RAM) suddenly we're experiencing an annoying problem: Cpu usage is costantly 100%. This error appears on catalina.out:

java.net.SocketTimeoutException: Read timed out
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:150)
        at java.net.SocketInputStream.read(SocketInputStream.java:121)
        at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
        at sun.security.ssl.InputRecord.read(InputRecord.java:503)
        at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:961)
        at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:918)
        at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        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.httpclient.AbstractHttpClient.executeMethod(AbstractHttpClient.java:135)
        at org.alfresco.httpclient.AbstractHttpClient.sendRemoteRequest(AbstractHttpClient.java:111)
        at org.alfresco.httpclient.HttpClientFactory$HttpsClient.sendRequest(HttpClientFactory.java:385)
        at org.alfresco.solr.client.SOLRAPIClient.getTextContent(SOLRAPIClient.java:1024)
        at org.alfresco.solr.SolrInformationServer.addContentPropertyToDocUsingAlfrescoRepository(SolrInformationServer.java:2451)
        at org.alfresco.solr.SolrInformationServer.addContentToDoc(SolrInformationServer.java:2438)
        at org.alfresco.solr.SolrInformationServer.updateContentToIndexAndCache(SolrInformationServer.java:2372)
        at org.alfresco.solr.tracker.ContentTracker$ContentIndexWorkerRunnable.doWork(ContentTracker.java:133)
        at org.alfresco.solr.tracker.AbstractWorkerRunnable.run(AbstractWorkerRunnable.java:40)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

We tried a SOLR reindex but nothing has changed. 

Can someone help me? Thanks in advance

[angelborroy]

You need to identify the service that is consuming that CPU. Using some profiling tool could help for this purpose.

[jonnypa]

Hi, thank for this hint, using jvmtop (my envorinment is a Centos 7 Server, without GUI) this is the output:

  99.95% (     1.70s) ....alfresco.repo.content.transform.TikaPoweredContentTr()
   0.02% (     0.00s) org.alfresco.httpclient.AbstractHttpClient.executeMethod()
   0.01% (     0.00s) com.mysql.jdbc.Messages.getString()
   0.01% (     0.00s) com.mysql.jdbc.MysqlIO.readPacket()
   0.01% (     0.00s) com.mysql.jdbc.util.ReadAheadInputStream.fill()
   0.01% (     0.00s) ....mysql.jdbc.ConnectionPropertiesImpl.exposeAsProperti()
   0.00% (     0.00s) ....alfresco.repo.transaction.TransactionServiceImpl.get()
   0.00% (     0.00s) ....mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnect()
   0.00% (     0.00s) org.alfresco.jlan.netbios.server.NetBIOSNameServer.run()
   0.00% (     0.00s) org.alfresco.jlan.netbios.NetBIOSSession.DecodeName()
   0.00% (     0.00s) ....alfresco.util.exec.RuntimeExec$InputStreamReaderThre()
   0.00% (     0.00s) ....alfresco.jlan.smb.server.nio.NIOCifsConnectionsHandl()
   0.00% (     0.00s) org.mortbay.jetty.bio.SocketConnector.accept()

so alfresco.repo.content.transform.TikaPoweredContentTr() is consuming all resources. Why?

[angelborroy · Accepted solution]

The problems seems related to PDF Transformation.

Not sure if that is the same issue, but I created some patch for something similar in:

https://github.com/keensoft/alf-21970-repo

[jonnypa]

Thank you for your reply. I can confirm that the problems were related to PDF Transformation. 

Following your suggestions regarding java process monitoring and this issue, I've enabled DEBUG logging for alfresco.repo.content.transform.TransformerDebug and I found some documents with transformation issues. 

Deleting these documents and restarting Alfresco, all CPU values ​​are back to normal.

Best regards.