socketexceptionatgendeca

CAS Recordstore SocketTimeoutException


While indexing from ATG, consistently we are getting the below error:

Caused by: java.net.SocketTimeoutException: SocketTimeoutException invoking http://(endeca-server):8500/ExmProd_en_data/: Read timed out


Here are the logs:

JBoss server (ATG):

2015-05-17 19:07:12,278 INFO  [nucleusNamespace.atg.endeca.index.DataDocumentSubmitter] (ProcessItemThread-482) Will attempt to contact record store "ExmProd_en_data" on host "<endeca-server>" on port 8,500
...
(/atg/dynamo/service/Scheduler-reusablejobhandler-ProductCatalogSimpleIndexingAdmin - Baseline) Bulk load completed with "true" result in 6,097,145 milliseconds.
2015-05-17 20:48:37,330 INFO  [nucleusNamespace.atg.endeca.index.SchemaDocumentSubmitter] (/atg/dynamo/service/Scheduler-reusablejobhandler-ProductCatalogSimpleIndexingAdmin - Baseline) Ending session of record store ExmProd_en_schema with transactionId 48 (submitted 11,531 records).
2015-05-17 20:48:37,415 INFO  [nucleusNamespace.atg.endeca.index.DimensionDocumentSubmitter] (/atg/dynamo/service/Scheduler-reusablejobhandler-ProductCatalogSimpleIndexingAdmin - Baseline) Ending session of record store ExmProd_en_dimvals with transactionId 48 (submitted 178,870 records).
2015-05-17 20:48:38,112 INFO  [nucleusNamespace.atg.endeca.index.DataDocumentSubmitter] (/atg/dynamo/service/Scheduler-reusablejobhandler-ProductCatalogSimpleIndexingAdmin - Baseline) Ending session of record store ExmProd_en_data with transactionId 48 (submitted 1,127,618 records).
...
2015-05-17 21:18:38,164 WARN  [org.apache.cxf.phase.PhaseInterceptorChain] (/atg/dynamo/service/Scheduler-reusablejobhandler-ProductCatalogSimpleIndexingAdmin - Baseline) Interceptor for {http://recordstore.itl.endeca.com/}RecordStoreService#{http://recordstore.itl.endeca.com/}commitTransaction has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: Could not send Message.
    at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:64)
    at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262)
    at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:532)
    at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:464)
    at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:367)
    at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:320)
    at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:89)
    at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:134)
    at com.sun.proxy.$Proxy179.commitTransaction(Unknown Source)
    at atg.endeca.index.RecordStoreDocumentSubmitterSessionImpl.endSession(RecordStoreDocumentSubmitterSessionImpl.java:593)
    at atg.endeca.index.AbstractRecordStoreAggregateSession.commitPending(AbstractRecordStoreAggregateSession.java:494)
    at atg.endeca.index.AbstractRecordStoreAggregateSession.endSession(AbstractRecordStoreAggregateSession.java:432)
    at atg.endeca.index.RecordSubmitterImpl.endSession(RecordSubmitterImpl.java:231)
    at atg.endeca.index.admin.IndexingPhase.doPhaseCleanup(IndexingPhase.java:376)
    at atg.endeca.index.admin.IndexingPhase.performPhaseTasks(IndexingPhase.java:324)
    at atg.endeca.index.admin.IndexingPhase.performPhaseTasksSerially(IndexingPhase.java:243)
    at atg.endeca.index.admin.IndexingJob.performJobSerially(IndexingJob.java:281)
    at com.example.commerce.endeca.index.admin.EXMSimpleIndexingAdmin.indexBaseline(EXMSimpleIndexingAdmin.java:428)
    at atg.endeca.index.admin.SimpleIndexingAdmin.indexBaseline(SimpleIndexingAdmin.java:637)
    at com.example.commerce.endeca.index.admin.EXMSimpleIndexingAdmin.indexBaseline(EXMSimpleIndexingAdmin.java:262)
    at atg.endeca.index.admin.SimpleIndexingAdmin.performScheduledTask(SimpleIndexingAdmin.java:867)
    at atg.service.scheduler.ScheduledJob.runJobs(ScheduledJob.java:479)
    at atg.service.scheduler.Scheduler$2handler.run(Scheduler.java:780)
Caused by: java.net.SocketTimeoutException: SocketTimeoutException invoking http://<endeca-server>:8500/ExmProd_en_data/: Read timed out
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
    at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.mapException(HTTPConduit.java:1457)
    at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1442)
    at org.apache.cxf.io.AbstractWrappedOutputStream.close(AbstractWrappedOutputStream.java:72)
    at org.apache.cxf.io.AbstractThresholdOutputStream.close(AbstractThresholdOutputStream.java:102)
    at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
    at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:658)
    at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
    ... 22 more
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:129)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:698)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:641)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1218)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:379)
    at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1577)
    at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1520)
    at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1428)
    ... 27 more

Endeca CAS server (cas-service.log):
(No ERRORs were found in the log, only the below WARNing is getting repeated often)

2015-05-15 03:13:02,486 WARN [ExmProd_en_data] [ExmProd_en_data-cleaner-1] com.endeca.itl.recordstore.impl.Cleaner: Exception caught while performing cleanup
java.lang.UnsupportedOperationException: Cleans while transactions are active not implemented yet
    at com.endeca.itl.recordstore.impl.RecordStoreImpl.clean(RecordStoreImpl.java:566)
    at com.endeca.itl.recordstore.impl.Cleaner$1.run(Cleaner.java:30)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
    at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)
    at com.endeca.itl.util.LoggingContextAwareThread.run(LoggingContextAwareThread.java:26)

ATG Version: 10.2 (ProductCatalogSimpleIndexingAdmin)
Endeca Version: 3.1.2 (pipeline based, i.e., Forge -> Dgidx).

Any help in fixing this issue is much appreciated.


Solution

  • Digged through the source code and figured out that the class com.endeca.itl.service.ServiceLocator has a socket timeout setting for this.


    Solution:

    Set the environment variable com.endeca.itl.socketReceiveTimeout to a much higher value than the current socket timeout time.

    For example, –Dcom.endeca.itl.socketReceiveTimeout=3600000 in your appropriate java VM of the server and rerun).

    (Default is 30 minutes = 1800000 milli seconds).

    (It’s so unfortunate that Oracle didn’t document such an important environment-specific configuration anywhere and what’s even more surprising is that such configuration are kept in private fields with read-only access; This should have been an explicit property in all the IndexingOutputConfig components).