-
Bug
-
Resolution: Duplicate
-
High
-
None
-
Fluorine SR1
-
None
-
Fedora 29 / openjdk version "1.8.0_191"
Fluorine-SR1
When odl-netconf-mdsal is installed, there is unnecessary delay in shutdown (5+1 minutes).
Steps to reproduce:
Download and extract https://nexus.opendaylight.org/content/repositories/opendaylight.release/org/opendaylight/integration/karaf/0.9.1/karaf-0.9.1.tar.gz
Start using
./bin/karaf
Install odl-netconf-mdsal
feature:install odl-netconf-mdsal
Request shutdown from second terminal
./bin/stop
Observe delay.
Here are relevant log entries:
2018-11-23T06:49:11,158 | INFO | Karaf Shutdown Socket Thread | ShutdownSocketThread | - - | Karaf shutdown socket: received shutdown command. Stopping framework...
2018-11-23T06:49:11,422 | INFO | Framework stop | BlueprintExtender | 18 - org.apache.aries.blueprint.core - 1.8.3 | Destroying BlueprintContainer for bundle mdsal-netconf-ssh/1.5.1
2018-11-23T06:54:11,424 | INFO | Framework stop | ReferenceRecipe | 18 - org.apache.aries.blueprint.core - 1.8.3 | Timeout expired when waiting for mandatory OSGi service reference (&(type=global-event-executor)(objectClass=io.netty.util.concurrent.EventExecutor))
Above is first part of delay (5 minutes), followed by another 1 minutes:
2018-11-23T06:54:11,425 | WARN | Framework stop | DefaultCloseFuture | 54 - org.apache.sshd.core - 1.6.0 | notifyListener(DefaultCloseFuture[id=SshServer[178c9d64]][value=true]) failed (ServiceUnavailableException) to invoke org.apache.sshd.common.util.closeable.SequentialCloseable$1@2ca9e995: Timeout expired when waiting for mandatory OSGi service reference: (&(type=global-event-executor)(objectClass=io.netty.util.concurrent.EventExecutor))
2018-11-23T06:55:11,426 | ERROR | Framework stop | BeanRecipe | 18 - org.apache.aries.blueprint.core - 1.8.3 | The blueprint bean netconfMdsalServer in bundle mdsal-netconf-ssh/1.5.1 incorrectly threw an exception from its destroy method.
java.net.SocketTimeoutException: Failed to receive closure confirmation within 60000 millis
I'm attaching full threaddump, but this seems to be most relevant to me:
"Framework stop" #263 daemon prio=5 os_prio=0 tid=0x00007f643c0c7000 nid=0x5620 in Object.wait() [0x00007f64311fd000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at org.apache.aries.blueprint.container.ReferenceRecipe.getService(ReferenceRecipe.java:211)
- locked <0x00000000ecf538d0> (a java.lang.Object)
at org.apache.aries.blueprint.container.ReferenceRecipe.access$000(ReferenceRecipe.java:56)
at org.apache.aries.blueprint.container.ReferenceRecipe$ServiceDispatcher.call(ReferenceRecipe.java:306)
at Proxyb6cc05cb_233a_49c6_985b_8f8122bb8cce.execute(Unknown Source)
at sun.nio.ch.AsynchronousChannelGroupImpl.executeOnPooledThread(AsynchronousChannelGroupImpl.java:188)
at sun.nio.ch.Invoker.invokeIndirectly(Invoker.java:212)
at sun.nio.ch.UnixAsynchronousServerSocketChannelImpl.implClose(UnixAsynchronousServerSocketChannelImpl.java:118)
at sun.nio.ch.AsynchronousServerSocketChannelImpl.close(AsynchronousServerSocketChannelImpl.java:111)
at org.apache.sshd.common.io.nio2.Nio2Acceptor.unbind(Nio2Acceptor.java:113)
at org.apache.sshd.common.io.nio2.Nio2Acceptor.unbind(Nio2Acceptor.java:99)
at org.apache.sshd.common.io.nio2.Nio2Acceptor.close(Nio2Acceptor.java:141)
at org.apache.sshd.common.util.closeable.SequentialCloseable$1.operationComplete(SequentialCloseable.java:56)
at org.apache.sshd.common.util.closeable.SequentialCloseable$1.operationComplete(SequentialCloseable.java:45)
at org.apache.sshd.common.future.AbstractSshFuture.notifyListener(AbstractSshFuture.java:159)
at org.apache.sshd.common.future.DefaultSshFuture.addListener(DefaultSshFuture.java:167)
at org.apache.sshd.common.util.closeable.SequentialCloseable$1.operationComplete(SequentialCloseable.java:57)
at org.apache.sshd.common.util.closeable.SequentialCloseable$1.operationComplete(SequentialCloseable.java:45)
at org.apache.sshd.common.util.closeable.SequentialCloseable.doClose(SequentialCloseable.java:69)
at org.apache.sshd.common.util.closeable.SimpleCloseable.close(SimpleCloseable.java:63)
at org.apache.sshd.common.util.closeable.AbstractInnerCloseable.doCloseImmediately(AbstractInnerCloseable.java:46)
at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:83)
at org.apache.sshd.server.SshServer.stop(SshServer.java:339)
at org.opendaylight.netconf.ssh.SshProxyServer.close(SshProxyServer.java:106)
at org.opendaylight.netconf.ssh.NetconfNorthboundSshServer.close(NetconfNorthboundSshServer.java:82)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
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:745)
at org.apache.aries.blueprint.container.BlueprintContainerImpl.tidyupComponents(BlueprintContainerImpl.java:956)
at org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:890)
at org.apache.aries.blueprint.container.BlueprintExtender$3.run(BlueprintExtender.java:325)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.aries.blueprint.container.BlueprintExtender.destroyContainer(BlueprintExtender.java:346)
at org.apache.aries.blueprint.container.BlueprintExtender.access$400(BlueprintExtender.java:68)
at org.apache.aries.blueprint.container.BlueprintExtender$BlueprintContainerServiceImpl.destroyContainer(BlueprintExtender.java:633)
at org.opendaylight.controller.blueprint.BlueprintBundleTracker.shutdownAllContainers(BlueprintBundleTracker.java:286)
at org.opendaylight.controller.blueprint.BlueprintBundleTracker.bundleChanged(BlueprintBundleTracker.java:191)
at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908)
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)
at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213)
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120)
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112)
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168)
at org.eclipse.osgi.container.Module.publishEvent(Module.java:476)
at org.eclipse.osgi.container.Module.doStop(Module.java:634)
at org.eclipse.osgi.container.Module.stop(Module.java:498)
at org.eclipse.osgi.container.SystemModule.stop(SystemModule.java:202)
at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule$1.run(EquinoxBundle.java:165)
at java.lang.Thread.run(Thread.java:748)
- duplicates
-
NETCONF-577 sshd-2.0.0 seems to be stuck on shutdown
- Resolved