What is the expected reply messages sequence after sending <close-session>?

Hi tail-f support,

We’re verifying notification feature based on confd and have a question related to close-session operation.

Right now, We found a strange behavior when we sent close-session to stop notification subscription. one case is rpc-reply ok returned after sending close-session as below.

<rpc message-id="167" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <close-session/>
</rpc>
<rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="167">
    <ok/>
</rpc-reply>

the other case is rpc-reply ok is not returned, instead, we will receive netconf-session-end event as below.

<rpc message-id="167" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <close-session/>
</rpc>
<notification xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
    <eventTime>2021-10-26T08:03:44.478232+00:00</eventTime>
    <netconf-session-end xmlns="urn:ietf:params:xml:ns:yang:ietf-netconf-notifications">
        <username>expert</username>
        <session-id>297</session-id>
        <source-host>10.255.4.2</source-host>
        <termination-reason>closed</termination-reason>
    </netconf-session-end>
</notification>

As our understandings, when we sent close-session, we should receive rpc-reply ok firstly, and if we also have executed create-subscription, then netconf-session-end received.
We just wonder that which above behavior is correct, or both are correct?

Thanks in advance.
Best,
Li

Hi,

The reason for the session being closed could be that there is a data provider error. See the ConfD developer log.

You can configure ConfD to send an rpc-error reply instead of closing the session immediately on a data provider error. See the ConfD configuration file confd.conf(5) man page:

/confdConfig/netconf/rpcErrors (close|inline) [close]
If rpcErrors is “inline”, and an error occurs during the processing of a or request when ConfD tries to fetch some data from a data provider, ConfD will generate an rpc-error element in the faulty element, and continue to process the next element.
If an error occurs and rpcErrors is “close”, the NETCONF transport is closed by ConfD.

Best regards

Hi,
Thanks for your reply. Our verification test is very simple without invoking the data provider api, the corresponding printout is shown as below.

<hello xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <capabilities>
    <capability>urn:ietf:params:netconf:base:1.0</capability>
  </capabilities>
</hello>]]>]]><?xml version="1.0" encoding="UTF-8" ?>
<rpc message-id="101" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <create-subscription xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
    <stream>NETCONF</stream>
  </create-subscription>
</rpc>]]>]]><?xml version="1.0" encoding="UTF-8"?>
<rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="101"><ok/></rpc-reply>]]>]]><?xml version="1.0" encoding="UTF-8" ?>
<rpc message-id="102" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <close-session/>
</rpc>]]>]]><?xml version="1.0" encoding="UTF-8"?>
<notification xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0"><eventTime>2021-12-02T02:06:37.727769+00:00</eventTime>
<netconf-session-end xmlns='urn:ietf:params:xml:ns:yang:ietf-netconf-notifications'>
  <username>user1</username>
  <session-id>18</session-id>
  <source-host>192.168.163.71</source-host>
  <termination-reason>closed</termination-reason>
</netconf-session-end>
</notification>]]>]]><?xml version="1.0" encoding="UTF-8"?>
<rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="102"><ok/></rpc-reply>]]>]]>Connection to 10.107.95.158 closed.

We think the above test result seems to not follow RFC6470 and RFC6241.
RFC6470 states:

netconf-session-end:
Generated when a NETCONF server detects that a NETCONF session has
terminated. A server MAY optionally generate this event for
non-NETCONF management sessions. Indicates the identity of the
user that owned the session, and why the session was terminated.

RFC6241 states:

Positive Response: If the device was able to satisfy the request, an
<rpc-reply> is sent that includes an <ok> element.

Negative Response: An <rpc-error> element is included in the
<rpc-reply> if the request cannot be completed for any reason.

According to our understanding, rpc-reply ok should be sent before netconf-session-end when close-session. What do you think of this? Thanks in advance.

Best,
Li

Hi,

Are you taking that printout from the NETCONF trace log on the ConfD side or from the NETCONF client and NETCONF stream notification subscriber side?

When I test with the ConfD 7.6.x examples.confd/netconf_notification examples the netconf.trace log show that the rpc-reply ok is sent before the netconf-config-change notification. Do you have a use case that requres ordering and if so, why? (just curious)

Either way, I do not see any guarantees for ordering between the “ok” rpc-reply and the netconf-config-change notification in the RFCs.

As a side note, one of the reasons behind the /confdConfig/netconf/rpcErrors configuration parameter, from RFC6241:

A server MUST NOT return application-level- or data-model-specific
error information in an element for which the client does
not have sufficient access rights.

Best regards

Hi, this printout is from the NETCONF client.

According to the statement from RFCs we pasted before, RFC6470 clearly states that netconf-session-end generates after the session has terminated, RFC6241 states that rpc-reply ok is sent if the NETCONF server satisfies close-session request. So we think rpc-reply ok should be sent once the NETCONF server start terminating.

Based on the above understandings, we think the steps in ConfD would be:

  1. Receive the close-session command.
  2. Return a rpc-reply ok if the server could satisfy the request or rpc-error if not.
  3. Notify the subscribers(usually another connection) that this session was closed or none is sent since it failed (then users don’t need to expect one).

However, our test result based on ConfD is different with what we think, the session being closed also receive the notification before rpc-reply ok. The tests are shown as below.

Test 1:
The client opened 2 sessions with the server, both sessions created a subscription specifying NETCONF stream. Session A requested close-session and session B did nothing, We found session A only received rpc-reply ok then was closed. Session B received netconf-session-end event of session A. We think this behavior follows RFCs.

Test 2:
Session B kept active, client reopened session A, performed the same steps as the first test, the result was different. In session A, first received netconf-session-end event then rpc-reply ok. While session B also received netconf-session-end event of session A.

Could you have a look and explain why? Thanks in advance.

Best,
Li

Hi,

Regardless of how we interpret the RFCs, I believe ConfD always sends the rpc-reply ok first.

You write that you are opening two sessions towards ConfD with your client. Can you guarantee that your client will always receive data from the sessions in the same order as they are sent by ConfD? I do not believe you always can.

You should verify that ConfD sends the rpc-reply ok first using the ConfD NETCONF log and/or NETCONF trace log, not using your client that has two separate sessions for notifications and configuration. You enable the NETCONF logs in confd.conf. See the confd.conf(5) man page.

You can use your client to verify if you handle the notifications and configuration in the same session, i.e. you enable the “interleave” capability for NETCONF notifications in your confd.conf. See /confdConfig/netconf/capabilities/notification/interleave/enabled in the confd.conf(5) man page.

Best regards

Hi, you’re right, the order of these two reply messages is not always the same, could you tell us how to use trace log to verify that ConfD sends rpc-reply ok first?
If ConfD is like what you said, we think the network issue between the client and ConfD causes the order is random, do you agree us? Could you tell us your opions? Thanks.

Best,
Li

Hi,

As described by the confd.conf(5) man page I pointed to previously you add something like the following to your confd.conf (or dyncfg if you have enabled dynamic config) to enable the netconf.log:

  <logs>
    ...
    <netconfLog>
      <enabled>true</enabled>
      <file>
        <enabled>true</enabled>
        <name>./netconf.log</name>
      </file>
      <syslog>
        <enabled>false</enabled>
      </syslog>
    </netconfLog>
    <!-- And/or if you want to log all NETCONF communication for debug purposes -->
    <netconfTraceLog>
      <enabled>true</enabled>
      <filename>./netconf.trace</filename>
      <format>pretty</format>
    </netconfTraceLog>
  </logs>

Yes, since you are using two separate sessions.

As mentioned previously, you can use a single session for both configuration and notifications if your client can handle it and if you enable the “interleave” capability for NETCONF notifications in your confd.conf.

  <netconf>
    ...
    <capabilities>
      ...
      <notification>
        <enabled>true</enabled>
        <interleave>
          <enabled>true</enabled>
        </interleave>
      </notification>
    </capabilities>
  </netconf>

You can verify using the netconf-console client tool (here using the netconf-notification example) that comes with ConfD:

$ cd examples.confd/netconf_notifications
$ make all
...
$ netconf-console -i

* Enter a NETCONF operation, end with an empty line, or only empty continuing session
<create-subscription xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
  <stream>NETCONF</stream>
</create-subscription>

<?xml version="1.0" encoding="UTF-8"?>
<rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="2">
  <ok/>
</rpc-reply>

* Enter a NETCONF operation, end with an empty line, or only empty continuing session
<edit-config xmlns:nc="urn:ietf:params:xml:ns:netconf:base:1.0">
  <target>
    <running/>
  </target>
  <config>
    <interfaces xmlns:nc="urn:ietf:params:xml:ns:netconf:base:1.0" xmlns="http://tail-f.com/ns/test/notif">
      <interface nc:operation="create">
        <if-index>11</if-index>
        <desc>Iinterface 11</desc>
      </interface>
      <interface nc:operation="create">
        <if-index>12</if-index>
        <desc>Interface 12</desc>
      </interface>
    </interfaces>
  </config>
</edit-config>

<?xml version="1.0" encoding="UTF-8"?>
<rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="3">
  <ok/>
</rpc-reply>

* Enter a NETCONF operation, end with an empty line, or only empty continuing session

<?xml version="1.0" encoding="UTF-8"?>
<notification xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
  <eventTime>2021-12-07T07:24:28.108222+00:00</eventTime>
  <netconf-config-change xmlns="urn:ietf:params:xml:ns:yang:ietf-netconf-notifications">
    <changed-by>
      <username>admin</username>
      <session-id>14</session-id>
      <source-host>127.0.0.1</source-host>
    </changed-by>
    <datastore>running</datastore>
    <edit>
      <target xmlns:notif="http://tail-f.com/ns/test/notif">/notif:interfaces/notif:interface[notif:if-index='11']</target>
      <operation>create</operation>
    </edit>
    <edit>
      <target xmlns:notif="http://tail-f.com/ns/test/notif">/notif:interfaces/notif:interface[notif:if-index='12']</target>
      <operation>create</operation>
    </edit>
  </netconf-config-change>
</notification>

Best regards

Hi,

We enabled netconfTraceLog and reproduced the issue based on confd-7.5.2.3, below is the printout from the trace log.

**> sess:25 new session

7-Dec-2021::11:00:55.170 **< sess:25 write:
<hello xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <capabilities>
    <capability>urn:ietf:params:netconf:base:1.0</capability>
    <capability>urn:ietf:params:netconf:base:1.1</capability>
    <capability>urn:ietf:params:netconf:capability:wriable-running:1.0</capability>
    <capability>urn:ietf:params:netconf:capability:rollback-on-error:1.0</capability>
    <capability>urn:ietf:params:netconf:capability:validate:1.0</capability>
    <capability>urn:ietf:params:netconf:capability:validate:1.1</capability>
    <capability>urn:ietf:params:netconf:capability:xpath:1.0</capability>
    <capability>urn:ietf:params:netconf:capability:notification:1.0</capability>
    <capability>urn:ietf:params:netconf:capability:interleave:1.0</capability>
    <capability>urn:ietf:params:netconf:capability:partial-lock:1.0</capability>
    <capability>urn:ietf:params:netconf:capability:with-defaults:1.0?basic-mode=explicit&amp;also-supported=report-all-tagged,report-all</capability>
    <capability>urn:ietf:params:netconf:capability:yang-library:1.0?revision=2019-01-04&amp;module-set-id=de6c4d04ab6a38374b8d13817a596379</capability>
    <capability>urn:ietf:params:netconf:capability:yang-library:1.1?revision=2019-01-04&amp;content-id=de6c4d04ab6a38374b8d13817a596379</capability>
    <capability>http://tail-f.com/ns/netconf/actions/1.0</capability>
    <capability>http://tail-f.com/ns/aaa/1.1?module=tailf-aaa&amp;revision=2018-09-12</capability>
    <capability>http://tail-f.com/ns/common/query?module=tailf-common-query&amp;revision=2017-12-15</capability>
    <capability>http://tail-f.com/ns/confd-progress?module=tailf-confd-progress&amp;revision=2020-06-29</capability>
    <capability>http://tail-f.com/ns/kicker?module=tailf-kicker&amp;revision=2020-11-26</capability>
    <capability>http://tail-f.com/ns/netconf/query?module=tailf-netconf-query&amp;revision=2017-01-06</capability>
    <capability>http://tail-f.com/yang/acm?module=tailf-acm&amp;revision=2013-03-07</capability>
    <capability>http://tail-f.com/yang/common?module=tailf-common&amp;revision=2020-11-26</capability>
    <capability>http://tail-f.com/yang/common-monitoring?module=tailf-common-monitoring&amp;revision=2019-04-09</capability>
    <capability>http://tail-f.com/yang/confd-monitoring?module=tailf-confd-monitoring&amp;revision=2019-10-30</capability>
    <capability>http://tail-f.com/yang/netconf-monitoring?module=tailf-netconf-monitoring&amp;revision=2019-03-28</capability>
    <capability>http://tail-f.com/yang/xsd-types?module=tailf-xsd-types&amp;revision=2017-11-20</capability>
    <capability>urn:ietf:params:xml:ns:netconf:base:1.0?module=ietf-netconf&amp;revision=2011-06-01&amp;features=writable-running,rollback-on-error,validate,xpath</capability>
    <capability>urn:ietf:params:xml:ns:netconf:partial-lock:1.0?module=ietf-netconf-partial-lock&amp;revision=2009-10-19</capability>
    <capability>urn:ietf:params:xml:ns:yang:iana-crypt-hash?module=iana-crypt-hash&amp;revision=2014-08-06&amp;features=crypt-hash-sha-512,crypt-hash-sha-256,crypt-hash-md5</capability>    <capability>urn:ietf:params:xml:ns:yang:ietf-inet-types?module=ietf-inet-types&amp;revision=2013-07-15</capability>
    <capability>urn:ietf:params:xml:ns:yang:ietf-netconf-acm?module=ietf-netconf-acm&amp;revision=2018-02-14</capability>
    <capability>urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?module=ietf-netconf-monitoring&amp;revision=2010-10-04</capability>
    <capability>urn:ietf:params:xml:ns:yang:ietf-netconf-notifications?module=ietf-netconf-notifications&amp;revision=2012-02-06</capability>
    <capability>urn:ietf:params:xml:ns:yang:ietf-netconf-with-defaults?module=ietf-netconf-with-defaults&amp;revision=2011-06-01</capability>
    <capability>urn:ietf:params:xml:ns:yang:ietf-yang-metadata?module=ietf-yang-metadata&amp;revision=2016-08-05</capability>
    <capability>urn:ietf:params:xml:ns:yang:ietf-yang-types?module=ietf-yang-types&amp;revision=2013-07-15</capability>
  </capabilities>
  <session-id>25</session-id>
</hello>

7-Dec-2021::11:00:55.170 **< sess:24 write:
<notification xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
  <eventTime>2021-12-07T10:00:55.169558+00:00</eventTime>
  <netconf-session-start xmlns="urn:ietf:params:xml:ns:yang:ietf-netconf-notifications">
    <username>user1</username>
    <session-id>25</session-id>
    <source-host>192.168.163.71</source-host>
  </netconf-session-start>
</notification>

7-Dec-2021::11:01:08.103 **> sess:25 read:
<hello xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <capabilities>
    <capability>urn:ietf:params:netconf:base:1.0</capability>
  </capabilities>
</hello>
]]>]]>
<rpc xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="101">
  <create-subscription xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
    <stream>NETCONF</stream>
  </create-subscription>
</rpc>

7-Dec-2021::11:01:25.497 **< sess:25 write:
<rpc-reply message-id="101" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <ok/>
</rpc-reply>
]]>]]>
<rpc xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="102">
  <close-session/>
</rpc>

7-Dec-2021::11:01:38.294 **< sess:25 write:
<notification xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
  <eventTime>2021-12-07T10:01:38.294512+00:00</eventTime>
  <netconf-session-end xmlns="urn:ietf:params:xml:ns:yang:ietf-netconf-notifications">
    <username>user1</username>
    <session-id>25</session-id>
    <source-host>192.168.163.71</source-host>
    <termination-reason>closed</termination-reason>
  </netconf-session-end>
</notification>

7-Dec-2021::11:01:38.295 **< sess:24 write:
<notification xmlns="urn:ietf:params:xml:ns:netconf:notification:1.0">
  <eventTime>2021-12-07T10:01:38.294512+00:00</eventTime>
  <netconf-session-end xmlns="urn:ietf:params:xml:ns:yang:ietf-netconf-notifications">
    <username>user1</username>
    <session-id>25</session-id>
    <source-host>192.168.163.71</source-host>
    <termination-reason>closed</termination-reason>
  </netconf-session-end>
</notification>

7-Dec-2021::11:01:38.296 **< sess:25 write:
<rpc-reply message-id="102" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
  <ok/>
</rpc-reply>

**< sess:25 session closed

When session 25 was closed, ConfD first generated netconf-session-end event then rpc-reply ok.

Hi,

So we go full circle back to RFC interpretation. ConfD sends the notification when ConfD has closed the NETCONF session. The RPC ok message to the client may come before or after the NETCONF stream notification, but the session state inside ConfD is always “closed” when the NETCONF stream notification is sent.

The RFC6470 says the following regarding netconf-session-end:

Generated when a NETCONF server detects that a NETCONF session has terminated.

And this is what ConfD does, i.e. sends a netconf-session-end when ConfD detects that the session has terminated.

I am guessing you have implemented some mechanism that relies on the ordering between NETCONF stream notifications and NETCONF RPC operations and therefore has an opinion on how to interpret the RFC based on that. I see that you have a ticket open with our support on this matter.