cxf-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Hadrian Zbarcea (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CXF-7394) Incorrect ERROR: Failed to send RM protocol message
Date Mon, 05 Jun 2017 19:55:04 GMT

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

Hadrian Zbarcea updated CXF-7394:
---------------------------------
    Fix Version/s: 3.1.12
                   3.2.0

> 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
>            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)

Mime
View raw message