CESNET / netopeer2

NETCONF toolset
BSD 3-Clause "New" or "Revised" License
296 stars 187 forks source link

Errors for yang push subscription to operational datastore #1450

Closed VasyaMeR closed 11 months ago

VasyaMeR commented 12 months ago

Hi,

I am trying to create yang push subscription to operational datastore to subscribe to its changes.

To do this, I started the netopeer2 server using the command 'netopeer2-server -d -v3 -t 100'. Then I used netopeer2-cli and the command 'establish-push --datastore operational --on-change --rpc-timeout 100'. I also tried this using libnetconf2

rpc = nc_rpc_establishpush_onchange(
        "ietf-datastores:operational",
        "",
        NULL,
        NULL,
        0,
        1,
        NULL,
        NC_PARAMTYPE_CONST);

r = nc_send_rpc(session, rpc, 1000, &msgid);

In response I received this output:

 - Using libnetconf2:
application operation-failed error User callback failed application operation-failed error User callback failed.

Logs of netopeer2 server:
<details>
  <summary>Logs</summary>

[INF]: SR: Connection 2 created. [INF]: SR: Session 49 (user "root", CID 2) created. [INF]: SR: Triggering "ietf-subscribed-notifications" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: LN: Listening on 0.0.0.0:830 for SSH connections. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-server" "done" event on enabled data. [INF]: SR: Triggering "ietf-keystore" "done" event on enabled data. [INF]: SR: Triggering "ietf-truststore" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-acm" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-acm" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-acm" "done" event on enabled data. [INF]: SR: Triggering "ietf-netconf-acm" "done" event on enabled data. [INF]: SR: Session 80 (user "root", CID 2) created. [INF]: LN: Received an SSH message "request-service" of subtype "ssh-userauth". [INF]: LN: Received an SSH message "request-auth" of subtype "none". [INF]: LN: Received an SSH message "request-auth" of subtype "password". [INF]: LN: User "root" authenticated. [INF]: LN: Received an SSH message "request-channel-open" of subtype "session". [INF]: LN: Received an SSH message "request-channel" of subtype "subsystem". [INF]: SR: Session 81 (user "root", CID 2) created. [INF]: SR: There are no subscribers for "ietf-netconf-notifications" notifications. [INF]: NP: Generated new event (netconf-session-start). [INF]: SR: EV ORIGIN: "/ietf-netconf-monitoring:get-schema" "rpc" ID 1 priority 0 for 1 subscribers published. [INF]: SR: EV LISTEN: "/ietf-netconf-monitoring:get-schema" "rpc" ID 1 priority 0 processing (remaining 1 subscribers). [INF]: NP: Module "ietf-datastores@" was requested. [INF]: SR: EV LISTEN: "/ietf-netconf-monitoring:get-schema" "rpc" ID 1 priority 0 success (remaining 0 subscribers). [INF]: SR: EV ORIGIN: "/ietf-netconf-monitoring:get-schema" "rpc" ID 1 priority 0 succeeded. [INF]: NP: Session 1: thread 2 event new RPC. [INF]: SR: EV ORIGIN: "/ietf-netconf:get" "rpc" ID 1 priority 0 for 1 subscribers published. [INF]: SR: EV LISTEN: "/ietf-netconf:get" "rpc" ID 1 priority 0 processing (remaining 1 subscribers). [INF]: SR: EV LISTEN: "/ietf-netconf:get" "rpc" ID 1 priority 0 success (remaining 0 subscribers). [INF]: SR: EV ORIGIN: "/ietf-netconf:get" "rpc" ID 1 priority 0 succeeded. [INF]: NP: Session 1: thread 2 event new RPC. [INF]: SR: EV ORIGIN: "/ietf-netconf:get" "rpc" ID 2 priority 0 for 1 subscribers published. [INF]: SR: EV LISTEN: "/ietf-netconf:get" "rpc" ID 2 priority 0 processing (remaining 1 subscribers). [INF]: SR: EV LISTEN: "/ietf-netconf:get" "rpc" ID 2 priority 0 success (remaining 0 subscribers). [INF]: SR: EV ORIGIN: "/ietf-netconf:get" "rpc" ID 2 priority 0 succeeded. [INF]: NP: Session 1: thread 1 event new RPC. [INF]: SR: EV ORIGIN: "/ietf-subscribed-notifications:establish-subscription" "rpc" ID 1 priority 0 for 1 subscribers published. [INF]: SR: EV LISTEN: "/ietf-subscribed-notifications:establish-subscription" "rpc" ID 1 priority 0 processing (remaining 1 subscribers). [INF]: SR: EV ORIGIN: "/ietf-netconf-acm:nacm/denied-operations" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/ietf-netconf-acm:nacm/denied-operations" "oper get" ID 1 processing. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 1 processing. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV LISTEN: "/ietf-netconf-acm:nacm/denied-operations" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/ietf-netconf-acm:nacm/denied-operations" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV ORIGIN: "/ietf-netconf-acm:nacm/denied-data-writes" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/ietf-netconf-acm:nacm/denied-data-writes" "oper get" ID 1 processing. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 2 published. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 2 processing. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 2 processing success. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 2 succeeded. [INF]: SR: EV LISTEN: "/ietf-netconf-acm:nacm/denied-data-writes" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/ietf-netconf-acm:nacm/denied-data-writes" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV ORIGIN: "/ietf-netconf-acm:nacm/denied-notifications" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/ietf-netconf-acm:nacm/denied-notifications" "oper get" ID 1 processing. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 3 published. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 3 processing. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 3 processing success. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 3 succeeded. [INF]: SR: EV LISTEN: "/ietf-netconf-acm:nacm/denied-notifications" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/ietf-netconf-acm:nacm/denied-notifications" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 4 published. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 4 processing. [INF]: SR: EV LISTEN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" ID 4 processing success. [INF]: SR: EV ORIGIN: "/sysrepo-monitoring:sysrepo-state/connection[cid='2']/nacm-stats" "oper get" index 0 ID 4 succeeded. [INF]: SR: EV ORIGIN: "/ietf-netconf-monitoring:netconf-state" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/ietf-netconf-monitoring:netconf-state" "oper get" ID 1 processing. [INF]: SR: EV LISTEN: "/ietf-netconf-monitoring:netconf-state" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/ietf-netconf-monitoring:netconf-state" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV ORIGIN: "/nc-notifications:netconf" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/nc-notifications:netconf" "oper get" ID 1 processing. [INF]: SR: EV LISTEN: "/nc-notifications:netconf" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/nc-notifications:netconf" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV ORIGIN: "/ietf-netconf-server:netconf-server/listen/endpoint/ssh/ssh-server-parameters/client-authentication/users" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/ietf-netconf-server:netconf-server/listen/endpoint/ssh/ssh-server-parameters/client-authentication/users" "oper get" ID 1 processing. [INF]: SR: EV LISTEN: "/ietf-netconf-server:netconf-server/listen/endpoint/ssh/ssh-server-parameters/client-authentication/users" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/ietf-netconf-server:netconf-server/listen/endpoint/ssh/ssh-server-parameters/client-authentication/users" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV ORIGIN: "/ietf-subscribed-notifications:streams" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/ietf-subscribed-notifications:streams" "oper get" ID 1 processing. [INF]: SR: EV LISTEN: "/ietf-subscribed-notifications:streams" "oper get" ID 1 processing success. [INF]: SR: EV ORIGIN: "/ietf-subscribed-notifications:streams" "oper get" index 0 ID 1 succeeded. [INF]: SR: EV ORIGIN: "/ietf-subscribed-notifications:subscriptions" "oper get" index 0 ID 1 published. [INF]: SR: EV LISTEN: "/ietf-subscribed-notifications:subscriptions" "oper get" ID 1 processing. [ERR]: SR: EV ORIGIN: "oper get" ID 1 processing timed out. [WRN]: SR: EV ORIGIN: "/ietf-subscribed-notifications:subscriptions" "oper get" index 0 ID 1 failed (Timeout expired). [ERR]: SR: User callback failed. [INF]: SR: EV LISTEN: "/ietf-subscribed-notifications:establish-subscription" "rpc" ID 1 priority 0 fail (remaining 1 subscribers). [INF]: SR: EV LISTEN: "oper get" ID 1 processing success (after timeout). [ERR]: SR: User callback failed [WRN]: SR: EV ORIGIN: "/ietf-subscribed-notifications:establish-subscription" "rpc" ID 1 priority 0 failed (User callback failed). [ERR]: SR: User callback failed. [ERR]: NP: Failed to send an RPC (User callback failed). [INF]: NP: Session 1: thread 2 event new RPC. [INF]: NP: Session 1: thread 2 event reply error.



</details>

OS version is Ubuntu 22.04.2 LTS, netopeer2-server 2.1.68, libsysrepo 2.2.98.

Could you please tell me how to fix this?
michalvasko commented 11 months ago

Please update netopeer2, should be fixed in the latest devel branch.

VasyaMeR commented 11 months ago

After the update, this error disappeared. But when I try to subscribe using this command 'establish-push --datastore operational --filter-xpath /ietf-subscribed-notifications:* --on-change', I got the first notification with the data about current subscriptions. Than I create a new subscription from another client (using the same command as before) and expect to receive a notification with the data about the new subscription I just created, but it doesn't.

michalvasko commented 11 months ago

On-change notifications for operational datastore are limited to the push oper data changes, pull cannot be reported unless a poll subscription is also created. More info in the docs.