Return-Path: X-Original-To: apmail-cxf-issues-archive@www.apache.org Delivered-To: apmail-cxf-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 8076D107CC for ; Tue, 1 Apr 2014 16:01:28 +0000 (UTC) Received: (qmail 58754 invoked by uid 500); 1 Apr 2014 16:01:28 -0000 Delivered-To: apmail-cxf-issues-archive@cxf.apache.org Received: (qmail 55733 invoked by uid 500); 1 Apr 2014 16:01:23 -0000 Mailing-List: contact issues-help@cxf.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cxf.apache.org Delivered-To: mailing list issues@cxf.apache.org Received: (qmail 55244 invoked by uid 99); 1 Apr 2014 16:01:20 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 01 Apr 2014 16:01:20 +0000 Date: Tue, 1 Apr 2014 16:01:20 +0000 (UTC) From: =?utf-8?Q?Przemys=C5=82aw_O=C5=82tarzewski_=28JIRA=29?= To: issues@cxf.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (CXF-5663) IllegalStateException using AsyncHTTPConduit MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 Przemys=C5=82aw O=C5=82tarzewski created CXF-5663: ------------------------------------------- Summary: 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-E= nterprise-T5120, 64bit Reporter: Przemys=C5=82aw O=C5=82tarzewski 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 IllegalSta= teException - Buffer already closed for writing (logs provided below). {noformat} 2014.04.01 10:47:22.601 org.apache.cxf.transport.http.asyncclient.AsyncHTTP= ConduitFactory$3 DEBUG [HLAPI-47] DefaultAsyncRequestDirector:208 [exchange= : 5663] start execution 2014.04.01 10:47:22.601 org.apache.cxf.transport.http.asyncclient.AsyncHTTP= ConduitFactory$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.AsyncHTTP= ConduitFactory$2 DEBUG [HLAPI-47] PoolingClientAsyncConnectionManager:172 C= onnection 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.AsyncHTTP= ConduitFactory$2 DEBUG [HLAPI-47] PoolingClientAsyncConnectionManager$Inter= nalPoolEntryCallback:297 Connection leased: [id: 1746][route: {}->http://10= .250.32.140:8082][total kept alive: 1; route allocated: 2 of 1000; total al= located: 2 of 5000] 2014.04.01 10:47:22.604 org.apache.cxf.transport.http.asyncclient.AsyncHTTP= ConduitFactory$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 DEBU= G [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 DEBU= G [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 DEBU= G [I/O dispatcher 18] LoggingIOSession:118 http-outgoing-1746 10.252.152.17= 7:65127<->10.250.32.140:8082[ACTIVE][r:r]: Close 2014.04.01 10:47:22.626 org.apache.http.impl.nio.reactor.IOSessionImpl DEBU= G [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.AsyncHTTP= ConduitFactory$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 DEBU= G [HLAPI-47] LoggingIOSession:133 http-outgoing-1746 [CLOSED][]: Shutdown 2014.04.01 10:47:22.629 org.apache.http.impl.nio.reactor.IOSessionImpl DEBU= G [HLAPI-47] LoggingIOSession:133 http-outgoing-1746 [CLOSED][]: Shutdown 2014.04.01 10:47:22.630 org.apache.cxf.transport.http.asyncclient.AsyncHTTP= ConduitFactory$2 DEBUG [HLAPI-47] PoolingClientAsyncConnectionManager:236 C= onnection 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 [H= LAPI-47] LogUtils:452 Interceptor for {http://implementation.web.api.icc.se= rvices.osp.in.alcatel.com}SubscriberLineManagerPortTypeService#{http://impl= ementation.web.api.icc.services.osp.in.alcatel.com}getAll has thrown except= ion, unwinding now java.lang.IllegalStateException: IllegalStateException invoking http://10.2= 50.32.140:8082/HighLevelApiWS-2.4/services/SubscriberLineManager: Buffer al= ready closed for writing at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Me= thod) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeCons= tructorAccessorImpl.java:39) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Delega= tingConstructorAccessorImpl.java:27) at java.lang.reflect.Constructor.newInstance(Constructor.java:513) at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.ma= pException(HTTPConduit.java:1339) at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.cl= ose(HTTPConduit.java:1328) at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$Async= WrappedOutputStream.close(AsyncHTTPConduit.java:381) at org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWr= iteOutputStream.java:50) at org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.ja= va:223) at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.j= ava:56) at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java= :628) at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSende= rEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInte= rceptorChain.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.ja= va:135) at $Proxy89.getAll(Unknown Source) at sun.reflect.GeneratedMethodAccessor38.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod= AccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at pl.infovide.inconfig.bep.backend.hlapi.HlapiCommunicator.send(Hl= apiCommunicator.java:236) at pl.infovide.inconfig.bep.backend.hlapi.HlapiBackend.send(HlapiBa= ckend.java:26) at pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.forw= ardRequest(UnifiedBackendImpl.java:194) at pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl.acce= ss$000(UnifiedBackendImpl.java:29) at pl.infovide.inconfig.bep.backend.unified.UnifiedBackendImpl$Send= erTask.run(UnifiedBackendImpl.java:276) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoo= lExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: java.lang.IllegalStateException: Buffer already closed for writi= ng at org.apache.cxf.transport.http.asyncclient.SharedOutputBuffer.wri= te(SharedOutputBuffer.java:231) at org.apache.cxf.transport.http.asyncclient.AsyncHTTPConduit$Async= WrappedOutputStream$1.write(AsyncHTTPConduit.java:397) at org.apache.cxf.io.AbstractWrappedOutputStream.write(AbstractWrap= pedOutputStream.java:51) at org.apache.cxf.io.AbstractThresholdOutputStream.write(AbstractTh= resholdOutputStream.java:69) at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.cl= ose(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.2#6252)