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

ncw · 2023-07-03T19:34:13Z

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 quimmuntal@gmail.com
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 gobot@golang.org
Reviewed-by: Damien Neil dneil@google.com
Reviewed-by: Alex Brainman alex.brainman@gmail.com
Run-TryBot: Quim Muntal quimmuntal@gmail.com
Reviewed-by: Bryan Mills bcmills@google.com

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

Any ideas much appreciated though!

See: rclone/rclone#7100

The text was updated successfully, but these errors were encountered:

qmuntal · 2023-07-04T07:26:29Z

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

ncw · 2023-07-04T08:43:47Z

@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 · 2023-07-04T08:45:45Z

@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 · 2023-07-04T09:21:42Z

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 · 2023-07-04T09:23:11Z

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 · 2023-07-04T09:26:36Z

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 · 2023-07-04T11:15:52Z

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 · 2023-07-04T11:53:37Z

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 · 2023-07-04T11:54:23Z

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

ncw · 2023-07-04T14:20:31Z

This is all looking good - thank you :-)

GetFileInformationByHandleEx can return `ERROR_FILE_NOT_FOUND` when no files were found in a root directory, as per MS-FSA 2.1.5.6.3 [1]. This error code should not be treated as an error, but rather as an indication that no files were found, in which case `readdir` should return an empty slice. This CL doesn't add any test as it is difficult to trigger this error code. Empty root directories created using Windows utilities such as `net use` always report at least the optional `.` and `..` entries. A reproducer is provided in golang#61159, but it requires WinFSP to be installed. Fixes golang#61159 [1] https://learn.microsoft.com/en-us/openspecs/windows_protocols/ms-fsa/fa8194e0-53ec-413b-8315-e8fa85396fd8 Change-Id: Id46452030f5355c292e5b0abbf5e22af434a84d2 Reviewed-on: https://go-review.googlesource.com/c/go/+/507775 Reviewed-by: Nick Craig-Wood <nickcw@gmail.com> TryBot-Result: Gopher Robot <gobot@golang.org> Run-TryBot: Quim Muntal <quimmuntal@gmail.com> Reviewed-by: Heschi Kreinick <heschi@google.com> Reviewed-by: Bryan Mills <bcmills@google.com>

ncw mentioned this issue Jul 3, 2023

build: update to go1.21rc2 and make go1.19 the minimum required version rclone/rclone#7100

Merged

5 tasks

seankhliao added OS-Windows NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Jul 3, 2023

qmuntal self-assigned this Jul 4, 2023

qmuntal added the release-blocker label Jul 4, 2023

qmuntal changed the title ~~os: regression with reading directories on Windows with go1.21rc2~~ os: regression with reading empty root directories on Windows with go1.21rc2 Jul 4, 2023

dmitshur added this to the Go1.21 milestone Jul 5, 2023

dmitshur added NeedsFix The path to resolution is known, but the work has not been done. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Jul 5, 2023

gopherbot closed this as completed in 5c15498 Jul 7, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

ncw commented Jul 3, 2023 •

edited by dmitshur

qmuntal commented Jul 4, 2023

ncw commented Jul 4, 2023

qmuntal commented Jul 4, 2023

ncw commented Jul 4, 2023

qmuntal commented Jul 4, 2023

qmuntal commented Jul 4, 2023 •

edited

ncw commented Jul 4, 2023

qmuntal commented Jul 4, 2023

gopherbot commented Jul 4, 2023

ncw commented Jul 4, 2023

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

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

Comments

ncw commented Jul 3, 2023 • edited by dmitshur

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

Does this issue reproduce with the latest release?

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

What did you do?

What did you expect to see?

What did you see instead?

qmuntal commented Jul 4, 2023

ncw commented Jul 4, 2023

qmuntal commented Jul 4, 2023

ncw commented Jul 4, 2023

qmuntal commented Jul 4, 2023

qmuntal commented Jul 4, 2023 • edited

ncw commented Jul 4, 2023

qmuntal commented Jul 4, 2023

gopherbot commented Jul 4, 2023

ncw commented Jul 4, 2023

ncw commented Jul 3, 2023 •

edited by dmitshur

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

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

qmuntal commented Jul 4, 2023 •

edited