Issues in closing the ovsdb connection and the connection service


Anil Jangam <anilj.mailing@...>
 

Hi,

I wrote a small test tool for the Ovsdb traffic generation and currently facing following issue. 

Description: 
I am using the ovsdb library and invoking it in manager mode, where I am waiting for the connections from the remote ovsdb client. The initialization is as follpws.

  this.ovsdbConnectionService.setOvsdbListenerPort(port);
  this.ovsdbConnectionService.startOvsdbManager();
  this.odlConnectionListener = new OdlConnectionListener(this);
  this.ovsdbConnectionService.registerConnectionListener(this.odlConnectionListener);

  // Wait till client connects with the ovsdb manager
  while (!newClientConnection) {
      try {
          Thread.sleep(1000);
      } catch (InterruptedException e) {
          e.printStackTrace();
      }
  }

In the connectionListener I am saving the new ovsdbClient connection handle to send/receive the OVSDB messages.

  // Perform certain ovsdb transaction processing here after the conection handle is available.
   < .... >


  // After the OVSDB transaction processing complete, close the OVSDB client/server infra.
  public void stopServer() {

      this.newClientConnection = false;

      if (this.ovsdbTransactionProcessor != null) {
          this.ovsdbTransactionProcessor.stop();
      }

      // Unregister the connection listener to stop establishing any new connections.
      if (this.ovsdbConnectionService != null) {
          try {
              logger.debug("Unregistering the connection lister call back handler");
              this.ovsdbConnectionService.unregisterConnectionListener(this.odlConnectionListener);

              this.ovsdbConnectionService.disconnect(this.ovsdbClient);
              this.ovsdbConnectionService.close();
          } catch (Exception e) {
              e.printStackTrace();
          }
      }

      if (this.ovsdbClient != null) {
          logger.debug("Disconnecting the ovsdb client connection");
          this.ovsdbClient.disconnect();
      }
  }



However, even after stopping the ovsdbClient connection handle as well as the connection service instance, it is still receiving the echo request from remote end (New Passive channel created) and it results in throwing an exception. 

Can someone please provide some comments on what is missing in my code as part of connection/service clean up? 

Thanks.

Java exception details:
=======================

2018-04-12T11:20:18.028-0700 [debug] [com.test.server.processor.OvsdbRunner][run:76] - All transactions processed successfully, stopping the test case
2018-04-12T11:20:18.029-0700 [debug] [com.test.server.processor.main.serverMain][stopServerMain:237] - Unregistering the connection lister call back handler
2018-04-12T11:20:18.029-0700 [info] [org.opendaylight.ovsdb.lib.impl.OvsdbConnectionService][close:502] - OvsdbConnectionService closed
2018-04-12T11:20:18.030-0700 [info] [org.opendaylight.ovsdb.lib.jsonrpc.JsonRpcEndpoint][close:232] - Shutting down reaper executor service
2018-04-12T11:20:18.030-0700 [debug] [com.test.server.processor.main.serverMain][stopServerMain:248] - Disconnecting the ovsdb client connection
2018-04-12T11:20:18.030-0700 [debug] [com.test.server.processor][executeOvsdbTest:50] - Ovsdb server has finished the test script run
2018-04-12T11:20:18.030-0700 [debug] [com.test.server.processor][executeOvsdbTest:54] - Test passed, ovsdb server exiting normally
2018-04-12T11:20:18.032-0700 [info] [org.opendaylight.ovsdb.lib.impl.OvsdbConnectionService][channelClosed:485] - Connection closed ConnectionInfo [Remote-address=127.0.0.1, Remote-port=56727, Local-address127.0.0.1, Local-port=6640, type=PASSIVE]
2018-04-12T11:20:20.124-0700 [info] [io.netty.handler.logging.LoggingHandler][info:101] - [id: 0x4329dbba, L:/0:0:0:0:0:0:0:0:6640] READ: [id: 0x69d40f37, L:/127.0.0.1:6640 - R:/127.0.0.1:56728]
2018-04-12T11:20:20.124-0700 [info] [io.netty.handler.logging.LoggingHandler][info:101] - [id: 0x4329dbba, L:/0:0:0:0:0:0:0:0:6640] READ COMPLETE
2018-04-12T11:20:20.125-0700 [debug] [org.opendaylight.ovsdb.lib.impl.OvsdbConnectionService][initChannel:317] - New Passive channel created : [id: 0x69d40f37, L:/127.0.0.1:6640 - R:/127.0.0.1:56728]
2018-04-12T11:20:20.127-0700 [trace] [org.opendaylight.ovsdb.lib.jsonrpc.JsonRpcEndpoint][lambda$getClient$1:118] - getClient Request : {"id":"fffa8994-1662-45b9-948d-c528747cfe1d","method":"echo","params":[]}



2018-04-12T11:20:50.130-0700 [debug] [org.opendaylight.ovsdb.lib.jsonrpc.ExceptionHandler][userEventTriggered:58] - Get idle state event
2018-04-12T11:20:50.130-0700 [debug] [org.opendaylight.ovsdb.lib.jsonrpc.ExceptionHandler][userEventTriggered:61] - Reader idle state. Send echo message to peer
2018-04-12T11:20:50.131-0700 [trace] [org.opendaylight.ovsdb.lib.jsonrpc.JsonRpcEndpoint][lambda$getClient$1:118] - getClient Request : {"id":"0dee85ce-9118-4bf6-978e-5f1d28fdd5ac","method":"echo","params":[]}
2018-04-12T11:20:50.133-0700 [error] [org.opendaylight.ovsdb.lib.jsonrpc.ExceptionHandler][exceptionCaught:32] - Exception occurred while processing connection pipeline
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@6a539624 rejected from java.util.concurrent.ScheduledThreadPoolExecutor@7cf9505[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
  at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047)
  at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
  at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326)
  at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533)
  at org.opendaylight.ovsdb.lib.jsonrpc.JsonRpcEndpoint.lambda$getClient$1(JsonRpcEndpoint.java:122)
  at com.sun.proxy.$Proxy19.echo(Unknown Source)
  at org.opendaylight.ovsdb.lib.impl.OvsdbClientImpl.echo(OvsdbClientImpl.java:292)
  at org.opendaylight.ovsdb.lib.jsonrpc.ExceptionHandler.userEventTriggered(ExceptionHandler.java:65)
  at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:329)
  at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:315)
  at io.netty.channel.AbstractChannelHandlerContext.fireUserEventTriggered(AbstractChannelHandlerContext.java:307)
  at io.netty.channel.ChannelInboundHandlerAdapter.userEventTriggered(ChannelInboundHandlerAdapter.java:108)
  at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:329)
  at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:315)
  at io.netty.channel.AbstractChannelHandlerContext.fireUserEventTriggered(AbstractChannelHandlerContext.java:307)
  at io.netty.handler.timeout.IdleStateHandler.channelIdle(IdleStateHandler.java:371)
  at io.netty.handler.timeout.IdleStateHandler$ReaderIdleTimeoutTask.run(IdleStateHandler.java:494)
  at io.netty.handler.timeout.IdleStateHandler$AbstractIdleTask.run(IdleStateHandler.java:466)
  at io.netty.util.concurrent.PromiseTask$RunnableAdapter.call(PromiseTask.java:38)
  at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:120)
  at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
  at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
  at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:463)
  at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
  at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
  at java.lang.Thread.run(Thread.java:745)
2018-04-12T11:20:50.133-0700 [error] [org.opendaylight.ovsdb.lib.jsonrpc.ExceptionHandler][exceptionCaught:50] - Exception was not handled by the exception handler, re-throwing it for next handler
2018-04-12T11:20:50.133-0700 [warn] [io.netty.channel.DefaultChannelPipeline][warn:151] - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.