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

Emile de Weerd updated CXF-8124:
--------------------------------
    Attachment: cxf-metrics-context-stop-issue.tar.xz

> CXF metrics - MetricsContext#stop called twice or without Fault in certain 
> error cases
> --------------------------------------------------------------------------------------
>
>                 Key: CXF-8124
>                 URL: https://issues.apache.org/jira/browse/CXF-8124
>             Project: CXF
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 3.1.18, 3.3.3
>            Reporter: Emile de Weerd
>            Priority: Major
>         Attachments: cxf-metrics-context-stop-issue.tar.xz
>
>
> While using the CXF metrics feature with a CXF REST client, in some situation 
> there are incoherent calls to the MetricsContext#stop method. 2 cases can be 
> isolated: server returns a 404 and the response body transmission is 
> interrupted in the middle of the transfer.
> I wrote a unit test that allows to clearly reproduce the 2 use cases. Of 
> course they are failing. The test prints out a stacktrace per call to the 
> MetricsContext#stop method.
> *notFoundStatusCode_stopCalledOnceWithFaultObjectInExchange*
> [main] INFO cxf.reproducers.CxfMetricsIssueReproducerTest - 
> MetricsContext#stop called 2 times
>  [main] INFO cxf.reproducers.CxfMetricsIssueReproducerTest - - stop called 
> with time = 16408651 ns, inSize = -1, outSize = 0, exchange that contains a 
> FaultMode = false; callad at:
>  [...]
>  at 
> org.apache.cxf.metrics.MetricsContext$$EnhancerByMockitoWithCGLIB$$1997d2d2.stop(<generated>)
>  at org.apache.cxf.metrics.ExchangeMetrics.stop(ExchangeMetrics.java:75)
>  at 
> org.apache.cxf.metrics.interceptors.AbstractMetricsInterceptor.stop(AbstractMetricsInterceptor.java:215)
>  at 
> org.apache.cxf.metrics.interceptors.MetricsMessageInPostInvokeInterceptor.handleMessage(MetricsMessageInPostInvokeInterceptor.java:34)
>  at 
> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
>  at 
> org.apache.cxf.jaxrs.client.ClientMessageObserver.onMessage(ClientMessageObserver.java:56)
>  at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1693)
>  at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1570)
>  at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1371)
>  at 
> org.apache.cxf.io.AbstractWrappedOutputStream.close(AbstractWrappedOutputStream.java:77)
>  at 
> org.apache.cxf.metrics.interceptors.CountingOutputStream.close(CountingOutputStream.java:47)
>  at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
>  at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:671)
>  at 
> org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63)
>  at 
> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
>  at 
> org.apache.cxf.jaxrs.client.AbstractClient.doRunInterceptorChain(AbstractClient.java:709)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.doChainedInvocation(ClientProxyImpl.java:887)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.invoke(ClientProxyImpl.java:335)
>  at com.sun.proxy.$Proxy22.getBook(Unknown Source)
>  at 
> cxf.reproducers.CxfMetricsIssueReproducerTest.notFoundStatusCode_stopCalledOnceWithFaultObjectInExchange(CxfMetricsIssueReproducerTest.java:151)
>  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>  at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>  at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>  at java.lang.reflect.Method.invoke(Method.java:498)
>  at 
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
>  at 
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
>  at 
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
>  at 
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
>  at 
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
>  at 
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
>  at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
>  at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
>  at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
>  at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
>  at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
>  at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
>  at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
>  at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
>  at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
>  [...]
>  [main] INFO cxf.reproducers.CxfMetricsIssueReproducerTest - - stop called 
> with time = 26412378 ns, inSize = -1, outSize = 0, exchange that contains a 
> FaultMode = true; callad at:
>  [...]
>  at 
> org.apache.cxf.metrics.MetricsContext$$EnhancerByMockitoWithCGLIB$$1997d2d2.stop(<generated>)
>  at org.apache.cxf.metrics.ExchangeMetrics.stop(ExchangeMetrics.java:75)
>  at 
> org.apache.cxf.metrics.interceptors.AbstractMetricsInterceptor.stop(AbstractMetricsInterceptor.java:215)
>  at 
> org.apache.cxf.metrics.interceptors.MetricsMessageInPostInvokeInterceptor.handleMessage(MetricsMessageInPostInvokeInterceptor.java:34)
>  at 
> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
>  at 
> org.apache.cxf.interceptor.AbstractFaultChainInitiatorObserver.onMessage(AbstractFaultChainInitiatorObserver.java:112)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.checkResponse(ClientProxyImpl.java:434)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.handleResponse(ClientProxyImpl.java:990)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.doChainedInvocation(ClientProxyImpl.java:895)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.invoke(ClientProxyImpl.java:335)
>  at com.sun.proxy.$Proxy22.getBook(Unknown Source)
>  at 
> cxf.reproducers.CxfMetricsIssueReproducerTest.notFoundStatusCode_stopCalledOnceWithFaultObjectInExchange(CxfMetricsIssueReproducerTest.java:151)
>  [...]
> *incompleteResponse_stopCalledOnceWithFaultObjectInExchange*
> [main] INFO cxf.reproducers.CxfMetricsIssueReproducerTest - 
> MetricsContext#stop called 1 times
>  [main] INFO cxf.reproducers.CxfMetricsIssueReproducerTest - - stop called 
> with time = 14901568 ns, inSize = -1, outSize = 0, exchange that contains a 
> FaultMode = false; callad at:
>  [...]
>  at 
> org.apache.cxf.metrics.MetricsContext$$EnhancerByMockitoWithCGLIB$$1997d2d2.stop(<generated>)
>  at org.apache.cxf.metrics.ExchangeMetrics.stop(ExchangeMetrics.java:75)
>  at 
> org.apache.cxf.metrics.interceptors.AbstractMetricsInterceptor.stop(AbstractMetricsInterceptor.java:215)
>  at 
> org.apache.cxf.metrics.interceptors.MetricsMessageInPostInvokeInterceptor.handleMessage(MetricsMessageInPostInvokeInterceptor.java:34)
>  at 
> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
>  at 
> org.apache.cxf.jaxrs.client.ClientMessageObserver.onMessage(ClientMessageObserver.java:56)
>  at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1693)
>  at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1570)
>  at 
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1371)
>  at 
> org.apache.cxf.io.AbstractWrappedOutputStream.close(AbstractWrappedOutputStream.java:77)
>  at 
> org.apache.cxf.metrics.interceptors.CountingOutputStream.close(CountingOutputStream.java:47)
>  at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
>  at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:671)
>  at 
> org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63)
>  at 
> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)
>  at 
> org.apache.cxf.jaxrs.client.AbstractClient.doRunInterceptorChain(AbstractClient.java:709)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.doChainedInvocation(ClientProxyImpl.java:887)
>  at 
> org.apache.cxf.jaxrs.client.ClientProxyImpl.invoke(ClientProxyImpl.java:335)
>  at com.sun.proxy.$Proxy22.getBook(Unknown Source)
>  at 
> cxf.reproducers.CxfMetricsIssueReproducerTest.incompleteResponse_stopCalledOnceWithFaultObjectInExchange(CxfMetricsIssueReproducerTest.java:171)
>  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>  at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>  at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>  at java.lang.reflect.Method.invoke(Method.java:498)
>  at 
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
>  at 
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
>  at 
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
>  at 
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
>  at 
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
>  at 
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
>  at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
>  at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
>  at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
>  at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
>  at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
>  at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
>  at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
>  at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
>  at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
>  [...]
>  



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Reply via email to