|
So something like this would work: https://git.opendaylight.org/gerrit/c/netconf/+/102590
But I'm not sure why session negotiation failure due to timeout requires a special treatment where promise is not failed, so negotiation is retried with the same promise. It seems to be just one of the failure scenarios - since timer does not start until channel becomes active, it does not cover pure reachability issue different from other exceptions.
|
|
Yeah, but that patch seems to have other issues. Gawking at the stack trace, it seems a tad strange: the channel was closed before channelActive() was invoked?!
Can you post logs with AsyncSshHandler at debug, please?
I wonder whether AsyncSshHandler.handleSshChanelOpened() is executing outside the event loop and we end up somehow circling to AsyncSshHandler.safelyDisconnect() before channelActive() is processed...
|
|
Post karaf log at the DEBUG level. The error was triggered when device configuration was reapplied a few times forcing controller to establish new NETCONF connections while interrupting the negotiation process at breakpoints set in AbstractNetconfSessionNegotiator (channelActive, channelRead).
|
|
Looks like the device initiated disconnection probably because of the long idle time before it receives hello back:
|
|
Okay so we have some inter-thread handover:
and then:
note how we have things executing on sshd-nio2 threads and on globalWorkerGroup threads.
Also, there is a 30 second delay in negotiation start – but note also that "Session negotiation started" is triggered after the channel is closed – pointing towards a problem in state checking. I think we need to handle the case where channelActive is triggered and there is also a channelInactive is staged in the executor,
|
|
The interesting thing is the delay of 37,579 seconds between "starting" and "started" messages on the global worker thread. It is during this delay that the session goes down. This seems to indicate that AbstractNetconfSessionNegotiator.start() needs to check whether the channel is still open before embarking on sending the message.
We also need to figure out how AsyncSshHandler.safelyDisconnect() -> AsyncSshHandlerWriter.close() -> channel.close() is synchronized w.r.t. the the negotiator.
|
|
Rather than mucking around with lifecycle and trying to synchronize things, the fix is to run the two methods interacting with channel lifecycle on the corresponding executor – thus providing natural sequencing.
|
|
karaf-netconf-905.log: karaf log for https://git.opendaylight.org/gerrit/c/netconf/+/102740/
|
|
So here we are catching this transition:
and also this:
Both of these are a failure to send initial hello message. Since these are in the Netty->SSHD direction, there simply are SSHD transitions we have not observed yet (as they are running concurrently with Netty) – a closed or closing channel may be one of those.
If this ever happens it is equivalent to the session never being established, as the failure occurred when attempting IDLE->OPEN_WAIT transition and hence the transition becomes IDLE->FAILED instead.
|
|
|
Generated at Wed Feb 07 20:16:12 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.
karaf-netconf-905-102751-4-mod.log