os: regression with reading empty root directories on Windows with go1.21rc2

[ncw]

What version of Go are you using (go version)?

go1.21rc2

Does this issue reproduce with the latest release?

It reproduces with tip also at 5b72f45

What operating system and processor architecture are you using (go env)?

I've been cross compiling for my Windows VM

go env Output

GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/home/ncw/.cache/go-build'
GOENV='/home/ncw/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/ncw/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/ncw/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/opt/go/go1.21'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/opt/go/go1.21/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='devel go1.21-5b72f45dd1 Fri Jun 30 22:02:00 2023 +0000'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/ncw/go/src/github.com/rclone/rclone/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build2943985512=/tmp/go-build -gno-record-gcc-switches'

What did you do?

This problem was spotted by the rclone test suite.

To reproduce (Windows only)

git clone https://github.com/rclone/rclone.git
cd rclone/cmd/cmount
go test -v -tags cmount -run TestMount/CacheMode=off/TestTouchAndDelete

You will need WinFSP installed too.

What did you expect to see?

I expected this test to pass

What did you see instead?

Output which looks like this

    fs.go:227:
                Error Trace:    /home/ncw/go/src/github.com/rclone/rclone/vfs/vfstest/fs.go:227
                                                        /home/ncw/go/src/github.com/rclone/rclone/vfs/vfstest/fs.go:267
                                                        /home/ncw/go/src/github.com/rclone/rclone/vfs/vfstest/edge_cases.go:14
                Error:          Received unexpected error:
                                GetFileInformationByHandleEx X:\: The system cannot find the file specified.
                Test:           TestMount/CacheMode=off/TestTouchAndDelete

Using a combination of bisect and reverting suspicious commits I managed to work out that it is caused by this commit by @qmuntal

commit 1951857
Author: qmuntal [email protected]
Date: Tue Nov 22 18:46:35 2022 +0100

os: use handle based APIs to read directories on windows

This CL updates File.readdir() on windows so it uses
GetFileInformationByHandleEx with FILE_ID_BOTH_DIR_INFO
instead of Find* APIs. The former is more performant because
it allows us to buffer IO calls and reduces the number of system calls,
passing from 1 per file to 1 every ~100 files
(depending on the size of the file name and the size of the buffer).

This change improve performance of File.ReadDir by 20-30%.

name old time/op new time/op delta
ReadDir-12 562µs ±14% 385µs ± 9% -31.60% (p=0.000 n=9+9)

name old alloc/op new alloc/op delta
ReadDir-12 29.7kB ± 0% 29.5kB ± 0% -0.88% (p=0.000 n=8+10)

name old allocs/op new allocs/op delta
ReadDir-12 399 ± 0% 397 ± 0% -0.50% (p=0.000 n=10+10)

This change also speeds up calls to os.SameFile when using FileStats
returned from File.readdir(), as their file ID can be inferred while
reading the directory.

Change-Id: Id56a338ee66c39656b564105cac131099218fb5d
Reviewed-on: https://go-review.googlesource.com/c/go/+/452995
TryBot-Result: Gopher Robot [email protected]
Reviewed-by: Damien Neil [email protected]
Reviewed-by: Alex Brainman [email protected]
Run-TryBot: Quim Muntal [email protected]
Reviewed-by: Bryan Mills [email protected]

The current reproducer is unsatisfactory so I will try to narrow it down tomorrow.

Any ideas much appreciated though!

See: rclone/rclone#7100

[qmuntal]

Can reproduce the issue. Will investigate so we have a path forward before go1.21.

[ncw]

@qmuntal do you need a simpler repro? I was going to make one today but if you don't need it I won't bother.

[qmuntal]

@qmuntal do you need a simpler repro? I was going to make one today but if you don't need it I won't bother.

I would welcome a simpler repro that doesn't require WinFSP so that it could be added to the os package tests, if that's possible.

[ncw]

I've been using this little program to test with

package main

import (
	"fmt"
	"io/ioutil"
	"os"
	"time"
)

func main() {
	if len(os.Args) < 2 {
		fmt.Println("Need directory as parameter")
		return
	}
	dir := os.Args[1]
	for {
		entries, err := ioutil.ReadDir(dir)
		fmt.Println("entries", entries)
		fmt.Println("err", err)
		time.Sleep(time.Second)
	}
}

And leaving it running in a powershell window as this where Q: is a non existent drive letter.

./readdir-sleep.exe Q:\

The problem reproduces if in another window we use rclone to mount an empty folder on Q:

 .\rclone mount C:\mnt\ q:

Giving errors

err GetFileInformationByHandleEx q:\: The system cannot find the file specified.

Adding a file in the directory causes the error to go away. Removing it causes it to come back.

Using net use to mount an empty directory does not reproduce the problem

net use q: \\localhost\c$\mnt
net use q: /delete

Looking with dir running under cmd (powershell seems to do something different)

With net use we see

C:\Users\Dev>dir q:\
 Volume in drive Q has no label.
 Volume Serial Number is 464C-ABA7

 Directory of q:\

04/07/2023  10:12    <DIR>          .
04/07/2023  10:12    <DIR>          ..
               0 File(s)              0 bytes
               2 Dir(s)   1,198,088,192 bytes free

But with rclone mount we see

C:\Users\Dev>dir q:\
 Volume in drive Q is ? C  mnt
 Volume Serial Number is 0A1F-8771

 Directory of q:\

File Not Found

C:\Users\Dev>

So the rclone mount is not adding the . and .. entries into the Q: directory.

This is arguably a bug in rclone - it should really be adding the . and .. directories.

However it is a regression in os.Readdir too.

[qmuntal]

I think I got it. When reading a directory, we use GetFileInformationByHandleEx with FILE_ID_BOTH_DIR_INFO to get the child entries. If that call fails, we ignore the error if it is ERROR_NO_MORE_FILES, as Windows uses it to inform that there are no more files to read:

go/src/os/dir_windows.go

Lines 81 to 86 in 5b72f45

	err = windows.GetFileInformationByHandleEx(file.pfd.Sysfd, infoClass, (*byte)(unsafe.Pointer(&(*d.buf)[0])), uint32(len(*d.buf)))
	runtime.KeepAlive(file)
	if err != nil {
	if err == syscall.ERROR_NO_MORE_FILES {
	break
	}

We should also be ignoring ERROR_FILE_NOT_FOUND, as Windows can return that when no files were found in the directory, as per MS-FSA 2.1.5.6.3 (search for STATUS_NO_SUCH_FILE). The problem with this error is that is difficult to trigger, all directories except empty root directories contain at least the . and .. entries, so it went unnoticed when I was implementing CL 452995.

[qmuntal]

Thanks for the samples @ncw. Seen them after posting my last reply.

This is arguably a bug in rclone - it should really be adding the . and .. directories.

Not sure if it is a bug in rclone, MS-FSA 2.1.5.6.3 says that . and .. are not required when listing a root directory:

If FirstQuery is TRUE or RestartScan is TRUE, the object store MUST set the "." and ".." file names as the first two records returned, unless one of the following is TRUE:

• Open.File == File.Volume.RootDirectory
  ...

I guess that net use adds them to avoid breaking problems that don't handle ERROR_FILE_NOT_FOUND, which are quite a few for what I can find doing a quick web search.

I'll submit a fix, although I'm not sure if I'll be able to add a test case, can't depend on WinFSP in the standard library.

[ncw]

Thanks @qmuntal

This is arguably a bug in rclone - it should really be adding the . and .. directories.

Not sure if it is a bug in rclone, MS-FSA 2.1.5.6.3 says that . and .. are not required when listing a root directory:

Rclone is adding the . and .. I discovered from a bit of trawling the source, but it appears WinFSP is filtering them out just from the root directory (or maybe Windows is).

So I suspect @billziss-gh (developer of WinFSP) has read that doc too!

If FirstQuery is TRUE or RestartScan is TRUE, the object store MUST set the "." and ".." file names as the first two records returned, unless one of the following is TRUE:

• Open.File == File.Volume.RootDirectory
  ...

I guess that net use adds them to avoid breaking problems that don't handle ERROR_FILE_NOT_FOUND, which are quite a few for what I can find doing a quick web search.

I'll submit a fix, although I'm not sure if I'll be able to add a test case, can't depend on WinFSP in the standard library.

Yes a test for this is quite hard I think unless we can find some builtin windows way of creating a drive letter like this.

I'm happy to give it a test when you are ready.

[qmuntal]

I'm happy to give it a test when you are ready.

I've submitted https://go-review.googlesource.com/c/go/+/507775, which fixes the failing rclone test on my computer. Would be great if you could run the relevant rclone test suite using that CL.

[gopherbot]

Change https://go.dev/cl/507775 mentions this issue: os: support reading empty root directories on Windows

[ncw]

This is all looking good - thank you :-)