client.go

package main

/**

Reproduction scenario for missing files / double file entries when testing against cgofuse.

Run me with e.g. `./client -mountpoint test`.

I can reproduce with golang 1.16.3, cgofuse 1.5.0, macfuse 4.1.2, macOS Big Sur 11.2.3.
I can't reproduce on Windows or on Linux.

Interestingly, the `recurse` goroutines don't trigger the problem, but they do cause load
that seems necessary for reproduction.

I can reproduce by running an `ls -la` in a loop; it should always come back with 28 lines
(25 entries + 3 lines at the top), but it does not:

    $ while :; do ls -la test/Tsttst | wc -l; sleep 1; done
    28
    27
    28
    20
    24
    28
    28
    28
    20
    28
    28
    28
    23
    23
    28
    28
    28
    28
    21

Also, the following lines of output from this application are suspicious:

    20:38:19.619751 client.go:124: Invalid stat "Tsttst/p\x03" (2), returning ENOENT
    20:38:19.619821 client.go:124: Invalid stat "Tsttst/\x98\x03" (2), returning ENOENT
    20:38:19.619869 client.go:124: Invalid stat "Tsttst/\xc0\x03" (2), returning ENOENT
    20:39:13.420416 client.go:124: Invalid stat "Tsttst/\x80\x03" (2), returning ENOENT
    20:39:20.683764 client.go:124: Invalid stat "Tsttst/\x0e" (2), returning ENOENT

*/

import (
	"flag"
	"io/ioutil"
	"log"
	"math/rand"
	"os"
	ospath "path"
	"strings"
	"sync/atomic"
	"time"

	"github.com/billziss-gh/cgofuse/fuse"
)

var (
	enableFuseDebug = flag.Bool("enable_fuse_debug", false, "Enable fuse debug logging")
	mountpoint      = flag.String("mountpoint", "", "Mountpoint")
	threads         = flag.Int("threads", 2, "Recurse threads for load")
)

func main() {
	log.SetFlags(log.Ltime | log.Lshortfile | log.Lmicroseconds)
	flag.Parse()

	log.Printf("running.")
	for i := 0; i < *threads; i += 1 {
		go recurse()
	}

	f := &Mount{}
	host := fuse.NewFileSystemHost(f)
	host.SetCapCaseInsensitive(false)
	host.SetCapReaddirPlus(true)
	options := []string{"-o", "ro", "-o", "volname=TEST", "-o", "uid=-1", "-o", "gid=-1"}
	if *enableFuseDebug {
		options = append(options, "-o", "debug")
	}
	if !host.Mount(*mountpoint, options) {
		log.Fatalf("failed to initialize cgofuse mount")
	}
	os.Exit(1)
}

func recurse() {
	// wait for mount to succeed
	time.Sleep(5 * time.Second)

	log.Printf("recurse starting.")
	for {
		recurseDir("")
		time.Sleep(10 * time.Millisecond)
	}
}

func recurseDir(directory string) {
	files, err := ioutil.ReadDir(ospath.Join(*mountpoint, directory))
	if err != nil {
		log.Printf("-!- recurse readdir err: %v", err)
		return
	}

	filesRead := len(files)
	filesExist := len(subdirectories[directory])
	if filesRead != filesExist {
		log.Printf("-!- Readdir difference: %d files from readdir, while %d files should actually exist.", filesRead, filesExist)
	}

	for _, file := range files {
		info, err := os.Stat(ospath.Join(*mountpoint, directory, file.Name()))
		if info.Name() != file.Name() {
			log.Printf("-!- name differs?")
		}
		if err != nil {
			log.Printf("-!- recurse stat err: %v", err)
			continue
		}
		if info.IsDir() {
			recurseDir(ospath.Join(directory, info.Name()))
		}
	}
}

// ==========================

type vfsFile struct {
	IsDirectory bool
	Mtime       time.Time
	Size        int64
	Files       map[string]*vfsFile
}

type Mount struct {
	fuse.FileSystemBase
	lastHandle uint64
}

func stripPath(path string) string {
	return strings.TrimPrefix(path, "/")
}

func (f *Mount) Access(_ string, mask uint32) int {
	return 0
}

func (f *Mount) Getattr(path string, attr *fuse.Stat_t, fh uint64) int {
	path = stripPath(path)
	if path == "" || path == "/" {
		attr.Mode = 0555 | fuse.S_IFDIR
		return 0
	}
	dn, fn := ospath.Split(path)
	if len(dn) > 0 && dn[len(dn)-1] == '/' {
		dn = dn[0 : len(dn)-1]
	}
	//time.Sleep(time.Millisecond * time.Duration(rand.Intn(20)))
	ret := vfsReaddir(dn)
	if ret == nil {
		log.Printf("Invalid stat %q (1), returning ENOENT", path)
		return -fuse.ENOENT
	}
	file, found := ret.Files[fn]
	if !found {
		if len(fn) > 0 && fn[0] != '.' {
			log.Printf("Invalid stat %q (2), returning ENOENT", path)
		}
		return -fuse.ENOENT
	}
	attr.Size = file.Size
	if file.IsDirectory {
		attr.Mode = 0755 | fuse.S_IFDIR
	} else {
		attr.Mode = 0644 | fuse.S_IFREG
	}
	attr.Mtim.Sec = file.Mtime.Unix()
	attr.Mtim.Nsec = file.Mtime.UnixNano()
	return 0
}

func (f *Mount) Readdir(path string, fill func(name string, stat *fuse.Stat_t, ofst int64) bool, ofst int64, fh uint64) int {
	/*start := time.Now()
	defer func() {
		log.Printf("Readdir %q took %d ms", path, time.Since(start).Milliseconds())
	}()*/

	path = stripPath(path)
	ret := vfsReaddir(path)
	if ret == nil {
		log.Printf("Invalid readdir %q, returning ENOENT", path)
		return -fuse.ENOENT
	}
	time.Sleep(time.Millisecond * time.Duration(rand.Intn(200)))

	for fn, f := range ret.Files {
		attr := fuse.Stat_t{}
		attr.Size = f.Size
		if f.IsDirectory {
			attr.Mode = 0755 | fuse.S_IFDIR
		} else {
			attr.Mode = 0644
		}
		attr.Mtim.Sec = f.Mtime.Unix()
		attr.Mtim.Nsec = f.Mtime.UnixNano()
		if !fill(fn, &attr, 0) {
			break
		}
	}
	return 0
}

func (f *Mount) Open(path string, flags int) (int, uint64) {
	return 0, atomic.AddUint64(&f.lastHandle, 1)
}

func (f *Mount) Read(path string, buff []byte, offset int64, fh uint64) int {
	for i := 0; i < len(buff); i += 1 {
		buff[i] = 0
	}
	return len(buff)
}

func (f *Mount) Release(_ string, fh uint64) int {
	return 0
}

// =========================

func vfsReaddir(path string) *vfsFile {
	res, ok := subdirectories[path]
	if !ok {
		return nil
	}

	files := map[string]*vfsFile{}
	for _, fn := range res {
		files[fn] = &vfsFile{
			IsDirectory: true,
			Mtime:       time.Now(),
			Size:        0,
			Files:       nil,
		}
	}

	return &vfsFile{
		IsDirectory: true,
		Mtime:       time.Now(),
		Size:        0,
		Files:       files,
	}
}

var subdirectories = map[string][]string{
	"": {"Tsttst"},
	"Tsttst": {
		"A AAA AAAAAA AAA",
		"BBBBBBBBB",
		"CCCCCCCCC.0000.CCCCC.CCCC.CC3-CCC",
		"DDDDDDDDD DDDDD",
		"EEEEE EEEE",
		"FFFF.FFFF.FFFF.FFFF.0000.000F.FFFFF.FFFF-FFFFF",
		"GGGGGG",
		"HHHHHHH (0000)",
		"IIIIIII IIIII (0000)",
		"JJJJJ JJJJJ",
		"KKKKKK KKKKKKKK.KKKKKKKKK",
		"LLLLLLLLL (0000)",
		"MMMM MMMMMM MMMM MMMMM",
		"NNN NNNN NNNNNNN",
		"OOOOOOO OO OOO OOOOOOOOO - OO OOOOOOOO OOOOO (0000) [0000o]",
		"PP",
		"QQQ QQQQQQ: QQ QQQQQQQQQQ QQQQQQQ",
		"RRR RRRR RRRRRRRRR",
		"SSS SSSSSS (0000)",
		"TTT TTTTT (0000)",
		"UUU UUUUU UUUUUUUU",
		"VVVVV VVVVVVVVVV VVVVVVV VVVVVV VVVVVVVV",
		"WWWWW WWWWWW (0000)",
		"XXXX XXXXX",
		"YYYYYY",
	},
	"Tsttst/A AAA AAAAAA AAA":                                            {},
	"Tsttst/BBBBBBBBB":                                                   {},
	"Tsttst/CCCCCCCCC.0000.CCCCC.CCCC.CC3-CCC":                           {},
	"Tsttst/DDDDDDDDD DDDDD":                                             {"Subdirectr"},
	"Tsttst/DDDDDDDDD DDDDD/Subdirectr":                                  {},
	"Tsttst/EEEEE EEEE":                                                  {"aaaaaa aaaaaa (0000)", "bbbbb bbbb bbb bbbbbbb bbb (0000) [0000b]"},
	"Tsttst/EEEEE EEEE/aaaaaa aaaaaa (0000)":                             {},
	"Tsttst/EEEEE EEEE/bbbbb bbbb bbb bbbbbbb bbb (0000) [0000b]":        {},
	"Tsttst/FFFF.FFFF.FFFF.FFFF.0000.000F.FFFFF.FFFF-FFFFF":              {"Subd"},
	"Tsttst/FFFF.FFFF.FFFF.FFFF.0000.000F.FFFFF.FFFF-FFFFF/Subd":         {},
	"Tsttst/GGGGGG":                                                      {"Subd"},
	"Tsttst/GGGGGG/Subd":                                                 {},
	"Tsttst/HHHHHHH (0000)":                                              {},
	"Tsttst/IIIIIII IIIII (0000)":                                        {},
	"Tsttst/JJJJJ JJJJJ":                                                 {"jj1", "jj2", "Subs"},
	"Tsttst/JJJJJ JJJJJ/jj1":                                             {},
	"Tsttst/JJJJJ JJJJJ/jj2":                                             {},
	"Tsttst/JJJJJ JJJJJ/Subs":                                            {},
	"Tsttst/KKKKKK KKKKKKKK.KKKKKKKKK":                                   {"ccccccccccc.ccccccccc", "eeeeeee.eeeeeeeee", "gggggggggg.ggggggggg", "tttttt.ttttttttt", "rrrrrrrrrrr.rrrrrrrrr"},
	"Tsttst/KKKKKK KKKKKKKK.KKKKKKKKK/ccccccccccc.ccccccccc":             {},
	"Tsttst/KKKKKK KKKKKKKK.KKKKKKKKK/eeeeeee.eeeeeeeee":                 {},
	"Tsttst/KKKKKK KKKKKKKK.KKKKKKKKK/gggggggggg.ggggggggg":              {},
	"Tsttst/KKKKKK KKKKKKKK.KKKKKKKKK/tttttt.ttttttttt":                  {},
	"Tsttst/KKKKKK KKKKKKKK.KKKKKKKKK/rrrrrrrrrrr.rrrrrrrrr":             {},
	"Tsttst/LLLLLLLLL (0000)":                                            {},
	"Tsttst/MMMM MMMMMM MMMM MMMMM":                                      {},
	"Tsttst/NNN NNNN NNNNNNN":                                            {"NNN NNNN NNNNNNN"},
	"Tsttst/NNN NNNN NNNNNNN/NNN NNNN NNNNNNN":                           {"annnn_TS", "vnnnn_TS"},
	"Tsttst/NNN NNNN NNNNNNN/NNN NNNN NNNNNNN/annnn_TS":                  {},
	"Tsttst/NNN NNNN NNNNNNN/NNN NNNN NNNNNNN/vnnnn_TS":                  {},
	"Tsttst/OOOOOOO OO OOO OOOOOOOOO - OO OOOOOOOO OOOOO (0000) [0000o]": {},
	"Tsttst/PP": {},
	"Tsttst/QQQ QQQQQQ: QQ QQQQQQQQQQ QQQQQQQ":        {},
	"Tsttst/RRR RRRR RRRRRRRRR":                       {"Subd"},
	"Tsttst/RRR RRRR RRRRRRRRR/Subd":                  {},
	"Tsttst/SSS SSSSSS (0000)":                        {},
	"Tsttst/TTT TTTTT (0000)":                         {},
	"Tsttst/UUU UUUUU UUUUUUUU":                       {},
	"Tsttst/VVVVV VVVVVVVVVV VVVVVVV VVVVVV VVVVVVVV": {},
	"Tsttst/WWWWW WWWWWW (0000)":                      {},
	"Tsttst/XXXX XXXXX":                               {},
	"Tsttst/YYYYYY":                                   {"subd"},
	"Tsttst/YYYYYY/subd":                              {},
}

go.mod

module github.com/sgielen/rufs-testcase

go 1.13

require (
	github.com/billziss-gh/cgofuse v1.5.0
)

go.sum

github.com/billziss-gh/cgofuse v1.5.0 h1:kH516I/s+Ab4diL/Y/ayFeUjjA8ey+JK12xDfBf4HEs=
github.com/billziss-gh/cgofuse v1.5.0/go.mod h1:LJjoaUojlVjgo5GQoEJTcJNqZJeRU0nCR84CyxKt2YM=