Uploaded image for project: 'CXF'
  1. CXF
  2. CXF-7391

WS-RM: ISE excpetion after server reconnect

Attach filesAttach ScreenshotVotersWatch issueWatchersCreate sub-taskLinkCloneUpdate Comment AuthorReplace String in CommentUpdate Comment VisibilityDelete Comments
    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Invalid
    • Affects Version/s: 3.1.7, 3.1.10
    • Fix Version/s: Invalid
    • Component/s: WS-* Components
    • Labels:
      None
    • Estimated Complexity:
      Unknown

      Description

      This is for a regular WS-RM scenario, traffic takes place normally, and then the server disconnects. After the server restart, the client continues to send messages using the known sequence id, but the first message gets rejected (rightfully so) with the following stack:

      2017-06-02 22:56:53,517 | INFO  | ion(3)-127.0.0.1 | GreeterService                   | 93 - org.apifocal.demo.wsrm.greeter-service - 1.0.0.SNAPSHOT | Greeter service starting...
      2017-06-02 22:56:53,522 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,type=Bus,instance.id=189207851: org.apache.cxf.bus.ManagedBus@2688afbd
      2017-06-02 22:56:53,522 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,type=Bus,instance.id=189207851: javax.management.modelmbean.RequiredModelMBean@10a214ea
      2017-06-02 22:56:53,523 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registered org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,type=Bus,instance.id=189207851
      2017-06-02 22:56:53,523 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,type=WSRM.Manager,instance.id=752558607: org.apache.cxf.ws.rm.ManagedRMManager@1f0684f2
      2017-06-02 22:56:53,525 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,type=WSRM.Manager,instance.id=752558607: javax.management.modelmbean.RequiredModelMBean@7c9035e8
      2017-06-02 22:56:53,526 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,WorkQueueManager=Bus.WorkQueueManager,type=WorkQueueManager,instance.id=2081782740: org.apache.cxf.bus.managers.WorkQueueManagerImplMBeanWrapper@92bf503
      2017-06-02 22:56:53,527 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,WorkQueueManager=Bus.WorkQueueManager,type=WorkQueueManager,instance.id=2081782740: javax.management.modelmbean.RequiredModelMBean@2221c1c0
      2017-06-02 22:56:53,530 | INFO  | ion(3)-127.0.0.1 | ReflectionServiceFactoryBean     | 46 - org.apache.cxf.cxf-rt-wsdl - 3.1.7 | Creating Service {http://demo.apifocal.org/greeter/wsrm}GreeterService from WSDL: META-INF/wsdl/org/apifocal/demo/greeter/wsrm/greeter.wsdl
      2017-06-02 22:56:53,557 | INFO  | ion(3)-127.0.0.1 | ServerImpl                       | 33 - org.apache.cxf.cxf-core - 3.1.7 | Setting the server's publish address to be /greeter-wsrm
      2017-06-02 22:56:53,557 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,type=Bus.Service.Endpoint,service="{http://demo.apifocal.org/greeter/wsrm}GreeterService",port="GreeterPort",instance.id=953867382: org.apache.cxf.endpoint.ManagedEndpoint@b7bb49d
      2017-06-02 22:56:53,558 | INFO  | ion(3)-127.0.0.1 | InstrumentationManagerImpl       | 40 - org.apache.cxf.cxf-rt-management - 3.1.7 | registering MBean org.apache.cxf:bus.id=org.apifocal.demo.wsrm.greeter-wsrm-cxf189207851,type=Bus.Service.Endpoint,service="{http://demo.apifocal.org/greeter/wsrm}GreeterService",port="GreeterPort",instance.id=953867382: javax.management.modelmbean.RequiredModelMBean@201cfe0
      2017-06-02 22:56:55,563 | INFO  | ion(3)-127.0.0.1 | RMCaptureOutInterceptor          | 45 - org.apache.cxf.cxf-rt-ws-rm - 3.1.7 | Captured message 4 in sequence urn:uuid:e4cc49cd-0da2-4f23-acbf-a2896305cfda
      2017-06-02 22:56:55,564 | WARN  | ion(3)-127.0.0.1 | RetransmissionQueueImpl          | 45 - org.apache.cxf.cxf-rt-ws-rm - 3.1.7 | Scheduling of WS-RM retransmission failed.
      java.lang.IllegalStateException: Timer already cancelled.
      	at java.util.Timer.sched(Timer.java:397)[:1.8.0_131]
      	at java.util.Timer.schedule(Timer.java:208)[:1.8.0_131]
      	at org.apache.cxf.ws.rm.soap.RetransmissionQueueImpl$ResendCandidate.schedule(RetransmissionQueueImpl.java:651)[45:org.apache.cxf.cxf-rt-ws-rm:3.1.7]
      	at org.apache.cxf.ws.rm.soap.RetransmissionQueueImpl$ResendCandidate.<init>(RetransmissionQueueImpl.java:452)[45:org.apache.cxf.cxf-rt-ws-rm:3.1.7]
      	at org.apache.cxf.ws.rm.soap.RetransmissionQueueImpl.cacheUnacknowledged(RetransmissionQueueImpl.java:350)[45:org.apache.cxf.cxf-rt-ws-rm:3.1.7]
      	at org.apache.cxf.ws.rm.soap.RetransmissionQueueImpl.addUnacknowledged(RetransmissionQueueImpl.java:134)[45:org.apache.cxf.cxf-rt-ws-rm:3.1.7]
      	at org.apache.cxf.ws.rm.RMCaptureOutInterceptor$CaptureEnd.handleMessage(RMCaptureOutInterceptor.java:277)[45:org.apache.cxf.cxf-rt-ws-rm:3.1.7]
      	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308)[33:org.apache.cxf.cxf-core:3.1.7]
      	at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:514)[33:org.apache.cxf.cxf-core:3.1.7]
      	at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:423)[33:org.apache.cxf.cxf-core:3.1.7]
      	at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:324)[33:org.apache.cxf.cxf-core:3.1.7]
      	at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:277)[33:org.apache.cxf.cxf-core:3.1.7]
      	at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)[39:org.apache.cxf.cxf-rt-frontend-simple:3.1.7]
      	at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:139)[38:org.apache.cxf.cxf-rt-frontend-jaxws:3.1.7]
      	at com.sun.proxy.$Proxy89.greetMe(Unknown Source)
      	at org.apifocal.demo.wsrm.itests.GreeterClientTest.testCall(GreeterClientTest.java:95)
      	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]
      

      This is configured all the way back to the client. Depending on the ws-rm configuration one can experience different behaviors. With a simple ws-rm configuration there is a workaround by ignoring the error in the app and re-sending the request, but that's defeating the purpose.

        Attachments

        Issue Links

          Activity

            People

            • Assignee:
              dkulp Daniel Kulp
              Reporter:
              hadrian Hadrian Zbarcea

              Dates

              • Created:
                Updated:
                Resolved:

                Issue deployment