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.

Sign up for GitHub

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

Jump to bottom

SSHClient connect extremely slow #2155

Open
felixtech-msp opened this issue Dec 6, 2022 · 3 comments
Open

SSHClient connect extremely slow #2155

felixtech-msp opened this issue Dec 6, 2022 · 3 comments
Labels
Support

Comments

@felixtech-msp
Copy link 

#!/usr/bin/env python3

import paramiko
import os
from datetime import datetime

client = paramiko.SSHClient()
client.set_missing_host_key_policy(paramiko.AutoAddPolicy())

time1 = datetime.now()
client.connect('192.168.1.1', username='user', key_filename='/path/to/keyfile')
time2 = datetime.now()
print(time2 - time1)

output = client.exec_command('...')[1]
client.close()

The above code takes for the line client.connect() about 35 seconds each time. The device to connect to is on the same local network. Connecting via PuTTY takes about 1.5 seconds.
How can this be improved? Is there a way to track in more detail the cause of the delay?
@jun66j5
Copy link
Contributor

jun66j5 commented Dec 6, 2022

  1. What version of paramiko are you using?
  2. Please provide log file using paramiko.util.log_to_file('/path/to/paramiko.log')
  3. Check whether Agent class is slow using python.exe -c "import paramiko; print(list(paramiko.Agent().get_keys()))"
  4. Pass allow_agent=False and look_for_keys=False to SSHClient.connect

@bskinn bskinn added the Support label Dec 6, 2022
@felixtech-msp
Copy link
Author

  1. Python 3.9.2 and Paramiko 2.11.0
  2. Log output below. Runtime of this execution was 35.5 sec.
  3. Output is [] within a fraction of a second.
  4. Passing those 2 parameters did not change the execution time.
DEB [20221206-16:19:55.553] thr=1   paramiko.transport: starting thread (client mode): 0xa640e8e0
DEB [20221206-16:19:55.554] thr=1   paramiko.transport: Local version/idstring: SSH-2.0-paramiko_2.11.0
DEB [20221206-16:19:55.677] thr=1   paramiko.transport: Remote version/idstring: SSH-2.0-OpenSSH_7.4p1 Debian-10+deb9u7
INF [20221206-16:19:55.677] thr=1   paramiko.transport: Connected (version 2.0, client OpenSSH_7.4p1)
DEB [20221206-16:19:55.681] thr=1   paramiko.transport: === Key exchange possibilities ===
DEB [20221206-16:19:55.681] thr=1   paramiko.transport: kex algos: curve25519-sha256, curve25519-sha256@libssh.org, ecdh-sha2-nistp256, ecdh-sha2-nistp384, ecdh-sha2-nistp521, diffie-hellman-group-exchange-sha256, diffie-hellman-group16-sha512, diffie-hellman-group18-sha512, diffie-hellman-group14-sha256, diffie-hellman-group14-sha1
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: client mac: 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
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: server mac: 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
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: client compress: none, zlib@openssh.com
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: server compress: none, zlib@openssh.com
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: client lang: <none>
DEB [20221206-16:19:55.682] thr=1   paramiko.transport: server lang: <none>
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: kex follows: False
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: === Key exchange agreements ===
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: Kex: curve25519-sha256@libssh.org
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: HostKey: ssh-ed25519
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: Cipher: aes128-ctr
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: MAC: hmac-sha2-256
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: Compression: none
DEB [20221206-16:19:55.683] thr=1   paramiko.transport: === End of kex handshake ===
DEB [20221206-16:19:55.790] thr=1   paramiko.transport: kex engine KexCurve25519 specified hash_algo <built-in function openssl_sha256>
DEB [20221206-16:19:55.791] thr=1   paramiko.transport: Switch to new keys ...
DEB [20221206-16:19:55.792] thr=2   paramiko.transport: Adding ssh-ed25519 host key for 192.168.1.1: b'dd534d0648d7440cde47766657578418'
DEB [20221206-16:19:55.792] thr=1   paramiko.transport: Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
DEB [20221206-16:19:59.044] thr=1   paramiko.transport: starting thread (client mode): 0x925fa790
DEB [20221206-16:19:59.045] thr=1   paramiko.transport: Local version/idstring: SSH-2.0-paramiko_2.11.0
DEB [20221206-16:19:59.168] thr=1   paramiko.transport: Remote version/idstring: SSH-2.0-OpenSSH_7.4p1 Debian-10+deb9u7
INF [20221206-16:19:59.168] thr=1   paramiko.transport: Connected (version 2.0, client OpenSSH_7.4p1)
DEB [20221206-16:19:59.172] thr=1   paramiko.transport: === Key exchange possibilities ===
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: kex algos: curve25519-sha256, curve25519-sha256@libssh.org, ecdh-sha2-nistp256, ecdh-sha2-nistp384, ecdh-sha2-nistp521, diffie-hellman-group-exchange-sha256, diffie-hellman-group16-sha512, diffie-hellman-group18-sha512, diffie-hellman-group14-sha256, diffie-hellman-group14-sha1
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: client mac: 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
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: server mac: 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
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: client compress: none, zlib@openssh.com
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: server compress: none, zlib@openssh.com
DEB [20221206-16:19:59.173] thr=1   paramiko.transport: client lang: <none>
DEB [20221206-16:19:59.174] thr=1   paramiko.transport: server lang: <none>
DEB [20221206-16:19:59.174] thr=1   paramiko.transport: kex follows: False
DEB [20221206-16:19:59.174] thr=1   paramiko.transport: === Key exchange agreements ===
DEB [20221206-16:19:59.174] thr=1   paramiko.transport: Kex: curve25519-sha256@libssh.org
DEB [20221206-16:19:59.174] thr=1   paramiko.transport: HostKey: ssh-ed25519
DEB [20221206-16:19:59.174] thr=1   paramiko.transport: Cipher: aes128-ctr
DEB [20221206-16:19:59.174] thr=1   paramiko.transport: MAC: hmac-sha2-256
DEB [20221206-16:19:59.175] thr=1   paramiko.transport: Compression: none
DEB [20221206-16:19:59.175] thr=1   paramiko.transport: === End of kex handshake ===
DEB [20221206-16:19:59.281] thr=1   paramiko.transport: kex engine KexCurve25519 specified hash_algo <built-in function openssl_sha256>
DEB [20221206-16:19:59.282] thr=1   paramiko.transport: Switch to new keys ...
DEB [20221206-16:19:59.283] thr=2   paramiko.transport: Adding ssh-ed25519 host key for 192.168.1.1: b'dd534d0648d7440cde47766657578418'
DEB [20221206-16:19:59.283] thr=1   paramiko.transport: Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
DEB [20221206-16:20:31.243] thr=2   paramiko.transport: Trying discovered key b'cfee770c07d953b590d617e6ce1ebbd7' in /path/to/keyfile
DEB [20221206-16:20:31.245] thr=1   paramiko.transport: userauth is OK
DEB [20221206-16:20:31.245] thr=1   paramiko.transport: Finalizing pubkey algorithm for key of type 'ssh-rsa'
DEB [20221206-16:20:31.246] thr=1   paramiko.transport: Our pubkey algorithm list: ['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa']
DEB [20221206-16:20:31.246] thr=1   paramiko.transport: Server-side algorithm list: ['ssh-ed25519', 'ssh-rsa', 'ssh-dss', 'ecdsa-sha2-nistp256', 'ecdsa-sha2-nistp384', 'ecdsa-sha2-nistp521']
DEB [20221206-16:20:31.246] thr=1   paramiko.transport: Agreed upon 'ssh-rsa' pubkey algorithm
INF [20221206-16:20:31.653] thr=1   paramiko.transport: Auth banner: b'  _____    _            \n | ____|__| | __ _  ___          (c) 2010-2020\n |  _| / _  |/ _  |/ _ \\         Ubiquiti Networks, Inc.\n | |__| (_| | (_| |  __/         \n |_____\\__._|\\__. |\\___|         https://www.ubnt.com\n             |___/\n\nWelcome to EdgeOS\n\nBy logging in, accessing, or using the Ubiquiti product, you\nacknowledge that you have read and understood the Ubiquiti\nLicense Agreement (available in the Web UI at, by default,\nhttp://192.168.1.1) and agree to be bound by its terms.\n\n'
INF [20221206-16:20:31.654] thr=1   paramiko.transport: Authentication (publickey) successful!
DEB [20221206-16:20:31.655] thr=2   paramiko.transport: [chan 0] Max packet in: 32768 bytes
DEB [20221206-16:20:31.941] thr=1   paramiko.transport: Received global request "hostkeys-00@openssh.com"
DEB [20221206-16:20:31.941] thr=1   paramiko.transport: Rejecting "hostkeys-00@openssh.com" global request from server.
DEB [20221206-16:20:31.985] thr=1   paramiko.transport: [chan 0] Max packet out: 32768 bytes
DEB [20221206-16:20:31.985] thr=1   paramiko.transport: Secsh channel 0 opened.
DEB [20221206-16:20:31.989] thr=1   paramiko.transport: [chan 0] Sesch channel 0 request ok
DEB [20221206-16:20:31.989] thr=2   paramiko.transport: [chan 0] EOF sent (0)
DEB [20221206-16:20:32.269] thr=1   paramiko.transport: [chan 0] EOF received (0)
DEB [20221206-16:20:35.012] thr=2   paramiko.transport: Trying discovered key b'cfee770c07d953b590d617e6ce1ebbd7' in /path/to/keyfile
DEB [20221206-16:20:35.014] thr=1   paramiko.transport: userauth is OK
DEB [20221206-16:20:35.014] thr=1   paramiko.transport: Finalizing pubkey algorithm for key of type 'ssh-rsa'
DEB [20221206-16:20:35.014] thr=1   paramiko.transport: Our pubkey algorithm list: ['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa']
DEB [20221206-16:20:35.015] thr=1   paramiko.transport: Server-side algorithm list: ['ssh-ed25519', 'ssh-rsa', 'ssh-dss', 'ecdsa-sha2-nistp256', 'ecdsa-sha2-nistp384', 'ecdsa-sha2-nistp521']
DEB [20221206-16:20:35.015] thr=1   paramiko.transport: Agreed upon 'ssh-rsa' pubkey algorithm
INF [20221206-16:20:35.411] thr=1   paramiko.transport: Auth banner: b'  _____    _            \n | ____|__| | __ _  ___          (c) 2010-2020\n |  _| / _  |/ _  |/ _ \\         Ubiquiti Networks, Inc.\n | |__| (_| | (_| |  __/         \n |_____\\__._|\\__. |\\___|         https://www.ubnt.com\n             |___/\n\nWelcome to EdgeOS\n\nBy logging in, accessing, or using the Ubiquiti product, you\nacknowledge that you have read and understood the Ubiquiti\nLicense Agreement (available in the Web UI at, by default,\nhttp://192.168.1.1) and agree to be bound by its terms.\n\n'
INF [20221206-16:20:35.412] thr=1   paramiko.transport: Authentication (publickey) successful!
DEB [20221206-16:20:35.413] thr=2   paramiko.transport: [chan 0] Max packet in: 32768 bytes
DEB [20221206-16:20:35.721] thr=1   paramiko.transport: Received global request "hostkeys-00@openssh.com"
DEB [20221206-16:20:35.721] thr=1   paramiko.transport: Rejecting "hostkeys-00@openssh.com" global request from server.
DEB [20221206-16:20:35.765] thr=1   paramiko.transport: [chan 0] Max packet out: 32768 bytes
DEB [20221206-16:20:35.766] thr=1   paramiko.transport: Secsh channel 0 opened.
DEB [20221206-16:20:35.771] thr=1   paramiko.transport: [chan 0] Sesch channel 0 request ok
DEB [20221206-16:20:35.771] thr=2   paramiko.transport: [chan 0] EOF sent (0)
DEB [20221206-16:20:36.137] thr=1   paramiko.transport: [chan 0] EOF received (0)

@jun66j5
Copy link
Contributor

jun66j5 commented Dec 20, 2022

Tried to reproduce with OpenSSH 7.4p1 in Debian 9 on Docker, however unable to reproduce it.

DEB [20221220-15:52:07.649] thr=1   paramiko.transport: starting thread (client mode): 0x3cfb9250
DEB [20221220-15:52:07.649] thr=1   paramiko.transport: Local version/idstring: SSH-2.0-paramiko_2.11.0
DEB [20221220-15:52:07.653] thr=1   paramiko.transport: Remote version/idstring: SSH-2.0-OpenSSH_7.4p1 Debian-10+deb9u7
INF [20221220-15:52:07.653] thr=1   paramiko.transport: Connected (version 2.0, client OpenSSH_7.4p1)
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: === Key exchange possibilities ===
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: kex algos: curve25519-sha256, curve25519-sha256@libssh.org, ecdh-sha2-nistp256, ecdh-sha2-nistp384, ecdh-sha2-nistp521, diffie-hellman-group-exchange-sha256, diffie-hellman-group16-sha512, diffie-hellman-group18-sha512, diffie-hellman-group14-sha256, diffie-hellman-group14-sha1
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: client mac: 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
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: server mac: 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
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: client compress: none, zlib@openssh.com
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: server compress: none, zlib@openssh.com
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: client lang: <none>
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: server lang: <none>
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: kex follows: False
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: === Key exchange agreements ===
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: Kex: curve25519-sha256@libssh.org
DEB [20221220-15:52:07.654] thr=1   paramiko.transport: HostKey: ssh-ed25519
DEB [20221220-15:52:07.655] thr=1   paramiko.transport: Cipher: aes128-ctr
DEB [20221220-15:52:07.655] thr=1   paramiko.transport: MAC: hmac-sha2-256
DEB [20221220-15:52:07.655] thr=1   paramiko.transport: Compression: none
DEB [20221220-15:52:07.655] thr=1   paramiko.transport: === End of kex handshake ===
DEB [20221220-15:52:07.663] thr=1   paramiko.transport: kex engine KexCurve25519 specified hash_algo <built-in function openssl_sha256>
DEB [20221220-15:52:07.663] thr=1   paramiko.transport: Switch to new keys ...
DEB [20221220-15:52:07.663] thr=2   paramiko.transport: Adding ssh-ed25519 host key for [127.0.0.1]:2200: b'c3e630f0ff42d1faa077126ea31ee20f'
DEB [20221220-15:52:07.667] thr=1   paramiko.transport: Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
DEB [20221220-15:52:07.673] thr=2   paramiko.transport: Trying discovered key b'9ce36fde7e8810dfde71fc6d47932543' in demos/user_rsa_key
DEB [20221220-15:52:07.673] thr=1   paramiko.transport: userauth is OK
DEB [20221220-15:52:07.673] thr=1   paramiko.transport: Finalizing pubkey algorithm for key of type 'ssh-rsa'
DEB [20221220-15:52:07.673] thr=1   paramiko.transport: Our pubkey algorithm list: ['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa']
DEB [20221220-15:52:07.674] thr=1   paramiko.transport: Server-side algorithm list: ['ssh-ed25519', 'ssh-rsa', 'ssh-dss', 'ecdsa-sha2-nistp256', 'ecdsa-sha2-nistp384', 'ecdsa-sha2-nistp521']
DEB [20221220-15:52:07.674] thr=1   paramiko.transport: Agreed upon 'ssh-rsa' pubkey algorithm
INF [20221220-15:52:07.677] thr=1   paramiko.transport: Authentication (publickey) successful!
DEB [20221220-15:52:07.677] thr=2   paramiko.transport: [chan 0] Max packet in: 32768 bytes
DEB [20221220-15:52:07.683] thr=1   paramiko.transport: Received global request "hostkeys-00@openssh.com"
DEB [20221220-15:52:07.683] thr=1   paramiko.transport: Rejecting "hostkeys-00@openssh.com" global request from server.
DEB [20221220-15:52:07.724] thr=1   paramiko.transport: [chan 0] Max packet out: 32768 bytes
DEB [20221220-15:52:07.724] thr=1   paramiko.transport: Secsh channel 0 opened.
DEB [20221220-15:52:07.724] thr=1   paramiko.transport: [chan 0] Sesch channel 0 request ok
DEB [20221220-15:52:07.725] thr=2   paramiko.transport: [chan 0] EOF sent (0)

The following line which spend 30 seconds in reporter's environment is weird:

DEB [20221206-16:19:59.283] thr=1   paramiko.transport: Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
DEB [20221206-16:20:31.243] thr=2   paramiko.transport: Trying discovered key b'cfee770c07d953b590d617e6ce1ebbd7' in /path/to/keyfile

@sverrevh sverrevh mentioned this issue Apr 9, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Support
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@jun66j5 @bskinn @felixtech-msp