Seeing "failed to read directory entry: readdirent: no such file or directory" with v1.52.2

I am creating a new Ubuntu 20.04 VM instance. With rclone version 1.52.2 installed, I'm seeing a bunch of "failed to read directory entry: readdirent: no such file or directory" errors in the log.

I roll back to version 1.51 and I see no errors in the log.

rclone copy -vv --tpslimit 10 --transfers=10 --exclude *.tmp /mnt/data/TV-Kaitlin gsuites:/Videos/TV-Kaitlin

Please include a log file with -vv.

output.log (680.7 KB)

Here is the log when running v1.51.0
output_1.51.0.log (250.4 KB)

What is "/mnt/data/TV-Kaitlin" ? Local disk? What user is rclone running as?

What's the ls -al on the directory it can't read?

Mounted drive
//192.168.2.225/DATA /mnt/data cifs

The directory it can't read changes each time it is run. I've attached another log from this morning.another_output_1.52.2.log (628.2 KB)

What's the ls -al on the directory it can't read?
What user is rclone running as?

The directory it says it can't read changes each time the copy is run. There are no issues listing the directories from commandline as the habskilla user.

rclone is running as habskilla

To keep everything simple, everything is running as habskilla.

What's the ls -al on the directory it can't read?

habskilla@Mate20:~/Desktop$ ls -al /mnt/data/TV-Kaitlin/
total 0
drwxrwxrwx 2 root root 0 Jun 19 16:09 .
drwxrwxrwx 2 root root 0 Jun 23 11:25 ..
drwxrwxrwx 2 root root 0 Jul 2 11:00 'American Dad!'
drwxrwxrwx 2 root root 0 Jul 2 11:42 'Archer (2009)'
drwxrwxrwx 2 root root 0 Jun 19 17:00 'Better Call Saul'
drwxrwxrwx 2 root root 0 Mar 10 14:09 Billions
drwxrwxrwx 2 root root 0 Mar 10 14:09 "Bob's Burgers"
drwxrwxrwx 2 root root 0 Mar 10 14:16 'Brooklyn Nine-Nine'
drwxrwxrwx 2 root root 0 Mar 10 14:49 'Family Guy'
drwxrwxrwx 2 root root 0 Jun 19 17:47 'Full Frontal with Samantha Bee'
drwxrwxrwx 2 root root 0 Jun 19 17:49 "Grey's Anatomy"
drwxrwxrwx 2 root root 0 Jun 19 17:49 Homeland
drwxrwxrwx 2 root root 0 Mar 10 19:26 "It's Always Sunny in Philadelphia"
drwxrwxrwx 2 root root 0 Mar 10 19:26 'Killing Eve'
drwxrwxrwx 2 root root 0 Mar 10 19:26 'Last Week Tonight with John Oliver'
drwxrwxrwx 2 root root 0 Jun 19 20:13 'Law & Order Special Victims Unit'
drwxrwxrwx 2 root root 0 Jun 19 20:13 Letterkenny
drwxrwxrwx 2 root root 0 Mar 11 00:27 Outlander
drwxrwxrwx 2 root root 0 Jun 19 20:13 'Pawn Stars'
drwxrwxrwx 2 root root 0 Mar 11 01:25 QI
drwxrwxrwx 2 root root 0 Mar 11 03:09 'Rick and Morty'
drwxrwxrwx 2 root root 0 Mar 11 03:16 "RuPaul's Drag Race All Stars"
drwxrwxrwx 2 root root 0 Jun 19 20:13 'Shameless (US)'
drwxrwxrwx 2 root root 0 Mar 11 06:25 'South Park'
drwxrwxrwx 2 root root 0 Mar 11 06:45 'Star Trek Discovery'
drwxrwxrwx 2 root root 0 Jun 19 22:41 Supernatural
drwxrwxrwx 2 root root 0 Mar 11 07:40 Superstore
drwxrwxrwx 2 root root 0 Jun 19 22:41 'The Flash (2014)'
drwxrwxrwx 2 root root 0 Jul 2 11:42 'The Goldbergs (2013)'
drwxrwxrwx 2 root root 0 Mar 11 10:45 'The Great British Bake Off'
drwxrwxrwx 2 root root 0 Mar 11 10:45 "The Handmaid's Tale"
drwxrwxrwx 2 root root 0 Mar 11 10:45 'The Orville'
drwxrwxrwx 2 root root 0 Jul 2 11:42 'The Simpsons'
drwxrwxrwx 2 root root 0 Jun 19 22:41 'This Is Us'
drwxrwxrwx 2 root root 0 Mar 11 14:07 Tosh.0
drwxrwxrwx 2 root root 0 Mar 11 14:19 Vikings
drwxrwxrwx 2 root root 0 Jun 19 22:41 Westworld
drwxrwxrwx 2 root root 0 Mar 11 15:22 'Whose Line Is It Anyway'
drwxrwxrwx 2 root root 0 Jun 20 01:03 'Young Sheldon'

This is ringing a bell, something to do with CIFS skipping directory entries when reading in 64 bit mode or something like that.

If you do this rclone lsf -R /path/to/source | sort > test1 a few times then diff the output files do you see differences?

Digging in a bit, I think this is either a kernel bug or a bug in the go runtime: https://github.com/golang/go/issues/39237

This issue is triggered by go's use of signals for its pre-emptive thread scheduling so you could try disabling async pre-emption in go with

export GODEBUG=asyncpreemptoff=1

If that works then I can give you a version compiled with go1.15rc1 which may fix the problem.

Hello ncw,
Just helping here : I had the exact same errors (hundreds of "readdirent: no such file or directory" over a 200k files SMB mounted directory) and your workaround worked like a charm : I'm now getting ~ 50 errors over a full scan when previoulsy it was ~1000.

Interesting.

If you tell me which OS you are on, I'll send an rclone compiled with the pre-release go compiler which I think should help with this problem.

I'm on a Linux Debian based system (Armbian), aarch64 with 5.7.6-meson64 kernel.

Here are two test builds for interested parties - I'd be interested in whether these are better for you @arpel and @habskilla

Thanks @ncw

export GODEBUG=asyncpreemptoff=1 worked

I'll add this to my script and wait for the official release.

Did you have a go with the beta I made?

No. Using v1.52_2 release

Can you try the beta? That will tell us whether this will be fixed in go1.15 and in rclone 1.53 or not - thanks

Thanks - I have been seeing this issue since the upgrade from 1.49, or so, I think. Allhough not sure what caused it and I never asked..... The workaround (export GODEBUG=asyncpreemptoff=1) also worked for me for the few attempts I tried. I saw the issue during "rclone sync".

I have also tried the beta: rclone-v1.52.2-223-g811b30d1-beta-linux-amd64.gz, however, I'm still getting errors on this. They are fairly consistent...

Here's a snapshot of the log:

2020/07/29 14:38:27 DEBUG : rclone: Version "v1.52.2-223-g811b30d1-beta" starting with parameters ["./rclone-beta" "sync" "xx/Billeder/" "private-crypt:/Photos" "--fast-list" "--checkers" "2" "--transfers" "2" >
2020/07/29 14:38:27 DEBUG : Using config file from "/home/xx/.config/rclone/rclone.conf"
2020/07/29 14:38:27 INFO : Starting bandwidth limiter at 10MBytes/s
......... (a lot of size identical and skipping)
2020/07/29 14:39:42 ERROR : 2016 - Jul: error reading source directory: failed to read directory entry: readdirent: no such file or directory
......... (a lot of size identical and skipping)
2020/07/29 14:39:44 DEBUG : Encrypted drive 'private-crypt:/Photos': Waiting for transfers to finish
2020/07/29 14:39:44 ERROR : Encrypted drive 'private-crypt:/Photos': not deleting files as there were IO errors
2020/07/29 14:39:44 ERROR : Encrypted drive 'private-crypt:/Photos': not deleting directories as there were IO errors
2020/07/29 14:39:44 INFO : There was nothing to transfer
2020/07/29 14:39:44 ERROR : Attempt 3/3 failed with 3 errors and: march failed with 2 error(s): first error: failed to read directory entry: readdirent: no such file or directory
2020/07/29 14:39:44 INFO :
Transferred: 0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors: 3 (retrying may help)
Checks: 10163 / 10163, 100%
Elapsed time: 0.4s
2020/07/29 14:39:44 DEBUG : 8 go routines active
2020/07/29 14:39:44 Failed to sync with 3 errors: last error was: march failed with 2 error(s): first error: failed to read directory entry: readdirent: no such file or directory

SMB mounted directory:

ls -al "2016 - Jul"
total 63664
drwxr-xr-x 2 root root 0 Sep 1 2019 .
drwxr-xr-x 2 root root 0 Feb 19 20:42 ..
-rwxr-xr-x 1 root root 3524474 Dec 23 2016 20161223_153123.jpg
......

Linux vm-ubuntu 5.4.0-42-generic #46-Ubuntu SMP Fri Jul 10 00:24:02 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

Edit: Using the workaround still works fine.