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

Consistent failures with recent rclone versions (1.64.2 at least) #304

Closed
nfebe opened this issue Nov 6, 2023 · 11 comments
Closed

Consistent failures with recent rclone versions (1.64.2 at least) #304

nfebe opened this issue Nov 6, 2023 · 11 comments

Comments

@nfebe
Copy link
Contributor

nfebe commented Nov 6, 2023 •
edited
Loading

Expected Behavior

In version 1.64.2, rclone should be able to create new directories in the remote location if they don't already exist.

Actual Behavior

rclone encounters an error when trying to create new directories. This issue does not occur in version 1.61.1. (and maybe up to 1.64.1/1.63.* but not tested yet)

Sample command rclone copy -v -P --create-empty-src-dirs ~/permanent-rclone-qa/test-tree/misc/variety/files "dev:/archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistenFolder"

Logs

2023/11/06 12:24:19 DEBUG : rclone: Version "v1.64.2" starting with parameters ["/usr/bin/rclone" "copy" "-vv" "--size-only" "--sftp-set-modtime=false" "--inplace" "/home/ubuntu/permanent-rclone-qa/test-tree/misc/variety/files" "dev:/archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder"]
2023/11/06 12:24:19 DEBUG : Creating backend with remote "/home/ubuntu/permanent-rclone-qa/test-tree/misc/variety/files"
2023/11/06 12:24:19 DEBUG : Using config file from "/home/ubuntu/.config/rclone/rclone.conf"
2023/11/06 12:24:19 DEBUG : Creating backend with remote "dev:/archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder"
2023/11/06 12:24:19 DEBUG : dev: detected overridden config - adding "{lDJqG}" suffix to name
2023/11/06 12:24:20 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Keyboard interactive auth requested
2023/11/06 12:24:20 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: New connection 10.0.1.109:35570->44.236.244.153:22 to "SSH-2.0-ssh2js1.14.0"
2023/11/06 12:24:20 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Shell type "unix" from config
2023/11/06 12:24:46 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Using root directory "/archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder"
2023/11/06 12:24:46 DEBUG : fs cache: renaming cache item "dev:/archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder" to be canonical "dev{lDJqG}:/archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder"
2023/11/06 12:24:59 ERROR : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: error reading destination root directory: error listing "": sftp: "An error occurred when attempting to load this directory from Permanent.org." (SSH_FX_FAILURE)
2023/11/06 12:24:59 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Waiting for checks to finish
2023/11/06 12:24:59 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Waiting for transfers to finish
2023/11/06 12:24:59 ERROR : Attempt 1/3 failed with 1 errors and: error listing "": sftp: "An error occurred when attempting to load this directory from Permanent.org." (SSH_FX_FAILURE)
2023/11/06 12:25:11 ERROR : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: error reading destination root directory: error listing "": sftp: "An error occurred when attempting to load this directory from Permanent.org." (SSH_FX_FAILURE)
2023/11/06 12:25:11 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Waiting for checks to finish
2023/11/06 12:25:11 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Waiting for transfers to finish
2023/11/06 12:25:11 ERROR : Attempt 2/3 failed with 1 errors and: error listing "": sftp: "An error occurred when attempting to load this directory from Permanent.org." (SSH_FX_FAILURE)
2023/11/06 12:25:24 ERROR : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: error reading destination root directory: error listing "": sftp: "An error occurred when attempting to load this directory from Permanent.org." (SSH_FX_FAILURE)
2023/11/06 12:25:24 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Waiting for checks to finish
2023/11/06 12:25:24 DEBUG : sftp://[email protected]@sftp.dev.permanent.org:22//archives/rclone QA 1 (dev) (07av-0000)/My Files/NonExistentFolder: Waiting for transfers to finish
2023/11/06 12:25:24 ERROR : Attempt 3/3 failed with 1 errors and: error listing "": sftp: "An error occurred when attempting to load this directory from Permanent.org." (SSH_FX_FAILURE)

Version Information

  • Rclone version: 1.64.2 (Issue present)
  • Rclone version: 1.61.1 (Issue not present)
  • Operating System: [Insert OS Details]

Additional Context

Perhaps some new flags have been introduced and investigations have to be completed by looking at the change logs.

I suspect #221 is related and that #190 could is made more recurrent.
@nfebe nfebe mentioned this issue Nov 7, 2023
Merged
@kfogel
Copy link
Contributor

kfogel commented Nov 28, 2023

@fenn-cs The latest version of rclone is v1.65.0. Could you please test with that and see if the problem is still present?

@nfebe
Copy link
Contributor Author

nfebe commented Nov 28, 2023

Sure @kfogel

@nfebe
Copy link
Contributor Author

nfebe commented Nov 28, 2023

Issue Update: Rclone Version Compatibility (1.61.0 vs 1.65.0)

Overview:

I conducted tests by installing Rclone versions 1.61.0 and 1.65.0 on both a local machine and a quick EC2 instance. The objective was to compare download/upload performances for a test development archive.

Results Summary:

Unfortunately, both versions (1.61.0 and 1.65.0) failed to clone down or upload successfully. Below are the key observations for each version:

1.61.0:

  • Upload Error: Files were listed as queued, but uploads for the files that were read stayed at 0%.

  • Upload Error Details:

    [Error]: Put mkParentDir failed: mkdir "/archives/rclone QA 1 (dev) (07av-0000)/My Files" failed.

1.65.0:

  • Upload Error: Failed to list files for upload.
  • Upload Error Details:

[Error]: Error reading destination root directory: error listing "".

Common Observations:

  • Both versions failed to clone down successfully.
  • Error messages indicated issues with directory creation and listing on Permanent.org.

Conclusion:

1.61.0 exhibited some progress in the upload queue, so my suspicion is that 1.65.0 is still not working

Next Steps:

  • Investigate why, our known working version is failing now failing (Suspect a deployment issue)
  • Repeat the tests again

@kfogel
Copy link
Contributor

kfogel commented Nov 28, 2023

@fenn-cs Hunh. I agree -- probably a deployment issue, and not anything to do with rclone itself. At the top of this issue, we claim that 1.61.1 works, and it would be very surprising if 1.61.1 would work and yet 1.61.0 would not.

Were you testing against the usual dev server?

@nfebe
Copy link
Contributor Author

nfebe commented Nov 28, 2023 •
edited
Loading

@kfogel Yes I used the usual dev server and for the records the last set of load tests that worked on the automated ec2 machines where using 1.61.0....

So there is confirmation that the version I used today has worked in the past.

@kfogel
Copy link
Contributor

kfogel commented Nov 28, 2023

@fenn-cs Got it. Looks like this is a deployment issue of some kind. And we need a working dev server anyway, so fixing that comes first!

@nfebe
Copy link
Contributor Author

nfebe commented Dec 1, 2023 •
edited
Loading

Update on working rlcone versions

Version Operation Status Comments
1.60.0 Download OK -
1.60.0 Upload OK Uploaded a folder containing 10, 1KB files, each file appear 3 times on Permanent
1.61.1 Download OK -
1.61.1 Upload OK Uploaded a folder containing 10, 1KB files, each file appear 3 times on Permanent
1.62.1 Download OK -
1.63.0 Download OK -
1.63.0 Upload OK Uploaded a folder containing 10, 1KB files, each file appear 3 times on Permanent
1.63.1 Download OK -
1.63.1 Upload ERROR First version after last working version, this is equally where the --inplace flag was introduced
1.64.1 Download OK -
1.64.1 Upload ERROR -
1.64.1 Download OK -
1.64.2 Upload ERROR -
1.65.0 Download OK -
1.65.0 Upload ERROR -

Additional notes

  • Each of the files appearing 3 times is new and may be due to the recent cache updates but not sure, what yet.
3 copies 1.61.1 3 copies 1.62.1 3 copies 1.63.0
Screenshot from 2023-12-01 03-19-00 Screenshot from 2023-12-01 03-19-19 Screenshot from 2023-12-01 03-19-19

Summarized logs (from terminal)

Even when uploads worked, errors like the ones below where reported for all version (probably connected with the upload repetitions still)

2023-12-01 03:03:57 ERROR : dkibiueutq: Failed to copy: Update Close failed: sftp: "An error occurred when attempting to register this file on Permanent.org." (SSH_FX_FAILURE)
2023-12-01 03:03:57 ERROR : ayrlkcknhb: Failed to copy: Update Close failed: sftp: "An error occurred when attempting to register this file on Permanent.org." (SSH_FX_FAILURE)
2023-12-01 03:03:58 ERROR : bzhipouhur: Failed to copy: Update Close failed: sftp: "An error occurred when attempting to register this file on Permanent.org." (SSH_FX_FAILURE)

@kfogel
Copy link
Contributor

kfogel commented Dec 1, 2023

Note: @fenn-cs told me that all the results above were obtained with rclone running against a local instance of the service.

/CC @slifty

@nfebe
Copy link
Contributor Author

nfebe commented Dec 1, 2023

Note: @fenn-cs told me that all the #304 (comment) were obtained with rclone running against a local instance of the service.

/CC @slifty

Yep, against this head of main - sftp-service as well as latest updates done on the back-end and related repositories. (So, all services where at the most recent)

@kfogel
Copy link
Contributor

kfogel commented Dec 6, 2023

FYI, @meisekimiu mentioned (in a Slack conversation just now) that she had rclone 1.63.x (most likely 1.63.1-1) working fine against dev SFTP last week, and pointed out that it was unlikely that there is a bug that affects rclone 1.62.x and 1.64.x and yet somehow not 1.63.x.

Other people have also reported having rclone (various versions) working against dev.

So I'm going to try to reproduce this bug with the latest development version of rclone, built from these instructions. Upstream dev source is currently 1.66-dev, but was recently 1.65. If the latest upstream rclone works against Permanent's dev servers, and I can't reproduce the bug shown here, then I think we can close this ticket.

/CC @fenn-cs @slifty @cecilia-donnelly

@kfogel
Copy link
Contributor

kfogel commented Dec 7, 2023

After further investigation and discussion, we've decided to close this because we can't reproduce it reliably. Specifically, I was able to download and upload successfully using rclone v1.66-DEV (i.e., unreleased rclone built from upstream source, commit 1ebbc74f1d62). I've attached an annotated transcript here that shows this.

@fenn-cs has updated PermanentOrg/sftp-qa-iac#6 accordingly. He also notes:

The only other thought, I have is if this can be a platform specific thing, because the once working automated scripts now fail with these recent versions on MY local and AWS (ubuntu machines that works when no other change is done except installing an earlier version).

Following the update of #6 I would just ssh into one ubuntu machine to double confirm here by running rclone for like 2 minute to see...

I too would be interested in the results from that.

Here is the transcript of my sessions:

2023-12-07-rclone-1.66-DEV-sessions-with-permanent-prod-transcript.txt

@kfogel kfogel closed this as completed Dec 7, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@kfogel @nfebe