cxf-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Christoph Hümbert (JIRA) <j...@apache.org>
Subject [jira] [Commented] (CXF-5663) IllegalStateException using AsyncHTTPConduit
Date Mon, 22 Aug 2016 14:49:21 GMT

    [ https://issues.apache.org/jira/browse/CXF-5663?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15430904#comment-15430904
] 

Christoph Hümbert commented on CXF-5663:
----------------------------------------

Hello,

I am facing the same problem when using Apache CXF 3.1.7. I already changed the HttpCore (4.4.4
> 4.4.5) but the result is the same. The following demo code shows how I parametrized and
that code is working in general beside that exception. 

{code:java}
SOAPMessage requestMessage = null;
MessageFactory mf;
try {
    mf = MessageFactory.newInstance(jaxWsProtocol);
    requestMessage = mf.createMessage(null, new ByteArrayInputStream(requestMsg.getBytes("UTF-8")));
} catch (SOAPException e) { ...
} catch (UnsupportedEncodingException e) {  ...
} catch (IOException e) {...}

SOAPMessage responseMessage = null;
DispatchImpl<SOAPMessage> dispatchCxf = null;

if(requestMsg != null) {
    
    Service service = Service.create(serviceQName);
    service.addPort(portQName, bindingType, endpointUrl);
    
    Dispatch<SOAPMessage> dispatch = service.createDispatch(portQName, SOAPMessage.class,
Service.Mode.MESSAGE);
    
    dispatchCxf = (DispatchImpl<SOAPMessage>)dispatch;
    Client client = dispatchCxf.getClient();
    
    HTTPConduit conduit = (HTTPConduit) client.getConduit();
    HTTPClientPolicy httpClientPolicy = new HTTPClientPolicy();
    httpClientPolicy.setAllowChunking(Boolean.FALSE);
    httpClientPolicy.setAutoRedirect(Boolean.TRUE);
    httpClientPolicy.setAsyncExecuteTimeout(30000L);
    httpClientPolicy.setReceiveTimeout(0);
    httpClientPolicy.setConnectionTimeout(0);
//            httpClientPolicy.setAsyncExecuteTimeoutRejection(true); // orignal: false
    conduit.setClient(httpClientPolicy);
    
    Bus bus = client.getBus();
    bus.setProperty("use.async.http.conduit", Boolean.TRUE);
    bus.setProperty("org.apache.cxf.transport.http.async.SO_LINGER", 60);
    
    Map<String, Object> rc = dispatch.getRequestContext();
    rc.put("use.async.http.conduit", Boolean.TRUE);
    rc.put("thread.local.request.context", Boolean.TRUE);
    
    if(credentials != null) {
        rc.put(Credentials.class.getName(), credentials);
    }
    if(soapAction != null){
        rc.put(BindingProvider.SOAPACTION_USE_PROPERTY, Boolean.TRUE);
        rc.put(BindingProvider.SOAPACTION_URI_PROPERTY, soapAction);
    }
    
    try {
        responseMessage = dispatchCxf.invoke(requestMessage);
    } catch (WebServiceException e) {
        if(e.getCause().getClass().equals(IOException.class)) {
            if(e.getCause().getMessage().startsWith("Authorization loop detected on Conduit"))
{
                System.out.println("Authentication failed: Wrong credentials: " + e.getCause().getMessage());
            }
        } else if(e.getCause().getClass().equals(SocketTimeoutException.class)) {
            System.out.println(e.getCause().getMessage()); 
        } else { System.out.println(e.getCause().getMessage());}
        throw new WsServiceException(e.getCause().getMessage());
    } finally {
        try {
            dispatchCxf.close();
        } catch (IOException e) { /* ignore */ }
    }
}
{code}

 I created a JUnit test which creates multiple objects with my implementation by using the
Callable interface. The DTOs contain connection information, credentials,etc. So I have 3
different web services with different credentials but on the same host.  In this test I created
3000 request which will run in thread pool. Sometimes it happened but sometimes not. When
use my implementation in Apache Tomcat the this exceptions occurs very quickly. 

{code:java}
@Test
public void testWithCallable()  {
    
    int numberOfHandlers = 3;
    SoapRequestHandler handler1 = new SoapRequestHandler(dto1);
    ...

    Set<Future<SOAPMessage>> set = new HashSet<Future<SOAPMessage>>();
    ExecutorService pool = Executors.newFixedThreadPool(50);
    int numberOfCalls = 1000;
    
    for(int i = 0; i < numberOfCalls; i++) {

        TestSoapServiceCallableRunner run1 = new TestSoapServiceCallableRunner(handler1);
        set.add(pool.submit(run1));

        TestSoapServiceCallableRunner run2 = new TestSoapServiceCallableRunner(handler2);
        set.add(pool.submit(run2));

        TestSoapServiceCallableRunner run3 = new TestSoapServiceCallableRunner(handler3);
        set.add(pool.submit(run3));
    }
    
    for (Future<SOAPMessage> afuture : set) {
        OutputStream os;
        try {
            os = verifySoapResult(afuture.get()); IOUtils.closeQuietly(os);
        } catch (InterruptedException e) {...
        } catch (ExecutionException e) {... }
    }
    assertEquals(numberOfCalls * numberOfHandlers, set.size());
}
{code}

Workarounds like retrying often run in the same exception again hence it makes no sense to
use it. I try to dive deeper into the topic...
My system: Fedora 24; i5. Ubuntu 14.04/16.04; OpenJDk 1.8.0_101


> IllegalStateException using AsyncHTTPConduit
> --------------------------------------------
>
>                 Key: CXF-5663
>                 URL: https://issues.apache.org/jira/browse/CXF-5663
>             Project: CXF
>          Issue Type: Bug
>          Components: Transports
>    Affects Versions: 2.7.10
>         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. Every
once in a while an attempt to send request ends in IllegalStateException - Buffer already
closed for writing (logs provided below).
> {noformat}
> 2014.04.01 10:47:22.601 org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3
DEBUG [HLAPI-47] DefaultAsyncRequestDirector:208 [exchange: 5663] start execution
> 2014.04.01 10:47:22.601 org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3
DEBUG [HLAPI-47] DefaultAsyncRequestDirector:625 [exchange: 5663] Request connection for {}->http://10.250.32.140:8082
> 2014.04.01 10:47:22.602 org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2
DEBUG [HLAPI-47] 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.04.01 10:47:22.603 org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2
DEBUG [HLAPI-47] PoolingClientAsyncConnectionManager$InternalPoolEntryCallback:297 Connection
leased: [id: 1746][route: {}->http://10.250.32.140:8082][total kept alive: 1; route allocated:
2 of 1000; total allocated: 2 of 5000]
> 2014.04.01 10:47:22.604 org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3
DEBUG [HLAPI-47] DefaultAsyncRequestDirector:558 [exchange: 5663] Connection allocated: [id:1746][route:{}->http://10.250.32.140:8082][state:null]
> 2014.04.01 10:47:22.625 org.apache.http.impl.nio.reactor.IOSessionImpl DEBUG [I/O dispatcher
18] LoggingIOSession$LoggingByteChannel:189 http-outgoing-1746 10.252.152.177:65127<->10.250.32.140:8082[ACTIVE][r:r]:
-1 bytes read
> 2014.04.01 10:47:22.625 org.apache.http.impl.nio.reactor.IOSessionImpl DEBUG [HLAPI-47]
LoggingIOSession:167 http-outgoing-1746 10.252.152.177:65127<->10.250.32.140:8082[ACTIVE][r:r]:
Set attribute http.nio.exchange-handler
> 2014.04.01 10:47:22.626 org.apache.http.impl.nio.reactor.IOSessionImpl DEBUG [I/O dispatcher
18] LoggingIOSession:118 http-outgoing-1746 10.252.152.177:65127<->10.250.32.140:8082[ACTIVE][r:r]:
Close
> 2014.04.01 10:47:22.626 org.apache.http.impl.nio.reactor.IOSessionImpl DEBUG [HLAPI-47]
LoggingIOSession:105 http-outgoing-1746 10.252.152.177:65127<->10.250.32.140:8082[CLOSED][]:
Event set [w]
> 2014.04.01 10:47:22.628 org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$3
DEBUG [HLAPI-47] DefaultAsyncRequestDirector:185 [exchange: 5663] aborting connection [id:1746][route:{}->http://10.250.32.140:8082][state:null]
> 2014.04.01 10:47:22.629 org.apache.http.impl.nio.reactor.IOSessionImpl DEBUG [HLAPI-47]
LoggingIOSession:133 http-outgoing-1746 [CLOSED][]: Shutdown
> 2014.04.01 10:47:22.629 org.apache.http.impl.nio.reactor.IOSessionImpl DEBUG [HLAPI-47]
LoggingIOSession:133 http-outgoing-1746 [CLOSED][]: Shutdown
> 2014.04.01 10:47:22.630 org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduitFactory$2
DEBUG [HLAPI-47] PoolingClientAsyncConnectionManager:236 Connection released: [id: 1746][route:
{}->http://10.250.32.140:8082][total kept alive: 1; route allocated: 1 of 1000; total allocated:
1 of 5000]
> 2014.04.01 10:47:22.642 org.apache.cxf.phase.PhaseInterceptorChain WARN  [HLAPI-47] LogUtils:452
Interceptor for {http://implementation.web.api.icc.services.osp.in.alcatel.com}SubscriberLineManagerPortTypeService#{http://implementation.web.api.icc.services.osp.in.alcatel.com}getAll
has thrown exception, unwinding now
> java.lang.IllegalStateException: IllegalStateException invoking http://10.250.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager:
Buffer already closed for writing
>         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:1339)
>         at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1328)
>         at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream.close(AsyncHTTPConduit.java:381)
>         at org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:50)
>         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:628)
>         at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
>         at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:272)
>         at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:565)
>         at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:474)
>         at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:377)
>         at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:330)
>         at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
>         at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:135)
>         at $Proxy89.getAll(Unknown Source)
>         at sun.reflect.GeneratedMethodAccessor38.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:236)
>         at pl.infovide.inconfig.bep.backend.hlapi.HlapiBackend.send(HlapiBackend.java:26)
>         at pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.forwardRequest(UnifiedBackendImpl.java:194)
>         at pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.access$000(UnifiedBackendImpl.java:29)
>         at pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl$SenderTask.run(UnifiedBackendImpl.java:276)
>         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.lang.IllegalStateException: Buffer already closed for writing
>         at org.apache.cxf.transport.http.asyncclient.SharedOutputBuffer.write(SharedOutputBuffer.java:231)
>         at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$AsyncWrappedOutputStream$1.write(AsyncHTTPConduit.java:397)
>         at org.apache.cxf.io.AbstractWrappedOutputStream.write(AbstractWrappedOutputStream.java:51)
>         at org.apache.cxf.io.AbstractThresholdOutputStream.write(AbstractThresholdOutputStream.java:69)
>         at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1296)
>         ... 25 common frames omitted
> {noformat}
> We are unable to provide a test-case since the problem is indeterministic. Roughly 10-20
out of ~14000 requests a day end this way.
> We will probably apply a workaround by catching the exception and retrying the request,
however CXF's behavior in this case doesn't seem to be valid.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message