Microsoft FTPS : rclone lsd remote: doesn't list files

What is the problem you are having with rclone?

The connection to the remote Microsoft FTP(S) server succeeds, but quit before listing files (see dump below). Similar problem when trying to copy file from remote to local directory.

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

$ rclone version
rclone v1.64.2
- os/version: debian 12.2 (64 bit)
- os/kernel: 6.1.0-13-amd64 (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.21.3
- go/linking: static
- go/tags: none

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

Microsoft FTP server

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

rclone lsd msLive: -vv --dump bodies --log-file=/tmp/rcloneDump

Please run 'rclone config redacted' and share the full output. If you get command not found, please make sure to update rclone.

[msLive]
type = ftp
host = XXX
user = XXX
explicit_tls = true
pass = XXX
tls = false
no_check_certificate = true
port = 21
force_list_hidden = true

A log from the command that you were trying to run with the -vv flag

2023/11/16 18:46:12 DEBUG : rclone: Version "v1.64.2" starting with parameters ["rclone" "lsd" "msLive:" "-vv" "--dump" "bodies" "--log-file=/tmp/rcloneDump"]
2023/11/16 18:46:12 DEBUG : Creating backend with remote "msLive:"
2023/11/16 18:46:12 DEBUG : Using config file from "/home/jeanluc/.config/rclone/rclone.conf"
2023/11/16 18:46:12 DEBUG : ftp://***SERVERNAME_REDACTED***:21: Connecting to FTP server
2023/11/16 18:46:12 DEBUG : ftp://***SERVERNAME_REDACTED**:21: dial("tcp","***SERVERNAME_REDACTED***:21")
2023/11/16 18:46:12 DEBUG : ftp://***SERVERNAME_REDACTED***:21: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/11/16 18:46:12 DEBUG : FTP Rx: "220 Microsoft FTP Service"
2023/11/16 18:46:12 DEBUG : FTP Tx: "AUTH TLS"
2023/11/16 18:46:12 DEBUG : FTP Rx: "234 AUTH command ok. Expecting TLS Negotiation."
2023/11/16 18:46:12 DEBUG : FTP Tx: "USER ***USERNAME_REDACTED***"
2023/11/16 18:46:12 DEBUG : FTP Rx: "331 Password required"
2023/11/16 18:46:12 DEBUG : FTP Tx: PASS *****
2023/11/16 18:46:12 DEBUG : FTP Rx: "230-Directory has 471,723,368,448 bytes of disk space available."
2023/11/16 18:46:12 DEBUG : FTP Rx: "230 User logged in."
2023/11/16 18:46:12 DEBUG : FTP Tx: "FEAT"
2023/11/16 18:46:12 DEBUG : FTP Rx: "211-Extended features supported:"
2023/11/16 18:46:12 DEBUG : FTP Rx: " LANG EN*"
2023/11/16 18:46:12 DEBUG : FTP Rx: " UTF8"
2023/11/16 18:46:12 DEBUG : FTP Rx: " AUTH TLS;TLS-C;SSL;TLS-P;"
2023/11/16 18:46:12 DEBUG : FTP Rx: " PBSZ"
2023/11/16 18:46:12 DEBUG : FTP Rx: " PROT C;P;"
2023/11/16 18:46:12 DEBUG : FTP Rx: " CCC"
2023/11/16 18:46:12 DEBUG : FTP Rx: " HOST"
2023/11/16 18:46:12 DEBUG : FTP Rx: " SIZE"
2023/11/16 18:46:12 DEBUG : FTP Rx: " MDTM"
2023/11/16 18:46:12 DEBUG : FTP Rx: " REST STREAM"
2023/11/16 18:46:12 DEBUG : FTP Rx: "211 END"
2023/11/16 18:46:12 DEBUG : FTP Tx: "TYPE I"
2023/11/16 18:46:12 DEBUG : FTP Rx: "200 Type set to I."
2023/11/16 18:46:12 DEBUG : FTP Tx: "OPTS UTF8 ON"
2023/11/16 18:46:12 DEBUG : FTP Rx: "200 OPTS UTF8 command successful - UTF8 encoding now ON."
2023/11/16 18:46:12 DEBUG : FTP Tx: "PBSZ 0"
2023/11/16 18:46:12 DEBUG : FTP Rx: "200 PBSZ command successful."
2023/11/16 18:46:12 DEBUG : FTP Tx: "PROT P"
2023/11/16 18:46:12 DEBUG : FTP Rx: "200 PROT command successful."
2023/11/16 18:46:12 DEBUG : FTP Tx: "EPSV"
2023/11/16 18:46:12 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||5119|)"
2023/11/16 18:46:12 DEBUG : ftp://***SERVERNAME_REDACTED***:21: dial("tcp","REDACTED:5119")
2023/11/16 18:46:12 DEBUG : ftp://***SERVERNAME_REDACTED***:21: > dial: conn=*tls.Conn, err=<nil>
2023/11/16 18:46:12 DEBUG : FTP Tx: "LIST -a"
2023/11/16 18:46:12 DEBUG : FTP Rx: "125 Data connection already open; Transfer starting."
2023/11/16 18:46:12 DEBUG : FTP Rx: "11-09-2023  02:48PM                 1177 repres.csv"
2023/11/16 18:46:12 DEBUG : FTP Rx: "11-16-2023  01:41PM                   12 testJL"
2023/11/16 18:46:12 DEBUG : FTP Rx: "11-09-2023  02:48PM                   72 vente.csv"
2023/11/16 18:46:12 DEBUG : FTP Rx: "226-Directory has 471,723,368,448 bytes of disk space available."
2023/11/16 18:46:12 DEBUG : FTP Rx: "226 Transfer complete."
2023/11/16 18:46:12 DEBUG : 4 go routines active
2023/11/16 18:46:12 DEBUG : ftp://***SERVERNAME_REDACTED***:21: closing 1 unused connections
2023/11/16 18:46:12 DEBUG : FTP Tx: "QUIT"

Attempt to copy from remote to local directory (ERROR : directory not found)

Command

rclone copy msLive:testJL /tmp -vv --dump bodies --log-file=/tmp/rcloneDumpCopy

Log (extract)

2023/11/16 19:11:26 DEBUG : rclone: Version "v1.64.2" starting with parameters ["rclone" "copy" "msLive:testJL" "/tmp" "-vv" "--dump" "bodies" "--log-file=/tmp/rcloneDumpCopy"]
2023/11/16 19:11:26 DEBUG : Creating backend with remote "msLive:testJL"
2023/11/16 19:11:26 DEBUG : Using config file from "/home/jeanluc/.config/rclone/rclone.conf"
2023/11/16 19:11:26 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: Connecting to FTP server
2023/11/16 19:11:26 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: dial("tcp","***SERVERNAME_REDACTED***")
2023/11/16 19:11:26 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: > dial: conn=*fshttp.timeoutConn, err=<nil>
[... same as above log]
2023/11/16 19:11:27 DEBUG : FTP Tx: "LIST -a ."
2023/11/16 19:11:27 DEBUG : FTP Rx: "125 Data connection already open; Transfer starting."
2023/11/16 19:11:27 DEBUG : FTP Rx: "11-09-2023  02:48PM                 1177 repres.csv"
2023/11/16 19:11:27 DEBUG : FTP Rx: "11-16-2023  01:41PM                   12 testJL"
2023/11/16 19:11:27 DEBUG : FTP Rx: "11-09-2023  02:48PM                   72 vente.csv"
2023/11/16 19:11:27 DEBUG : FTP Rx: "226-Directory has 471,723,360,256 bytes of disk space available."
2023/11/16 19:11:27 DEBUG : FTP Rx: "226 Transfer complete."
2023/11/16 19:11:27 ERROR : ftp://***SERVERNAME_REDACTED***/testJL: error reading source root directory: directory not found
2023/11/16 19:11:27 DEBUG : Local file system at /tmp: Waiting for checks to finish
2023/11/16 19:11:27 DEBUG : Local file system at /tmp: Waiting for transfers to finish
2023/11/16 19:11:27 ERROR : Attempt 2/3 failed with 1 errors and: directory not found
2023/11/16 19:11:27 DEBUG : FTP Tx: "EPSV"
2023/11/16 19:11:27 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||5070|)"
2023/11/16 19:11:27 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: dial("tcp","REDACTED:5070")
2023/11/16 19:11:27 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: > dial: conn=*tls.Conn, err=<nil>
2023/11/16 19:11:27 DEBUG : FTP Tx: "LIST -a testJL"
2023/11/16 19:11:27 DEBUG : FTP Rx: "125 Data connection already open; Transfer starting."
2023/11/16 19:11:27 DEBUG : FTP Rx: "11-16-2023  01:41PM                   12 testJL"
2023/11/16 19:11:27 DEBUG : FTP Rx: "226-Directory has ? bytes of disk space available."
2023/11/16 19:11:27 DEBUG : FTP Rx: "226 Transfer complete."
2023/11/16 19:11:27 DEBUG : FTP Tx: "EPSV"
2023/11/16 19:11:27 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||5030|)"
2023/11/16 19:11:27 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: dial("tcp","REDACTED:5030")
2023/11/16 19:11:27 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: > dial: conn=*tls.Conn, err=<nil>
2023/11/16 19:11:27 DEBUG : FTP Tx: "LIST -a ."
2023/11/16 19:11:27 DEBUG : FTP Rx: "125 Data connection already open; Transfer starting."
2023/11/16 19:11:27 DEBUG : FTP Rx: "11-09-2023  02:48PM                 1177 repres.csv"
2023/11/16 19:11:27 DEBUG : FTP Rx: "11-16-2023  01:41PM                   12 testJL"
2023/11/16 19:11:27 DEBUG : FTP Rx: "11-09-2023  02:48PM                   72 vente.csv"
2023/11/16 19:11:27 DEBUG : FTP Rx: "226-Directory has 471,723,360,256 bytes of disk space available."
2023/11/16 19:11:27 DEBUG : FTP Rx: "226 Transfer complete."
2023/11/16 19:11:27 ERROR : ftp://***SERVERNAME_REDACTED***/testJL: error reading source root directory: directory not found
2023/11/16 19:11:27 DEBUG : Local file system at /tmp: Waiting for checks to finish
2023/11/16 19:11:27 DEBUG : Local file system at /tmp: Waiting for transfers to finish
2023/11/16 19:11:27 ERROR : Attempt 3/3 failed with 1 errors and: directory not found
2023/11/16 19:11:27 INFO  : 
Transferred:   	          0 B / 0 B, -, 0 B/s, ETA -
Errors:                 1 (retrying may help)
Elapsed time:         0.8s

2023/11/16 19:11:27 DEBUG : 5 go routines active
2023/11/16 19:11:27 DEBUG : ftp://***SERVERNAME_REDACTED***/testJL: closing 1 unused connections
2023/11/16 19:11:27 DEBUG : FTP Tx: "QUIT"
2023/11/16 19:11:27 Failed to copy: directory not found

welcome to the forum,

tl;dr - try rclone ls msLive:


yes, that is correct behavior.

  • rclone lsd -> list directories
  • rclone ls -> list files

and based on the FTP Tx: "LIST -a", no directories in that list.
so nothing for rclone lsd to output

i did a quick test using msftp server, downloads to local seem to work as expected.

rclone copy msftp:zork .\tmp  -vv 
DEBUG : Setting --config "C:\\data\\rclone\\rclone.conf" from environment variable RCLONE_CONFIG="C:\\data\\rclone\\rclone.conf"
DEBUG : rclone: Version "v1.64.2" starting with parameters ["c:\\data\\rclone\\rclone.exe" "copy" "msftp:zork" ".\\tmp" "-vv"]
DEBUG : Creating backend with remote "msftp:zork"
DEBUG : Using config file from "C:\\data\\rclone\\rclone.conf"
DEBUG : ftp://127.0.0.1:21/zork: Connecting to FTP server
DEBUG : ftp://127.0.0.1:21/zork: dial("tcp","127.0.0.1:21")
DEBUG : ftp://127.0.0.1:21/zork: > dial: conn=*fshttp.timeoutConn, err=<nil>
DEBUG : ftp://127.0.0.1:21/zork: dial("tcp","127.0.0.1:59188")
DEBUG : ftp://127.0.0.1:21/zork: > dial: conn=*tls.Conn, err=<nil>
DEBUG : Creating backend with remote ".\\tmp"
DEBUG : fs cache: renaming cache item ".\\tmp" to be canonical "//?/d:/data/rclone/other/newtest/tmp"
DEBUG : ftp://127.0.0.1:21/zork: dial("tcp","127.0.0.1:59190")
DEBUG : ftp://127.0.0.1:21/zork: > dial: conn=*tls.Conn, err=<nil>
DEBUG : file.ext: Need to transfer - File not found at Destination
DEBUG : Local file system at //?/d:/data/rclone/other/newtest/tmp: Waiting for checks to finish
DEBUG : Local file system at //?/d:/data/rclone/other/newtest/tmp: Waiting for transfers to finish
DEBUG : ftp://127.0.0.1:21/zork: dial("tcp","127.0.0.1:59192")
DEBUG : ftp://127.0.0.1:21/zork: > dial: conn=*tls.Conn, err=<nil>
DEBUG : ftp://127.0.0.1:21/zork: Connecting to FTP server
DEBUG : ftp://127.0.0.1:21/zork: dial("tcp","127.0.0.1:21")
DEBUG : ftp://127.0.0.1:21/zork: > dial: conn=*fshttp.timeoutConn, err=<nil>
DEBUG : file.ext.royosez2.partial: renamed to: file.ext
INFO  : file.ext: Copied (new)

rclone tree msftp:zork 
/
└── file.ext

0 directories, 1 files

rclone lsd msftp:zork 

rclone ls msftp:zork 
       18 file.ext

Thanks for your input but I have also tried rclone ls remote: same problem : no output despite the fact that in the log the FTP Tx LIST -a returns something in the log but not in the shell. It looks like rclone closes the connection before displaying anything.

2023/11/16 20:36:49 DEBUG : rclone: Version "v1.64.2" starting with parameters ["rclone" "ls" "msLive:" "-vv" "--dump" "bodies"]
[...]
2023/11/16 20:36:49 DEBUG : ftp://***SERVERNAME_REDACTED***: dial("tcp","REDACTED:5187")
2023/11/16 20:36:49 DEBUG : ftp://***SERVERNAME_REDACTED***: > dial: conn=*tls.Conn, err=<nil>
2023/11/16 20:36:49 DEBUG : FTP Tx: "LIST -a"
2023/11/16 20:36:49 DEBUG : FTP Rx: "125 Data connection already open; Transfer starting."
2023/11/16 20:36:49 DEBUG : FTP Rx: "11-09-2023  02:48PM                 1177 repres.csv"
2023/11/16 20:36:49 DEBUG : FTP Rx: "11-16-2023  01:41PM                   12 testJL"
2023/11/16 20:36:49 DEBUG : FTP Rx: "11-09-2023  02:48PM                   72 vente.csv"
2023/11/16 20:36:49 DEBUG : FTP Rx: "226-Directory has 471,722,606,592 bytes of disk space available."
2023/11/16 20:36:49 DEBUG : FTP Rx: "226 Transfer complete."
2023/11/16 20:36:49 DEBUG : 4 go routines active
2023/11/16 20:36:49 DEBUG : ftp://***SERVERNAME_REDACTED***: closing 1 unused connections
2023/11/16 20:36:49 DEBUG : FTP Tx: "QUIT"

Do you know exactly what type of server this is?

It doesn't support MLST which means rclone is using the old and not very standardized LIST command. I suspect that rclone just doesn't understand these lines so is ignoring them:

They look closest to these lines

But the year is 4 digits not 2.

So I suspect the upstream FTP client needs a patch...

It would be really helpful to know exactly which FTP server this is

I have no control on the server but I can ask.

the ftp server is Microsoft FTP(S) server.
microsoft os has offered a built-in www+ftps server for decades.
DEBUG : FTP Rx: "220 Microsoft FTP Service"

i think you are correct about that.

my ms-ftp server is using two digits, not four.
my rclone command ouput the ilst of files.

DEBUG : FTP Tx: "LIST -a"
DEBUG : FTP Rx: "125 Data connection already open; Transfer starting."
DEBUG : FTP Rx: "11-16-23  03:11PM                   18 file.ext"
DEBUG : FTP Rx: "226 Transfer complete."
DEBUG : FTP Tx: "MDTM file.ext"
DEBUG : FTP Rx: "213 20231116201109"
       18 2023-11-16 15:11:09.000000000 file.ext

How do you run it? I can try it on my Windows VM.

Looks like the 4 digit years is a setting

Four-digit years Specifies the year format to use when displaying the last modified date for each file. If enabled, displays dates with four-digit years; otherwise, displays dates with two-digit years.

  1. run appwiz.cpl
  2. click Turn Windows features on or off
  3. make sure to install the IIS Management Console
    image

to run the console, from the start button,
image

then will need to create a ftp site
image

good idea, i was about to do the same ;wink

i will test that and let you know

edit: i just enabled four-digit, tested and now, i am getting same two issues as OP.

  • rclone ls has no output
  • rclone copy error out with directory not found

so i guess the workaround is to disable four-digit ouput in ms-ftp.

there is another setting.
now, i tested that rclone ls and rclone copy work, including four digit years.
UNIX - Displays files and folder using the UNIX format.

image

this time, the output from ms-ftp server is unix style, using four digit years and rclone seems to be ok with that.

2023/11/16 17:34:26 DEBUG : rclone: Version "v1.64.2" starting with parameters ["c:\\data\\rclone\\rclone.exe" "lsl" "msftp:zork" "--dump=bodies"]
2023/11/16 17:34:26 DEBUG : FTP Rx: "220 Microsoft FTP Service"
2023/11/16 17:34:26 DEBUG : FTP Tx: "LIST -a zork"
2023/11/16 17:34:26 DEBUG : FTP Rx: "125 Data connection already open; Transfer starting."
2023/11/16 17:34:26 DEBUG : FTP Rx: "-rwxrwxrwx   1 owner    group              18 Dec 31  1999 file.ext"
2023/11/16 17:34:26 DEBUG : FTP Rx: "226 Transfer complete."
2023/11/16 17:34:26 DEBUG : FTP Tx: "MDTM zork/file.ext"
2023/11/16 17:34:26 DEBUG : FTP Rx: "213 19991231173456"
       18 1999-12-31 12:34:56.000000000 file.ext
2023/11/16 17:34:26 DEBUG : 2 go routines active
2023/11/16 17:34:26 DEBUG : ftp://127.0.0.1:21/zork: closing 1 unused connections
2023/11/16 17:34:26 DEBUG : FTP Tx: "QUIT"

Nice :slight_smile: - thank you for testing.

@Jean-Luc_Lacroix can you get your server changed to use that setting?

"No, I am still waiting for a response from the company in charge of the FTP server, but I have very limited hope. Their response (translated): "For our part, we are also blocked because the restrictions are quite strong for our Datacenter"

I will contact them again on Monday. Is there anything to change in the rclone code to encompass this buggy setting, or is it embedded in the FTP library used by rclone?"

It is in the upstream library, yes.

It is probably a fairly easy patch to the upstream library

You'd need to add another time format here

It looks like the parser does support 4 digit years, but not with AM/PM times!

A new line like this will probably fix the problem

"2006-01-02  03:04PM",

I'd add some new test cases also here

Do you want to have a go at this?

1 Like

Yes, I can give it a go, but I need some directions. So far, I have cloned the rclone v1.65.0-DEV and also added the upstream FTP library with a go get -u github.com/jlaffaye/ftp in my go 1.19.8 environment.

I then modified the jlaffaye parse.go file as per your suggestions above.

When I want build rclone.go, I don't know how to link it to the modified FTP library sources that now resides in my local $GOPATH/src/github.com/jlaffaye/ftp`

Anything to change in the rclone `go.mod to link it to the local ftp library that I have modified ?

You are doing well so far!

This is the tricky part...

Edit the go.mod to have a line like this near the top

replace github.com/jlaffaye/ftp => /path/to/src/github.com/jlaffaye/ftp

That will tell go build to pick up the ftp module from the absolute path you provided. (You might be able to use relative paths &or env vars, but I always use absolute paths!).

That should build using the new ftp module you made.

1 Like

That fixed the issue, and the remote FTP directory is now listing correctly. I wasn't familiar with the replace directive in go.mod. Good to know!

Should I submit a pull request to the jlffaye/ftp repository for these new date format ?

Thanks, Nick, for all your hard work on rclone. It's an invaluable tool for me!

I would add your failing listings to the test cases I linked above then check them with go test. Then, yes, absolutely, make a pull request!

Great :smiley:

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