Details
-
Bug
-
Status: Closed
-
Minor
-
Resolution: Fixed
-
3.1.7, 3.1.10
-
None
-
Unknown
Description
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.
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.