'Rclone rc --loopback operations/deletefile' produces strange result

What is the problem you are having with rclone?

rclone rc --loopback operations/deletefile fs=<my cloud provider>: remote=/x1/tarball/<myFileName> does not delete the file (when that file exists); also, it produces this text output: {} (sic!). The command returns true. (I am using Bash, on Linux.) See below for a thickening of the plot.

What is your rclone version (output from rclone version)

rclone v1.57.0
os/version: linuxmint 20.2 (64 bit)
os/kernel: 5.11.0-40-generic (x86_64)
os/type: linux
os/arch: amd64
go/version: go1.17.2
go/linking: static
go/tags: none

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

b2.

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

rclone rc --loopback operations/deletefile fs=<my cloud provider>: remote=/x1/tarball/<myFileName>

The rclone config contents with secrets removed.

[b2]
type = b2
account = [. .]
key = [. .]
hard_delete = true

[enc-b2]
type = crypt
remote = b2:x1-everything
filename_encryption = standard
password = [. .]
password2 = [. .]

A log from the command with the -vv flag

2021/11/28 23:57:13 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "-vv" "rc" "--loopback" "operations/deletefile" "fs=enc-b2:" "remote=/x1/tarball/ball.tar"]
2021/11/28 23:57:13 DEBUG : Creating backend with remote "enc-b2:"
2021/11/28 23:57:13 DEBUG : Using config file from "/home/nicholas/.config/rclone/rclone.conf"
2021/11/28 23:57:13 DEBUG : Creating backend with remote "b2:x1-everything"
2021/11/28 23:57:14 DEBUG : Couldn't decode error response: EOF
2021/11/28 23:57:14 DEBUG : 6 go routines active
2021/11/28 23:57:14 Failed to rc: loopback call failed: object not found

But: the output above is from a later time than the output - from the version of the command lacking the -vvflags - that I posted further above. I suspect the following. For a period - of very approximately ten minutes? - a deleted file enters a kind of netherworld, half way between being deleted and being extant. This may well be a b2 problem - but perhaps rclone could work around it.

It occurs to me that the real problem, at least for me, is not a strange result from a delete command - for, if an item is in a state of flux en route to deletion, then I need not delete it again. Rather, the problem is that, when item ${incomingBall_fullPath} is in flux, rclone lsf --format "ps" "${incomingBall_fullPath}" returns ball.tar;184320, i.e. suggests that the file is (fully) extant. Perhaps the solution is to query the items existence not with rclone lsf but with a `loopback' command.

Later addition

OK - the following seems to work, both to check the existence of an item and (for I wanted this to) to check its size. This solution is in Bash and requires various Linux utilities including 'jq'. jq was preinstalled on my distro (and has horrible syntax and bad documentation; I used the guide - such as it is - here).

#!/usr/bin/env bash
function ifExistsPrintSize
{
	local output
	if output=$(\
		rclone \
		rc --loopback operations/stat \
		fs="${rl_remote_prefix}"\
		remote="${incomingBall_fullPath}" \
		| jq '.[] | .Size' \
	)
	then
		# Return false if either the variable has no content or has the content 'null'.
		[[ -z ${output} || ${output} == null ]] \
			return 1
		[[ ${output} == null ]] \
			&& return 1
		# So, we've obtained a value. Now make it more readable.
		local -i incomingBall_size_bytes
		local incomingBall_size_leaf
		incomingBall_size_bytes="$(echo "${output}" | awk 'BEGIN { FS = ";" } ; {print $NF}' )"
		incomingBall_size_leaf="$(echo "${output}" | awk 'BEGIN { FS = ";" } ; {print $1}' )"
		if [[ -n ${incomingBall_size_leaf} ]] ; then
			local incomingBall_size_human
			incomingBall_size_human=$(\
				echo "${incomingBall_size_bytes}"\
				| numfmt --to iec --format "%8.1f" \
				| sed -e 's/^[[:space:]]*//' -e 's/[[:space:]]*$//'\
			)
			echo ".. Found ${incomingBall_size_leaf} (${incomingBall_size_human})."
			return 0
		fi
	fi
	return 1
}

I tried to replicate this on b2 with a small file but I couldn't.

I'm guessing that you are trying to delete a big file?

Cloud storage in general and b2 in specific are only guaranteed to be eventually consistent. This means that there may be times when directory listings don't agree with the actual files.

I suspect that is what you are seeing, that the backend is taking some time to delete the large file and it appears for a moment in the listings before disappearing.

10 minutes sounds like a long time for eventual consistency though - I'd expect a few seconds at most, so maybe it was something else.

Can you reproduce this problem at will? If so it might be worth reporting to backblaze.

1 Like

Thanks Nick.

I'm guessing that you are trying to delete a big file?

No. Normally the file is smaller than some 300KB. (I should have mentioned that before.)

Cloud storage in general and b2 in specific are only guaranteed to be eventually consistent.

Aha. Yet, it seems odd (perhaps because of my ignorance) that the new method I adopted for detecting the existence of a file, namely the 'loopback' one, seems always to be accurate.

Can you reproduce this problem at will? If so it might be worth reporting to backblaze.

I think I can. However, I seem to recall having trouble reporting technical problems to BackBlaze. If you have reasonable access to someone at BackBlaze, might you report the problem? I'd be willing to try to setup a reproduction algorithm for you.

If you could make a small replication, I can check it over to double check it isn't an rclone problem then pass it on to backblaze if necessary.

Thank you, Nick.

I have discovered that actually querying item existence with a loopback command is just as inaccurate (more or less, anyway) as via a non-loopback command. It was an error in my script - specifically, in path formatting - that made things seem otherwise.

But I am writing a script to check whether b2 is reporting items as deleted too slowly. In so doing, though, I continue to be hindered ('continue', because I think that I reported this before) by the formatting of some rclone documentation. This page says that one should use a path of the form 'remote:path'. But that is ambiguous - between (1) <the path to one's remote> and (2) remote:<the path to one's remote>.

I have put a script, which tests how fast file deletion works, here. Judging by the output of that script, things stand with b2 - at least at present - as follows.

All is well if one queries an item's existence with rclone lsf. Yet, things are a bit problematic if one uses --loopback operations/stat. For explanation, see the script and its results.

EDITED.

I had a go with your script...

As far as operations/stat goes it says this in the docs

item - an object as described in the lsjson command. Will be null if not found.

That possibly wasn't the best decision ever but that is what is documented!

The output of the script looked like this

At present the script is configured as follows.

file_block_count                                 3                                            
file_block_size_mb                               1                                            
path_local_dir                                   /home/ncw                                    
path_leafname                                    testFile                                     
path_remote_full                                 b2:/test-isos/testFile                       
queryExistenceViaJson                            true                                         
sleepSeconds_beforeDeletingRemoteFile            120                                          
sleepSeconds_beforeQueryingRemoteFil             120                                          

STARTING ..

Script <rclone-b2-test.sh>: ● Creating local file </home/ncw/testFile>, comprising random data ..
3+0 records in
3+0 records out
3145728 bytes (3.1 MB, 3.0 MiB) copied, 0.0523713 s, 60.1 MB/s

Script <rclone-b2-test.sh>: ● Pushing local file </home/ncw/testFile> to <b2:/test-isos/testFile>, using rclone . .
2021/12/01 11:39:06 INFO  : testFile: Copied (new)
2021/12/01 11:39:06 INFO  : 
Transferred:   	        3 MiB / 3 MiB, 100%, 0 B/s, ETA -
Transferred:            1 / 1, 100%
Elapsed time:         0.0s

Script <rclone-b2-test.sh>: ● Deleting local file </home/ncw/testFile> ..
Script <rclone-b2-test.sh>: Done.

Script <rclone-b2-test.sh>: ● About to delete the remote file <b2:/test-isos/testFile>, after a sleep of <120> seconds ..
Script <rclone-b2-test.sh>: Done.

Script <rclone-b2-test.sh>: ● About to query the existence of remote file <b2:/test-isos/testFile> - via a JSON query of its size - after a sleep of <120> seconds ..
Output is: {
	"item": null
}
outputJsonified is: null
Script <rclone-b2-test.sh>: ● The query command succeded, which ideally it should not if the file has been deleted.
Script <rclone-b2-test.sh>: ● However, the json returned by the query command was 'null'. So, let us say:
Script <rclone-b2-test.sh>: ● The remote reports that the file no longer exists. ✓

Which looks like it didn't detect a problem?

If I set query existence via JSON to false I get

This script (named 'rclone-b2-test.sh') determines whether deleted remote files register as deleted.

At present the script is configured as follows.

file_block_count                                 3                                            
file_block_size_mb                               1                                            
path_local_dir                                   /home/ncw                                    
path_leafname                                    testFile                                     
path_remote_full                                 b2:/test-isos/testFile                       
queryExistenceViaJson                            false                                        
sleepSeconds_beforeDeletingRemoteFile            120                                          
sleepSeconds_beforeQueryingRemoteFil             120                                          

STARTING ..

Script <rclone-b2-test.sh>: ● Creating local file </home/ncw/testFile>, comprising random data ..
3+0 records in
3+0 records out
3145728 bytes (3.1 MB, 3.0 MiB) copied, 0.0512333 s, 61.4 MB/s

Script <rclone-b2-test.sh>: ● Pushing local file </home/ncw/testFile> to <b2:/test-isos/testFile>, using rclone . .
2021/12/01 11:52:39 INFO  : testFile: Copied (replaced existing)
2021/12/01 11:52:39 INFO  : 
Transferred:   	        3 MiB / 3 MiB, 100%, 0 B/s, ETA -
Transferred:            1 / 1, 100%
Elapsed time:         0.0s

Script <rclone-b2-test.sh>: ● Deleting local file </home/ncw/testFile> ..
Script <rclone-b2-test.sh>: Done.

Script <rclone-b2-test.sh>: ● About to delete the remote file <b2:/test-isos/testFile>, after a sleep of <120> seconds ..
Script <rclone-b2-test.sh>: Done.

Script <rclone-b2-test.sh>: ● About to query the existence of remote file <b2:/test-isos/testFile>, after a sleep of <120> seconds ..
Script <rclone-b2-test.sh>: ● The remote reports that the file no longer exists. ✓

So it looked like it worked there too.

Thank you for your work.

Ah. Obviously, I should have checked the documentation. Sorry.

I think that I am continuing to have problems. By 'problems' I mean: reports from b2, via rclone, of files existing a considerable time after I had told b2 - again via rclone - to delete them. Yet, perhaps I am confused (confused by the different methods of querying and perhaps I am remembering problems caused by my misunderstanding of that 'null' output). I will try to test some more. If I find anything useful, I will report it here.

Nick, or anyone: if I may - I am having trouble finding documentation on what operations/deletefile returns, by way of exitcode (in shell) or output, if it cannot find the file the user tries to delete.

Experimentation suggests that the answer is: a false exitcode (and indeed I think I was told that, here on this forum, a while ago) and the message ' Failed to rc: loopback call failed: object not found'. Yet, sometimes, and when I am sure that the item does not exist, the command returns true and, er, {}. Apologies if I misunderstand something.

(EDITED to fix a punctuation mistake.)

I am not sure I understand, but perhaps you are looking for one of these:
https://rclone.org/docs/#exit-code
https://rclone.org/docs/#error-on-no-transfer

Yes the internal error ObjectNotFound sounds like the correct response.

Can you give an example of that I don't think that should happen.

Can you give an example of that I don't think that should happen.

Here you are.

$ rclone rc --loopback operations/deletefile fs=enc-b2: remote='x1/old/m10d27/home/<myUsername>/Desktop/For X230 Conky'
{}
$

The file existed and after the command - judging by the program 'Rclone Browser' at least - it no longer exists.

I tried the command again, but this time with a non-existent file. The result was as expected and as desired. For see the following.

$ rclone rc --loopback operations/deletefile fs=enc-b2: remote='x1/old/m10d27/home/<my username>/Desktop/For X230 Conky Wibble'
2021/12/03 01:35:20 Failed to rc: loopback call failed: object not found

And the exitcode was that of falsity.

Then - some sixty seconds after the very first command - I repeated that first command and received, as expected and desired, the 'object not found' response (and an exitcode of false).

If the file existed before and didn't exist after then that looks correct?

That looks OK.

That seems OK too.

I'm not sure I understand the problem?

Matters have got rather confused but what continues to puzzle me is something that, if I understood you, should not happen but does happen. That thing is: a successful deletion not only returning true (which is what one expects) but, additionally, and more surprisingly, printing '{}'.

The rclone rc calls always return something if successful. If they haven't got any useful info to return then they will return {}.

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