Uploaded image for project: 'netconf'
  1. netconf
  2. NETCONF-844

Websocket notification streams immediately closing upon connection

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Medium Medium
    • 2.0.12
    • 2.0.11
    • restconf-nb

      In the latest release Phosphorus-SR1, websocket streams are immediately closed upon connection.

      Jetty cannot call the handler method. Relevant part of the log is below.

      14:55:09.830 DEBUG [qtp939618066-416] [SERVER] WebSocketSession.onSessionOpened()
      14:55:09.830 DEBUG [qtp939618066-416] [SERVER] WebSocketSession.onSessionOpened()
      14:55:09.830 DEBUG [qtp939618066-416] [SERVER] WebSocketSession.open()
      14:55:09.834 DEBUG [qtp939618066-416] [SERVER] WebSocketSession.open() remote=WebSocketRemoteEndpoint@f7f7a2b[batching=true]
      14:55:09.835 DEBUG [qtp939618066-416] openSession(WebSocketSession[websocket=JettyAnnotatedEventDriver[org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler@53319d2c],behavior=SERVER,connection=WebSocketServerConnection@2d11b2f8::SocketChannelEndPoint@58a89dd2{l=/127.0.0.1:8181,r=/127.0.0.1:51032,OPEN,fill=-,flush=-,to=12/30000}{io=0/0,kio=0,kro=1}->WebSocketServerConnection@2d11b2f8[s=ConnectionState@3f16ae11[OPENING],f=Flusher@5138ead3[IDLE][queueSize=0,aggregateSize=-1,terminated=null],g=Generator[SERVER,validating],p=Parser@76b5af3a[ExtensionStack,s=START,c=0,len=0,f=null]],remote=WebSocketRemoteEndpoint@f7f7a2b[batching=true],incoming=JettyAnnotatedEventDriver[org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler@53319d2c],outgoing=ExtensionStack[queueSize=0,extensions=[],incoming=org.eclipse.jetty.websocket.common.WebSocketSession,outgoing=org.eclipse.jetty.websocket.server.WebSocketServerConnection]]) objectFactory=org.eclipse.jetty.util.DecoratedObjectFactory[decorators=1]
      14:55:09.835 DEBUG [qtp939618066-416] onConnect() - events.onConnect=CallableMethod[pojo=org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler,method=public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler.onWebSocketConnected(org.eclipse.jetty.websocket.api.Session)]
      14:55:09.837 DEBUG [qtp939618066-416] callApplicationOnError()java.lang.RuntimeException: Cannot call method public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler#onWebSocketConnected(org.eclipse.jetty.websocket.api.Session) with args: [org.eclipse.jetty.websocket.common.WebSocketSession]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.unwrapRuntimeException(CallableMethod.java:93) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:75) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onConnect(JettyAnnotatedEventDriver.java:178) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.openSession(AbstractEventDriver.java:217) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:493) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.onOpened(WebSocketSession.java:459) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection.onOpened(AbstractConnection.java:213) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection.onOpen(AbstractConnection.java:205) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractEndPoint.upgrade(AbstractEndPoint.java:444) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:407) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:820) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:368) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:137) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.43.v20210629]
       at java.lang.Thread.run(Thread.java:829) [?:?]
      Caused by: java.lang.IllegalAccessException: class org.eclipse.jetty.websocket.common.events.annotated.CallableMethod cannot access a member of class org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler with modifiers "public synchronized"
       at jdk.internal.reflect.Reflection.newIllegalAccessException(Reflection.java:361) ~[?:?]
       at java.lang.reflect.AccessibleObject.checkAccess(AccessibleObject.java:591) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:558) ~[?:?]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:70) ~[bundleFile:9.4.43.v20210629]
       ... 21 more
      14:55:09.840 DEBUG [qtp939618066-416] onError(java.lang.RuntimeException) - events.onError=OptionalSessionCallableMethod[pojo=org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler,method=public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler.onWebSocketError(java.lang.Throwable),wantsSession=false,streaming=false]
      14:55:09.841 WARN [qtp939618066-416] Exception while notifying onErrorjava.lang.RuntimeException: Cannot call method public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler#onWebSocketError(java.lang.Throwable) with args: [java.lang.RuntimeException]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.unwrapRuntimeException(CallableMethod.java:93) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:75) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.annotated.OptionalSessionCallableMethod.call(OptionalSessionCallableMethod.java:72) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onError(JettyAnnotatedEventDriver.java:192) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.callApplicationOnError(WebSocketSession.java:416) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:209) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:130) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.openSession(AbstractEventDriver.java:221) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:493) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.onOpened(WebSocketSession.java:459) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection.onOpened(AbstractConnection.java:213) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection.onOpen(AbstractConnection.java:205) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractEndPoint.upgrade(AbstractEndPoint.java:444) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:407) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:820) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:368) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:137) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.43.v20210629]
       at java.lang.Thread.run(Thread.java:829) [?:?]
      Caused by: java.lang.IllegalAccessException: class org.eclipse.jetty.websocket.common.events.annotated.CallableMethod cannot access a member of class org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler with modifiers "public synchronized"
       at jdk.internal.reflect.Reflection.newIllegalAccessException(Reflection.java:361) ~[?:?]
       at java.lang.reflect.AccessibleObject.checkAccess(AccessibleObject.java:591) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:558) ~[?:?]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:70) ~[bundleFile:9.4.43.v20210629]
       ... 25 more
      14:55:09.845 DEBUG [qtp939618066-416] callApplicationOnClose(CloseInfo[code=1011,reason=Cannot call method public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler#onWebSocke])
      14:55:09.846 DEBUG [qtp939618066-416] onClose(CloseInfo[code=1011,reason=Cannot call method public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler#onWebSocke]) - events.onClose=OptionalSessionCallableMethod[pojo=org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler,method=public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler.onWebSocketClosed(int,java.lang.String),wantsSession=false,streaming=false]
      14:55:09.846 WARN [qtp939618066-416] Exception while notifying onClosejava.lang.RuntimeException: Cannot call method public synchronized void org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler#onWebSocketClosed(int, java.lang.String) with args: [java.lang.Integer, java.lang.String]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.unwrapRuntimeException(CallableMethod.java:93) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:75) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.annotated.OptionalSessionCallableMethod.call(OptionalSessionCallableMethod.java:72) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onClose(JettyAnnotatedEventDriver.java:164) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.callApplicationOnClose(WebSocketSession.java:394) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:225) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:130) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.openSession(AbstractEventDriver.java:221) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:493) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.websocket.common.WebSocketSession.onOpened(WebSocketSession.java:459) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection.onOpened(AbstractConnection.java:213) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection.onOpen(AbstractConnection.java:205) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractEndPoint.upgrade(AbstractEndPoint.java:444) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:407) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:820) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:368) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:137) ~[bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.43.v20210629]
       at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.43.v20210629]
       at java.lang.Thread.run(Thread.java:829) [?:?]
      Caused by: java.lang.IllegalAccessException: class org.eclipse.jetty.websocket.common.events.annotated.CallableMethod cannot access a member of class org.opendaylight.restconf.nb.rfc8040.streams.WebSocketSessionHandler with modifiers "public synchronized"
       at jdk.internal.reflect.Reflection.newIllegalAccessException(Reflection.java:361) ~[?:?]
       at java.lang.reflect.AccessibleObject.checkAccess(AccessibleObject.java:591) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:558) ~[?:?]
       at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:70) ~[bundleFile:9.4.43.v20210629]
       ... 25 more
      14:55:09.851 DEBUG [qtp939618066-416] outgoingFrame(CLOSE[len=125,fin=true,rsv=...,masked=false], org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$CallbackBridge@18ac0999)
      

            rovarga Robert Varga
            ppuskar Peter Puškár
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: