search

ktbyers / netmiko

Multi-vendor library to simplify Paramiko SSH connections to network devices
MIT License
3.62k stars 1.31k forks source link

Arista driver will fail if terminal width 511 command fails #2175

Open ktbyers opened 3 years ago

ktbyers commented 3 years ago

Netmiko tries to verify this command successfully occurred in session_preparation() so if it fails then the SSH connection fails (in the session_preparation step).

This can occur if user does not have permissions to execute that command. One end-user that ran into this would see:

% Authorization denied for command 'terminal width 511'

When he tried to execute that command and get a:

    raise NetmikoTimeoutException(
netmiko.ssh_exception.NetmikoTimeoutException: Timed-out reading channel, data not available.
nrocco commented 2 years ago

We also notice this with our Arista switches. Is there a workaround (other than giving the user authorization for this command)?

ktbyers commented 2 years ago

Not right now, someone would have to submit a PR to at least not crash on this failure.

Why can't this be allowed as an authorization command. It is pretty desirable from an automation perspective to allow this (i.e. even if we fix this, you are likely going to run into problems without the proper terminal width).

nrocco commented 2 years ago

@ktbyers after investigating a bit more I think the issue we have is different. Let me know if I should open another github issue.

We are not seeing the Authorization denied for command error.

Instead we experience random behaviour, on all our 60 Arista devices with EOS 4.18.11M.

Failures look like this:

[2022-02-16 21:39:08,430] [DEBUG] starting thread (client mode): 0x8974b780
[2022-02-16 21:39:08,431] [DEBUG] Local version/idstring: SSH-2.0-paramiko_2.9.2
[2022-02-16 21:39:08,554] [DEBUG] Remote version/idstring: SSH-2.0-OpenSSH_6.6.1
[2022-02-16 21:39:08,554] [INFO] Connected (version 2.0, client OpenSSH_6.6.1)
[2022-02-16 21:39:08,555] [DEBUG] === Key exchange possibilities ===
[2022-02-16 21:39:08,555] [DEBUG] kex algos: curve25519-sha256@libssh.org, ecdh-sha2-nistp521, ecdh-sha2-nistp256, ecdh-sha2-nistp384, diffie-hellman-group14-sha1
[2022-02-16 21:39:08,555] [DEBUG] server key: ssh-rsa, ecdsa-sha2-nistp521, ssh-ed25519
[2022-02-16 21:39:08,555] [DEBUG] client encrypt: aes256-gcm@openssh.com, aes128-gcm@openssh.com, aes256-ctr, aes192-ctr, aes128-ctr
[2022-02-16 21:39:08,556] [DEBUG] server encrypt: aes256-gcm@openssh.com, aes128-gcm@openssh.com, aes256-ctr, aes192-ctr, aes128-ctr
[2022-02-16 21:39:08,556] [DEBUG] client mac: hmac-sha2-512-etm@openssh.com, hmac-sha2-256-etm@openssh.com, hmac-sha1-etm@openssh.com, hmac-sha2-512, hmac-sha2-256, hmac-sha1
[2022-02-16 21:39:08,556] [DEBUG] server mac: hmac-sha2-512-etm@openssh.com, hmac-sha2-256-etm@openssh.com, hmac-sha1-etm@openssh.com, hmac-sha2-512, hmac-sha2-256, hmac-sha1
[2022-02-16 21:39:08,556] [DEBUG] client compress: none, zlib@openssh.com
[2022-02-16 21:39:08,556] [DEBUG] server compress: none, zlib@openssh.com
[2022-02-16 21:39:08,556] [DEBUG] client lang: <none>
[2022-02-16 21:39:08,556] [DEBUG] server lang: <none>
[2022-02-16 21:39:08,556] [DEBUG] kex follows: False
[2022-02-16 21:39:08,556] [DEBUG] === Key exchange agreements ===
[2022-02-16 21:39:08,556] [DEBUG] Kex: curve25519-sha256@libssh.org
[2022-02-16 21:39:08,556] [DEBUG] HostKey: ssh-ed25519
[2022-02-16 21:39:08,556] [DEBUG] Cipher: aes128-ctr
[2022-02-16 21:39:08,556] [DEBUG] MAC: hmac-sha2-256
[2022-02-16 21:39:08,556] [DEBUG] Compression: none
[2022-02-16 21:39:08,556] [DEBUG] === End of kex handshake ===
[2022-02-16 21:39:08,592] [DEBUG] kex engine KexCurve25519 specified hash_algo <built-in function openssl_sha256>
[2022-02-16 21:39:08,592] [DEBUG] Switch to new keys ...
[2022-02-16 21:39:08,593] [DEBUG] Adding ssh-ed25519 host key for xx.xx.xx.xx: b'6f8b17659acba3790ab745da4dc327a5'
[2022-02-16 21:39:08,630] [DEBUG] userauth is OK
[2022-02-16 21:39:08,739] [DEBUG] Authentication type (password) not permitted.
[2022-02-16 21:39:08,739] [DEBUG] Allowed methods: ['publickey', 'keyboard-interactive']
[2022-02-16 21:39:08,740] [DEBUG] userauth is OK
[2022-02-16 21:39:09,017] [INFO] Authentication (keyboard-interactive) successful!
[2022-02-16 21:39:09,018] [DEBUG] [chan 0] Max packet in: 32768 bytes
[2022-02-16 21:39:09,041] [DEBUG] [chan 0] Max packet out: 32768 bytes
[2022-02-16 21:39:09,041] [DEBUG] Secsh channel 0 opened.
[2022-02-16 21:39:09,050] [DEBUG] [chan 0] Sesch channel 0 request ok
[2022-02-16 21:39:09,051] [DEBUG] [chan 0] Sesch channel 0 request ok
[2022-02-16 21:39:09,051] [DEBUG] write_channel: b'terminal width 511\n'
[2022-02-16 21:39:09,052] [DEBUG] Pattern is: Width set to
[2022-02-16 21:39:09,052] [DEBUG] _read_channel_expect read_data: Last login: Wed Feb 16 21:32:13 2022 from yy.yy.yy.yy

[2022-02-16 21:39:09,062] [DEBUG] _read_channel_expect read_data: terminal width 511

[2022-02-16 21:39:09,534] [DEBUG] _read_channel_expect read_data: terminal width 511

[2022-02-16 21:39:09,544] [DEBUG] _read_channel_expect read_data: MY-SWITCH-NAME#
[2022-02-16 21:39:29,555] [DEBUG] write_channel: b'\n'
[2022-02-16 21:39:29,555] [DEBUG] Pattern is:
[2022-02-16 21:39:29,556] [DEBUG] _read_channel_expect read_data:
MY-SWITCH-NAME#
[2022-02-16 21:39:29,556] [DEBUG] Pattern found:
MY-SWITCH-NAME#
[2022-02-16 21:39:29,557] [DEBUG] write_channel: b'exit\n'
[2022-02-16 21:39:29,557] [ERROR] Timed-out reading channel, data not available.
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/paramiko/channel.py", line 699, in recv
    out = self.in_buffer.read(nbytes, self.timeout)
  File "/usr/local/lib/python3.6/dist-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/dist-packages/netmiko/base_connection.py", line 573, in _read_channel_expect
    new_data = self.remote_conn.recv(MAX_BUFFER)
  File "/usr/local/lib/python3.6/dist-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/lib/python3.6/dist-packages/backup/backup.py", line 7, in backup_network_device
    network_device = devices.config_to_network_device(network_device_config)
  File "/usr/local/lib/python3.6/dist-packages/backup/devices/__init__.py", line 41, in config_to_network_device
    return network_device_class(config)
  File "/usr/local/lib/python3.6/dist-packages/backup/devices/base.py", line 37, in __init__
    super(NetworkDevice, self).__init__(**params)
  File "/usr/local/lib/python3.6/dist-packages/netmiko/arista/arista.py", line 10, in __init__
    return super().__init__(*args, **kwargs)
  File "/usr/local/lib/python3.6/dist-packages/netmiko/base_connection.py", line 350, in __init__
    self._open()
  File "/usr/local/lib/python3.6/dist-packages/netmiko/base_connection.py", line 356, in _open
    self._try_session_preparation()
  File "/usr/local/lib/python3.6/dist-packages/netmiko/base_connection.py", line 792, in _try_session_preparation
    self.session_preparation()
  File "/usr/local/lib/python3.6/dist-packages/netmiko/arista/arista.py", line 16, in session_preparation
    self.set_terminal_width(command=cmd, pattern=r"Width set to")
  File "/usr/local/lib/python3.6/dist-packages/netmiko/base_connection.py", line 1131, in set_terminal_width
    output = self.read_until_pattern(pattern=pattern)
  File "/usr/local/lib/python3.6/dist-packages/netmiko/base_connection.py", line 655, in read_until_pattern
    return self._read_channel_expect(*args, **kwargs)
  File "/usr/local/lib/python3.6/dist-packages/netmiko/base_connection.py", line 584, in _read_channel_expect
    "Timed-out reading channel, data not available."
netmiko.ssh_exception.NetmikoTimeoutException: Timed-out reading channel, data not available.
nrocco commented 2 years ago

Another observation that might help. I have a netmiko based script called backup.py.

  1. I run backup.py and it fails on setting terminal width.
  2. I ssh to the device and after logging in type exit
  3. I run backup.py once again and it succeeds

I can continue running backup.py for a few more minutes and every invocation is successful. After some time backup.py consistently fails again. sshing into the device makes netmiko work again.

ktbyers commented 10 months ago

@nrocco Sorry your issue slipped through...if you are still working on your problem (still experiencing it, then we should open up a new issue on it).

nrocco commented 10 months ago

Hi @ktbyers, thanks for coming back to this comment. Highly appreciated. We are not 100% sure if we still have this issue but that is because we have a work around in place by overriding session_preparation:

def session_preparation(self):
        self.set_base_prompt()
        self.disable_paging(cmd_verify=False, pattern=r"Pagination disabled")

Once we have some time we will remove this work around and see if we can still reproduce the problem.

If we can reproduce, we will open a new fresh github issue, as per your recommendation.

Thanks for this awesome library btw.

jessebutryn commented 9 months ago

I am also having this issue:

DEBUG:netmiko:read_channel: terminal width 511
% Authorization denied for command 'terminal width 511'

My user doesn't have authorization to execute that command

ktbyers commented 9 months ago

@jessebutryn Yes, in general the fix is to convince your security to allow permissions to that (since it is a totally benign terminal setting).

If that doesn't work, you can try using the generic device_type. There is a good chance you will run into issues using this, however (and you will need to disable output paging yourself i.e. use Netmiko to send this command).