Why are there error messages about non-existing files in the log?

What is the problem you are having with rclone?

In the logging is an error complaining rclone can not delete a file that is not present on the remote. But the file is also no longer present on the local system. So why does rclone think this file exists? The file used to exist in the past but I manually delete it on the remote (as a test)

What is your rclone version (output from rclone version)

rclone v1.52.1

  • os/arch: linux/amd64
  • go version: go1.14.4

Which OS you are using and how many bits (eg Windows 7, 64 bit)

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

BackBlaze B2

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

rclone: Version "v1.52.1" starting with parameters ["rclone" "-vv" "sync" "/" "Backblaze-inzicht-Crypt:/" "--filter-from" "/usr/local/share/rclone/rclone_backup.filter" "--log-file=/var/log/rclone/rclone_backup.sh-donderdag.log" "--fast-list" "--skip-links" "--delete-excluded" "--ignore-errors"]

The rclone config contents with secrets removed.

[Backblaze]
type = b2
account = 
key = 
endpoint = 

[Backblaze-inzicht-Crypt]
type = crypt
remote = Backblaze:inzicht
filename_encryption = off
password = 
password2 = 

A log from the command with the -vv flag

2020/07/02 03:18:35 ERROR : etc/systemd/system/snap-signal\x2ddesktop-308.mount: Couldn't delete: failed to hide "etc/systemd/system/snap-signal\\x2ddesktop-308.mount.bin": File not present: etc/systemd/system/snap-signal´╝╝x2ddesktop-308.mount.bin (400 no_such_file)

That means it was there when it started and when it tries to find it again, it wasn't.

Looks like a snap mount or something that might be transient in terms of being there.

If only it was that simple. See these two parts of logfiles of the last two days:

root@inzicht:/var/log/rclone# grep ERROR rclone_backup.sh-thursday.log | grep snap-pycharm | grep 188
2020/07/02 02:52:56 ERROR : etc/systemd/system/snap-pycharm\x2dcommunity-188.mount: Couldn't delete: failed to hide "etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin": File not present: etc/systemd/system/snap-pycharm´╝╝x2dcommunity-188.mount.bin (400 no_such_file)
2020/07/02 03:08:28 ERROR : etc/systemd/system/snap-pycharm\x2dcommunity-188.mount: Couldn't delete: failed to hide "etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin": File not present: etc/systemd/system/snap-pycharm´╝╝x2dcommunity-188.mount.bin (400 no_such_file)
2020/07/02 03:18:33 ERROR : etc/systemd/system/snap-pycharm\x2dcommunity-188.mount: Couldn't delete: failed to hide "etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin": File not present: etc/systemd/system/snap-pycharm´╝╝x2dcommunity-188.mount.bin (400 no_such_file)

root@inzicht:/var/log/rclone# grep ERROR rclone_backup.sh-friday.log | grep snap-pycharm | grep 188
2020/07/03 03:39:49 ERROR : etc/systemd/system/snap-pycharm\x2dcommunity-188.mount: Couldn't delete: failed to hide "etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin": File not present: etc/systemd/system/snap-pycharm´╝╝x2dcommunity-188.mount.bin (400 no_such_file)
2020/07/03 03:56:01 ERROR : etc/systemd/system/snap-pycharm\x2dcommunity-188.mount: Couldn't delete: failed to hide "etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin": File not present: etc/systemd/system/snap-pycharm´╝╝x2dcommunity-188.mount.bin (400 no_such_file)
2020/07/03 04:06:38 ERROR : etc/systemd/system/snap-pycharm\x2dcommunity-188.mount: Couldn't delete: failed to hide "etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin": File not present: etc/systemd/system/snap-pycharm´╝╝x2dcommunity-188.mount.bin (400 no_such_file)

Now let's see what is on the system:

root@inzicht:/var/log/rclone# ls -la /etc/systemd/system/snap-pycharm*
-rw-r--r-- 1 root root 279 mei 7 10:20 '/etc/systemd/system/snap-pycharm\x2dcommunity-194.mount'
-rw-r--r-- 1 root root 279 jun 3 20:14 '/etc/systemd/system/snap-pycharm\x2dcommunity-197.mount'
-rw-r--r-- 1 root root 288 mei 7 13:46 '/etc/systemd/system/snap-pycharm\x2dprofessional-198.mount'
-rw-r--r-- 1 root root 288 jun 3 20:15 '/etc/systemd/system/snap-pycharm\x2dprofessional-201.mount'

It has been like this for at least the last week. I have no idea how rclone thinks that he should backup a non-existing directory. there are no stale mounts as far as I can see.

This is weird voodoo :slight_smile:

This is rclone in the delete phase of the sync. What it is saying is that it tried to delete etc/systemd/system/snap-pycharm\x2dcommunity-188.mount which isn't there any more on the source but is on the destination, but it received this error from b2: File not present: etc/systemd/system/snap-pycharm´╝╝x2dcommunity-188.mount.bin (400 no_such_file)

I note that you are using crypt but with filename_encryption = off - I wonder if this is part of the problem. You can't write \ to b2 file names so rclone translates them transparently between that and a similar unicode character ´╝╝.

Did all the failures have ´╝╝ in them?

If you try to find that directory on the b2 web interface what does it look like?

Can you try rclone lsf on etc/systemd/system/ for the crypted b2 and the normal b2?

Sure, it says

# rclone lsf Backblaze-inzicht-Crypt:etc/systemd/system/ | grep snap-pycharm | grep 188
snap-pycharm\x2dcommunity-188.mount

# rclone lsf Backblaze:inzicht/etc/systemd/system/ | grep snap-pycharm | grep 188
snap-pycharm\x2dcommunity-188.mount.bin

That seems to check out. I do not encrypt the filenames themselves because of the warning about that on the rclone website.

Hm, doing on the rclone site the web gui to browse the directory it does NOT show the 188 version. Interesting.

Let's see if I can delete the file manually from the command line:
So the file is present remote, but I can't seem to find a way to select just this single file. I can do lsf for the directory, but not for that specific file:

# rclone ls "Backblaze-inzicht-Crypt:etc/systemd/system/snap-pycharm/community-188.mount.bin"
# rclone ls "Backblaze-inzicht-Crypt:etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.b in"
# rclone ls Backblaze-inzicht-Crypt:etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin

So, rclone can save a file containing a slash in the filename but it can not address it anymore. is this a bug?

By the way, thanks so much for thinking with me on this one.
Best, Jeroen

It sounds like it. I haven't quite got my head round exactly where the bug is yet though...

You'll need to use single quotes around this otherwise bash will intepret the \x2d so

rclone ls 'Backblaze-inzicht-Crypt:etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin'

That is on the b2 web site isn't it.

I think we need to see what B2 sends us back for that file.

If you do

rclone lsf Backblaze:inzicht/etc/systemd/system/ -vv --dump bodies

You'll see lots of stuff returned - you are looking for a bit of JSON which looks like this but is about the 188 file

    {
      "accountId": "f2XXX",
      "action": "upload",
      "bucketId": "efXXX",
      "contentLength": 77,
      "contentSha1": "f94193d1fc5abc95bddb29dd1681ffdda265cdde",
      "contentType": "application/octet-stream",
      "fileId": "4_zef920d23509dcb3b5f680e1b_f100c30f68fdc8f6b_d20200703_m182831_c001_v0001001_t0032",
      "fileInfo": {
        "src_last_modified_millis": "1593800909889"
      },
      "fileName": "file with backslash ´╝╝ oh yes.txt.bin",
      "size": 77,
      "uploadTimestamp": 1593800911000
    },

Can you post that? You can redact the IDs if you want - the most sensitive is the accountId the others aren't particularly sensitive.

I suspect that file might have a "action": "upload" that rclone isn't expecting - that would explain things.

# rclone ls 'Backblaze-inzicht-Crypt:etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin'

Still no joy :slight_smile:

{
      "accountId": "obfuscated",
      "action": "upload",
      "bucketId": "also obfuscated",
      "contentLength": 327,
      "contentSha1": "403efc2009f0718aa5ccf2d91b361789a94e1d38",
      "contentType": "application/octet-stream",
      "fileId": "changed a bit m082339_f002_v0901235_t0039",
      "fileInfo": {
        "src_last_modified_millis": "1585997512064"
      },
      "fileName": "etc/systemd/system/snap-pycharm\\x2dcommunity-188.mount.bin",
      "size": 327,
      "uploadTimestamp": 1586330569000
    },

Indeed status is upload.
Greets, Jeroen

But that filename has a backslash in it which I thought wasn't allowed.

Here is what the docs say

Names can be pretty much any UTF-8 string up to 1024 bytes long. There are a few picky rules:

No character codes below 32 are allowed.
DEL characters (127) are not allowed.

So backslashes are allowed.

I wonder why we are escaping them... and how an unescaped file name made it onto b2

I think either way this should appear in the listings though...

so does rclone lsf Backblaze:inzicht/etc/systemd/system/ | grep 188 show the file?

So here is what I think

  • there is a bug which has somehow allowed an unescaped file name into b2
  • we are escaping \ unecessarily. This doesn't matter particularly except for the above

I suspect you will be able to access the file with -b2-encoding "Slash,Del,Ctl,InvalidUtf8,Dot"

Did the 188 file get uploaded with rclone? If so which version?

# rclone lsf Backblaze:inzicht/etc/systemd/system/ | grep 188
snap-pycharm\x2dcommunity-188.mount.bin

# rclone lsf   -b2-encoding "Slash,Del,Ctl,InvalidUtf8,Dot"  Backblaze:inzicht/etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin
Error: unknown shorthand flag: 'b' in -b2-encoding

# rclone version
rclone v1.52.1
- os/arch: linux/amd64
- go version: go1.14.4

Yes, the file got uploaded using rclone somewhere in history.
Probably at least version 1.44, 1.45, 1.51 or now 1.52.1

p.s. I do have a strong opinion towards a developer at Jetbrains who decided that it was a good idea to put a slash in a filename.

Sorry that should be --b2-encoding (two dashes at the start)

I think what happened is that this file was uploaded with a pre encoding B2 backend - that explains the problem and you rclone versions match that hypothesis.

I think adding the encoding should work.

I now need to decide whether to change the default encoding.

If I do it potentially means people's syncs will upload stuff with back slashes again which is annoying but not the end of the world. If I don't then your problem will happen and rclone will be incompatible with other B2 tools.

I'm inclined to change it - what do you think?

# rclone lsf   --b2-encoding "Slash,Del,Ctl,InvalidUtf8,Dot"  Backblaze:inzicht/etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin
# rclone lsf   --b2-encoding "Slash,Del,Ctl,InvalidUtf8,Dot"  'Backblaze:inzicht/etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin'
snap-pycharm\x2dcommunity-188.mount.bin
#

So, with this last cli I can 'grab' and probably delete the file.
As my problem only pertains to a small number of files it is no hassle to manually delete them. Larger numbers can be done by scripting.
I would advice against changing the default encoding. Maybe some people need to check or fix their remote contents, but I think it is way better than introducing a change that could effect everybody.
But, of course, I am only a humble rclone user and no backup expert and these are just my 2 cents. :slight_smile:

I will no go ahead and try to remove the files manually.

Regards,
Jeroen

# rclone deletefile   --b2-encoding "Slash,Del,Ctl,InvalidUtf8,Dot"  'Backblaze:inzicht/etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin'
# rclone lsf   --b2-encoding "Slash,Del,Ctl,InvalidUtf8,Dot"  'Backblaze:inzicht/etc/systemd/system/snap-pycharm\x2dcommunity-188.mount.bin'
# rclone lsf   --b2-encoding "Slash,Del,Ctl,InvalidUtf8,Dot"  'Backblaze:inzicht/etc/systemd/system/' | grep snap-pycharm
snap-pycharm\x2dcommunity-192.mount.bin
snap-pycharm\x2dprofessional-192.mount.bin
... some more files...

Yep. Works. Will do the rest now.

Thanks so much for your help on this!
Regards,
Jeroen

1 Like

I'm glad we've got to the bottom of this!

I looked in the wayback machine - the docs from 2018-09 say

Names can be pretty much any UTF-8 string up to 1024 bytes long. There are a few picky rules:

  • No character codes below 32 are allowed.
  • Backslashes are not allowed.
  • DEL characters (127) are not allowed.
  • File names cannot start with "/", end with "/", or contain "//".

This changed in 2020-05 to

Names can be pretty much any UTF-8 string up to 1024 bytes long. There are a few picky rules:

  • No character codes below 32 are allowed.
  • DEL characters (127) are not allowed.

I'm guessing these changed to make it more s3 compatible.

I think I'll leave the encoding alone since it shouldn't cause trouble for users.

I'll put a note in the docs about it.

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