cxf-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Przemysław Ołtarzewski (JIRA) <j...@apache.org>
Subject [jira] [Updated] (CXF-5762) Connection leak after SocketTimeoutException using Asynchronous Client HTTP Transport
Date Fri, 23 May 2014 11:47:02 GMT

     [ 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)

Mime
View raw message