benchmark: move bulkstatting to separate binary.

This makes CFuse and go-fuse easier to compare.  Get rid of the
baroque analysis code, unused delay code, and some general cleanup.

benchmark/Makefile

 cstatfs: statfs.cc
 	g++ -O2 -Wall -std=c++0x $< `pkg-config fuse --cflags --libs` -o $@
+
+bulkstat.bin: bulkstat/main.go
+	(cd bulkstat && go build main.go)
+	cp bulkstat/main $@

benchmark/benchmark.go

@@ -4,13 +4,8 @@ package benchmark
 
 import (
 	"bufio"
-	"fmt"
 	"log"
-	"math"
 	"os"
-	"regexp"
-	"sort"
-	"time"
 )
 
 func ReadLines(name string) []string {
@@ -37,101 +32,3 @@ func ReadLines(name string) []string {
 
 	return l
 }
-
-// Used for benchmarking.  Returns milliseconds.
-func BulkStat(parallelism int, files []string) float64 {
-	todo := make(chan string, len(files))
-	dts := make(chan time.Duration, parallelism)
-	for i := 0; i < parallelism; i++ {
-		go func() {
-			t := time.Now()
-			for {
-				fn := <-todo
-				if fn == "" {
-					break
-				}
-
-				_, err := os.Lstat(fn)
-				if err != nil {
-					log.Fatal("All stats should succeed:", err)
-				}
-			}
-			dts <- time.Now().Sub(t)
-		}()
-	}
-
-	for _, v := range files {
-		todo <- v
-	}
-	close(todo)
-
-	total := 0.0
-	for i := 0; i < parallelism; i++ {
-		total += float64(<-dts) / float64(time.Millisecond)
-	}
-
-	avg := total / float64(len(files))
-
-	return avg
-}
-
-func AnalyzeBenchmarkRuns(label string, times []float64) {
-	sorted := times
-	sort.Float64s(sorted)
-
-	tot := 0.0
-	for _, v := range times {
-		tot += v
-	}
-	n := float64(len(times))
-
-	avg := tot / n
-	variance := 0.0
-	for _, v := range times {
-		variance += (v - avg) * (v - avg)
-	}
-	variance /= n
-
-	stddev := math.Sqrt(variance)
-
-	median := sorted[len(times)/2]
-	perc90 := sorted[int(n*0.9)]
-	perc10 := sorted[int(n*0.1)]
-
-	if VerboseTest() {
-		fmt.Printf(
-			"%s: %d samples\n"+
-				"avg %.3fms +/- %.0f%% "+
-				"median %.3fms, 10%%tiles: [-%.0f%%, +%.0f%%]\n",
-			label,
-			len(times), avg, 100.0*2*stddev/avg,
-			median, 100*(median-perc10)/median, 100*(perc90-median)/median)
-	}
-}
-
-func RunBulkStat(runs int, threads int, sleepTime time.Duration, files []string) (results []float64) {
-	for j := 0; j < runs; j++ {
-		result := BulkStat(threads, files)
-		results = append(results, result)
-
-		if j < runs-1 {
-			fmt.Printf("Sleeping %d seconds\n", sleepTime)
-			time.Sleep(sleepTime)
-		}
-	}
-	return results
-}
-
-func CountCpus() int {
-	var contents [10240]byte
-
-	f, err := os.Open("/proc/stat")
-	defer f.Close()
-	if err != nil {
-		return 1
-	}
-	n, _ := f.Read(contents[:])
-	re, _ := regexp.Compile("\ncpu[0-9]")
-
-	return len(re.FindAllString(string(contents[:n]), 100))
-}

benchmark/bulkstat/main.go

+package main
+
+import (
+	"bufio"
+	"flag"
+	"log"
+	"os"
+	"path/filepath"
+	"sync"
+)
+
+func BulkStat(parallelism int, files []string) {
+	todo := make(chan string, len(files))
+	var wg sync.WaitGroup
+	wg.Add(parallelism)
+	for i := 0; i < parallelism; i++ {
+		go func() {
+			for {
+				fn := <-todo
+				if fn == "" {
+					break
+				}
+				_, err := os.Lstat(fn)
+				if err != nil {
+					log.Fatal("All stats should succeed:", err)
+				}
+			}
+			wg.Done()
+		}()
+	}
+
+	for _, v := range files {
+		todo <- v
+	}
+	close(todo)
+	wg.Wait()
+}
+
+func ReadLines(name string) []string {
+	f, err := os.Open(name)
+	if err != nil {
+		log.Fatal("ReadLines: ", err)
+	}
+	defer f.Close()
+	r := bufio.NewReader(f)
+
+	l := []string{}
+	for {
+		line, _, err := r.ReadLine()
+		if line == nil || err != nil {
+			break
+		}
+
+		fn := string(line)
+		l = append(l, fn)
+	}
+	if len(l) == 0 {
+		log.Fatal("no files added")
+	}
+
+	return l
+}
+
+func main() {
+	N := flag.Int("N", 1000, "how many files to stat")
+	cpu := flag.Int("cpu", 1, "how many threads to use")
+	prefix := flag.String("prefix", "", "mount point")
+	quiet := flag.Bool("quiet", false, "be quiet")
+	flag.Parse()
+
+	f := flag.Arg(0)
+	files := ReadLines(f)
+	for i, f := range files {
+		files[i] = filepath.Join(*prefix, f)
+	}
+	if !*quiet {
+		log.Printf("statting %d with %d threads; first file %s (%d names)", *N, *cpu, files[0], len(files))
+	}
+	todo := *N
+	for todo > 0 {
+		if len(files) > todo {
+			files = files[:todo]
+		}
+		BulkStat(*cpu, files)
+		todo -= len(files)
+	}
+}

benchmark/stat_test.go

@@ -24,7 +24,7 @@ func VerboseTest() bool {
 	return flag != nil && flag.Value.String() == "true"
 }
 
-func setupFs(fs pathfs.FileSystem) (string, func()) {
+func setupFs(fs pathfs.FileSystem, N int) (string, func()) {
 	opts := &nodefs.Options{
 		EntryTimeout:    0.0,
 		AttrTimeout:     0.0,
@@ -44,14 +44,18 @@ func setupFs(fs pathfs.FileSystem) (string, func()) {
 
 	return mountPoint, func() {
 		if VerboseTest() {
+			var total time.Duration
 			for _, n := range []string{"LOOKUP", "GETATTR", "OPENDIR", "READDIR",
-				"READDIRPLUS",
+				"READDIRPLUS", "RELEASEDIR", "FLUSH",
 			} {
 				if count, dt := lmap.Get(n); count > 0 {
+					total += dt
 					log.Printf("%s %v/call n=%d", n,
 						dt/time.Duration(count), count)
 				}
 			}
+
+			log.Printf("total %v, %v/bench op", total, total/time.Duration(N))
 		}
 
 		err := state.Unmount()
@@ -60,19 +64,18 @@ func setupFs(fs pathfs.FileSystem) (string, func()) {
 		} else {
 			os.RemoveAll(mountPoint)
 		}
-
 	}
 }
 
 func TestNewStatFs(t *testing.T) {
-	fs := NewStatFs()
+	fs := NewStatFS()
 	for _, n := range []string{
 		"file.txt", "sub/dir/foo.txt",
 		"sub/dir/bar.txt", "sub/marine.txt"} {
 		fs.AddFile(n)
 	}
 
-	wd, clean := setupFs(fs)
+	wd, clean := setupFs(fs, 1)
 	defer clean()
 
 	names, err := ioutil.ReadDir(wd)
@@ -114,18 +117,18 @@ func TestNewStatFs(t *testing.T) {
 	}
 }
 
-func BenchmarkGoFuseThreadedStat(b *testing.B) {
+func BenchmarkGoFuseStat(b *testing.B) {
 	b.StopTimer()
-	fs := NewStatFs()
-	fs.delay = delay
+	fs := NewStatFS()
 
 	wd, _ := os.Getwd()
-	files := ReadLines(wd + "/testpaths.txt")
+	fileList := wd + "/testpaths.txt"
+	files := ReadLines(fileList)
 	for _, fn := range files {
 		fs.AddFile(fn)
 	}
 
-	wd, clean := setupFs(fs)
+	wd, clean := setupFs(fs, b.N)
 	defer clean()
 
 	for i, l := range files {
@@ -133,7 +136,9 @@ func BenchmarkGoFuseThreadedStat(b *testing.B) {
 	}
 
 	threads := runtime.GOMAXPROCS(0)
-	TestingBOnePass(b, threads, files)
+	if err := TestingBOnePass(b, threads, fileList, wd); err != nil {
+		log.Fatalf("TestingBOnePass %v8", err)
+	}
 }
 
 func readdir(d string) error {
@@ -149,8 +154,7 @@ func readdir(d string) error {
 
 func BenchmarkGoFuseReaddir(b *testing.B) {
 	b.StopTimer()
-	fs := NewStatFs()
-	fs.delay = delay
+	fs := NewStatFS()
 
 	wd, _ := os.Getwd()
 	dirSet := map[string]struct{}{}
@@ -160,7 +164,7 @@ func BenchmarkGoFuseReaddir(b *testing.B) {
 		dirSet[filepath.Dir(fn)] = struct{}{}
 	}
 
-	wd, clean := setupFs(fs)
+	wd, clean := setupFs(fs, b.N)
 	defer clean()
 
 	var dirs []string
@@ -183,30 +187,37 @@ func BenchmarkGoFuseReaddir(b *testing.B) {
 	b.StopTimer()
 }
 
-func TestingBOnePass(b *testing.B, threads int, files []string) (results []float64) {
+func TestingBOnePass(b *testing.B, threads int, filelist, mountPoint string) error {
 	runtime.GC()
 	var before, after runtime.MemStats
 	runtime.ReadMemStats(&before)
 
+	// We shell out to an external program, so the time spent by
+	// the part stat'ing doesn't interfere with the time spent by
+	// the FUSE server.
+	cmd := exec.Command("./bulkstat.bin",
+		fmt.Sprintf("-cpu=%d", threads),
+		fmt.Sprintf("-prefix=%s", mountPoint),
+		fmt.Sprintf("-N=%d", b.N),
+		fmt.Sprintf("-quiet=%v", !VerboseTest()),
+		filelist)
+
+	cmd.Stdout = os.Stdout
+	cmd.Stderr = os.Stderr
+
 	b.StartTimer()
-	todo := b.N
-	for todo > 0 {
-		if len(files) > todo {
-			files = files[:todo]
-		}
-		result := BulkStat(threads, files)
-		todo -= len(files)
-		results = append(results, result)
-	}
+	err := cmd.Run()
 	b.StopTimer()
 	runtime.ReadMemStats(&after)
+	if err != nil {
+		return err
+	}
 
 	if VerboseTest() {
 		fmt.Printf("GC count %d, total GC time: %d ns/file\n",
 			after.NumGC-before.NumGC, (after.PauseTotalNs-before.PauseTotalNs)/uint64(b.N))
-		AnalyzeBenchmarkRuns(fmt.Sprintf("Go-FUSE %d CPUs", threads), results)
 	}
-	return results
+	return nil
 }
 
 // Add this so we can estimate impact on latency numbers.
@@ -220,7 +231,8 @@ func BenchmarkCFuseThreadedStat(b *testing.B) {
 	b.StopTimer()
 
 	wd, _ := os.Getwd()
-	lines := ReadLines(wd + "/testpaths.txt")
+	fileList := wd + "/testpaths.txt"
+	lines := ReadLines(fileList)
 	unique := map[string]int{}
 	for _, l := range lines {
 		unique[l] = 1
@@ -253,8 +265,7 @@ func BenchmarkCFuseThreadedStat(b *testing.B) {
 		"entry_timeout=0.0,attr_timeout=0.0,ac_attr_timeout=0.0,negative_timeout=0.0",
 		mountPoint)
 	cmd.Env = append(os.Environ(),
-		fmt.Sprintf("STATFS_INPUT=%s", f.Name()),
-		fmt.Sprintf("STATFS_DELAY_USEC=%d", delay/time.Microsecond))
+		fmt.Sprintf("STATFS_INPUT=%s", f.Name()))
 	cmd.Start()
 
 	bin, err := exec.LookPath("fusermount")
@@ -267,13 +278,10 @@ func BenchmarkCFuseThreadedStat(b *testing.B) {
 	}
 	defer stop.Run()
 
-	for i, l := range lines {
-		lines[i] = filepath.Join(mountPoint, l)
-	}
-
 	time.Sleep(100 * time.Millisecond)
 	os.Lstat(mountPoint)
 	threads := runtime.GOMAXPROCS(0)
-	results := TestingBOnePass(b, threads, lines)
-	AnalyzeBenchmarkRuns(fmt.Sprintf("CFuse on %d CPUS", threads), results)
+	if err := TestingBOnePass(b, threads, fileList, mountPoint); err != nil {
+		log.Fatalf("TestingBOnePass %v", err)
+	}
 }

benchmark/statfs.go

@@ -3,68 +3,61 @@ package benchmark
 import (
 	"path/filepath"
 	"strings"
-	"time"
 
 	"github.com/hanwen/go-fuse/fuse"
 	"github.com/hanwen/go-fuse/fuse/pathfs"
 )
 
-var delay = 0 * time.Microsecond
-
-type StatFs struct {
+type StatFS struct {
 	pathfs.FileSystem
 	entries map[string]*fuse.Attr
 	dirs    map[string][]fuse.DirEntry
-	delay   time.Duration
 }
 
-func (me *StatFs) Add(name string, a *fuse.Attr) {
+func (fs *StatFS) Add(name string, a *fuse.Attr) {
 	name = strings.TrimRight(name, "/")
-	_, ok := me.entries[name]
+	_, ok := fs.entries[name]
 	if ok {
 		return
 	}
 
-	me.entries[name] = a
+	fs.entries[name] = a
 	if name == "/" || name == "" {
 		return
 	}
 
 	dir, base := filepath.Split(name)
 	dir = strings.TrimRight(dir, "/")
-	me.dirs[dir] = append(me.dirs[dir], fuse.DirEntry{Name: base, Mode: a.Mode})
-	me.Add(dir, &fuse.Attr{Mode: fuse.S_IFDIR | 0755})
+	fs.dirs[dir] = append(fs.dirs[dir], fuse.DirEntry{Name: base, Mode: a.Mode})
+	fs.Add(dir, &fuse.Attr{Mode: fuse.S_IFDIR | 0755})
 }
 
-func (me *StatFs) AddFile(name string) {
-	me.Add(name, &fuse.Attr{Mode: fuse.S_IFREG | 0644})
+func (fs *StatFS) AddFile(name string) {
+	fs.Add(name, &fuse.Attr{Mode: fuse.S_IFREG | 0644})
 }
 
-func (me *StatFs) GetAttr(name string, context *fuse.Context) (*fuse.Attr, fuse.Status) {
-	if d := me.dirs[name]; d != nil {
+func (fs *StatFS) GetAttr(name string, context *fuse.Context) (*fuse.Attr, fuse.Status) {
+	if d := fs.dirs[name]; d != nil {
 		return &fuse.Attr{Mode: 0755 | fuse.S_IFDIR}, fuse.OK
 	}
-	e := me.entries[name]
+	e := fs.entries[name]
 	if e == nil {
 		return nil, fuse.ENOENT
 	}
 
-	if me.delay > 0 {
-		time.Sleep(me.delay)
-	}
 	return e, fuse.OK
 }
 
-func (me *StatFs) OpenDir(name string, context *fuse.Context) (stream []fuse.DirEntry, status fuse.Status) {
-	entries := me.dirs[name]
+func (fs *StatFS) OpenDir(name string, context *fuse.Context) (stream []fuse.DirEntry, status fuse.Status) {
+	entries := fs.dirs[name]
 	if entries == nil {
 		return nil, fuse.ENOENT
 	}
 	return entries, fuse.OK
 }
 
-func NewStatFs() *StatFs {
-	return &StatFs{
+func NewStatFS() *StatFS {
+	return &StatFS{
 		FileSystem: pathfs.NewDefaultFileSystem(),
 		entries:    make(map[string]*fuse.Attr),
 		dirs:       make(map[string][]fuse.DirEntry),