[
https://issues.apache.org/jira/browse/CXF-7394?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Daniel Kulp resolved CXF-7394.
------------------------------
Resolution: Fixed
Assignee: Daniel Kulp
> Incorrect ERROR: Failed to send RM protocol message
> ---------------------------------------------------
>
> Key: CXF-7394
> URL: https://issues.apache.org/jira/browse/CXF-7394
> Project: CXF
> Issue Type: Bug
> Components: WS-* Components
> Affects Versions: 3.1.7, 3.1.10
> Reporter: Hadrian Zbarcea
> Assignee: Daniel Kulp
> Priority: Minor
> Fix For: 3.2.0, 3.1.12
>
>
> The WS-RM protocol sends out-f-band messages. When the service goes down, for
> instance, if the client attempts to CloseSequence (out-of-band, see below)
> the request will clearly fail.
> The behavior of the RM feature looks correct (to me), however the log
> incorrectly shows the ERROR which creates unnecessary confusion. The
> recommendation is to catch it and only get a WARN in the logs.
> {code}
> 2017-06-05 15:18:25,297 | INFO | ion(3)-127.0.0.1 | REQ_OUT
> | 41 - org.apache.cxf.cxf-rt-features-logging - 3.1.10 |
> <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/";>
> <soap:Header>
> <Action
> xmlns="http://www.w3.org/2005/08/addressing";>http://docs.oasis-open.org/ws-rx/wsrm/200702/CloseSequence</Action>
> <MessageID
> xmlns="http://www.w3.org/2005/08/addressing";>urn:uuid:db7ae5ef-6ee4-4d1b-865c-f6e19c14dc74</MessageID>
> <To
> xmlns="http://www.w3.org/2005/08/addressing";>http://localhost:8181/cxf/greeter-wsrm</To>
> <ReplyTo xmlns="http://www.w3.org/2005/08/addressing";>
> <Address>http://www.w3.org/2005/08/addressing/anonymous</Address>
> </ReplyTo>
> </soap:Header>
> <soap:Body>
> <CloseSequence xmlns="http://docs.oasis-open.org/ws-rx/wsrm/200702";
> xmlns:ns2="http://www.w3.org/2005/08/addressing";>
> <Identifier>urn:uuid:693f8fe0-f239-4549-8b6e-6ee01663f9c5</Identifier>
> <LastMsgNumber>3</LastMsgNumber>
> </CloseSequence>
> </soap:Body>
> </soap:Envelope>
> 2017-06-05 15:18:25,298 | WARN | qtp8911442-113 | ServletController
> | 47 - org.apache.cxf.cxf-rt-transports-http - 3.1.10 | Can't find
> the the request for http://localhost:8181/cxf/greeter-wsrm's Observer
> 2017-06-05 15:18:25,301 | WARN | ion(3)-127.0.0.1 | PhaseInterceptorChain
> | 37 - org.apache.cxf.cxf-core - 3.1.10 | Interceptor for
> {http://docs.oasis-open.org/ws-rx/wsrm/200702}SequenceAbstractService#{http://docs.oasis-open.org/ws-rx/wsrm/200702}CloseSequence
> 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)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:514)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:423)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.ws.rm.Proxy.invoke(Proxy.java:317)[51:org.apache.cxf.cxf-rt-ws-rm:3.1.10]
> at
> org.apache.cxf.ws.rm.Proxy.invoke(Proxy.java:334)[51:org.apache.cxf.cxf-rt-ws-rm:3.1.10]
> at
> org.apache.cxf.ws.rm.Proxy.lastMessage(Proxy.java:240)[51:org.apache.cxf.cxf-rt-ws-rm:3.1.10]
> at
> org.apache.cxf.ws.rm.RMEndpoint.shutdown(RMEndpoint.java:819)[51:org.apache.cxf.cxf-rt-ws-rm:3.1.10]
> at
> org.apache.cxf.ws.rm.RMManager.shutdown(RMManager.java:512)[51:org.apache.cxf.cxf-rt-ws-rm:3.1.10]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)[:1.8.0_131]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_131]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_131]
> at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_131]
> at
> org.apache.cxf.common.injection.ResourceInjector.invokePreDestroy(ResourceInjector.java:366)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.common.injection.ResourceInjector.destroy(ResourceInjector.java:139)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.bus.extension.ExtensionManagerImpl.destroyBeans(ExtensionManagerImpl.java:392)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.bus.extension.ExtensionManagerBus.destroyBeans(ExtensionManagerBus.java:317)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.bus.extension.ExtensionManagerBus.shutdown(ExtensionManagerBus.java:331)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.bus.extension.ExtensionManagerBus.shutdown(ExtensionManagerBus.java:313)[37:org.apache.cxf.cxf-core:3.1.10]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)[:1.8.0_131]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_131]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_131]
> at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_131]
> at
> org.apache.aries.blueprint.utils.ReflectionUtils.invoke(ReflectionUtils.java:299)
> at
> org.apache.aries.blueprint.container.BeanRecipe.invoke(BeanRecipe.java:980)
> at
> org.apache.aries.blueprint.container.BeanRecipe.destroy(BeanRecipe.java:887)
> at
> org.apache.aries.blueprint.container.BlueprintRepository.destroy(BlueprintRepository.java:329)
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.destroyComponents(BlueprintContainerImpl.java:765)
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.tidyupComponents(BlueprintContainerImpl.java:964)
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:909)
> at
> org.apache.aries.blueprint.container.BlueprintExtender$3.run(BlueprintExtender.java:325)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_131]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_131]
> at
> org.apache.aries.blueprint.container.BlueprintExtender.destroyContainer(BlueprintExtender.java:346)
> at
> org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:238)
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500)
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433)
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725)
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463)
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422)
> at
> org.apache.felix.framework.util.SecureAction.invokeBundleEventHook(SecureAction.java:1179)
> at
> org.apache.felix.framework.EventDispatcher.createWhitelistFromHooks(EventDispatcher.java:730)
> at
> org.apache.felix.framework.EventDispatcher.fireBundleEvent(EventDispatcher.java:485)
> at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)
> at org.apache.felix.framework.Felix.stopBundle(Felix.java:2600)
> at org.apache.felix.framework.BundleImpl.stop(BundleImpl.java:1038)
> at org.apache.felix.framework.BundleImpl.stop(BundleImpl.java:1024)
> at
> org.apifocal.demo.wsrm.itests.GreeterClientTest.testCall(GreeterClientTest.java:90)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)[:1.8.0_131]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_131]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_131]
> at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_131]
> 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.ops4j.pax.exam.invoker.junit.internal.ContainerTestRunner.runLeafWithRetry(ContainerTestRunner.java:97)
> at
> org.ops4j.pax.exam.invoker.junit.internal.ContainerTestRunner.runChildWithRetry(ContainerTestRunner.java:84)
> at
> org.ops4j.pax.exam.invoker.junit.internal.ContainerTestRunner.runChild(ContainerTestRunner.java:75)
> at
> org.ops4j.pax.exam.invoker.junit.internal.ContainerTestRunner.runChild(ContainerTestRunner.java:44)
> 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)
> at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
> at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
> at
> org.ops4j.pax.exam.invoker.junit.internal.JUnitProbeInvoker.invokeViaJUnit(JUnitProbeInvoker.java:124)
> at
> org.ops4j.pax.exam.invoker.junit.internal.JUnitProbeInvoker.findAndInvoke(JUnitProbeInvoker.java:97)
> at
> org.ops4j.pax.exam.invoker.junit.internal.JUnitProbeInvoker.call(JUnitProbeInvoker.java:73)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)[:1.8.0_131]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_131]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_131]
> at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_131]
> at
> org.ops4j.pax.exam.rbc.internal.RemoteBundleContextImpl.remoteCall(RemoteBundleContextImpl.java:83)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)[:1.8.0_131]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_131]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_131]
> at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_131]
> at
> sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:346)[:1.8.0_131]
> at sun.rmi.transport.Transport$1.run(Transport.java:200)[:1.8.0_131]
> at sun.rmi.transport.Transport$1.run(Transport.java:197)[:1.8.0_131]
> at java.security.AccessController.doPrivileged(Native
> Method)[:1.8.0_131]
> at
> sun.rmi.transport.Transport.serviceCall(Transport.java:196)[:1.8.0_131]
> at
> sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)[:1.8.0_131]
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)[:1.8.0_131]
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683)[:1.8.0_131]
> at java.security.AccessController.doPrivileged(Native
> Method)[:1.8.0_131]
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)[:1.8.0_131]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_131]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_131]
> at java.lang.Thread.run(Thread.java:748)[:1.8.0_131]
> Caused by: org.apache.cxf.transport.http.HTTPException: HTTP response '404:
> Not Found' when communicating with http://localhost:8181/cxf/greeter-wsrm
> at
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.doProcessResponseCode(HTTPConduit.java:1608)[47:org.apache.cxf.cxf-rt-transports-http:3.1.10]
> at
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1615)[47:org.apache.cxf.cxf-rt-transports-http:3.1.10]
> at
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1559)[47:org.apache.cxf.cxf-rt-transports-http:3.1.10]
> at
> org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1356)[47:org.apache.cxf.cxf-rt-transports-http:3.1.10]
> at
> org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:216)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)[37:org.apache.cxf.cxf-core:3.1.10]
> at
> org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:653)[47:org.apache.cxf.cxf-rt-transports-http:3.1.10]
> at
> org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)[37:org.apache.cxf.cxf-core:3.1.10]
> ... 94 more
> 2017-06-05 15:18:25,333 | ERROR | ion(3)-127.0.0.1 | Proxy
> | 51 - org.apache.cxf.cxf-rt-ws-rm - 3.1.10 | Failed to send RM
> protocol message {http://docs.oasis-open.org/ws-rx/wsrm/200702}CloseSequence.
> org.apache.cxf.interceptor.Fault: Could not send Message.
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
