ktbyers
commented
4 years ago Can you turn on Netmiko logging and record what happens when it fails (and post that here)?
Thanks. Kirk
Closed shorton3 closed 4 years ago
ktbyers
commented
4 years ago Can you turn on Netmiko logging and record what happens when it fails (and post that here)?
Thanks. Kirk
shorton3
commented
4 years ago Hi Kirk, this is the log output for get_facts:
DEBUG:napalm:Starting napalm's debugging tool
DEBUG:napalm:Gathering napalm packages
DEBUG:napalm:napalm==2.5.0
DEBUG:napalm:get_network_driver - Calling with args: ('iosxr',), {}
DEBUG:napalm:get_network_driver - Successful
DEBUG:napalm:init - Calling with args: (<class 'napalm.iosxr.iosxr.IOSXRDriver'>, '10.10.10.10', 'userid'), {'password': '***', 'timeout': 60, 'optional_args': {}}
DEBUG:napalm:init - Successful
DEBUG:napalm:pre_connection_tests - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7f8f0b902898>,), {}
DEBUG:napalm:open - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7f8f0b902898>,), {}
DEBUG:paramiko.transport:starting thread (client mode): 0xc2d6be0
DEBUG:paramiko.transport:Local version/idstring: SSH-2.0-paramiko_2.7.1
DEBUG:paramiko.transport:Remote version/idstring: SSH-2.0-Cisco-2.0
INFO:paramiko.transport:Connected (version 2.0, client Cisco-2.0)
DEBUG:paramiko.transport:kex algos:['diffie-hellman-group14-sha1', 'diffie-hellman-group1-sha1'] server key:['ssh-rsa'] client encrypt:['aes128-ctr', 'aes192-ctr', 'aes256-ctr'] server encrypt:['aes128-ctr', 'aes192-ctr', 'aes256-ctr'] client mac:['hmac-sha1'] server mac:['hmac-sha1'] client compress:['none'] server compress:['none'] client lang:[''] server lang:[''] kex follows?False
DEBUG:paramiko.transport:Kex agreed: diffie-hellman-group14-sha1
DEBUG:paramiko.transport:HostKey agreed: ssh-rsa
DEBUG:paramiko.transport:Cipher agreed: aes128-ctr
DEBUG:paramiko.transport:MAC agreed: hmac-sha1
DEBUG:paramiko.transport:Compression agreed: none
DEBUG:paramiko.transport:kex engine KexGroup14 specified hash_algo
Last switch-over Fri Dec 13 00:03:45 2019: 9 weeks, 6 days, 1 hour, 9 minutes ago
RP/0/RP0:XXXXXX10-01234567A# DEBUG:netmiko:read_channel: DEBUG:netmiko:read_channel: DEBUG:netmiko:read_channel: DEBUG:netmiko:write_channel: b'\n' DEBUG:netmiko:read_channel: RP/0/RP0:XXXXXX10-01234567A# DEBUG:netmiko:read_channel: DEBUG:netmiko:[find_prompt()]: prompt is RP/0/RP0:XXXXXX10-01234567A# DEBUG:netmiko:read_channel: DEBUG:netmiko:In disable_paging DEBUG:netmiko:Command: terminal length 0
DEBUG:netmiko:write_channel: b'terminal length 0\n' DEBUG:netmiko:Pattern is: terminal\ length\ 0 DEBUG:netmiko:_read_channel_expect read_data: terminal length 0
DEBUG:netmiko:Pattern found: terminal\ length\ 0 terminal length 0
DEBUG:netmiko:terminal length 0
DEBUG:netmiko:Exiting disable_paging DEBUG:netmiko:write_channel: b'terminal width 511\n' DEBUG:netmiko:Pattern is: terminal\ width\ 511 DEBUG:netmiko:_read_channel_expect read_data: Thu Feb 20 01:12:56.812 GMT
DEBUG:netmiko:_read_channel_expect read_data: terminal width 511
DEBUG:netmiko:Pattern found: terminal\ width\ 511 Thu Feb 20 01:12:56.812 GMT terminal width 511
DEBUG:netmiko:read_channel: RP/0/RP0:XXXXXX10-01234567A#terminal width 511 Thu Feb 20 01:12:57.004 GMT RP/0/RP0:XXXXXX10-01234567A# DEBUG:netmiko:Clear buffer detects data in the channel DEBUG:netmiko:read_channel: DEBUG:netmiko:read_channel: DEBUG:netmiko:write_channel: b'\n' DEBUG:netmiko:read_channel: RP/0/RP0:XXXXXX10-01234567A# DEBUG:netmiko:read_channel: DEBUG:netmiko:[find_prompt()]: prompt is RP/0/RP0:XXXXXX10-01234567A# DEBUG:netmiko:read_channel: DEBUG:netmiko:write_channel: b'xml\n' DEBUG:netmiko:send_command_timing current output: DEBUG:netmiko:read_channel: xml Thu Feb 20 01:12:58.096 GMT
DEBUG:netmiko:read_channel: DEBUG:netmiko:read_channel: XML> DEBUG:netmiko:read_channel: DEBUG:netmiko:read_channel: DEBUG:netmiko:send_command_timing final output: xml
Thu Feb 20 01:12:58.096 GMT
XML>
DEBUG:napalm:open - Successful
DEBUG:napalm:connection_tests - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7f8f0b902898>,), {}
DEBUG:napalm:get_facts - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7f8f0b902898>,), {}
DEBUG:netmiko:read_channel:
DEBUG:netmiko:write_channel: b'<?xml version="1.0" encoding="UTF-8"?>
XML> ERROR:napalm:get_facts - Failed: Timed-out reading channel, data not available.
ktbyers
commented
4 years ago Okay, this is a bug that I will need to fix. You will need to use Netmiko 2.4.2 until I fix this issue.
shorton3
commented
4 years ago Thank you sir!
rdpravin1895
commented
4 years ago @ktbyers Has this bug been fixed??
ktbyers
commented
4 years ago Nope, this still needs fixed.
melewitz
commented
4 years ago Fixed The problem was due to Netmiko 3's send_command option that defaults to true e.g. wait for the sent text to be echoed. XML servers don't echo. Now sending cmd_verify=False in pyIOSXR: https://github.com/fooelisa/pyiosxr/pull/61
melewitz
commented
4 years ago Kirk let me know that pyIOSXR is now included with Napalm. I've opened a PR on Napalm with a fix that globally disables cmd_verify from pyIOSXR: https://github.com/napalm-automation/napalm/pull/1188
ktbyers
commented
4 years ago Fixed in above PR.
xschlef
commented
4 years ago Exactly the same problem happens with the nxos_ssh driver. Downgrading to netmiko 2.4.2 fixed the issue temporarily.
ktbyers
commented
4 years ago Adding a comment as while they have a similar underlying cause (namely cmd_verify=True being enabled for Netmiko 3.X), the problem is not really all that similar.
This is because the IOS-XR driver and XML-agent behavior cannot/does not work with verifying the echo of commands (there is no echo).
NX-OS on the other hand should generally work with cmd_verify=True.
napalm==2.5.0 netmiko==3.0.0 Cisco IOSXR device
I am able to run napalm using on this same device with an older version of napalm and netmiko, but in a recent build of my environment and latest packages, its failing. Any ideas if this is caused by netmiko 3.0.0 or something else? I am able to login to the device via ssh. Thoughts on what to look at next? I've tried on dozen devices (all IOSXR), and with multiple getters, same results
napalm --user useruid --password 'ourpass' --vendor iosxr --debug x.x.x.x call get_interfaces 2020-02-19 22:00:49,934 - napalm - DEBUG - Starting napalm's debugging tool 2020-02-19 22:00:49,934 - napalm - DEBUG - Gathering napalm packages 2020-02-19 22:00:49,934 - napalm - DEBUG - napalm==2.5.0 2020-02-19 22:00:49,934 - napalm - DEBUG - get_network_driver - Calling with args: ('iosxr',), {} 2020-02-19 22:00:49,991 - napalm - DEBUG - get_network_driver - Successful 2020-02-19 22:00:49,991 - napalm - DEBUG - init - Calling with args: (<class 'napalm.iosxr.iosxr.IOSXRDriver'>, 'x.x.x.x', 'userid'), {'password': '***', 'timeout': 60, 'optional_args': {}} 2020-02-19 22:00:49,991 - napalm - DEBUG - init - Successful 2020-02-19 22:00:49,991 - napalm - DEBUG - pre_connection_tests - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7fbd0fcf9da0>,), {} 2020-02-19 22:00:49,991 - napalm - DEBUG - open - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7fbd0fcf9da0>,), {} 2020-02-19 22:01:01,955 - napalm - DEBUG - open - Successful 2020-02-19 22:01:01,955 - napalm - DEBUG - connection_tests - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7fbd0fcf9da0>,), {} 2020-02-19 22:01:01,955 - napalm - DEBUG - get_facts - Calling with args: (<napalm.iosxr.iosxr.IOSXRDriver object at 0x7fbd0fcf9da0>,), {} 2020-02-19 22:01:24,312 - napalm - ERROR - get_facts - Failed: Timed-out reading channel, data not available.
================= Traceback =================
Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/paramiko/channel.py", line 699, in recv out = self.in_buffer.read(nbytes, self.timeout) File "/usr/local/lib/python3.6/site-packages/paramiko/buffered_pipe.py", line 164, in read raise PipeTimeout() paramiko.buffered_pipe.PipeTimeout
During handling of the above exception, another exception occurred:
Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/netmiko/base_connection.py", line 541, in _read_channel_expect new_data = self.remote_conn.recv(MAX_BUFFER) File "/usr/local/lib/python3.6/site-packages/paramiko/channel.py", line 701, in recv raise socket.timeout() socket.timeout
During handling of the above exception, another exception occurred:
Traceback (most recent call last): File "/usr/local/bin/napalm", line 11, in
sys.exit(main())
File "/usr/local/lib/python3.6/site-packages/napalm/base/clitools/cl_napalm.py", line 312, in main
run_tests(args)
File "/usr/local/lib/python3.6/site-packages/napalm/base/clitools/cl_napalm.py", line 291, in run_tests
call_facts(device)
File "/usr/local/lib/python3.6/site-packages/napalm/base/clitools/cl_napalm.py", line 31, in wrapper
r = func(*args, kwargs)
File "/usr/local/lib/python3.6/site-packages/napalm/base/clitools/cl_napalm.py", line 199, in call_facts
facts = device.get_facts()
File "/usr/local/lib/python3.6/site-packages/napalm/iosxr/iosxr.py", line 163, in get_facts
facts_rpc_reply = ETREE.fromstring(self.device.make_rpc_call(facts_rpc_request))
File "/usr/local/lib/python3.6/site-packages/pyIOSXR/iosxr.py", line 151, in make_rpc_call
result = self._execute_rpc(rpc_command)
File "/usr/local/lib/python3.6/site-packages/pyIOSXR/iosxr.py", line 365, in _execute_rpc
response = self._send_command(xml_rpc_command, delay_factor=delay_factor)
File "/usr/local/lib/python3.6/site-packages/pyIOSXR/iosxr.py", line 275, in _send_command
max_loops=max_loops)
File "/usr/local/lib/python3.6/site-packages/netmiko/base_connection.py", line 1447, in send_command_expect
return self.send_command(*args, *kwargs)
File "/usr/local/lib/python3.6/site-packages/netmiko/base_connection.py", line 1366, in send_command
new_data = self.read_until_pattern(pattern=re.escape(cmd))
File "/usr/local/lib/python3.6/site-packages/netmiko/base_connection.py", line 618, in read_until_pattern
return self._read_channel_expect(args, kwargs)
File "/usr/local/lib/python3.6/site-packages/netmiko/base_connection.py", line 552, in _read_channel_expect
"Timed-out reading channel, data not available."
netmiko.ssh_exception.NetmikoTimeoutException: Timed-out reading channel, data not available.