[ 
https://issues.apache.org/jira/browse/CXF-5762?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Przemysław Ołtarzewski updated CXF-5762:
----------------------------------------

    Description: 
We are using CXF with Async HTTP Transport to call web services of another 
system (about 15000 requests per day). Some messages sent each day end in 
SocketTimeoutException. About 15-30 out of them cause connection leak (logs 
provided below).

{noformat}
2014.05.23 08:27:26.801 
org.apache.cxf.services.SubscriberLineManagerPortTypeService.SubscriberLineManagerPortTypePort.SubscriberLineManagerPortType
 INFO  [HLAPI-68] AbstractLoggingInterceptor:239 Outbound Message
---------------------------
ID: 277
Address: 
http://10.250.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager
Encoding: UTF-8
Http-Method: POST
Content-Type: text/xml
Headers: {Accept=[*/*], Connection=[Keep-Alive], SOAPAction=["urn:getAll"]}
Payload: <?xml version="1.0" encoding="UTF-8"?>
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/";>
  <soap:Body>
    <ns2:getAll xmlns="http://pojo.web.api.icc.services.osp.in.alcatel.com/xsd"; 
xmlns:ns2="http://implementation.web.api.icc.services.osp.in.alcatel.com"; 
xmlns:ns3="http://web.api.icc.services.osp.in.alcatel.com/xsd"; 
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";>
      <ns2:subscriberLineId>
        <ceSepGroupName xsi:nil="true"/>
        <communityId xsi:nil="true"/>
        <platformName xsi:nil="true"/>
        <serviceRetailerName>HEYAH</serviceRetailerName>
        <subscriberLineId>0048888522289</subscriberLineId>
        <subscriberLineIdType>1</subscriberLineIdType>
        <validityDate xsi:nil="true"/>
      </ns2:subscriberLineId>
      <ns2:additionalParameters>
        <chargingCommand xsi:nil="true"/>
        <depth>1</depth>
        <extCorrelationIdentifier>71001465||</extCorrelationIdentifier>
      </ns2:additionalParameters>
    </ns2:getAll>
  </soap:Body>
</soap:Envelope>

--------------------------------------
2014.05.23 08:27:26.802 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
[HLAPI-68] DefaultAsyncRequestDirector:208 [exchange: 277] start execution
2014.05.23 08:27:26.803 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
[HLAPI-68] DefaultAsyncRequestDirector:625 [exchange: 277] Request connection 
for {}->http://10.250.32.140:8082
2014.05.23 08:27:26.804 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2 DEBUG 
[HLAPI-68] PoolingClientAsyncConnectionManager:172 Connection request: [route: 
{}->http://10.250.32.140:8082][total kept alive: 2; route allocated: 2 of 1000; 
total allocated: 2 of 5000]
2014.05.23 08:27:26.805 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2 DEBUG 
[HLAPI-68] PoolingClientAsyncConnectionManager$InternalPoolEntryCallback:297 
Connection leased: [id: 72][route: {}->http://10.250.32.140:8082][total kept 
alive: 1; route allocated: 2 of 1000; total allocated: 2 of 5000]
2014.05.23 08:27:26.805 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
[HLAPI-68] DefaultAsyncRequestDirector:558 [exchange: 277] Connection 
allocated: [id:72][route:{}->http://10.250.32.140:8082][state:null]
2014.05.23 08:27:46.838 org.apache.cxf.phase.PhaseInterceptorChain WARN  
[HLAPI-68] LogUtils:452 Interceptor for 
{http://implementation.web.api.icc.services.osp.in.alcatel.com}SubscriberLineM
anagerPortTypeService#{http://implementation.web.api.icc.services.osp.in.alcatel.com}getAll
 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:272)
        at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:570)
        at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:479)
        at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:382)
        at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:335)
        at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
        at 
org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:135)
        at $Proxy88.getAll(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at 
pl.infovide.inconfig.bep.backend.hlapi.HlapiCommunicator.send(HlapiCommunicator.java:212)
        at 
pl.infovide.inconfig.bep.backend.hlapi.HlapiBackend.send(HlapiBackend.java:26)
        at 
pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.forwardRequest(UnifiedBackendImpl.java:230)
        at 
pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.access$000(UnifiedBackendImpl.java:34)
        at 
pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl$SenderTask.run(UnifiedBackendImpl.java:316)
        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)
Caused by: java.net.SocketTimeoutException: SocketTimeoutException invoking 
http://10.250.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager: 
Read Timeout
        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:1347)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1331)
        at 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.close(AsyncHTTPConduit.java:383)
        at 
org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56)
        at 
org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:223)
        at 
org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
        at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:632)
        at 
org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
        ... 19 common frames omitted
Caused by: java.net.SocketTimeoutException: Read Timeout
        at 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.getHttpResponse(AsyncHTTPConduit.java:583)
        at 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.getResponseCode(AsyncHTTPConduit.java:674)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1543)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1513)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1318)
        ... 25 common frames omitted
{noformat}

The connection allocated (id: 72) is never released to the connection pool.

The main detail about scenario that causes the connection leak is no further 
activity during the exchange after connection allocation. In particular, there 
is no indication that the request processing has even started - the following 
line is missing from log (copied from correct exchange):

{noformat}
2014.05.23 12:15:32.372 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG [I/O 
dispatcher 18] DefaultAsyncRequestDirector:313 [exchange: 5144] Attempt 1 to 
execute request
{noformat}

In other cases with the same exception, there are some bytes sent / events set 
on the exchange etc. and the connection is correctly aborted afterwards, but in 
this specific case the connection just leaks silently. Leaked connections 
accumulate in the pool and after some time make it unusable.

Relevant configuration parameters:

ReceiveTimeout=20000
ConnectionTimeout=20000
use.async.http.conduit=true

Keep-alive time is 5000 ms.

The problem is critical since with pool size of 1000 connections per route and 
using a single route, we are forced to restart our service every 1-2 months and 
are unable to provide high availability requested by our business client.

A workaround for us would be to use the default, synchronous HTTP Transport, 
however we have noticed that sometimes it attempts to send a request via a 
connection that is already half-closed by the server side. Has this issue been 
diagnosed / fixed?

  was:
We are using CXF with Async HTTP Transport to call web services of another 
system (about 15000 requests per day). Some messages sent each day end in 
SocketTimeoutException. About 15-30 out of them cause connection leak (logs 
provided below).

{noformat}
2014.05.23 08:27:26.801 
org.apache.cxf.services.SubscriberLineManagerPortTypeService.SubscriberLineManagerPortTypePort.SubscriberLineManagerPortType
 INFO  [HLAPI-68] AbstractLoggingInterceptor:239 Outbound Message
---------------------------
ID: 277
Address: 
http://10.250.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager
Encoding: UTF-8
Http-Method: POST
Content-Type: text/xml
Headers: {Accept=[*/*], Connection=[Keep-Alive], SOAPAction=["urn:getAll"]}
Payload: <?xml version="1.0" encoding="UTF-8"?>
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/";>
  <soap:Body>
    <ns2:getAll xmlns="http://pojo.web.api.icc.services.osp.in.alcatel.com/xsd"; 
xmlns:ns2="http://implementation.web.api.icc.services.osp.in.alcatel.com"; 
xmlns:ns3="http://web.api.icc.services.osp.in.alcatel.com/xsd"; 
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";>
      <ns2:subscriberLineId>
        <ceSepGroupName xsi:nil="true"/>
        <communityId xsi:nil="true"/>
        <platformName xsi:nil="true"/>
        <serviceRetailerName>HEYAH</serviceRetailerName>
        <subscriberLineId>0048888522289</subscriberLineId>
        <subscriberLineIdType>1</subscriberLineIdType>
        <validityDate xsi:nil="true"/>
      </ns2:subscriberLineId>
      <ns2:additionalParameters>
        <chargingCommand xsi:nil="true"/>
        <depth>1</depth>
        <extCorrelationIdentifier>71001465||</extCorrelationIdentifier>
      </ns2:additionalParameters>
    </ns2:getAll>
  </soap:Body>
</soap:Envelope>

--------------------------------------
2014.05.23 08:27:26.802 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
[HLAPI-68] DefaultAsyncRequestDirector:208 [exchange: 277] start execution
2014.05.23 08:27:26.803 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
[HLAPI-68] DefaultAsyncRequestDirector:625 [exchange: 277] Request connection 
for {}->http://10.250.32.140:8082
2014.05.23 08:27:26.804 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2 DEBUG 
[HLAPI-68] PoolingClientAsyncConnectionManager:172 Connection request: [route: 
{}->http://10.250.32.140:8082][total kept alive: 2; route allocated: 2 of 1000; 
total allocated: 2 of 5000]
2014.05.23 08:27:26.805 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2 DEBUG 
[HLAPI-68] PoolingClientAsyncConnectionManager$InternalPoolEntryCallback:297 
Connection leased: [id: 72][route: {}->http://10.250.32.140:8082][total kept 
alive: 1; route allocated: 2 of 1000; total allocated: 2 of 5000]
2014.05.23 08:27:26.805 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
[HLAPI-68] DefaultAsyncRequestDirector:558 [exchange: 277] Connection 
allocated: [id:72][route:{}->http://10.250.32.140:8082][state:null]
2014.05.23 08:27:46.838 org.apache.cxf.phase.PhaseInterceptorChain WARN  
[HLAPI-68] LogUtils:452 Interceptor for 
{http://implementation.web.api.icc.services.osp.in.alcatel.com}SubscriberLineM
anagerPortTypeService#{http://implementation.web.api.icc.services.osp.in.alcatel.com}getAll
 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:272)
        at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:570)
        at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:479)
        at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:382)
        at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:335)
        at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
        at 
org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:135)
        at $Proxy88.getAll(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at 
pl.infovide.inconfig.bep.backend.hlapi.HlapiCommunicator.send(HlapiCommunicator.java:212)
        at 
pl.infovide.inconfig.bep.backend.hlapi.HlapiBackend.send(HlapiBackend.java:26)
        at 
pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.forwardRequest(UnifiedBackendImpl.java:230)
        at 
pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.access$000(UnifiedBackendImpl.java:34)
        at 
pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl$SenderTask.run(UnifiedBackendImpl.java:316)
        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)
Caused by: java.net.SocketTimeoutException: SocketTimeoutException invoking 
http://10.250.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager: 
Read Timeout
        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:1347)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1331)
        at 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.close(AsyncHTTPConduit.java:383)
        at 
org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56)
        at 
org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:223)
        at 
org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
        at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:632)
        at 
org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
        ... 19 common frames omitted
Caused by: java.net.SocketTimeoutException: Read Timeout
        at 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.getHttpResponse(AsyncHTTPConduit.java:583)
        at 
org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.getResponseCode(AsyncHTTPConduit.java:674)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1543)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1513)
        at 
org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1318)
        ... 25 common frames omitted
{noformat}

The connection allocated (id: 72) is never released to the connection pool.

The main detail about scenario that causes the memory leak is no further 
activity during the exchange (see exchange: 277) after connection allocation.
In other cases with the same exception, there are some bytes sent / events set 
on the exchange etc. and the connection is correctly aborted afterwards, but in 
this specific case the connection just leaks silently.
Leaked connections accumulate in the pool and after some time make it unusable.

Relevant configuration parameters:

ReceiveTimeout=20000
ConnectionTimeout=20000
use.async.http.conduit=true

Keep-alive time is 5000 ms.

The problem is critical since with pool size of 1000 connections per route and 
using a single route, we are forced to restart our service every 1-2 months and 
are unable to provide high availability requested by our business client.

A workaround for us would be to use the default, synchronous HTTP Transport, 
however we have noticed that sometimes it attempts to send a request via a 
connection that is already half-closed by the server side. Has this issue been 
diagnosed / fixed?


> Connection leak after SocketTimeoutException using Asynchronous Client HTTP 
> Transport
> -------------------------------------------------------------------------------------
>
>                 Key: CXF-5762
>                 URL: https://issues.apache.org/jira/browse/CXF-5762
>             Project: CXF
>          Issue Type: Bug
>          Components: Transports
>    Affects Versions: 2.7.11
>         Environment: SunOS 5.10 Generic_147440-25 sun4v sparc 
> SUNW,SPARC-Enterprise-T5120, 64bit
>            Reporter: Przemysław Ołtarzewski
>
> We are using CXF with Async HTTP Transport to call web services of another 
> system (about 15000 requests per day). Some messages sent each day end in 
> SocketTimeoutException. About 15-30 out of them cause connection leak (logs 
> provided below).
> {noformat}
> 2014.05.23 08:27:26.801 
> org.apache.cxf.services.SubscriberLineManagerPortTypeService.SubscriberLineManagerPortTypePort.SubscriberLineManagerPortType
>  INFO  [HLAPI-68] AbstractLoggingInterceptor:239 Outbound Message
> ---------------------------
> ID: 277
> Address: 
> http://10.250.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager
> Encoding: UTF-8
> Http-Method: POST
> Content-Type: text/xml
> Headers: {Accept=[*/*], Connection=[Keep-Alive], SOAPAction=["urn:getAll"]}
> Payload: <?xml version="1.0" encoding="UTF-8"?>
> <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/";>
>   <soap:Body>
>     <ns2:getAll 
> xmlns="http://pojo.web.api.icc.services.osp.in.alcatel.com/xsd"; 
> xmlns:ns2="http://implementation.web.api.icc.services.osp.in.alcatel.com"; 
> xmlns:ns3="http://web.api.icc.services.osp.in.alcatel.com/xsd"; 
> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";>
>       <ns2:subscriberLineId>
>         <ceSepGroupName xsi:nil="true"/>
>         <communityId xsi:nil="true"/>
>         <platformName xsi:nil="true"/>
>         <serviceRetailerName>HEYAH</serviceRetailerName>
>         <subscriberLineId>0048888522289</subscriberLineId>
>         <subscriberLineIdType>1</subscriberLineIdType>
>         <validityDate xsi:nil="true"/>
>       </ns2:subscriberLineId>
>       <ns2:additionalParameters>
>         <chargingCommand xsi:nil="true"/>
>         <depth>1</depth>
>         <extCorrelationIdentifier>71001465||</extCorrelationIdentifier>
>       </ns2:additionalParameters>
>     </ns2:getAll>
>   </soap:Body>
> </soap:Envelope>
> --------------------------------------
> 2014.05.23 08:27:26.802 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
> [HLAPI-68] DefaultAsyncRequestDirector:208 [exchange: 277] start execution
> 2014.05.23 08:27:26.803 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
> [HLAPI-68] DefaultAsyncRequestDirector:625 [exchange: 277] Request connection 
> for {}->http://10.250.32.140:8082
> 2014.05.23 08:27:26.804 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2 DEBUG 
> [HLAPI-68] PoolingClientAsyncConnectionManager:172 Connection request: 
> [route: {}->http://10.250.32.140:8082][total kept alive: 2; route allocated: 
> 2 of 1000; total allocated: 2 of 5000]
> 2014.05.23 08:27:26.805 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2 DEBUG 
> [HLAPI-68] PoolingClientAsyncConnectionManager$InternalPoolEntryCallback:297 
> Connection leased: [id: 72][route: {}->http://10.250.32.140:8082][total kept 
> alive: 1; route allocated: 2 of 1000; total allocated: 2 of 5000]
> 2014.05.23 08:27:26.805 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
> [HLAPI-68] DefaultAsyncRequestDirector:558 [exchange: 277] Connection 
> allocated: [id:72][route:{}->http://10.250.32.140:8082][state:null]
> 2014.05.23 08:27:46.838 org.apache.cxf.phase.PhaseInterceptorChain WARN  
> [HLAPI-68] LogUtils:452 Interceptor for 
> {http://implementation.web.api.icc.services.osp.in.alcatel.com}SubscriberLineM
> anagerPortTypeService#{http://implementation.web.api.icc.services.osp.in.alcatel.com}getAll
>  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:272)
>         at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:570)
>         at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:479)
>         at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:382)
>         at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:335)
>         at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
>         at 
> org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:135)
>         at $Proxy88.getAll(Unknown Source)
>         at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
>         at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>         at java.lang.reflect.Method.invoke(Method.java:597)
>         at 
> pl.infovide.inconfig.bep.backend.hlapi.HlapiCommunicator.send(HlapiCommunicator.java:212)
>         at 
> pl.infovide.inconfig.bep.backend.hlapi.HlapiBackend.send(HlapiBackend.java:26)
>         at 
> pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.forwardRequest(UnifiedBackendImpl.java:230)
>         at 
> pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.access$000(UnifiedBackendImpl.java:34)
>         at 
> pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl$SenderTask.run(UnifiedBackendImpl.java:316)
>         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)
> Caused by: java.net.SocketTimeoutException: SocketTimeoutException invoking 
> http://10.250.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager: 
> Read Timeout
>         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:1347)
>         at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1331)
>         at 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.close(AsyncHTTPConduit.java:383)
>         at 
> org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56)
>         at 
> org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:223)
>         at 
> org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
>         at 
> org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:632)
>         at 
> org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
>         ... 19 common frames omitted
> Caused by: java.net.SocketTimeoutException: Read Timeout
>         at 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.getHttpResponse(AsyncHTTPConduit.java:583)
>         at 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.getResponseCode(AsyncHTTPConduit.java:674)
>         at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1543)
>         at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1513)
>         at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1318)
>         ... 25 common frames omitted
> {noformat}
> The connection allocated (id: 72) is never released to the connection pool.
> The main detail about scenario that causes the connection leak is no further 
> activity during the exchange after connection allocation. In particular, 
> there is no indication that the request processing has even started - the 
> following line is missing from log (copied from correct exchange):
> {noformat}
> 2014.05.23 12:15:32.372 
> org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3 DEBUG 
> [I/O dispatcher 18] DefaultAsyncRequestDirector:313 [exchange: 5144] Attempt 
> 1 to execute request
> {noformat}
> In other cases with the same exception, there are some bytes sent / events 
> set on the exchange etc. and the connection is correctly aborted afterwards, 
> but in this specific case the connection just leaks silently. Leaked 
> connections accumulate in the pool and after some time make it unusable.
> Relevant configuration parameters:
> ReceiveTimeout=20000
> ConnectionTimeout=20000
> use.async.http.conduit=true
> Keep-alive time is 5000 ms.
> The problem is critical since with pool size of 1000 connections per route 
> and using a single route, we are forced to restart our service every 1-2 
> months and are unable to provide high availability requested by our business 
> client.
> A workaround for us would be to use the default, synchronous HTTP Transport, 
> however we have noticed that sometimes it attempts to send a request via a 
> connection that is already half-closed by the server side. Has this issue 
> been diagnosed / fixed?



--
This message was sent by Atlassian JIRA
(v6.2#6252)

Reply via email to