@ncw , we can reliably reproduce the issue(s). The main problem (Problem B below) is that "rclone check" when run in a docker container is not exiting in a certain scenario (Problem A below) and keeps running until the docker container is killed.
Problem A: When performing "rclone check" on an backend that is busy updating the version of one of the objects/files, rclone returns an error when the command is run locally (and doesn't return when run in a container):
stderr: b'2022/03/29 14:32:02 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "check" "-vv" "--combined" "-" "--one-way" "--files-from" "/var/spool/caringo/cloudgateway/features/41123165DFF94056/objectFile" "hybridclouds3clonelocalswarm:sourcebucket" "hybridclouds3cloneremote:destbucket"]
...
2022/03/29 14:32:02 DEBUG : fs cache: renaming cache item "hybridclouds3cloneremote:destbucket" to be canonical "hybridclouds3cloneremote{EvD5b}:destbucket"
2022/03/29 14:32:02 INFO : Using md5 for hash comparisons
2022/03/29 14:32:02 DEBUG : S3 bucket destbucket: Waiting for checks to finish
2022/03/29 14:32:55 ERROR : S3 bucket sourcebucket: error reading source root directory: RequestError: send request failed
caused by: Get "http://hctest-20220329-192949-271-tenant0000000500x0000000000-domain1:8082/sourcebucket?delimiter=%2F&max-keys=1000&prefix=": dial tcp: lookup hctest-20220329-192949-271-tenant0000000500x0000000000-domain1 on 172.30.0.20:53: no such host
2022/03/29 14:32:55 NOTICE: S3 bucket destbucket: 1 differences found
2022/03/29 14:32:55 NOTICE: S3 bucket destbucket: 1 errors while checking
2022/03/29 14:32:55 INFO :
Transferred: \t 0 B / 0 B, -, 0 B/s, ETA -
Errors: 1 (retrying may help)
Elapsed time: 53.0s
This is not the best experience, but I think I can prevent this scenario with one or more of the following 1) Add the "--no-traverse" option, since it is not an object from the "--files-from" specification 2) Wait to run check until after the object is finished writing to the backend 3) Add "--retries" or "--low-level-retries" with "--low-level-retries"
Do "--retries" and "--low-level-retries" with the "check" command?
Problem B: When the "rclone check" is run in a container, and experiences Problem A, the process never exits and runs indefinitely. This causes a process to hang when it is waiting on the container to be released.
The process can be seen when running the command
ps -ef | grep docker:
Let's try to fix the not returning in a container problem:
Can you get it to lock up, and when it has done so, enter the container and issue kill -QUIT to kill rclone. This will print a backtrace to stderr which you'll need to collect and post here. This will show exactly what rclone is doing.
Cloud storage systems are inherently not 100% reliable - there are too many moving parts, eventual consistency, internet etc.
This is why rclone has --retries and --low-level-retries.
--low-level-retries work, and unless you turned them off, you'll be getting 10 of them.
--retries do not work with rclone check as if there is a check problem usually retrying it won't make it go away.
However you could retry in shell script if you wanted.
Can you also try this with rclone 1.58 which may behave differently when the error is reported.
Sorry, I posted before I fully understood the scenario. The rclone check process actually did complete and return and the container finished. What is remaining and not returning is the docker run process that originally created the container to run the rclone command. I killed the docker run process and now am able to see the returncode, stdout, and stderr from the rclone check. I think the problem might be with the returncode, which is "-9" in this case. (Sorry, it is not actually hitting the "no such host" scenario in this case after all.)
What is returncode "-9"?
Here are the values from the rclone process (command, returncode, stdout, and stderr) with some of the boring parts removed:
I'm familiar with positive 9. I've gotten that when I run copy with "--error-on-no-transfer". However, this is negative 9. I'm running check without the "--error-on-no-transfer" flag.
More info: The check command did not complete before exiting with error code -9. When I look through the check result for all 500 objects, I see that I only got the result for half to three quarters of them. I also expect stderr (with -vv verbosity) to end with "go routines active\n" and it ended with "so0000000365: md5 = d41d8cd98f00b204e9800998ecf84" instead. Also note the md5 was cut off there; would expect three more characters: d41d8cd98f00b204e9800998ecf8427e.
The -9 is printed from my python process. We think the -9 is unrelated to the rclone exit code, it's just that I was using SIGKILL kill -9 on the docker run process and python returns -{SIGNAL NUMBER} when it's terminated by a signal.
Sorry, this looks to be an issue with Docker containers, or containers usage, and not rclone. I got the issue to happen with a second copy command in place of the check.
FYI: Root caused! The latest reproducible version of this issue was a Python user error and not a Docker or rclone error. I was letting the stdout/stderr pipes fill up and the Python subprocess.Popen was waiting for them to clear up before continuing, but I had no clearing mechanism (like communicate()). The reason it happened on my call to "rclone check" and not "rclone copy" was because my call to copy was piping stdout/stderr to a file with option "--log-file".
It's still a mystery why we saw this intermittently on our old environment which was running subprocess.run (which does periodically clear std/err buffers) instead of subprocess.Popen, but I know what to look for next time I see this issue. Rclone check has more rapid output to stdout and stderr than other commands, so it could push the boundaries of some environments and the calling mechanism should account for that.
