0

I am trying to connect to a remote sftp server using python. This server is owned and managed by a third party.

I can connect to the server using Filezilla and also with Pycharm's deployment tools (so can rule out firewall and whitelisting issues I think).

I can connect to a demo server using

import paramiko

transport = paramiko.Transport(('test.rebex.net',22))
transport.connect(username='demo',
                  password='password')
print(transport) 

output:

<paramiko.Transport at 0xf448c50 (cipher aes128-ctr, 128 bits) (active; 0 open channel(s))>

However when trying to connect to the server I need I run:

import paramiko

transport = paramiko.Transport((ftp_server,22))
transport.connect(username=username,password=password)

and get

Traceback (most recent call last):
  File "<input>", line 2, in <module>
  File "/venv/lib/python3.7/site-packages/paramiko/transport.py", line 1291, in connect
    self.start_client()
  File "/venv/lib/python3.7/site-packages/paramiko/transport.py", line 660, in start_client
    raise e
  File "/venv/lib/python3.7/site-packages/paramiko/transport.py", line 2055, in run
    ptype, m = self.packetizer.read_message()
  File "/venv/lib/python3.7/site-packages/paramiko/packet.py", line 459, in read_message
    header = self.read_all(self.__block_size_in, check_rekey=True)
  File "S/venv/lib/python3.7/site-packages/paramiko/packet.py", line 303, in read_all
    raise EOFError()
EOFError

I suspected this question was relevant but I still get the same error as soon as I call connect().

I've also tried using an SSHClient object and calling connect() on that, but get the same error.

I've very little theoretical understanding of networking or SSH & SFTP so, whilst it seems there's nothing coming back from the server when packetizer is trying to read the header to make the initial connection, I'm stumped as to why that is or how to resolve. Is anyone able to shed light on this, or even point me to an alternative to paramiko (if that might help)?

EDIT 2:

import paramiko
import logging

logging.basicConfig()
logging.getLogger("paramiko").setLevel(logging.DEBUG)
ftp_server = 'XXX'
username = 'YYY'
password = 'ZZZ'

transport = paramiko.Transport((ftp_server,22))

output

DEBUG:paramiko.transport:starting thread (client mode): 0x3d2f510
DEBUG:paramiko.transport:Local version/idstring: SSH-2.0-paramiko_2.7.2
DEBUG:paramiko.transport:Remote version/idstring: SSH-2.0-OpenSSH_6.6
INFO:paramiko.transport:Connected (version 2.0, client OpenSSH_6.6)
DEBUG:paramiko.transport:kex algos:['diffie-hellman-group-exchange-sha1', 'diffie-hellman-group14-sha1', 'diffie-hellman-group1-sha1'] server key:['ssh-dss', 'ssh-rsa'] client encrypt:['aes128-ctr', 'aes192-ctr', 'aes256-ctr', 'arcfour256', 'arcfour128', 'chacha20-poly1305@openssh.com', 'aes128-cbc', '3des-cbc', 'blowfish-cbc', 'cast128-cbc', 'aes192-cbc', 'aes256-cbc', 'arcfour', 'rijndael-cbc@lysator.liu.se'] server encrypt:['aes128-ctr', 'aes192-ctr', 'aes256-ctr', 'arcfour256', 'arcfour128', 'chacha20-poly1305@openssh.com', 'aes128-cbc', '3des-cbc', 'blowfish-cbc', 'cast128-cbc', 'aes192-cbc', 'aes256-cbc', 'arcfour', 'rijndael-cbc@lysator.liu.se'] client mac:['hmac-md5-etm@openssh.com', 'hmac-sha1-etm@openssh.com', 'umac-64-etm@openssh.com', 'umac-128-etm@openssh.com', 'hmac-sha2-256-etm@openssh.com', 'hmac-sha2-512-etm@openssh.com', 'hmac-ripemd160-etm@openssh.com', 'hmac-sha1-96-etm@openssh.com', 'hmac-md5-96-etm@openssh.com', 'hmac-md5', 'hmac-sha1', 'umac-64@openssh.com', 'umac-128@openssh.com', 'hmac-ripemd160', 'hmac-ripemd160@openssh.com', 'hmac-sha1-96', 'hmac-md5-96'] server mac:['hmac-md5-etm@openssh.com', 'hmac-sha1-etm@openssh.com', 'umac-64-etm@openssh.com', 'umac-128-etm@openssh.com', 'hmac-sha2-256-etm@openssh.com', 'hmac-sha2-512-etm@openssh.com', 'hmac-ripemd160-etm@openssh.com', 'hmac-sha1-96-etm@openssh.com', 'hmac-md5-96-etm@openssh.com', 'hmac-md5', 'hmac-sha1', 'umac-64@openssh.com', 'umac-128@openssh.com', 'hmac-ripemd160', 'hmac-ripemd160@openssh.com', 'hmac-sha1-96', 'hmac-md5-96'] client compress:['none', 'zlib@openssh.com'] server compress:['none', 'zlib@openssh.com'] client lang:[''] server lang:[''] kex follows?False
DEBUG:paramiko.transport:Kex agreed: diffie-hellman-group-exchange-sha1
DEBUG:paramiko.transport:HostKey agreed: ssh-rsa
DEBUG:paramiko.transport:Cipher agreed: aes128-ctr
DEBUG:paramiko.transport:MAC agreed: hmac-sha2-256-etm@openssh.com
DEBUG:paramiko.transport:Compression agreed: none
DEBUG:paramiko.transport:EOF in transport thread
Traceback (most recent call last):
  File "<input>", line 11, in <module>
  File "/venv/lib/python3.7/site-packages/paramiko/transport.py", line 1291, in connect
    self.start_client()
  File "/venv/lib/python3.7/site-packages/paramiko/transport.py", line 660, in start_client
    raise e
  File "/venv/lib/python3.7/site-packages/paramiko/transport.py", line 2055, in run
    ptype, m = self.packetizer.read_message()
  File "/venv/lib/python3.7/site-packages/paramiko/packet.py", line 459, in read_message
    header = self.read_all(self.__block_size_in, check_rekey=True)
  File "/venv/lib/python3.7/site-packages/paramiko/packet.py", line 303, in read_all
    raise EOFError()
EOFError

EDIT 2.1:

successful connection from filezilla logfile - sensitive info replaced with <HOST> and <USERNAME>

2020-12-11 21:14:36 7151 1 Status: Disconnected from server
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::DoClose(66)
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::ResetOperation(66)
2020-12-11 21:14:36 7151 1 Trace: CFileZillaEnginePrivate::ResetOperation(66)
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::DoClose(66)
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::ResetOperation(66)
2020-12-11 21:14:36 7151 1 Trace: CFileZillaEnginePrivate::ResetOperation(66)
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::DoClose(66)
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::ResetOperation(66)
2020-12-11 21:14:36 7151 1 Trace: CFileZillaEnginePrivate::ResetOperation(66)
2020-12-11 21:14:36 7151 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::SendNextCommand()
2020-12-11 21:14:36 7151 1 Trace: CSftpConnectOpData::Send() in state 0
2020-12-11 21:14:36 7151 1 Status: Connecting to <HOST>...
2020-12-11 21:14:36 7151 1 Trace: Going to execute /private/var/folders/6c/ntd0ljws4m5636vj156l175r0000gn/T/AppTranslocation/6D8907E9-A65E-4E2D-A4EC-65C46A4F1DD1/d/FileZilla.app/Contents/MacOS//fzsftp
2020-12-11 21:14:36 7151 1 Response: fzSftp started, protocol_version=9
2020-12-11 21:14:36 7151 1 Trace: CSftpConnectOpData::ParseResponse() in state 0
2020-12-11 21:14:36 7151 1 Trace: CControlSocket::SendNextCommand()
2020-12-11 21:14:36 7151 1 Trace: CSftpConnectOpData::Send() in state 3
2020-12-11 21:14:36 7151 1 Command: open "<HOST>" 22
2020-12-11 21:14:36 7151 1 Trace: Looking up host "<HOST>" for SSH connection
2020-12-11 21:14:36 7151 1 Trace: Connecting to <HOST_IP> port 22
2020-12-11 21:14:36 7151 1 Trace: We claim version: SSH-2.0-FileZilla_3.49.1
2020-12-11 21:14:36 7151 1 Trace: Remote version: SSH-2.0-OpenSSH_6.6
2020-12-11 21:14:36 7151 1 Trace: We believe remote version has SSH-2 channel request bug
2020-12-11 21:14:36 7151 1 Trace: Using SSH protocol version 2
2020-12-11 21:14:36 7151 1 Trace: Doing Diffie-Hellman group exchange
2020-12-11 21:14:36 7151 1 Trace: Doing Diffie-Hellman key exchange using 2048-bit modulus and hash SHA-1 (unaccelerated) with a server-supplied group
2020-12-11 21:14:37 7151 1 Trace: Server also has ssh-dss host key, but we don't know it
2020-12-11 21:14:37 7151 1 Trace: Host key fingerprint is:
2020-12-11 21:14:37 7151 1 Trace: ssh-rsa 1024 df:d1:18:0e:4d:0b:bc:24:33:84:4c:2a:fe:de:7d:8c yWV/XCKgcAafF1nZTA52HiYK83VBby5W/hELuNchbsA=
2020-12-11 21:14:37 7151 1 Trace: Initialised AES-256 SDCTR (AES-NI accelerated) outbound encryption
2020-12-11 21:14:37 7151 1 Trace: Initialised HMAC-SHA-1 (unaccelerated) outbound MAC algorithm
2020-12-11 21:14:37 7151 1 Trace: Initialised AES-256 SDCTR (AES-NI accelerated) inbound encryption
2020-12-11 21:14:37 7151 1 Trace: Initialised HMAC-SHA-1 (unaccelerated) inbound MAC algorithm
2020-12-11 21:14:37 7151 1 Trace: Pageant is running. Requesting keys.
2020-12-11 21:14:37 7151 1 Trace: Pageant has 0 SSH-2 keys
2020-12-11 21:14:37 7151 1 Status: Using username "<USERNAME>". 
2020-12-11 21:14:37 7151 1 Trace: Attempting keyboard-interactive authentication
2020-12-11 21:14:37 7151 1 Trace: Server refused keyboard-interactive authentication
2020-12-11 21:14:37 7151 1 Command: Pass: ************
2020-12-11 21:14:37 7151 1 Trace: Sent password
2020-12-11 21:14:37 7151 1 Trace: Access granted
2020-12-11 21:14:37 7151 1 Trace: Opening main session channel
2020-12-11 21:14:37 7151 1 Trace: Opened main channel
2020-12-11 21:14:37 7151 1 Trace: Started a shell/command
2020-12-11 21:14:37 7151 1 Status: Connected to <HOST>
2020-12-11 21:14:38 7151 1 Trace: Remote working directory is /sftp
2020-12-11 21:14:38 7151 1 Trace: CSftpConnectOpData::ParseResponse() in state 3
2020-12-11 21:14:38 7151 1 Trace: CControlSocket::ResetOperation(0)
2020-12-11 21:14:38 7151 1 Trace: CSftpConnectOpData::Reset(0) in state 3
2020-12-11 21:14:38 7151 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)
2020-12-11 21:14:38 7151 1 Trace: CControlSocket::SendNextCommand()
2020-12-11 21:14:38 7151 1 Trace: CSftpListOpData::Send() in state 0
2020-12-11 21:14:38 7151 1 Status: Retrieving directory listing...
2020-12-11 21:14:38 7151 1 Trace: CSftpChangeDirOpData::Send() in state 0
2020-12-11 21:14:38 7151 1 Trace: CSftpChangeDirOpData::Send() in state 1
2020-12-11 21:14:38 7151 1 Command: pwd
2020-12-11 21:14:38 7151 1 Response: Current directory is: "/sftp"
2020-12-11 21:14:38 7151 1 Trace: CSftpChangeDirOpData::ParseResponse() in state 1
2020-12-11 21:14:38 7151 1 Trace: CControlSocket::ResetOperation(0)
2020-12-11 21:14:38 7151 1 Trace: CSftpChangeDirOpData::Reset(0) in state 1
2020-12-11 21:14:38 7151 1 Trace: CSftpListOpData::SubcommandResult(0) in state 1
2020-12-11 21:14:38 7151 1 Trace: CControlSocket::SendNextCommand()
2020-12-11 21:14:38 7151 1 Trace: CSftpListOpData::Send() in state 2
2020-12-11 21:14:38 7151 1 Trace: CSftpListOpData::Send() in state 3
2020-12-11 21:14:38 7151 1 Command: ls
2020-12-11 21:14:38 7151 1 Status: Listing directory /sftp
2020-12-11 21:14:38 7151 1 Trace: CSftpListOpData::ParseResponse() in state 3
2020-12-11 21:14:38 7151 1 Trace: CControlSocket::ResetOperation(0)
2020-12-11 21:14:38 7151 1 Trace: CSftpListOpData::Reset(0) in state 3
2020-12-11 21:14:38 7151 1 Status: Directory listing of "/sftp" successful
2020-12-11 21:14:38 7151 1 Trace: CFileZillaEnginePrivate::ResetOperation(0)

EDIT 3:

Paramiko version 1.18.5 works.

DEBUG:paramiko.transport:starting thread (client mode): 0x1102df10
DEBUG:paramiko.transport:Local version/idstring: SSH-2.0-paramiko_1.18.5
DEBUG:paramiko.transport:Remote version/idstring: SSH-2.0-OpenSSH_6.6
INFO:paramiko.transport:Connected (version 2.0, client OpenSSH_6.6)
DEBUG:paramiko.transport:kex algos:['diffie-hellman-group-exchange-sha1', 'diffie-hellman-group14-sha1', 'diffie-hellman-group1-sha1'] server key:['ssh-dss', 'ssh-rsa'] client encrypt:['aes128-ctr', 'aes192-ctr', 'aes256-ctr', 'arcfour256', 'arcfour128', 'chacha20-poly1305@openssh.com', 'aes128-cbc', '3des-cbc', 'blowfish-cbc', 'cast128-cbc', 'aes192-cbc', 'aes256-cbc', 'arcfour', 'rijndael-cbc@lysator.liu.se'] server encrypt:['aes128-ctr', 'aes192-ctr', 'aes256-ctr', 'arcfour256', 'arcfour128', 'chacha20-poly1305@openssh.com', 'aes128-cbc', '3des-cbc', 'blowfish-cbc', 'cast128-cbc', 'aes192-cbc', 'aes256-cbc', 'arcfour', 'rijndael-cbc@lysator.liu.se'] client mac:['hmac-md5-etm@openssh.com', 'hmac-sha1-etm@openssh.com', 'umac-64-etm@openssh.com', 'umac-128-etm@openssh.com', 'hmac-sha2-256-etm@openssh.com', 'hmac-sha2-512-etm@openssh.com', 'hmac-ripemd160-etm@openssh.com', 'hmac-sha1-96-etm@openssh.com', 'hmac-md5-96-etm@openssh.com', 'hmac-md5', 'hmac-sha1', 'umac-64@openssh.com', 'umac-128@openssh.com', 'hmac-ripemd160', 'hmac-ripemd160@openssh.com', 'hmac-sha1-96', 'hmac-md5-96'] server mac:['hmac-md5-etm@openssh.com', 'hmac-sha1-etm@openssh.com', 'umac-64-etm@openssh.com', 'umac-128-etm@openssh.com', 'hmac-sha2-256-etm@openssh.com', 'hmac-sha2-512-etm@openssh.com', 'hmac-ripemd160-etm@openssh.com', 'hmac-sha1-96-etm@openssh.com', 'hmac-md5-96-etm@openssh.com', 'hmac-md5', 'hmac-sha1', 'umac-64@openssh.com', 'umac-128@openssh.com', 'hmac-ripemd160', 'hmac-ripemd160@openssh.com', 'hmac-sha1-96', 'hmac-md5-96'] client compress:['none', 'zlib@openssh.com'] server compress:['none', 'zlib@openssh.com'] client lang:[''] server lang:[''] kex follows?False
DEBUG:paramiko.transport:Kex agreed: diffie-hellman-group1-sha1
DEBUG:paramiko.transport:HostKey agreed: ssh-rsa
DEBUG:paramiko.transport:Cipher agreed: aes128-ctr
DEBUG:paramiko.transport:MAC agreed: hmac-md5
DEBUG:paramiko.transport:Compression agreed: none
DEBUG:paramiko.transport:kex engine KexGroup1 specified hash_algo <built-in function openssl_sha1>
DEBUG:paramiko.transport:Switch to new keys ...
DEBUG:paramiko.transport:Attempting password auth...
DEBUG:paramiko.transport:userauth is OK
INFO:paramiko.transport:Authentication (password) successful!
DEBUG:paramiko.transport:EOF in transport thread

Should I raise this as an issue in the paramiko project?

  • Please post [Paramiko log file](https://stackoverflow.com/q/27587716/850848) as well as a verbose log file from any SSH/SFTP client that can connect to the same server from the same local machine. – Martin Prikryl Dec 11 '20 at 07:02
  • See edit, will try to gather logfile from sftp client and add to question – user3796138 Dec 11 '20 at 07:35
  • Seems strange. The first `DEBUG` logging happens *before the `read_message`*. – Martin Prikryl Dec 11 '20 at 07:45
  • Actually I don't think it is outputting a logfile at all. Removed the file and reran with `paramiko.util.log_to_file("./logfile.log", level='DEBUG')` and no file was created – user3796138 Dec 11 '20 at 08:02
  • Did you try `logging.basicConfig()` `logging.getLogger("paramiko").setLevel(logging.DEBUG)`? + That's not a verbose FileZilla log file. That's (mostly useless) GUI message log. – Martin Prikryl Dec 11 '20 at 08:06
  • see new edits... sorry filezilla uses 'verbose' and 'debug' to describe logging levels... verbose obviously ins't. – user3796138 Dec 11 '20 at 08:24
  • Do you have an access to server-side log files? + It's possibly due to some incompatibility in algorithm (KEX?) implementation between OpenSSH 6.6 and Paramiko. Try to force different algorithms, see https://github.com/paramiko/paramiko/issues/1120#issuecomment-346960602 – Martin Prikryl Dec 11 '20 at 08:36
  • The old version of Paramiko probably works, because it uses different algorithms for MAC and KEX (as it does not support the new algorithms that 2.7.2 does). As per my previous comment, try to force the same algorithms in 2.7.2 – It will probably work too. – Martin Prikryl Dec 11 '20 at 21:10

0 Answers0