CAS 记录库 SocketTimeoutException
CAS Recordstore SocketTimeoutException
从 ATG 编制索引时,我们始终收到以下错误:
Caused by: java.net.SocketTimeoutException: SocketTimeoutException
invoking http://(endeca-server):8500/ExmProd_en_data/: Read timed out
这是日志:
JBoss 服务器 (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.Schedulerhandler.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 服务器 (cas-service.log):
(在日志中没有发现错误,只有下面的警告经常重复)
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.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.access1(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 版本:10.2 (ProductCatalogSimpleIndexingAdmin)
Endeca 版本:3.1.2(基于管道,即 Forge -> Dgidx)。
非常感谢任何解决此问题的帮助。
深入研究源代码,发现 class com.endeca.itl.service.ServiceLocator
有一个套接字超时设置。
解决方案:
将环境变量 com.endeca.itl.socketReceiveTimeout
设置为比当前套接字超时时间高得多的值。
例如,–Dcom.endeca.itl.socketReceiveTimeout=3600000
在服务器的适当 java VM 中并重新运行)。
(默认为 30 分钟 = 1800000 毫秒)。
(很遗憾,Oracle 没有在任何地方记录如此重要的特定于环境的配置,更令人惊讶的是,此类配置保存在具有只读访问权限的私有字段中;这应该是一个明确的 属性 在所有 IndexingOutputConfig 组件中)。
从 ATG 编制索引时,我们始终收到以下错误:
Caused by: java.net.SocketTimeoutException: SocketTimeoutException invoking http://(endeca-server):8500/ExmProd_en_data/: Read timed out
这是日志:
JBoss 服务器 (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.Schedulerhandler.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 服务器 (cas-service.log):
(在日志中没有发现错误,只有下面的警告经常重复)
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.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.access1(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 版本:10.2 (ProductCatalogSimpleIndexingAdmin)
Endeca 版本:3.1.2(基于管道,即 Forge -> Dgidx)。
非常感谢任何解决此问题的帮助。
深入研究源代码,发现 class com.endeca.itl.service.ServiceLocator
有一个套接字超时设置。
解决方案:
将环境变量 com.endeca.itl.socketReceiveTimeout
设置为比当前套接字超时时间高得多的值。
例如,–Dcom.endeca.itl.socketReceiveTimeout=3600000
在服务器的适当 java VM 中并重新运行)。
(默认为 30 分钟 = 1800000 毫秒)。
(很遗憾,Oracle 没有在任何地方记录如此重要的特定于环境的配置,更令人惊讶的是,此类配置保存在具有只读访问权限的私有字段中;这应该是一个明确的 属性 在所有 IndexingOutputConfig 组件中)。