Topic "[BUG] Cannot initialize SFTP protocol"

Author Message
onslo
[View user's profile]

Joined: 2009-04-15
Posts: 7
Hi,

I'm trying to connect to manage a website hosted at bluehost using SFTP. It works flawlessly with Filezilla 3.2.3.1, but fails with WinSCP 4.2.1 (Build 428)

If I set port number as 21 and file protocol as SFTP, connection times out. I left SFTP protocol version at 5. If I leave port number as 22 and file protocol as 22, I get the following error message:

Quote:
Received tool large (168450415 B) SFTP packet. Max supported packet size is 102400 B.

The error is typically caused by message printed from startup script (like .profile). The message may start with ""\n\nYo"".

Cannot initialize SFTP protocol. Is the host running a SFTP server?


The following is the WinSCP log:

Quote:
. 2009-04-14 23:21:51.878 --------------------------------------------------------------------------
. 2009-04-14 23:21:51.878 WinSCP Version 4.2.1 (Build 428) (OS 5.1.2600 Service Pack 3)
. 2009-04-14 23:21:51.878 Login time: Tuesday, April 14, 2009 11:21:51 PM
. 2009-04-14 23:21:51.878 --------------------------------------------------------------------------
. 2009-04-14 23:21:51.878 Session name: username@www.domain.com
. 2009-04-14 23:21:51.878 Host name: www.domain.com (Port: 22)
. 2009-04-14 23:21:51.878 User name: username (Password: No, Key file: No)
. 2009-04-14 23:21:51.878 Tunnel: No
. 2009-04-14 23:21:51.878 Transfer Protocol: SFTP
. 2009-04-14 23:21:51.878 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2009-04-14 23:21:51.878 Proxy: none
. 2009-04-14 23:21:51.878 SSH protocol version: 2 only; Compression: Yes
. 2009-04-14 23:21:51.878 Bypass authentication: No
. 2009-04-14 23:21:51.878 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2009-04-14 23:21:51.878 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2009-04-14 23:21:51.878 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2009-04-14 23:21:51.878 SFTP Bugs: -,-
. 2009-04-14 23:21:51.878 Return code variable: Autodetect; Lookup user groups: Yes
. 2009-04-14 23:21:51.878 Shell: default, EOL: 0
. 2009-04-14 23:21:51.878 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2009-04-14 23:21:51.878 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2009-04-14 23:21:51.878 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2009-04-14 23:21:51.878 Cache directory changes: Yes, Permanent: Yes
. 2009-04-14 23:21:51.878 DST mode: 1
. 2009-04-14 23:21:51.878 --------------------------------------------------------------------------
. 2009-04-14 23:21:52.059 Looking up host "www.domain.com"
. 2009-04-14 23:21:52.089 Connecting to xxx.xxx.xxx.xxx port 22
. 2009-04-14 23:21:52.129 Selecting events 63 for socket 728
. 2009-04-14 23:21:52.129 We claim version: SSH-2.0-WinSCP_release_4.2.1
. 2009-04-14 23:21:52.139 Waiting for the server to continue with the initialisation
. 2009-04-14 23:21:52.139 Looking for incoming data
. 2009-04-14 23:21:52.139 Looking for network events
. 2009-04-14 23:21:52.139 Detected network event
. 2009-04-14 23:21:52.139 Enumerating network events for socket 728
. 2009-04-14 23:21:52.139 Enumerated 18 network events making 18 cumulative events for socket 728
. 2009-04-14 23:21:52.139 Handling network write event on socket 728 with error 0
. 2009-04-14 23:21:52.139 Handling network connect event on socket 728 with error 0
. 2009-04-14 23:21:52.139 Looking for network events
. 2009-04-14 23:21:52.179 Detected network event
. 2009-04-14 23:21:52.179 Enumerating network events for socket 728
. 2009-04-14 23:21:52.179 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:21:52.179 Handling network read event on socket 728 with error 0
. 2009-04-14 23:21:52.179 Server version: SSH-2.0-OpenSSH_3.9p1
. 2009-04-14 23:21:52.179 Using SSH protocol version 2
. 2009-04-14 23:21:52.179 Waiting for the server to continue with the initialisation
. 2009-04-14 23:21:52.179 Looking for incoming data
. 2009-04-14 23:21:52.179 Looking for network events
. 2009-04-14 23:21:52.229 Detected network event
. 2009-04-14 23:21:52.229 Enumerating network events for socket 728
. 2009-04-14 23:21:52.229 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:21:52.229 Handling network read event on socket 728 with error 0
. 2009-04-14 23:21:52.229 Doing Diffie-Hellman group exchange
. 2009-04-14 23:21:52.229 Waiting for the server to continue with the initialisation
. 2009-04-14 23:21:52.229 Looking for incoming data
. 2009-04-14 23:21:52.229 Looking for network events
. 2009-04-14 23:21:52.349 Detected network event
. 2009-04-14 23:21:52.349 Enumerating network events for socket 728
. 2009-04-14 23:21:52.349 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:21:52.349 Handling network read event on socket 728 with error 0
. 2009-04-14 23:21:52.349 Doing Diffie-Hellman key exchange with hash SHA-1
. 2009-04-14 23:21:52.549 Waiting for the server to continue with the initialisation
. 2009-04-14 23:21:52.549 Looking for incoming data
. 2009-04-14 23:21:52.549 Looking for network events
. 2009-04-14 23:21:52.599 Detected network event
. 2009-04-14 23:21:52.599 Enumerating network events for socket 728
. 2009-04-14 23:21:52.599 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:21:52.599 Handling network read event on socket 728 with error 0
. 2009-04-14 23:21:52.810 Selecting events 63 for socket 728
. 2009-04-14 23:21:52.810 Host key fingerprint is:
. 2009-04-14 23:21:52.810 ssh-rsa 1024 88:4d:78:64:63:b1:31:7e:db:d9:7e:45:fe:ab:6f:1f
. 2009-04-14 23:21:52.810 Initialised AES-256 SDCTR client->server encryption
. 2009-04-14 23:21:52.810 Initialised HMAC-SHA1 client->server MAC algorithm
. 2009-04-14 23:21:52.810 Initialised zlib (RFC1950) compression
. 2009-04-14 23:21:52.810 Initialised AES-256 SDCTR server->client encryption
. 2009-04-14 23:21:52.810 Initialised HMAC-SHA1 server->client MAC algorithm
. 2009-04-14 23:21:52.810 Initialised zlib (RFC1950) decompression
. 2009-04-14 23:21:52.810 Waiting for the server to continue with the initialisation
. 2009-04-14 23:21:52.810 Looking for incoming data
. 2009-04-14 23:21:52.810 Looking for network events
. 2009-04-14 23:21:52.930 Detected network event
. 2009-04-14 23:21:52.930 Enumerating network events for socket 728
. 2009-04-14 23:21:52.930 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:21:52.930 Handling network read event on socket 728 with error 0
! 2009-04-14 23:21:52.930 Using username "username".
. 2009-04-14 23:21:52.930 Waiting for the server to continue with the initialisation
. 2009-04-14 23:21:52.930 Looking for incoming data
. 2009-04-14 23:21:52.930 Looking for network events
. 2009-04-14 23:21:52.980 Detected network event
. 2009-04-14 23:21:52.980 Enumerating network events for socket 728
. 2009-04-14 23:21:52.980 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:21:52.980 Handling network read event on socket 728 with error 0
. 2009-04-14 23:21:52.980 Prompt (6, SSH password, , &Password: )
. 2009-04-14 23:22:05.218 Sent password
. 2009-04-14 23:22:05.218 Waiting for the server to continue with the initialisation
. 2009-04-14 23:22:05.218 Looking for incoming data
. 2009-04-14 23:22:05.218 Looking for network events
. 2009-04-14 23:22:05.268 Detected network event
. 2009-04-14 23:22:05.268 Enumerating network events for socket 728
. 2009-04-14 23:22:05.268 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:22:05.268 Handling network read event on socket 728 with error 0
. 2009-04-14 23:22:05.268 Access granted
. 2009-04-14 23:22:05.268 Waiting for the server to continue with the initialisation
. 2009-04-14 23:22:05.268 Looking for incoming data
. 2009-04-14 23:22:05.268 Looking for network events
. 2009-04-14 23:22:05.318 Detected network event
. 2009-04-14 23:22:05.318 Enumerating network events for socket 728
. 2009-04-14 23:22:05.318 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:22:05.318 Handling network read event on socket 728 with error 0
. 2009-04-14 23:22:05.318 Opened channel for session
. 2009-04-14 23:22:05.318 Waiting for the server to continue with the initialisation
. 2009-04-14 23:22:05.318 Looking for incoming data
. 2009-04-14 23:22:05.318 Looking for network events
. 2009-04-14 23:22:05.438 Detected network event
. 2009-04-14 23:22:05.438 Enumerating network events for socket 728
. 2009-04-14 23:22:05.438 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:22:05.438 Handling network read event on socket 728 with error 0
. 2009-04-14 23:22:05.438 Started a shell/command
. 2009-04-14 23:22:05.448 --------------------------------------------------------------------------
. 2009-04-14 23:22:05.448 Using SFTP protocol.
. 2009-04-14 23:22:05.448 Doing startup conversation with host.
> 2009-04-14 23:22:05.448 Type: SSH_FXP_INIT, Size: 5, Number: -1
> 2009-04-14 23:22:05.448 01,00,00,00,05,
. 2009-04-14 23:22:05.448 Sent 9 bytes
. 2009-04-14 23:22:05.448 There are 0 bytes remaining in the send buffer
. 2009-04-14 23:22:05.448 Looking for network events
. 2009-04-14 23:22:05.448 Timeout waiting for network events
. 2009-04-14 23:22:05.448 Waiting for another 4 bytes
. 2009-04-14 23:22:05.448 Looking for incoming data
. 2009-04-14 23:22:05.448 Looking for network events
. 2009-04-14 23:22:05.488 Detected network event
. 2009-04-14 23:22:05.488 Enumerating network events for socket 728
. 2009-04-14 23:22:05.488 Enumerated 1 network events making 1 cumulative events for socket 728
. 2009-04-14 23:22:05.488 Handling network read event on socket 728 with error 0
. 2009-04-14 23:22:05.488 Received 573 bytes (0)
. 2009-04-14 23:22:05.488 Read 4 bytes (569 pending)
. 2009-04-14 23:22:05.488 Attempt to close connection due to fatal exception:
* 2009-04-14 23:22:05.488 Received too large (168450415 B) SFTP packet. Max supported packet size is 102400 B.
* 2009-04-14 23:22:05.488
* 2009-04-14 23:22:05.488 The error is typically caused by message printed from startup script (like .profile). The message may start with ""\n\nYo"".
. 2009-04-14 23:22:05.488 Closing connection.
. 2009-04-14 23:22:05.488 Sending special code: 12
. 2009-04-14 23:22:05.488 Sent EOF message
. 2009-04-14 23:22:05.488 Selecting events 0 for socket 728
* 2009-04-14 23:22:05.508 (ESshFatal) Received too large (168450415 B) SFTP packet. Max supported packet size is 102400 B.
* 2009-04-14 23:22:05.508
* 2009-04-14 23:22:05.508 The error is typically caused by message printed from startup script (like .profile). The message may start with ""\n\nYo"".
* 2009-04-14 23:22:05.508 Cannot initialize SFTP protocol. Is the host running a SFTP server?




The following is the Log from Filezilla:

Quote:
Status: Resolving address of www.xxxxx.com
Status: Connecting to xxx.xxx.xxx.xxx:21...
Status: Connection established, waiting for welcome message...
Response: 220---------- Welcome to Pure-FTPd [TLS] ----------
Response: 220-You are user number 14 of 50 allowed.
Response: 220-Local time is now 00:13. Server port: 21.
Response: 220-IPv6 connections are also welcome on this server.
Response: 220 You will be disconnected after 15 minutes of inactivity.
Command: AUTH TLS
Response: 234 AUTH TLS OK.
Status: Initializing TLS...
Status: Verifying certificate...
Command: USER xxxx
Status: TLS/SSL connection established.
Response: 331 User xxxx OK. Password required
Command: PASS ********
Response: 230-User xxxx has group access to: xxxx
Response: 230 OK. Current restricted directory is /
Command: SYST
Response: 215 UNIX Type: L8
Command: FEAT
Response: 211-Extensions supported:
Response: EPRT
Response: IDLE
Response: MDTM
Response: SIZE
Response: REST STREAM
Response: MLST type*;size*;sizd*;modify*;UNIX.mode*;UNIX.uid*;UNIX.gid*;unique*;
Response: MLSD
Response: ESTP
Response: PASV
Response: EPSV
Response: SPSV
Response: ESTA
Response: AUTH TLS
Response: PBSZ
Response: PROT
Response: 211 End.
Command: PBSZ 0
Response: 200 PBSZ=0
Command: PROT P
Response: 534 Fallback to [C]
Status: Connected
Status: Retrieving directory listing...
Command: PWD
Response: 257 "/" is your current location
Command: TYPE I
Response: 200 TYPE is now 8-bit binary
Command: PASV
Response: 227 Entering Passive Mode (xxx,xxx,xxx,xxx,xxx,xxx)
Command: LIST
Response: 150 Accepted data connection
Response: 226-ASCII
Response: 226-Options: -a -l
Response: 226 28 matches total
Status: Calculating timezone offset of server...
Command: MDTM .bash_logout
Response: 213 20090222004043
Status: Timezone offsets: Server: -25200 seconds. Local: -25200 seconds. Difference: 0 seconds.
Status: Directory listing successful
Advertisements
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
With filezilla you are obviously using FTP protocol (on default port 21).

With WinSCP you are using SFTP. The reason it fails is explained in the error message. You will find more information on the error in documentation.
If you want to use FTP with WinSCP, make sure you select FTP protocol. Using SFTP on port 21 can hardly work.
_________________
Martin Prikryl
onslo
[View user's profile]

Joined: 2009-04-15
Posts: 7
prikryl wrote:
With filezilla you are obviously using FTP protocol (on default port 21).

Not true. Filezilla showed the locked icon and I've even verified, using WireShark, that the data stream is encrypted.

If you look at the Filezilla log, you will see where it negotiated TLS security.
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
OK, but it is FTP nevertheless, or FTPS if you want. Not SFTP.
Refer to documentation to see how to configure protocol in WinSCP.
_________________
Martin Prikryl
onslo
[View user's profile]

Joined: 2009-04-15
Posts: 7
Ok. Thanks. Got it connecting now. Only thing left to do is solve the inability to get directory listing, but I'll have to do that tomorrow.

I was confused because the drop-down was for "FTP" so I didn't choose it, not knowing there would be an encryption option if I did. Laughing
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
For details about error message "Cannot initialize SFTP protocol. Is the host running a SFTP server?" see:
http://winscp.net/eng/docs/message_cannot_initialize_sftp_protocol
_________________
Martin Prikryl
Advertisements

You can post new topics in this forum






Search Site

What is WinSCP?

It is award-winning SFTP client, SCP client, FTPS client and FTP client integrated into one software program for file transfer to FTP server or secure SFTP server. [More]

And it's free!

Donate

About donations

$9   $19   $49   $99

About donations

Recommend

WinSCP Privacy Policy

WinSCP License