CESNET
netconf2.Error: Failed to parse <get> reply
Hi there,
sorry for what could be a stupid question for an educated one but I've struggling with a Failed to parse <get> reply from the pynetconf2 for days and can't get to know why I'm getting it.
For some background information, I'm trying to get via netconf the output of a "show version" command from a Nokia router by means of the libnetconf2 python wrapper using this query:
"<oper-data-format-cli-block> <cli-show>version</cli-show> </oper-data-format-cli-block>"
So, other than for those #15 at the end of some lines (are they a replacement for \r\n?), I think the answer from the router is OK:
#012<?xml version="1.0" encoding="UTF-8"?>
#012<rpc-reply message-id="2" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
#012 <data>
#012 <oper-data-format-cli-block xmlns="urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13">
#012 <item>
#012 <cli-show>version</cli-show>
#012 <response>
#012TiMOS-B-16.0.R4 both/x86_64 Nokia 7750 SR Copyright (c) 2000-2018 Nokia.#015#015
#012All rights reserved. All use subject to applicable license agreements.#015#015
#012Built on Mon Nov 5 07:26:36 PST 2018 by builder in /builds/c/160B/R4/panos/main#015#015
#012 </response>
#012 </item>
#012 </oper-data-format-cli-block>
#012 </data>
#012</rpc-reply>
Now, the netconf2.Error: Failed to parse <get> reply error seems to be, in turn, caused by this one (which is repeated multiple times):
The above exception was the direct cause of the following exception:
SystemError: <class 'netconf2.Warning'> returned a result with an error set
but couldn't find the way to solve or work around it.
Any hint on what I'm missing or doing wrong?
I'm attaching a file with the python file I use for the query, the debug output I get from it, the syslog messages from the client and a dump of the router's (netconf server) debug info.
Thanks in advance, zappacor
Hi Rolando, I cannot be certain without trying it myself but I would focus on the errors as they are the most likely cause.
Firstly, the client gets some invalid ietf-yang-library-data
libyang[0]: Value "" does not satisfy the constraint "1..max" (range, length, or pattern). (path: /ietf-yang-library:modules-state/module[name='iana-if-type'][revision='2014-05-08']/feature[.=''])
Then there are some invalid models
libyang[0]: Invalid keyword ";".
libyang[0]: Module "alu-conf-system-r13" parsing failed.
libyang[0]: A circular dependency (include) for submodule "nokia-state-service".
libyang[0]: Submodule "nokia-state-svc-vprn" parsing failed.
libyang[0]: Including "nokia-state-svc-vprn" module into "nokia-state-service" failed.
libyang[0]: Submodule "nokia-state-service" parsing failed.
libyang[0]: Including "nokia-state-service" module into "nokia-state-filter" failed.
libyang[0]: Submodule "nokia-state-filter" parsing failed.
libyang[0]: Including "nokia-state-filter" module into "nokia-state" failed.
You should try to fix these models and then try again.
Regards, Michal
Hi Michal,
First of all, thanks for your prompt answer!
So, corrected some errors on the models (hence, not getting the libyang ones you mentioned above anymore) but I'm still getting errors from the client:
Nov 26 21:02:55 RJZ-WRK-LNX python3[9674]: Session 46: sending message:#012#012#249
Nov 26 21:02:55 RJZ-WRK-LNX python3[9674]: Session 46: sending message:#012<rpc xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="1"><get xmlns="urn:ietf:params:xml:ns:netconf:base:1.0"><filter type="subtree"><oper-data-format-cli-block> <cli-show>time</cli-show> </oper-data-format-cli-block></filter></get></rpc>
Nov 26 21:02:55 RJZ-WRK-LNX python3[9674]: Session 46: sending message:#012#012##
Nov 26 21:02:55 RJZ-WRK-LNX python3[9674]: Session 46: received message:#012<?xml version="1.0" encoding="UTF-8"?>#012<rpc-reply message-id="1" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">#012 <data>#012 <oper-data-format-cli-block xmlns="urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13">#012 <item>#012 <cli-show>time</cli-show>#012 <response>#012Mon Nov 26 21:02:52 UTC 2018#015#012 </response>#012 </item>#012 </oper-data-format-cli-block>#012 </data>#012</rpc-reply>
Nov 26 21:02:55 RJZ-WRK-LNX python3[9674]: Failed to parse <get> reply.
Traceback (most recent call last):
File "/home/rzappaco/libnetconf2/libnetconf2/libnetconf2-master/python/examples/get-sros.py", line 43, in <module>
data = session.rpcGet(ncfilter)
ConnectionError: Failed to receive a reply.
Since the router is sending the answer, I'm wondering what could be causing the client to miss it (as implied by its error message above)?
Any hint or idea on what could be wrong?
Thanks in advance, zappacor
Logs for this new test (/var/log/syslog and pynetconf output only): logs2.txt
Hi,
I may have an idea how to get some detailed error message but it requires a few changes. Firstly, in libnetconf2 python bindings source (libnetconf2/python) at rpc.c:56 nc_recv_reply() is called. Add LYD_OPT_STRICT flag to the specified flags so that the line is
msgtype = nc_recv_reply(session, rpc, msgid, TIMEOUT_RECV, LYD_OPT_DESTRUCT | LYD_OPT_NOSIBLINGS | LYD_OPT_STRICT, &reply);
Next, we will have to make sure it is not unset so in libnetconf2/src/session_client.c:1919 you need to comment out the if
/*if (!(session->flags & NC_SESSION_CLIENT_NOT_STRICT)) {
parseroptions &= LYD_OPT_STRICT;
}*/
If you then compile and install this, we should see an actual error message.
Regards, Michal
Well... still no luck. Unfortunatelly, it seems like those changes didn't really add anything to the output I got before:
libyang[2]: Resolving unresolved data nodes and their constraints...
libyang[2]: All data nodes and constraints resolved.
Nov 27 19:08:49 RJZ-WRK-LNX python3[7039]: Session 14: sending message:#012#012#249
Nov 27 19:08:49 RJZ-WRK-LNX python3[7039]: Session 14: sending message:#012<rpc xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="1"><get xmlns="urn:ietf:params:xml:ns:netconf:base:1.0"><filter type="subtree"><oper-data-format-cli-block> <cli-show>time</cli-show> </oper-data-format-cli-block></filter></get></rpc>
Nov 27 19:08:49 RJZ-WRK-LNX python3[7039]: Session 14: sending message:#012#012##
Nov 27 19:08:49 RJZ-WRK-LNX python3[7039]: Session 14: received message:#012<?xml version="1.0" encoding="UTF-8"?>#012<rpc-reply message-id="1" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">#012 <data>#012 <oper-data-format-cli-block xmlns="urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13">#012 <item>#012 <cli-show>time</cli-show>#012 <response>#012Tue Nov 27 19:08:48 UTC 2018#015#012 </response>#012 </item>#012 </oper-data-format-cli-block>#012 </data>#012</rpc-reply>
Nov 27 19:08:49 RJZ-WRK-LNX python3[7039]: Failed to parse <get> reply.
Traceback (most recent call last):
File "/home/rzappaco/libnetconf2/libnetconf2/libnetconf2-master/python/examples/get-sros.py", line 43, in <module>
data = session.rpcGet(ncfilter)
ConnectionError: Failed to receive a reply.
Now, besides that, I just realized one thing: the reply from the router mentions this namespace:
<oper-data-format-cli-block xmlns="urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13">
and that's in fact present in the folder with all the other models:
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2# grep -i cli-content-layer-r13 *
alu-cli-content-layer-r13.yang:module alu-cli-content-layer-r13 {
alu-cli-content-layer-r13.yang: namespace "urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13";
alu-cli-content-layer-r13.yang: prefix cli-content-layer-r13;
alu-cli-content-layer-r13.yang: This alu-cli-content-layer-r13 YANG module embodies Alcatel-Lucent's
logs3.txt:Nov 27 19:15:57 RJZ-WRK-LNX python3[7080]: Session 15: received message:#012<?xml version="1.0" encoding="UTF-8"?>#012<rpc-reply message-id="1" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">#012 <data>#012 <oper-data-format-cli-block xmlns="urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13">#012 <item>#012 <cli-show>time</cli-show>#012 <response>#012Tue Nov 27 19:15:56 UTC 2018#015#012 </response>#012 </item>#012 </oper-data-format-cli-block>#012 </data>#012</rpc-reply>
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2#
However, I don't get any message mentioning either it's been loaded or that it fais to load: as you can see on the last line of above output, it only appears on the routers reply dump in the logs (which I'm attaching).
My guess is I should get anything for that one, am I right?
Hi, regarding the namespace, I have already checked that in the log before (log2) and it is there, I do not know why it is not in this latest log, whether you changed something or not.
Anyway, I made a small change (bugfix, actually) in the current libnetconf2, can you please try it again with it and report whether anything changed? Thanks.
Regards, Michal
Hi Michal,
Compiled and tried it but I'm getting a segmentation fault:
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2# logFile=logs4.txt; rm $logFile
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2# tail -0f /var/log/syslog &>>$logFile &
[1] 19295
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2# PYTHONPATH=/usr/local/lib/python2.7/dist-packages/ /home/rzappaco/libnetconf2/libnetconf2/libnetconf2-master/python/examples/get-sros.py &>>$logFile
Segmentation fault (core dumped)
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2# fg
tail -0f /var/log/syslog &>> $logFile
^C
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2#
Filtering out what (I think) is not relevant by egrep'ing the logs, this is what we get now:
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2# egrep -v ': Session [0-9]*: reading schema from localfile \".*\"\.|: Module \".*\" now implemented\.|: [Uu]nable to identify revision of the [a-z ]* \".*\"[ ,].*from the available server side information.|: Session [0-9]*: retreiving data for schema \".*\", revision \".*\"\.|^ session = nc.Session\(\".*\", .*, .*\)|libyang\[1\]: Missing status in obsolete subtree ' $logFile
Nov 28 19:58:43 RJZ-WRK-LNX python3[19296]: nc_sock_connect(10.0.0.11, 830, -1, -1)
Nov 28 19:58:43 RJZ-WRK-LNX python3[19296]: Trying to connect via IPv4.
Nov 28 19:58:43 RJZ-WRK-LNX python3[19296]: Successfully connected to 10.0.0.11:830 over IPv4.
Nov 28 19:58:44 RJZ-WRK-LNX python3[19296]: Password authentication (host "10.0.0.11", user "admin").
Nov 28 19:58:44 RJZ-WRK-LNX python3[19296]: Authentication successful.
libyang[2]: Plugin "/usr/local/lib/libyang/extensions/metadata.so" successfully loaded.
libyang[2]: Plugin "/usr/local/lib/libyang/extensions/nacm.so" successfully loaded.
libyang[2]: Plugin "/usr/local/lib/libyang/extensions/yangdata.so" successfully loaded.
libyang[2]: Plugin "/usr/local/lib/libyang/user_types/user_date_and_time.so" successfully loaded.
libyang[2]: Reading module "ietf-yang-metadata".
libyang[2]: Module "ietf-yang-metadata@2016-08-05" successfully parsed as implemented.
libyang[2]: Reading module "yang".
libyang[2]: Resolving "yang" unresolved schema nodes and their constraints...
libyang[2]: All "yang" schema nodes and constraints resolved.
libyang[2]: Module "yang@2017-02-20" successfully parsed as implemented.
libyang[2]: Reading module "ietf-inet-types".
libyang[2]: Resolving derived type "union" failed, it will be attempted later.
libyang[2]: Resolving derived type "union" failed, it will be attempted later.
libyang[2]: Resolving derived type "union" failed, it will be attempted later.
libyang[2]: Resolving derived type "union" failed, it will be attempted later.
libyang[2]: Resolving "ietf-inet-types" unresolved schema nodes and their constraints...
libyang[2]: All "ietf-inet-types" schema nodes and constraints resolved.
libyang[2]: Module "ietf-inet-types@2013-07-15" successfully parsed as implemented.
libyang[2]: Reading module "ietf-yang-types".
libyang[2]: Module "ietf-yang-types@2013-07-15" successfully parsed as implemented.
Nov 28 19:58:44 RJZ-WRK-LNX python3[19296]: Session 0: sending message:#012<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></capabilities></hello>
Nov 28 19:58:44 RJZ-WRK-LNX python3[19296]: Session 0: sending message:#012]]>]]>
Nov 28 19:58:44 RJZ-WRK-LNX python3[19296]: Session 0: received message:#012<?xml version="1.0" encoding="UTF-8"?>#012<hello xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">#012 <capabilities>#012 <capability>urn:ietf:params:netconf:base:1.0</capability>#012 <capability>urn:ietf:params:netconf:base:1.1</capability>#012 <capability>urn:ietf:params:netconf:capability:candidate:1.0</capability>#012 <capability>urn:ietf:params:netconf:capability:confirmed-commit:1.1</capability>#012 <capability>urn:ietf:params:netconf:capability:notification:1.0</capability>#012 <capability>urn:ietf:params:netconf:capability:interleave:1.0</capability>#012 <capability>urn:ietf:params:netconf:capability:validate:1.0</capability>#012 <capability>urn:ietf:params:netconf:capability:validate:1.1</capability>#012 <capability>urn:ietf:params:netconf:capability:startup:1.0</capability>#012 <capability>urn:ietf:params:netconf:capability:url:1.0?scheme=ftp,tftp,file</capability>#012 <capability>urn:ietf:params:netconf:capability:with-defaults:1.0?basic-mode=explicit&also-supported=report-all</capability>#012 <capability>urn:ietf:params:xml:ns:netconf:base:1.0?module=ietf-netconf&revision=2011-06-01&features=validate,startup,url&deviations=alu-netconf-deviations-r13</capability>#012 <capability>urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring</capability>#012 <capability>urn:ietf:params:netconf:capability:yang-library:1.0?revision=2016-04-09&module-set-id=16.0.R4</capability>#012 <capability>urn:ietf:params:xml:ns:yang:ietf-inet-types?module=ietf-inet-types&revision=2013-07-15</capability>#012 <capability>urn:ietf:params:xml:ns:yang:ietf-yang-types?module=ietf-yang-types&revision=2013-07-15</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:netconf-deviations-r13?module=alu-netconf-deviations-r13&revision=2015-01-23</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13?module=alu-cli-content-layer-r13&revision=2015-01-23</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-r13?module=alu-conf-r13&revision=2018-10-10</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-aaa-r13?module=alu-conf-aaa-r13&revision=2018-10-19</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-aa-r13?module=alu-conf-aa-r13&revision=2018-08-02</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-bmp-r13?module=alu-conf-bmp-r13&revision=2018-10-10</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-calltrace-r13?module=alu-conf-calltrace-r13&revision=2017-05-02</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-card-r13?module=alu-conf-card-r13&revision=2018-10-12</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-mda-cellular-r13?module=alu-conf-mda-cellular-r13&revision=2018-10-12</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-cflowd-r13?module=alu-conf-cflowd-r13&revision=2018-10-08</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-conn-prof-r13?module=alu-conf-conn-prof-r13&revision=2017-09-15</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-con-profvlan-r13?module=alu-conf-con-profvlan-r13&revision=2017-09-01</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-eth-cfm-r13?module=alu-conf-eth-cfm-r13&revision=2018-04-30</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-eth-ring-r13?module=alu-conf-eth-ring-r13&revision=2016-12-16</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-eth-tunnel-r13?module=alu-conf-eth-tunnel-r13&revision=2016-12-16</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-filter-r13?module=alu-conf-filter-r13&revision=2018-10-15</capability>#012 <capability>urn:alcatel-lucent.com:sros:ns:yang:conf-ip-except-r13?module=alu-conf-ip-except-r13&revision=2018-03-01</capa
Nov 28 19:58:44 RJZ-WRK-LNX python3[19296]: Session 29: loading NETCONF ietf-yang-library schema failed, unable to automatically use <get-schema>.
Nov 28 19:58:57 RJZ-WRK-LNX python3[19296]: Failed to load schema "nokia-conf@2016-07-06".
Nov 28 19:58:57 RJZ-WRK-LNX python3[19296]: Failed to load schema "nokia-openconfig-mpls-augments@None".
Nov 28 19:58:57 RJZ-WRK-LNX python3[19296]: Failed to load schema "nokia-openconfig-network-instance-augments@None".
/home/rzappaco/libnetconf2/libnetconf2/libnetconf2-master/python/examples/get-sros.py:14: Warning: Session 29: loading NETCONF ietf-yang-library schema failed, unable to automatically use <get-schema>.
/home/rzappaco/libnetconf2/libnetconf2/libnetconf2-master/python/examples/get-sros.py:14: Warning: Failed to load schema "nokia-conf@2016-07-06".
/home/rzappaco/libnetconf2/libnetconf2/libnetconf2-master/python/examples/get-sros.py:14: Warning: Failed to load schema "nokia-openconfig-mpls-augments@None".
/home/rzappaco/libnetconf2/libnetconf2/libnetconf2-master/python/examples/get-sros.py:14: Warning: Failed to load schema "nokia-openconfig-network-instance-augments@None".
Nov 28 19:59:11 RJZ-WRK-LNX python3[19296]: Session 29: some models failed to be loaded, any data from these models (and any other unknown) will be ignored.
libyang[2]: Resolving unresolved data nodes and their constraints...
libyang[2]: All data nodes and constraints resolved.
Nov 28 19:59:11 RJZ-WRK-LNX python3[19296]: Session 29: sending message:#012#012#249
Nov 28 19:59:11 RJZ-WRK-LNX python3[19296]: Session 29: sending message:#012<rpc xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="1"><get xmlns="urn:ietf:params:xml:ns:netconf:base:1.0"><filter type="subtree"><oper-data-format-cli-block> <cli-show>time</cli-show> </oper-data-format-cli-block></filter></get></rpc>
Nov 28 19:59:11 RJZ-WRK-LNX python3[19296]: Session 29: sending message:#012#012##
Nov 28 19:59:11 RJZ-WRK-LNX python3[19296]: Session 29: received message:#012<?xml version="1.0" encoding="UTF-8"?>#012<rpc-reply message-id="1" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">#012 <data>#012 <oper-data-format-cli-block xmlns="urn:alcatel-lucent.com:sros:ns:yang:cli-content-layer-r13">#012 <item>#012 <cli-show>time</cli-show>#012 <response>#012Wed Nov 28 19:59:09 UTC 2018#015#012 </response>#012 </item>#012 </oper-data-format-cli-block>#012 </data>#012</rpc-reply>
Nov 28 19:59:11 RJZ-WRK-LNX kernel: [ 9862.826680] get-sros.py[19296]: segfault at 8 ip 00007f7e8517fc02 sp 00007fff1acadc20 error 4 in netconf2.cpython-36m-x86_64-linux-gnu.so[7f7e85178000+d000]
root@RJZ-WRK-LNX:/usr/local/share/libnetconf2#
This is the complete log for this run: logs4.txt
BTW, is there any way I can get the full dump of the data received from the server? (there seems to be some limit to the number of characters dumped)
Hi,
I have tried to cover one situation I found that could cause a SEGFAULT but we will also take another look at the python bindings themselves. In the meantime, this crash points to the fact that the reply fails to be parsed because the relevant model fails to be loaded. The safest fix would be to get rid of all the Failed to load schema ... errors so that you do not get the final warning
some models failed to be loaded, any data from these models (and any other unknown) will be ignored.
Regards, Michal