Description
During shutdown we can observe the following bit:
2022-08-22T13:01:11,816 | INFO | Framework stop - Equinox Container: b2b91105-3e38-49c8-add9-45cf9fe2a942 | BlueprintExtender | 27 - org.apache.aries.blueprint.core - 1.10.3 | Destroying container for blueprint bundle org.opendaylight.netconf.mdsal-netconf-tcp/4.0.2.SNAPSHOT
2022-08-22T13:01:11,817 | INFO | Framework stop - Equinox Container: b2b91105-3e38-49c8-add9-45cf9fe2a942 | BlueprintExtender | 27 - org.apache.aries.blueprint.core - 1.10.3 | Destroying container for blueprint bundle org.opendaylight.netconf.mdsal-netconf-ssh/4.0.2.SNAPSHOT
2022-08-22T13:01:11,823 | WARN | Framework stop - Equinox Container: b2b91105-3e38-49c8-add9-45cf9fe2a942 | DefaultCloseFuture | 283 - org.opendaylight.netconf.shaded-sshd - 4.0.2.SNAPSHOT | notifyListener(DefaultCloseFuture[id=][value=true]) failed (UnsupportedOperationException) to invoke org.opendaylight.netconf.shaded.sshd.common.util.closeable.SequentialCloseable$1@66c732b7: null
2022-08-22T13:02:11,824 | ERROR | Framework stop - Equinox Container: b2b91105-3e38-49c8-add9-45cf9fe2a942 | BeanRecipe | 27 - org.apache.aries.blueprint.core - 1.10.3 | The blueprint bean netconfMdsalServer in bundle org.opendaylight.netconf.mdsal-netconf-ssh/4.0.2.SNAPSHOT incorrectly threw an exception from its destroy method.
java.net.SocketTimeoutException: Failed to receive closure confirmation within PT1M millis
at org.opendaylight.netconf.shaded.sshd.server.SshServer.stop(SshServer.java:370) ~[?:?]
at org.opendaylight.netconf.ssh.SshProxyServer.close(SshProxyServer.java:118) ~[?:?]
at org.opendaylight.netconf.ssh.NetconfNorthboundSshServer.close(NetconfNorthboundSshServer.java:82) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
at org.apache.aries.blueprint.utils.ReflectionUtils.invoke(ReflectionUtils.java:337) ~[?:?]
at org.apache.aries.blueprint.container.BeanRecipe.invoke(BeanRecipe.java:835) ~[?:?]
at org.apache.aries.blueprint.container.BeanRecipe.destroy(BeanRecipe.java:742) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintRepository.destroy(BlueprintRepository.java:434) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintContainerImpl.destroyComponents(BlueprintContainerImpl.java:778) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintContainerImpl.tidyupComponents(BlueprintContainerImpl.java:987) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:923) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintExtender$3.run(BlueprintExtender.java:360) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintExtender.destroyContainer(BlueprintExtender.java:381) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintExtender.stop(BlueprintExtender.java:199) ~[?:?]
at org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:248) ~[?:?]
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.eclipse.osgi.internal.framework.EquinoxEventPublisher.lambda$1(EquinoxEventPublisher.java:252) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.notifyHookPrivileged(ServiceRegistry.java:1349) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.notifyHooksPrivileged(ServiceRegistry.java:1322) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.notifyEventHooksPrivileged(EquinoxEventPublisher.java:252) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:210) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:138) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:130) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:217) ~[?:?]
at org.eclipse.osgi.container.Module.publishEvent(Module.java:499) ~[?:?]
at org.eclipse.osgi.container.Module.doStop(Module.java:658) ~[?:?]
at org.eclipse.osgi.container.Module.stop(Module.java:521) ~[?:?]
at org.eclipse.osgi.container.SystemModule.stop(SystemModule.java:207) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule$1.run(EquinoxBundle.java:226) ~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
I very much suspect the UnsupportedOpeationException is hiding the reason for the delay in shutdown and eventual reported error.
Attachments
| # | Subject | Branch | Project | Status | CR | V |
|---|---|---|---|---|---|---|
| 102584,6 | Fix mdsal-netconf-ssh shutdown | master | netconf | Status: MERGED | +2 | +1 |
| 102641,1 | Fix mdsal-netconf-ssh shutdown | 3.0.x | netconf | Status: MERGED | +2 | +1 |