Rclone "packet too long" for version packet from Debian SSH server: "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"

helpimnotdrowning · June 16, 2024, 8:18pm

What is the problem you are having with rclone?

rclone can't connect to my Debian 12 server over ssh/sftp because it's version string is too long (?) : SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2

Run the command 'rclone version' and share the full output of the command.

rclone v1.67.0
- os/version: Microsoft Windows 11 Home 24H2 (64 bit)
- os/kernel: 10.0.26120.961 (x86_64)
- os/type: windows
- os/arch: amd64
- go/version: go1.22.4
- go/linking: static
- go/tags: cmount

Which cloud storage system are you using? (eg Google Drive)

sftp over LAN running on Debian 12 (SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2)

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

& (gcm rclone).source -vv mount sftp-helpi@URUHA:/mnt/V V:

, expands to:

& C:\Users\helpi\AppData\Local\Microsoft\WinGet\Links\rclone.exe -vv mount sftp-helpi@URUHA:/mnt/V V:

The rclone config contents with secrets removed.

[sftp-helpi@URUHA]
type = sftp
host = URUHA.***
user = helpimnotdrowning
key_file = C:/Users/helpi/.ssh/id_rsa
shell_type = powershell
md5sum_command = md5sum
sha1sum_command = sha1sum

A log from the command with the `-vv` flag

2024/06/16 **:**:49 DEBUG : rclone: Version "v1.67.0" starting with parameters ["C:\\Users\\helpi\\AppData\\Local\\Microsoft\\WinGet\\Links\\rclone.exe" "-vv" "mount" "sftp-helpi@URUHA:/mnt/V" "V:"]
2024/06/16 **:**:49 DEBUG : Creating backend with remote "sftp-helpi@URUHA:/mnt/V"
2024/06/16 **:**:49 DEBUG : Using config file from "C:\\Users\\helpi\\AppData\\Roaming\\rclone\\rclone.conf"
2024/06/16 **:**:49 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19488->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:51 DEBUG : pacer: low level retry 1/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:51 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2024/06/16 **:**:51 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19490->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:52 DEBUG : pacer: low level retry 2/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:52 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2024/06/16 **:**:52 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19491->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:53 DEBUG : pacer: low level retry 3/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:53 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2024/06/16 **:**:53 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19492->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:54 DEBUG : pacer: low level retry 4/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:54 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2024/06/16 **:**:54 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19493->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:55 DEBUG : pacer: low level retry 5/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:55 DEBUG : pacer: Rate limited, increasing sleep to 2s
2024/06/16 **:**:55 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19495->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:56 DEBUG : pacer: low level retry 6/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:57 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19497->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:58 DEBUG : pacer: low level retry 7/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:59 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19498->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:00 DEBUG : pacer: low level retry 8/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:01 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19500->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:02 DEBUG : pacer: low level retry 9/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:03 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:19502->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:04 DEBUG : pacer: low level retry 10/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:04 Failed to create file system for "sftp-helpi@URUHA:/mnt/V": NewFs: couldn't initialise SFTP: error receiving version packet from server: packet too long

asdffdsa · June 16, 2024, 8:30pm

welcome to the forum,

so the sftp server is running on a windows machine?

what other sftp client tools have you tested?

better to test using a simple command, rclone lsd
to keep the log small, use --retries=1

helpimnotdrowning · June 16, 2024, 8:50pm

The server runs Debian and I have Powershell 7 set as the default shell.

I also use WinSCP to connect to the server. I had a similar error earlier today with it, but that was because I had some text printing out on the non-interactive session. I removed the echo from my profile and was able to connect.

--retries=1 had no effect, but here's the log (retries were snipped):

2024/06/16 **:**:46 DEBUG : rclone: Version "v1.67.0" starting with parameters ["C:\\Users\\helpi\\AppData\\Local\\Microsoft\\WinGet\\Links\\rclone.exe" "lsd" "sftp-helpi@URUHA:/mnt/V" "--retries=1" "-vv"]
2024/06/16 **:**:46 DEBUG : Creating backend with remote "sftp-helpi@URUHA:/mnt/V"
2024/06/16 **:**:46 DEBUG : Using config file from "C:\\Users\\helpi\\AppData\\Roaming\\rclone\\rclone.conf"
2024/06/16 **:**:46 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:57050->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:48 DEBUG : pacer: low level retry 1/10 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:48 DEBUG : pacer: Rate limited, increasing sleep to 200ms
...
2024/06/16 **:**:01 Failed to create file system for "sftp-helpi@URUHA:/mnt/V": NewFs: couldn't initialise SFTP: error receiving version packet from server: packet too long

asdffdsa · June 16, 2024, 9:00pm

at a test, try shell_type = unix

asdffdsa · June 16, 2024, 9:02pm

--low-level-retries=1

helpimnotdrowning · June 16, 2024, 9:08pm

I should also note that this was working perfectly fine yesterday/two days ago: no updates on the server side (packages updated today after bug encounter, did not help), but there was an overnight (yesterday I think? poor memory lol) update on my machine to Windows 11's Insider Dev build 10.0.26120.961 . The release notes don't hint at anything in particular ("a small set of general improvements and fixes that improve the overall experience").

Log with updated command and shell_type = unix (no change):

2024/06/16 **:**:55 DEBUG : rclone: Version "v1.67.0" starting with parameters ["C:\\Users\\helpi\\AppData\\Local\\Microsoft\\WinGet\\Links\\rclone.exe" "lsd" "sftp-helpi@URUHA:/mnt/V" "--low-level-retries=1" "-vv"]
2024/06/16 **:**:55 DEBUG : Creating backend with remote "sftp-helpi@URUHA:/mnt/V"
2024/06/16 **:**:55 DEBUG : Using config file from "C:\\Users\\helpi\\AppData\\Roaming\\rclone\\rclone.conf"
2024/06/16 **:**:55 DEBUG : sftp://helpimnotdrowning@URUHA.***:22//mnt/V: New connection 192.168.1.64:40394->192.168.1.243:22 to "SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2"
2024/06/16 **:**:59 DEBUG : pacer: low level retry 1/1 (error couldn't initialise SFTP: error receiving version packet from server: packet too long)
2024/06/16 **:**:59 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2024/06/16 **:**:59 Failed to create file system for "sftp-helpi@URUHA:/mnt/V": NewFs: couldn't initialise SFTP: error receiving version packet from server: packet too long

(accidentally deleted last post)

asdffdsa · June 16, 2024, 9:29pm

rclone v1.67.0
- os/version: Microsoft Windows 11 Pro 23H2 (64 bit)
- os/kernel: 10.0.22631.3593 (x86_64)
- os/type: windows
- os/arch: amd64
- go/version: go1.22.4
- go/linking: static
- go/tags: cmount

[hetzner_sftp_powershell_tailscale]
type = sftp
host = 100.115.202.129
port = 22
user = user01
key_file = c:/data/c/combined/hetzner/keys/id_ed25519
shell_type = powershell
md5sum_command = md5sum
sha1sum_command = sha1sum

rclone copy d:\files\file.ext hetzner_sftp_powershell_tailscale:zork -vv 
DEBUG : Setting --config "C:\\data\\rclone\\rclone.conf" from environment variable RCLONE_CONFIG="C:\\data\\rclone\\rclone.conf"
DEBUG : rclone: Version "v1.67.0" starting with parameters ["d:\\data\\rclone\\exe\\windows\\rclone-v1.67.0-windows-amd64\\rclone.exe" "copy" "d:\\files\\file.ext" "hetzner_sftp_powershell_tailscale:zork" "-vv"]
DEBUG : Creating backend with remote "d:\\files\\file.ext"
DEBUG : Using config file from "C:\\data\\rclone\\rclone.conf"
DEBUG : fs cache: adding new entry for parent of "d:\\files\\file.ext", "//?/d:/files"
DEBUG : Creating backend with remote "hetzner_sftp_powershell_tailscale:zork"
DEBUG : sftp://user01@100.115.202.129:22/zork: New connection 100.109.123.23:15733->100.115.202.129:22 to "SSH-2.0-OpenSSH_8.9p1 Ubuntu-3ubuntu0.7"
DEBUG : sftp://user01@100.115.202.129:22/zork: Shell type "powershell" from config
DEBUG : sftp://user01@100.115.202.129:22/zork: Relative path resolved to "/home/user01/zork"
DEBUG : sftp://user01@100.115.202.129:22/zork: Using root directory "/home/user01/zork"
DEBUG : file.ext: Need to transfer - File not found at Destination
DEBUG : sftp://user01@100.115.202.129:22/zork: Shell path "/home/user01/zork/file.ext.lamugus3.partial"
DEBUG : sftp://user01@100.115.202.129:22/zork: Running remote command: md5sum '/home/user01/zork/file.ext.lamugus3.partial'
DEBUG : sftp://user01@100.115.202.129:22/zork: Remote command result: 9afcb2d16863f2df14342a4143c7e45d  /home/user01/zork/file.ext.lamugus3.partial
DEBUG : file.ext.lamugus3.partial: Parsed hash: 9afcb2d16863f2df14342a4143c7e45d
DEBUG : file.ext: md5 = 9afcb2d16863f2df14342a4143c7e45d OK
DEBUG : file.ext.lamugus3.partial: renamed to: file.ext
INFO  : file.ext: Copied (new)

ncw · June 17, 2024, 10:45am

I'm not sure what is causing this problem but I discovered the error is an SFTP error rather than an SSH error

github.com

pkg/sftp/blob/c8fe1f69640c3d92b05e1d7f0072addd6ece3ed2/client.go#L236


      
          		}
          	}
          
          	if err := sftp.sendInit(); err != nil {
          		wr.Close()
          		return nil, fmt.Errorf("error sending init packet to server: %w", err)
          	}
          
          	if err := sftp.recvVersion(); err != nil {
          		wr.Close()
          		return nil, fmt.Errorf("error receiving version packet from server: %w", err)
          	}
          
          	sftp.clientConn.wg.Add(1)
          	go func() {
          		defer sftp.clientConn.wg.Done()
          
          		if err := sftp.clientConn.recv(); err != nil {
          			sftp.clientConn.broadcastErr(err)
          		}
          	}()

So it might be worth investigating whether the SFTP server changed somehow.

system · July 17, 2024, 10:45am

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.