Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

os: fs.ReadFile() returns an empty slice when reading some sysfs files via os.DirFS #53761

Open
ivan4th opened this issue Jul 8, 2022 · 7 comments
Labels
help wanted NeedsFix
Milestone

Comments

@ivan4th
Copy link

@ivan4th ivan4th commented Jul 8, 2022

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

$ go version
go version go1.18.3 linux/amd64

Does this issue reproduce with the latest release?

Yes

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

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/root/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/root/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.18.3"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build3873644549=/tmp/go-build -gno-record-gcc-switches"

What did you do?

package main

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

func verify(fpath string) {
	bs, err := fs.ReadFile(os.DirFS(""), fpath)
	if err != nil {
		panic(err)
	}
	fmt.Printf("fs.ReadFile %q: %q\n", fpath, bs)

	f, err := os.Open("/" + fpath)
	if err != nil {
		panic(err)
	}
	defer f.Close()

	bs, err = ioutil.ReadAll(f)
	if err != nil {
		panic(err)
	}
	fmt.Printf("ReadAll %q: %q\n", fpath, bs)
}

func main() {
	verify("sys/fs/cgroup/cpuset.cpus.effective")
	verify("sys/devices/system/cpu/cpu0/topology/thread_siblings_list")
}

What did you expect to see?

I'd expect thread_sibling_list file to be read correctly:

fs.ReadFile "sys/fs/cgroup/cpuset.cpus.effective": "0\n"
ReadAll "sys/fs/cgroup/cpuset.cpus.effective": "0\n"
fs.ReadFile "sys/devices/system/cpu/cpu0/topology/thread_siblings_list": "0\n"
ReadAll "sys/devices/system/cpu/cpu0/topology/thread_siblings_list": "0\n"

There are no problems with thread_sibling_list on Ubuntu 20.04 / kernel 5.4.0:

Linux i4u 5.4.0-73-generic #82-Ubuntu SMP Wed Apr 14 17:39:42 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

What did you see instead?

When code is run on Ubuntu 22.04 on Linux 5.15.0 the following output is produced:

fs.ReadFile "sys/fs/cgroup/cpuset.cpus.effective": "0\n"
ReadAll "sys/fs/cgroup/cpuset.cpus.effective": "0\n"
fs.ReadFile "sys/devices/system/cpu/cpu0/topology/thread_siblings_list": ""
ReadAll "sys/devices/system/cpu/cpu0/topology/thread_siblings_list": "0\n"

Note that for thread_siblings_list, the empty string is returned.
I tested it on my own machine with Ubuntu 22.04 and also on a Digital Ocean instance with Ubuntu 22.04:

Linux rmmenow 5.15.0-25-generic #25-Ubuntu SMP Wed Mar 30 15:54:22 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

Additional notes

The relevant part of strace looks like this:

[pid  3185] openat(AT_FDCWD, "/sys/fs/cgroup/cpuset.cpus.effective", O_RDONLY|O_CLOEXEC) = 3
[pid  3185] epoll_create1(EPOLL_CLOEXEC) = 4
[pid  3185] pipe2([5, 6], O_NONBLOCK|O_CLOEXEC) = 0
[pid  3185] epoll_ctl(4, EPOLL_CTL_ADD, 5, {events=EPOLLIN, data={u32=5665744, u64=5665744}}) = 0
[pid  3185] epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=3003887392, u64=140633118060320}}) = 0
[pid  3185] fcntl(3, F_GETFL)           = 0x8000 (flags O_RDONLY|O_LARGEFILE)
[pid  3185] fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
[pid  3185] fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
[pid  3185] read(3, "0", 1)             = 1
[pid  3185] read(3, "\n", 7)            = 1
[pid  3185] read(3, "", 6)              = 0
[pid  3185] epoll_ctl(4, EPOLL_CTL_DEL, 3, 0xc000066ca4) = 0
[pid  3185] close(3)                    = 0
[pid  3185] write(1, "fs.ReadFile \"sys/fs/cgroup/cpuse"..., 57fs.ReadFile "sys/fs/cgroup/cpuset.cpus.effective": "0\n"
) = 57
[pid  3185] openat(AT_FDCWD, "/sys/fs/cgroup/cpuset.cpus.effective", O_RDONLY|O_CLOEXEC) = 3
[pid  3185] epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=3003887392, u64=140633118060320}}) = 0
[pid  3188] futex(0xc000038948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3186] <... nanosleep resumed>NULL) = 0
[pid  3185] fcntl(3, F_GETFL)           = 0x8000 (flags O_RDONLY|O_LARGEFILE)
[pid  3185] fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
[pid  3185] read(3, "0\n", 512)         = 2
[pid  3185] read(3, "", 510)            = 0
[pid  3185] write(1, "ReadAll \"sys/fs/cgroup/cpuset.cp"..., 53ReadAll "sys/fs/cgroup/cpuset.cpus.effective": "0\n"
) = 53
[pid  3185] epoll_ctl(4, EPOLL_CTL_DEL, 3, 0xc000066d8c) = 0
[pid  3185] close(3)                    = 0
[pid  3185] openat(AT_FDCWD, "/sys/devices/system/cpu/cpu0/topology/thread_siblings_list", O_RDONLY|O_CLOEXEC) = 3
[pid  3185] epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=3003887392, u64=140633118060320}}) = 0
[pid  3185] fcntl(3, F_GETFL)           = 0x8000 (flags O_RDONLY|O_LARGEFILE)
[pid  3185] fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
[pid  3185] fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
[pid  3185] read(3, "", 1)              = 0
[pid  3185] epoll_ctl(4, EPOLL_CTL_DEL, 3, 0xc000066ca4) = 0
[pid  3185] close(3)                    = 0
[pid  3185] write(1, "fs.ReadFile \"sys/devices/system/"..., 76fs.ReadFile "sys/devices/system/cpu/cpu0/topology/thread_siblings_list": ""
) = 76
[pid  3185] openat(AT_FDCWD, "/sys/devices/system/cpu/cpu0/topology/thread_siblings_list", O_RDONLY|O_CLOEXEC) = 3
[pid  3185] epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=3003887392, u64=140633118060320}}) = 0
[pid  3185] fcntl(3, F_GETFL)           = 0x8000 (flags O_RDONLY|O_LARGEFILE)
[pid  3185] fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
[pid  3185] read(3, "0\n", 512)         = 2
[pid  3185] read(3, "", 510)            = 0
[pid  3185] write(1, "ReadAll \"sys/devices/system/cpu/"..., 75ReadAll "sys/devices/system/cpu/cpu0/topology/thread_siblings_list": "0\n"
) = 75
[pid  3185] epoll_ctl(4, EPOLL_CTL_DEL, 3, 0xc000066d8c) = 0
[pid  3185] close(3)                    = 0
[pid  3185] exit_group(0)               = ?
[pid  3187] <... futex resumed>)        = ?
[pid  3187] +++ exited with 0 +++
[pid  3186] +++ exited with 0 +++
[pid  3188] <... futex resumed>)        = ?
[pid  3188] +++ exited with 0 +++
+++ exited with 0 +++

I suspect that the culprit is probably O_NONBLOCK combined that the fact that seeing the file size of 0 in sysfs

go/src/io/fs/readfile.go

Lines 43 to 49 in 5c1a13e

var size int
if info, err := file.Stat(); err == nil {
size64 := info.Size()
if int64(int(size64)) == size64 {
size = int(size64)
}
}

fs.ReadFile tries to read just one byte from it

go/src/io/fs/readfile.go

Lines 51 to 57 in 5c1a13e

data := make([]byte, 0, size+1)
for {
if len(data) >= cap(data) {
d := append(data[:cap(data)], 0)
data = d[:len(data)]
}
n, err := file.Read(data[len(data):cap(data)])

The resulting read() syscall returns 0 (perhaps due to O_NONBLOCK?)

read(3, "", 1)                          = 0

and file.Read() returns EOF error.

This is quite possibly a Linux kernel bug, nevertheless, it may affect many Go programs, as it's quite tempting to use io/fs to make sysfs-dependent code testable.

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Jul 8, 2022

I think the difference is that fs.ReadFile uses stat to get the file size, and reads that much data. That probably doesn't work with sysfs. ioutil.ReadAll doesn't care about the file size, it just reads to EOF.

In os.Readfile there is a workaround:

	// If a file claims a small size, read at least 512 bytes.
	// In particular, files in Linux's /proc claim size 0 but
	// then do not work right if read in small pieces,
	// so an initial read of 1 byte would not work correctly.
	if size < 512 {
		size = 512
	}

No such workaround exists in fs.Readfile.

One fix would be for os.dirFS to implement the fs.ReadFileFS interface. That seems like the simplest fix to me. I don't see why we should change io/fs for the vagaries of Linux file systems.

@ianlancetaylor ianlancetaylor changed the title fs: fs.ReadFile() returns an empty slice when reading some sysfs files os: fs.ReadFile() returns an empty slice when reading some sysfs files via os.DirFS Jul 8, 2022
@ianlancetaylor ianlancetaylor added help wanted NeedsFix labels Jul 8, 2022
@ianlancetaylor ianlancetaylor added this to the Backlog milestone Jul 8, 2022
@ivan4th
Copy link
Author

@ivan4th ivan4th commented Jul 8, 2022

@ianlancetaylor It's almost like that but with a small difference: if stat returns 0, fs.ReadFile() does actually try to read a byte, note +1 in data := make([]byte, 0, size+1), and if this byte is read, then the remainder of the file is read, too. That's why it works with an older kernel where the size of the file is also 0; and also it works with another sysfs file with the newer kernel, too. The problem that is for some files, this 1-byte read results in zero-length read and EOF

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Jul 8, 2022

I think we may be saying the same thing. That is the problem that the code in os.ReadFile is trying to work around: it converts a read of 1 byte into a read of 512 bytes.

@ivan4th
Copy link
Author

@ivan4th ivan4th commented Jul 9, 2022

Yes, the workaround should do the trick, so making os.dirFS implement fs.ReadFileFS should fix the problem, that's entirely correct.
It's just that, as a remark, apparently in some cases read(2) appears to misbehave on Linux sysfs, and that is possibly triggered by O_NONBLOCK
(note that one zero-sized sysfs file is read correctly, and another one is not)

@hopehook
Copy link
Contributor

@hopehook hopehook commented Jul 9, 2022

To clarify, will a new API be added here?
I think its implementation is like this, it needs to go through the Proposal process, right?

func (dir dirFS) ReadFile(name string) ([]byte, error) {
	if !fs.ValidPath(name) || runtime.GOOS == "windows" && containsAny(name, `\:`) {
		return nil, &PathError{Op: "readfile", Path: name, Err: ErrInvalid}
	}
	return ReadFile(string(dir) + "/" + name)
}

@ivan4th Please take a look, can this code solve your problem?
I don't have a test environment here, thanks~

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Jul 9, 2022

I'm not sure this needs to go through the proposal process, but I guess it can't hurt. I can turn this issue into a proposal if the patch does indeed fix the problem.

@gopherbot
Copy link

@gopherbot gopherbot commented Jul 9, 2022

Change https://go.dev/cl/416775 mentions this issue: os: implement fs.ReadFileFS for DirFS

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
help wanted NeedsFix
Projects
None yet
Development

No branches or pull requests

4 participants