Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AsyncSSH Hanging on Cisco UCS #730

Open
NinjaNas opened this issue Jan 5, 2025 · 24 comments
Open

AsyncSSH Hanging on Cisco UCS #730

NinjaNas opened this issue Jan 5, 2025 · 24 comments

Comments

@NinjaNas
Copy link

NinjaNas commented Jan 5, 2025

Hi Ron,

I am working on Cisco UCS Fabric Interconnects and I am running into issues with it hanging when awaiting for the stdout.

Cisco UCS requires me to use the connect nxos a and connect nxos b commands to access the commands I need to run. I found a solution to get connect nxos a to work but not connect nxos b.

I am currently using an interactive shell to run all of the commands at once and dump them at the end of the session. I have also been using write_eof() to get sessions to close on normal Cisco and Arista switches since they would hang without it. Please tell me if doing this is a bad idea or not.

    async def run_client_multiple_commands(
        self, host, username, password, commands
    ):
        if not commands:
            return None

        if isinstance(commands, str):
            commands = [commands]

        logger.debug(f"Running commands on host {host}: {commands}")
        try:
            asyncssh.set_log_level('DEBUG')
            asyncssh.set_sftp_log_level('DEBUG')
            asyncssh.set_debug_level(2)
            async with await asyncio.wait_for(
                asyncssh.connect(
                    host,
                    username=username,
                    password=password,
                    port=22,
                    known_hosts=None,
                ),
                timeout=3,
            ) as conn:
                async with await asyncio.wait_for(
                    conn.create_process(stderr=asyncssh.STDOUT), timeout=3
                ) as process:
                    res = {}
                    for command in commands:
                        logger.debug(f'--- Running "{command}" ---')
                        process.stdin.write(f"{command}\n")
                        process.stdin.write("show show\n")  # Delimiter between commands
                     process.stdin.write_eof()
                    try:
                        res = await asyncio.wait_for(process.stdout.read(), timeout=30) 
                    except asyncio.TimeoutError:
                        logger.error("Timeout: process.stdout.read() did not return within the specified time")

                    # Split at "show show" including the next three lines
                    pattern = re.compile(r"\n.*show show.*(?:\n.*){0,3}")
                    # Removes empty strings from the list
                    res = list(filter(None, pattern.split(res)))
                
                res = {command: res[i] for i, command in enumerate([command for command in commands if command not in ["exit", "connect nxos a"]])}

                return res
        except asyncio.TimeoutError as e:
            logger.warning(f"Timeout while connecting to {host}: {e}")

commands = ["show service-profile status", "connect nxos a", "show mac address", "show interface description", "exit", "exit"] # this works

commands = ["show service-profile status", "connect nxos b", "show mac address", "show interface description", "exit", "exit"] # this hangs

self.run_multiple_commands(ip, os.getenv("UCS_USERNAME"), os.getenv("UCS_PASSWORD"), commands)

with process.write_eof()

INFO: [conn=4] Beginning auth for user rtools
DEBUG: [conn=4] Received authentication banner
DEBUG: [conn=4] Remaining auth methods: publickey,password,keyboard-interactive
DEBUG: [conn=4] Preferred auth methods: gssapi-keyex,gssapi-with-mic,hostbased,publickey,keyboard-interactive,password
DEBUG: [conn=4] Trying keyboard-interactive auth
INFO: [conn=4] Auth for user rtools succeeded
DEBUG: [conn=4, chan=0] Set write buffer limits: low-water=16384, high-water=65536
INFO: [conn=4, chan=0] Requesting new SSH session
DEBUG: [conn=4, chan=0]   Initial recv window 2097152, packet size 32768
DEBUG: [conn=4] Ignoring server host key message: no handler
DEBUG: [conn=4, chan=0]   Initial send window 0, packet size 32768
INFO: [conn=4, chan=0]   Interactive shell requested
DEBUG: [conn=4, chan=0] Received window adjust of 2097152 bytes, new window 2097152
[DEBUG] --- Running "show service-profile status" ---
DEBUG: [conn=4, chan=0] Sending 28 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "connect nxos b" ---
DEBUG: [conn=4, chan=0] Sending 15 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "show mac address" ---
DEBUG: [conn=4, chan=0] Sending 17 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "show interface description" ---
DEBUG: [conn=4, chan=0] Sending 27 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "exit" ---
DEBUG: [conn=4, chan=0] Sending 5 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "exit" ---
DEBUG: [conn=4, chan=0] Sending 5 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
DEBUG: [conn=4, chan=0] Sending EOF
DEBUG: [conn=4, chan=0] Reading from channel started
DEBUG: [conn=4, chan=0] Received 586 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 1436 data bytes
DEBUG: [conn=4, chan=0] Received 33 data bytes from STDERR
DEBUG: [conn=4, chan=0] Received 18 data bytes
DEBUG: [conn=4, chan=0] Received 40 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 8192 data bytes
DEBUG: [conn=4, chan=0] Received 8192 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 8192 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 8192 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 1008 data bytes
DEBUG: [conn=4, chan=0] Received 40 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 3557 data bytes
DEBUG: [conn=4, chan=0] Received 40 data bytes
DEBUG: [conn=4, chan=0] Received 48 data bytes
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
DEBUG: [conn=4, chan=0] Received 1 data byte
...
Repeats until timeout

Without process.write_eof()

[DEBUG] Running commands on host ip: ['show service-profile status', 'connect nxos b', 'show mac address', 'show interface description', 'exit', 'exit']
INFO: Host canonicalization disabled
INFO: Opening SSH connection to ip, port 22
INFO: [conn=4] Connected to SSH server at ip, port 22
INFO: [conn=4]   Local address: ip, port 39016
INFO: [conn=4]   Peer address: ip port 22
DEBUG: [conn=4] Sending version SSH-2.0-AsyncSSH_2.19.0
DEBUG: [conn=4] Received version SSH-2.0-OpenSSH_7.6 PKIX[11.0]
DEBUG: [conn=4] Requesting key exchange
DEBUG: [conn=4]   Key exchange algs: curve25519-sha256,curve25519-sha256@libssh.org,curve448-sha512,ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,ecdh-sha2-1.3.132.0.10,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group15-sha512,diffie-hellman-group16-sha512,diffie-hellman-group17-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256@ssh.com,diffie-hellman-group14-sha1,rsa2048-sha256,ext-info-c,kex-strict-c-v00@openssh.com
DEBUG: [conn=4]   Host key algs: rsa-sha2-256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ssh-ed448-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-1.3.132.0.10-cert-v01@openssh.com,rsa-sha2-256,rsa-sha2-512,ssh-rsa-sha224@ssh.com,ssh-rsa-sha256@ssh.com,ssh-rsa-sha384@ssh.com,ssh-rsa-sha512@ssh.com,ssh-rsa,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,webauthn-sk-ecdsa-sha2-nistp256@openssh.com,ssh-ed25519,ssh-ed448,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,ecdsa-sha2-1.3.132.0.10
DEBUG: [conn=4]   Encryption algs: chacha20-poly1305@openssh.com,aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr
DEBUG: [conn=4]   MAC algs: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha256-2@ssh.com,hmac-sha224@ssh.com,hmac-sha256@ssh.com,hmac-sha384@ssh.com,hmac-sha512@ssh.com
DEBUG: [conn=4]   Compression algs: none,zlib@openssh.com
DEBUG: [conn=4] Received key exchange request
DEBUG: [conn=4]   Key exchange algs: diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512
DEBUG: [conn=4]   Host key algs: ssh-rsa,rsa-sha2-256,rsa-sha2-512
DEBUG: [conn=4]   Client to server:
DEBUG: [conn=4]     Encryption algs: aes128-ctr,aes192-ctr,aes256-ctr
DEBUG: [conn=4]     MAC algs: hmac-sha2-256,hmac-sha2-512,
DEBUG: [conn=4]     Compression algs: none,zlib@openssh.com
DEBUG: [conn=4]   Server to client:
DEBUG: [conn=4]     Encryption algs: aes128-ctr,aes192-ctr,aes256-ctr
DEBUG: [conn=4]     MAC algs: hmac-sha2-256,hmac-sha2-512,
DEBUG: [conn=4]     Compression algs: none,zlib@openssh.com
DEBUG: [conn=4] Beginning key exchange
DEBUG: [conn=4]   Key exchange alg: diffie-hellman-group-exchange-sha256
DEBUG: [conn=4]   Client to server:
DEBUG: [conn=4]     Encryption alg: aes256-ctr
DEBUG: [conn=4]     MAC alg: hmac-sha2-256
DEBUG: [conn=4]     Compression alg: none
DEBUG: [conn=4]   Server to client:
DEBUG: [conn=4]     Encryption alg: aes256-ctr
DEBUG: [conn=4]     MAC alg: hmac-sha2-256
DEBUG: [conn=4]     Compression alg: none
DEBUG: [conn=4] Requesting service ssh-userauth
DEBUG: [conn=4] Completed key exchange
DEBUG: [conn=4] Request for service ssh-userauth accepted
INFO: [conn=4] Beginning auth for user rtools
DEBUG: [conn=4] Received authentication banner
DEBUG: [conn=4] Remaining auth methods: publickey,password,keyboard-interactive
DEBUG: [conn=4] Preferred auth methods: gssapi-keyex,gssapi-with-mic,hostbased,publickey,keyboard-interactive,password
DEBUG: [conn=4] Trying keyboard-interactive auth
INFO: [conn=4] Auth for user rtools succeeded
DEBUG: [conn=4, chan=0] Set write buffer limits: low-water=16384, high-water=65536
INFO: [conn=4, chan=0] Requesting new SSH session
DEBUG: [conn=4, chan=0]   Initial recv window 2097152, packet size 32768
DEBUG: [conn=4] Ignoring server host key message: no handler
DEBUG: [conn=4, chan=0]   Initial send window 0, packet size 32768
INFO: [conn=4, chan=0]   Interactive shell requested
DEBUG: [conn=4, chan=0] Received window adjust of 2097152 bytes, new window 2097152
[DEBUG] --- Running "show service-profile status" ---
DEBUG: [conn=4, chan=0] Sending 28 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "connect nxos b" ---
DEBUG: [conn=4, chan=0] Sending 15 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "show mac address" ---
DEBUG: [conn=4, chan=0] Sending 17 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "show interface description" ---
DEBUG: [conn=4, chan=0] Sending 27 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "exit" ---
DEBUG: [conn=4, chan=0] Sending 5 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
[DEBUG] --- Running "exit" ---
DEBUG: [conn=4, chan=0] Sending 5 data bytes
DEBUG: [conn=4, chan=0] Sending 10 data bytes
DEBUG: [conn=4, chan=0] Reading from channel started
DEBUG: [conn=4, chan=0] Received 586 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 1434 data bytes
DEBUG: [conn=4, chan=0] Received 33 data bytes from STDERR
DEBUG: [conn=4, chan=0] Received 18 data bytes
DEBUG: [conn=4, chan=0] Received 40 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 8192 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 8192 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 16384 data bytes
DEBUG: [conn=4, chan=0] Received 12288 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 8192 data bytes
DEBUG: [conn=4, chan=0] Received 12288 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 12288 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 427 data bytes
DEBUG: [conn=4, chan=0] Received 40 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 4096 data bytes
DEBUG: [conn=4, chan=0] Received 3557 data bytes
DEBUG: [conn=4, chan=0] Received 40 data bytes
[ERROR] Timeout: process.stdout.read() did not return within the specified time
INFO: [conn=4, chan=0] Closing channel
INFO: [conn=4, chan=0] Received exit signal PIPE
DEBUG: [conn=4, chan=0]   Core dumped: False
DEBUG: [conn=4, chan=0]   Message:
INFO: [conn=4, chan=0] Received channel close
INFO: [conn=4, chan=0] Channel closed
INFO: [conn=4] Closing connection
INFO: [conn=4] Sending disconnect: Disconnected by application (11)
INFO: [conn=4] Connection closed

I believe that the connect nxos b creates a ssh tunnel to its pair and that is why it is not working as intended. When run in the CLI it displays Operating in CiscoSSL FIPS mode which does not show when running connect nxos a. Is there a way I can get this to work without having to connect directly to the other host?

Another thing that is weird is that I have to write the exit command for it to not hang while using connect nxos a. If I am connected to a normal Cisco or Arista device using exit is not necessary and commands = ["show mac address"] would return and not hang for this code. How can I better grasp what AsyncSSH is doing here?

Originally, I was using Paramiko and did get this to work so hopefully it is possible in AsyncSSH as well.

Please let me know your thoughts on this.

@ronf
Copy link
Owner

ronf commented Jan 7, 2025

I think the biggest issue here is that you are using read() with no arguments, rather than passing in the number of bytes to read. With no argument, read() will wait until the server sends an EOF before it returns anything. So, unless you've send a command like "exit" or doing your own write_eof() before calling read(), the client will probably hang (or time out).

If you pass in an integer argument, it will read up to that many bytes, but it will also return early if some bytes are received but the number is less than the value you pass in, without needing either the client or the server to send an EOF. That said, it may take multiple reads to get all the data you want, but that's where you can do things like use readuntil() instead, to try and get it to read until you reach a specific pattern that indicates you're at the end of a command's output. Note that the "separator" in readuntil() can be a compiled regex instead of a list of literals. See the notes on readuntil() about other issues related to using a regex with it, though.

Something else to think about is that some devices may not handle writing input to them while they're still processing a previous command. So, ideally, you'd find some way to send a single command and then read the output in its entirety from that before you write the next command, if you want to send multiple commands in a single SSH session. You also shouldn't send EOF until you're completely done, or alternately finish with an "exit" command (or equivalent for your device) and let it be the one to end the session.

@NinjaNas
Copy link
Author

NinjaNas commented Jan 7, 2025

Hi Ron,

Thanks for your detailed response. I managed to get it working using readuntil(). One of my main problem when refactoring was that connect nxos a and connect nxos b overrides(?) one of the delimiters. I would end up hanging since I would have one more readuntil() call than I had delimiters. This could be related to what you said:

Something else to think about is that some devices may not handle writing input to them while they're still processing a previous command.

I do not handle this issue perfectly here but it does get me the output I need. I will keep it in mind if I do run it that issue in the future.

It also works without having to input exit commands.

If you have any more improvements, please tell me. Otherwise, you can close this issue. Thank You!

commands = ["show service-profile status", "connect nxos b", "show mac address", "show interface description"]

async def run_client_multiple_commands(
    self, host, username, password, commands, command_name_key=[]
):
    if not commands:
        return None

    if isinstance(commands, str):
        commands = [commands]

    logger.debug(f"Running commands on host {host}: {commands}")
    try:
        asyncssh.set_log_level('DEBUG')
        asyncssh.set_sftp_log_level('DEBUG')
        asyncssh.set_debug_level(2)
        async with await asyncio.wait_for(
            asyncssh.connect(
                host,
                username=username,
                password=password,
                port=22,
                known_hosts=None,
            ),
            timeout=10,
        ) as conn:
            async with await asyncio.wait_for(
                conn.create_process(stderr=asyncssh.STDOUT), timeout=10
            ) as process:
                res = {}
                for i, command in enumerate(commands):
                    logger.debug(f'--- Running "{command}" ---')
                    process.stdin.write(f"{command}\n")
                    process.stdin.write("show show\n")  # Delimiter between commands
                    
                for command in commands:
                    if command not in ["connect nxos a", "connect nxos b"]:
                        if command_name_key:
                            if isinstance(command_name_key, str):
                                command_name_key = [command_name_key]
                            res[command_name_key[i]] = await process.stdout.readuntil("show show")
                        else:
                            res[command] = await process.stdout.readuntil("show show")

                process.stdin.write_eof()

            return res
    except asyncio.TimeoutError as e:
        logger.warning(f"Timeout while connecting to {host}: {e}")

@NinjaNas
Copy link
Author

NinjaNas commented Jan 7, 2025

One of my main problem when refactoring was that connect nxos a and connect nxos b overrides(?) one of the delimiters.

After some more tinkering, this is not true. The main ucs terminal doesn't not echo back the delimiter on a syntax error, but the nxos terminal does. This leads to the delimiter/readuntil mismatch.

So I have to figure out a different solution for that but at least I understand what it doing better now.

I can add a regex to readuntil() like this right?
await process.stdout.readuntil(re.compile("a|b"), 1)

@ronf
Copy link
Owner

ronf commented Jan 8, 2025

I can add a regex to readuntil() like this right?
await process.stdout.readuntil(re.compile("a|b"), 1)

Yes, that's right.

If you log in to one of the devices with OpenSSH and do a "connect", does it echo your input in that case? If so, it seems kind of odd that it wouldn't echo it for an AsyncSSH connection, but it could have something to do with whether you try to set up a pseudo-TTY or not. If you add something like term_type='ansi' to the connect() call, does that change anything? Alternately, if you run OpenSSH with "-T" to disable the PTY request, does that affect echoing at all?

I'm also wondering if maybe the "show" command is getting dropped because you are sending it before the previous command has been fully processed, especially in the case of something like the "connect". You could try adding a delay before sending that just to see what happens, though that's not a great final solution.

@FindDefinition
Copy link

I recommend to use shell integration (vscode example) to detect several kind of command events (e.g. command start/end) with asyncssh. it's really hard to detect command end without shell integration.

@NinjaNas
Copy link
Author

NinjaNas commented Jan 8, 2025

@ronf

If you log in to one of the devices with OpenSSH and do a "connect", does it echo your input in that case?

Yes, it does echo back the input using OpenSSH. Sorry if I misspoke earlier but it does not show up in the AsyncSSH stdout unless term_type='ansi' is set which is my problem.

Alternately, if you run OpenSSH with "-T" to disable the PTY request, does that affect echoing at all?

With "-T" it hangs after I enter the password when trying to connect.

If you add something like term_type='ansi' to the connect() call, does that change anything?

This does work in echoing back the input. I have to add a delay for the commands to be processed correctly. Otherwise, I get this:

{
    'show service-profile status': 'show service-profile status\r\nshow show', 
    'connect nxos b': '\r\nconnect nxos b\r\nshow show', 
    'show mac address': '\r\nshow mac address\r\nshow show', 
    'show interface description': '\r\nshow interface description\r\nshow show'
}

I think this is a okay solution, I should be able to use terminal length 0 and it should work with a small time delay. It is supposed to be used in an internal tool so there is not a lot of user input and a bit of time delay does not matter.

Without ansi and a delay, the output I get from SSH is without any input echoes:

Output from show service-profile status
% Invalid Command at '^' marker\n\n
Output from show fabric-interconnect b
Output from connect nxos b
% Invalid command\nSyntax error while parsing 'show show"
Output from show mac address
Syntax error while parsing 'show show"
Output from show interface description
Syntax error while parsing 'show show"

What is weird is how connect nxos seems to take the last stderr into itself. This also the same output if I put a delay after each of the commands.

The other problem is if I do a regex with like Invalid Command it will break if the actual command is also invalid as it will cause a mismatch. This works in my case since I can force only valid commands but it would nice to find a general solution.

It would be nice to get the stdin to output here as well without using ansi.

I will try to mess around with it some more.

@FindDefinition
Thanks, I will check it out!

@ronf
Copy link
Owner

ronf commented Jan 9, 2025

@FindDefinition, how would this apply in the case of talking to something like a network switch or router with a CLI which isn't a typical Linux shell (and which might not be Linux-based at all)?

@ronf
Copy link
Owner

ronf commented Jan 9, 2025

This does work in echoing back the input. I have to add a delay for the commands to be processed correctly. Otherwise, I get this:

{
'show service-profile status': 'show service-profile status\r\nshow show',
'connect nxos b': '\r\nconnect nxos b\r\nshow show',
'show mac address': '\r\nshow mac address\r\nshow show',
'show interface description': '\r\nshow interface description\r\nshow show'
}

I think this is a okay solution, I should be able to use terminal length 0 and it should work with a small time delay. It is supposed to be used in an internal tool so there is not a lot of user input and a bit of time delay does not matter.

Yeah, I was going to ask you about the "More" prompt issue, and the potential need to send "terminal length 0" or equivalent.

Without ansi and a delay, the output I get from SSH is without any input echoes:

Output from show service-profile status
% Invalid Command at '^' marker\n\n
Output from show fabric-interconnect b
Output from connect nxos b
% Invalid command\nSyntax error while parsing 'show show"
Output from show mac address
Syntax error while parsing 'show show"
Output from show interface description
Syntax error while parsing 'show show"
What is weird is how connect nxos seems to take the last stderr into itself. This also the same output if I put a delay after each of the commands.

This looks pretty much like I'd expect.

The other problem is if I do a regex with like Invalid Command it will break if the actual command is also invalid as it will cause a mismatch. This works in my case since I can force only valid commands but it would nice to find a general solution.

Is there any command which just takes a string and echoes that string back (independent of the input echoing)? Alternately, if you do have input echoing, is there any "comment" character you can put at the beginning of a command you send, so you get only the input echo but no other output? This may still not be enough without a delay depending on when the input is echoed, but on some devices this might be enough to get the input to show up only after the output of the previous command, and by using a comment string you don't have to worry about Invalid Command errors.

It would be nice to get the stdin to output here as well without using ansi.

Unfortunately, this behavior is coming from the target device. There isn't really anything you can do in AsyncSSH (or any other SSH client) to change this behavior. Basically, the pseudo-TTY you request when setting the terminal type is what is responsible on the SSH server for doing the input echoing.

@NinjaNas
Copy link
Author

NinjaNas commented Jan 9, 2025

Is there any command which just takes a string and echoes that string back (independent of the input echoing)? Alternately, if you do have input echoing, is there any "comment" character you can put at the beginning of a command you send, so you get only the input echo but no other output?

I do not think there is one, unfortunately. The closest thing would be sending a newline but that does not output any newlines in the output.

I wrote this workaround so I have to deal with messing around with timers for now. I am surprised that it works, at least for my purposes of dumping the device data based on the command. I most likely won't have any invalid commands entered so it works for me.

commands = ["show service-profile status", "show fabric-interconnect inventory", "connect nxos a", "show mac address", "show interface description", "exit", "connect nxos b", "show mac address", "show interface description"]

    async def run_client_multiple_commands(
        self, host, username, password, commands, command_name_key=[]
    ):
        if not commands:
            return None

        if isinstance(commands, str):
            commands = [commands]

        logger.debug(f"Running commands on host {host}: {commands}")
        try:
            asyncssh.set_log_level('DEBUG')
            asyncssh.set_sftp_log_level('DEBUG')
            asyncssh.set_debug_level(2)
            async with await asyncio.wait_for(
                asyncssh.connect(
                    host,
                    username=username,
                    password=password,
                    port=22,
                    known_hosts=None,
                ),
                timeout=10,
            ) as conn:
                async with await asyncio.wait_for(
                    conn.create_process(stderr=asyncssh.STDOUT), timeout=10
                ) as process:
                    res = {}
                    for i, command in enumerate(commands):
                        logger.debug(f'--- Running "{command}" ---')
                        process.stdin.write(f"{command}\n")
                        process.stdin.write("show show\n")  # Delimiter between commands

                    for command in commands:
                        if command not in ["connect nxos", "connect nxos a", "connect nxos b"]:
                            if command_name_key:
                                if isinstance(command_name_key, str):
                                    command_name_key = [command_name_key]
                                res[command_name_key[i]] = res.get(command_name_key[i], '') + await process.stdout.readuntil(re.compile("Invalid Command|show show"), 15)
                            else:
                                res[command] = res.get(command, '') + await process.stdout.readuntil(re.compile("Invalid Command|show show"), 15)

                    process.stdin.write_eof()

                return res
        except asyncio.TimeoutError as e:
            logger.warning(f"Timeout while connecting to {host}: {e}")

@ronf
Copy link
Owner

ronf commented Jan 10, 2025

Regarding the command output boundary, does it work to start a command with an '!'? Many switches will treat everything from there to the end of the line as a comment and ignore it, but I don't know if it works on a line by itself with no command preceding it.

The other thought I had was to maybe set the CLI prompt that the switch outputs to something unique that you don't expect to see in the output of the commands you are running. If you search for that, you might not need to send the "show show" and match on invalid command errors. You could just directly readuntil that prompt. This might also avoid the need for a timeout, though you may still need the PTY depending on whether the switch outputs prompts when no PTY is allocated.

On another note, if you are allocating a PTY, you don't need to worry about redirecting stderr to stdout. With a PTY allocated, that happens automatically and the two streams are merged into one. So, the stderr=asyncssh.STDOUT wouldn't be needed in that case. You might still want it if you get things working without a PTY, though. I don't know offhand if switches ever output stuff to stderr when there is no PTY.

@NinjaNas
Copy link
Author

Regarding the command output boundary, does it work to start a command with an '!'? Many switches will treat everything from there to the end of the line as a comment and ignore it, but I don't know if it works on a line by itself with no command preceding it.

After testing, "!" does work in the nxos terminal but not the main ucs terminal.

The other thought I had was to maybe set the CLI prompt that the switch outputs to something unique that you don't expect to see in the output of the commands you are running. If you search for that, you might not need to send the "show show" and match on invalid command errors. You could just directly readuntil that prompt. This might also avoid the need for a timeout, though you may still need the PTY depending on whether the switch outputs prompts when no PTY is allocated.

I do not know if my read access would allow me to do this. Also, the main ucs terminal does not have a setting to change the prompt.

On another note, if you are allocating a PTY, you don't need to worry about redirecting stderr to stdout. With a PTY allocated, that happens automatically and the two streams are merged into one. So, the stderr=asyncssh.STDOUT wouldn't be needed in that case. You might still want it if you get things working without a PTY, though. I don't know offhand if switches ever output stuff to stderr when there is no PTY.

This is good to know.

The main ucs terminal is very limited in what it can do and also does it differently than the nxos terminal. The only way you could do this is by sending a multiple \n and have the regex pick up if multiple CLI prompts have happened in succession. This works in both environments, plus you can send extra newlines to increase the chances to match in case some of the newlines get corrupted or get interrupted by switch logs. Its a bit costly, but programmatically no one should be sending an empty newline without a command.

@ronf
Copy link
Owner

ronf commented Jan 11, 2025

After testing, "!" does work in the nxos terminal but not the main ucs terminal.

I don't really have any experience with UCS, but looking online for a CLI reference, I don't see any mention of supporting comments the way other Cisco CLIs do, so this may not be possible.

I do not know if my read access would allow me to do this. Also, the main ucs terminal does not have a setting to change the prompt.

Yeah - maybe not. Are the existing prompts already unique enough to serve this purpose, though? Perhaps you could parse out the first prompt and then remember that and use it for finding the end of the output for future commands.

Sending an extra newline here to get two prompts in a row is an interesting idea, if you think the single prompt isn't unique enough by itself.

@NinjaNas
Copy link
Author

NinjaNas commented Jan 13, 2025

Are the existing prompts already unique enough to serve this purpose, though?

They should be unique enough.

Sending an extra newline here to get two prompts in a row is an interesting idea, if you think the single prompt isn't unique enough by itself.

The main problem is not the uniqueness, rather network devices also contain logging that disrupts the commands being sent. I don't know how they fully work with ssh output but I am worried if someone shuts down a port, it will send a log followed by a new command prompt line.

Edit:
It seems it does not produce a new prompt line when logging happens so one prompt should be fine.

@ronf
Copy link
Owner

ronf commented Jan 14, 2025

Yeah - if there is such output, it may get captured as part of some command you are running, but it shouldn't change the prompts. The only possible issue I could imagine is if someone the log output came out in the middle of the prompt, but I'm not even sure if that's possible. It would depend on where (if at all) buffering was happening on the output.

@NinjaNas
Copy link
Author

Unfortunately, my workaround started hanging on a Cisco device running a maintenance release of NXOS in a similar fashion to #628. Even using a wait_for it still hangs on Closing channel. Any ideas?

@ronf
Copy link
Owner

ronf commented Jan 28, 2025

Do you have a sample of the debug log from when the problem occurred (preferable at debug level 2)?

Also, what specifically are you calling wait_for on?

A call to close() on a channel should never block - did you mean it is blocking in wait_closed(), or perhaps that it is blocking when exiting a context manager for the connection or for the session/process?

If you are calling close() directly, be aware that you should never do any further operations of any kind on a session, process, or connection once that's done. The only thing legal to call after close() is an await on wait_closed().

A hang could also be triggered by an exception you are not catching, but you should be able to see that show up once you enable debug logging.

@NinjaNas
Copy link
Author

I am calling wait_for on readuntil.

It should not be an exception that is causing it, there is no indication that it is happening. The function still works for most Cisco NXOS device in the environment so I don't know what it is causing it to break here.

DEBUG: Reading config from "/u/SSO/.ssh/config"
INFO: Host canonicalization disabled
INFO: Opening SSH connection to IP, port 22
INFO: [conn=0] Connected to SSH server at IP, port 22
INFO: [conn=0]   Local address: IP, port 49564
INFO: [conn=0]   Peer address: IP, port 22
DEBUG: [conn=0] Sending version SSH-2.0-AsyncSSH_2.19.0
DEBUG: [conn=0] Received version SSH-2.0-OpenSSH_9.1 PKIX[13.5]
DEBUG: [conn=0] Requesting key exchange
DEBUG: [conn=0]   Key exchange algs: curve25519-sha256,[email protected],curve448-sha512,ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,ecdh-sha2-1.3.132.0.10,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group15-sha512,diffie-hellman-group16-sha512,diffie-hellman-group17-sha512,diffie-hellman-group18-sha512,[email protected],diffie-hellman-group14-sha1,rsa2048-sha256,ext-info-c,[email protected]
DEBUG: [conn=0]   Host key algs: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],rsa-sha2-256,rsa-sha2-512,[email protected],[email protected],[email protected],[email protected],ssh-rsa,[email protected],[email protected],[email protected],ssh-ed25519,ssh-ed448,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,ecdsa-sha2-1.3.132.0.10
DEBUG: [conn=0]   Encryption algs: [email protected],[email protected],[email protected],aes256-ctr,aes192-ctr,aes128-ctr
DEBUG: [conn=0]   MAC algs: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1,[email protected],[email protected],[email protected],[email protected],[email protected]
DEBUG: [conn=0]   Compression algs: none,[email protected]
DEBUG: [conn=0] Received key exchange request
DEBUG: [conn=0]   Key exchange algs: curve25519-sha256,[email protected],ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group16-sha512,diffie-hellman-group14-sha1,diffie-hellman-group14-sha256,[email protected]
DEBUG: [conn=0]   Host key algs: ssh-rsa,rsa-sha2-256
DEBUG: [conn=0]   Client to server:
DEBUG: [conn=0]     Encryption algs: aes128-ctr,aes256-ctr,[email protected],[email protected],[email protected]
DEBUG: [conn=0]     MAC algs: [email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: [conn=0]     Compression algs: none,[email protected]
DEBUG: [conn=0]   Server to client:
DEBUG: [conn=0]     Encryption algs: aes128-ctr,aes256-ctr,[email protected],[email protected],[email protected]
DEBUG: [conn=0]     MAC algs: [email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: [conn=0]     Compression algs: none,[email protected]
DEBUG: [conn=0] Beginning key exchange
DEBUG: [conn=0]   Key exchange alg: curve25519-sha256
DEBUG: [conn=0]   Client to server:
DEBUG: [conn=0]     Encryption alg: [email protected]
DEBUG: [conn=0]     MAC alg: [email protected]
DEBUG: [conn=0]     Compression alg: none
DEBUG: [conn=0]   Server to client:
DEBUG: [conn=0]     Encryption alg: [email protected]
DEBUG: [conn=0]     MAC alg: [email protected]
DEBUG: [conn=0]     Compression alg: none
DEBUG: [conn=0] Requesting service ssh-userauth
DEBUG: [conn=0] Completed key exchange
DEBUG: [conn=0] Received extension info
DEBUG: [conn=0]   [email protected]: x509v3-sign-rsa,x509v3-sign-dss,ssh-ed25519,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,rsa-sha2-256,rsa-sha2-512
DEBUG: [conn=0]   server-sig-algs: x509v3-sign-rsa,x509v3-sign-dss,ssh-ed25519,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,rsa-sha2-256,rsa-sha2-512
DEBUG: [conn=0] Request for service ssh-userauth accepted
INFO: [conn=0] Beginning auth for user SSO
DEBUG: [conn=0] Received authentication banner
DEBUG: [conn=0] Remaining auth methods: publickey,password,keyboard-interactive
DEBUG: [conn=0] Preferred auth methods: gssapi-keyex,gssapi-with-mic,hostbased,publickey,keyboard-interactive,password
DEBUG: [conn=0] Trying public key auth with rsa-sha2-256 key
DEBUG: [conn=0] Remaining auth methods: publickey,password,keyboard-interactive
DEBUG: [conn=0] Preferred auth methods: gssapi-keyex,gssapi-with-mic,hostbased,publickey,keyboard-interactive,password
DEBUG: [conn=0] Trying keyboard-interactive auth
INFO: [conn=0] Auth for user SSO succeeded
DEBUG: [conn=0, chan=0] Set write buffer limits: low-water=16384, high-water=65536
INFO: [conn=0, chan=0] Requesting new SSH session
DEBUG: [conn=0, chan=0]   Initial recv window 2097152, packet size 32768
DEBUG: [conn=0] Ignoring server host key message: no handler
DEBUG: [conn=0, chan=0]   Initial send window 0, packet size 32768
INFO: [conn=0, chan=0]   Interactive shell requested
DEBUG: [conn=0, chan=0] Received window adjust of 2097152 bytes, new window 2097152
[DEBUG] --- Running "show version" ---
DEBUG: [conn=0, chan=0] Sending 13 data bytes
DEBUG: [conn=0, chan=0] Sending 10 data bytes
[DEBUG] --- Running "show ip int brief" ---
DEBUG: [conn=0, chan=0] Sending 18 data bytes
DEBUG: [conn=0, chan=0] Sending 10 data bytes
DEBUG: [conn=0, chan=0] Reading from channel started
DEBUG: [conn=0, chan=0] Received 1 data byte
DEBUG: [conn=0, chan=0] Received 55 data bytes from STDERR
DEBUG: [conn=0, chan=0] Received 1792 data bytes
DEBUG: [conn=0, chan=0] Received 40 data bytes
DEBUG: [conn=0, chan=0] Received 96 data bytes
DEBUG: [conn=0, chan=0] Received 40 data bytes
DEBUG: [conn=0, chan=0] Sending EOF
INFO: [conn=0, chan=0] Closing channel <---- Hangs here 
^CINFO: [conn=0] Closing connection
INFO: [conn=0, chan=0] Closing channel
INFO: [conn=0] Sending disconnect: Disconnected by application (11)
INFO: [conn=0] Connection closed
INFO: [conn=0, chan=0] Closing channel due to connection close
INFO: [conn=0, chan=0] Channel closed
[ERROR] Traceback (most recent call last):
  File "ssh.py", line 242, in ssh_i
    async with await asyncio.wait_for(
               ^^^^^^^^^^^^^^^^^^^^^^^
  File "/.venv/lib/python3.12/site-packages/asyncssh/process.py", line 830, in __aexit__
    await self.wait_closed()
  File "/.venv/lib/python3.12/site-packages/asyncssh/process.py", line 1208, in wait_closed
    await self._chan.wait_closed()
  File ".venv/lib/python3.12/site-packages/asyncssh/channel.py", line 795, in wait_closed
    await self._close_event.wait()
  File ".local/share/uv/python/cpython-3.12.7-linux-x86_64-gnu/lib/python3.12/asyncio/locks.py", line 212, in wait
    await fut
asyncio.exceptions.CancelledError

Traceback (most recent call last):
  File ".local/share/uv/python/cpython-3.12.7-linux-x86_64-gnu/lib/python3.12/asyncio/runners.py", line 118, in run
    return self._loop.run_until_complete(task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/.local/share/uv/python/cpython-3.12.7-linux-x86_64-gnu/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "test.py", line 107, in main
    await tester.run_tests()
  File "test.py", line 80, in run_tests
    results = {method: await asyncio.gather(*tasks[method]) for method in tasks}
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "test.py", line 42, in test_multi_ssh
    output = await CLASS.ssh(ip, SSO, self.password, ["show version", "show ip int brief"], ssh_debug=True, exception_traceback=True)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "ssh.py", line 242, in ssh_i
    async with await asyncio.wait_for(
               ^^^^^^^^^^^^^^^^^^^^^^^
  File "/.venv/lib/python3.12/site-packages/asyncssh/process.py", line 830, in __aexit__
    await self.wait_closed()
  File "/.venv/lib/python3.12/site-packages/asyncssh/process.py", line 1208, in wait_closed
    await self._chan.wait_closed()
  File "/.venv/lib/python3.12/site-packages/asyncssh/channel.py", line 795, in wait_closed
    await self._close_event.wait()
  File "/.local/share/uv/python/cpython-3.12.7-linux-x86_64-gnu/lib/python3.12/asyncio/locks.py", line 212, in wait
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test.py", line 112, in <module>
    asyncio.run(main())
  File "/.local/share/uv/python/cpython-3.12.7-linux-x86_64-gnu/lib/python3.12/asyncio/runners.py", line 194, in run
    return runner.run(main)
           ^^^^^^^^^^^^^^^^
  File "/.local/share/uv/python/cpython-3.12.7-linux-x86_64-gnu/lib/python3.12/asyncio/runners.py", line 123, in run
    raise KeyboardInterrupt()
KeyboardInterrupt
    @staticmethod
    async def ssh(
        host: str,
        username: str,
        password: str,
        commands: List[str],
        command_name_key: List[str] = [],
        ssh_debug: bool = False,
        exception_traceback: bool = False,
        timeout: int = 10,
    ) -> Optional[Dict[str, Any]]:
        if not commands:
            return None

        if isinstance(commands, str):
            commands = [commands]

        if ssh_debug:
            asyncssh.set_log_level("DEBUG")
            asyncssh.set_sftp_log_level("DEBUG")
            asyncssh.set_debug_level(2)

        logger.debug(
            f"Running command on host {BGB}{host}{RESET}: {BGB}{commands}{RESET}"
        )

        # Connect to the host using AsyncSSH
        try:
            async with await asyncio.wait_for(
                asyncssh.connect(
                    host,
                    username=username,
                    password=password,
                    port=22,
                    known_hosts=None,
                ),
                timeout=timeout,
            ) as conn:
                # Create interactive SSH session on host
                async with await asyncio.wait_for(
                    conn.create_process(stderr=asyncssh.STDOUT), timeout=timeout
                ) as process:
                    res = {}

                    # Run each command on the host
                    for i, command in enumerate(commands):
                        logger.debug(f'--- Running "{BGB}{command}{RESET}" ---')
                        process.stdin.write(f"{command}\n")

                        # Delimiter between commands
                        process.stdin.write("show show\n")

                    # Read the output of each command
                    for command in commands:
                        # Workaround to ignore the connect commands on UCS chassis
                        if command not in [
                            "connect nxos",
                            "connect nxos a",
                            "connect nxos b",
                        ]:
                            # Set output using command_name_key
                            if command_name_key:
                                if isinstance(command_name_key, str):
                                    command_name_key = [command_name_key]
                                res[command_name_key[i]] = res.get(
                                    command_name_key[i], ""
                                ) + await asyncio.wait_for(process.stdout.readuntil(
                                    # Read until stderr containing "Invalid Command" or "show show"
                                    re.compile("Invalid Command|show show"),
                                    max_separator_len=15,
                                ), timeout=timeout)
                            # Else set output using actual command
                            else:
                                res[command] = res.get(
                                    command, ""
                                ) + await asyncio.wait_for(process.stdout.readuntil(
                                    # Read until stderr containing "Invalid Command" or "show show"
                                    re.compile("Invalid Command|show show"),
                                    max_separator_len=15,
                                ), timeout=timeout)

                    # Force the process to close
                    process.stdin.write_eof()

                return res
        except Exception as e:
            logger.error(f"Failed to connect to host {host}: {e}")
            raise CommandExecutionError(host, f"{e.__class__.__module__}.{e.__class__.__name__}: {e}")
        finally:
            if exception_traceback:
                logger.error(traceback.format_exc())

@ronf
Copy link
Owner

ronf commented Jan 29, 2025

I can't be sure, but it looks like this may be a case where the server is ignoring the EOF you are sending and keeping the session open despite that. If that's the case, you may need to send something like an "exit" command at the end instead of sending EOF. If that triggers the server to send EOF (or close) back to you, the implicit wait_closed() triggered by exiting the context manager block should allow the close to finish. and you should be able to exit cleanly.

@NinjaNas
Copy link
Author

I just tried adding an exit command at the end and it still hangs at Closing Channel, unfortunately.

@ronf
Copy link
Owner

ronf commented Jan 29, 2025

Did you add it inside the "async with block for the process, at the same place where the write_eof() call is now? Do you see anything different in the debug output as a result of that change?

If the exit isn't triggering a close, I wonder if somehow that's getting sent before the remote device is back at a command prompt. You could try adding a small delay before sending the "exit" to see if that makes any difference.

@NinjaNas
Copy link
Author

Yes I put it at the same place where the write_eof() is. I have tried it with and without the eof also. The only difference I see is the output sends 5 bytes ("exit\n") before logging Closing Channel.

If I add a delay before the exit, Closing Channel is logged and no further logs happen even after the delay.

@ronf
Copy link
Owner

ronf commented Jan 30, 2025

I don't really understand why the Cisco device isn't closing the channel. Even if it ignored both the "exit" and the EOF, it really should send us back a close when we send our close. Without it, it's expected for wait_closed() to hang.

A workaround here would be to not use a context manager for the call to create_process(). Instead of "async with", do a plain "await" to get the process and do an explicit process.close() after you are done sending commands, without awaiting on wait_closed(). This should avoid the hang, and the associated SSH session will be cleaned up when the connection is cleaned up by the outer context manager for conn.

@NinjaNas
Copy link
Author

Okay it looks that workaround did work correctly. Is there any downside to using this workaround?

@ronf
Copy link
Owner

ronf commented Jan 31, 2025

Since you are exiting the outer context manager (for the connection) immediately after doing so for the SSH session/process, there's really no downside in this case. In fact, you can probably get by without even calling process.close() explicitly and still be fine. When closing the connection, all remaining open sessions are automatically cleaned up.

The place where this might be an issue would be where you are opening a long-lived connection object and then opening multiple sessions on it. If the server never responds with a close for those sessions, you could end up building up multiple session/process objects that don't get cleaned up even though you've called close() on each before you open another one. By doing the wait_closed() on the session (or using the inner context manager), you'd know for sure that the previous session is completely cleaned up before opening the next one, and as you saw here it would hang if the earlier session was NOT being cleaned up properly.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants