Emile de Weerd created CXF-8124:
-----------------------------------
Summary: 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.3.3, 3.1.18
Reporter: Emile de Weerd
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 = 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.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)}}
{{ [...]}}
{{[main] INFO cxf.reproducers.CxfMetricsIssueReproducerTest - - stop called
with time = 26412378 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.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 = 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.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)}}
{{ [...]}}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
