Adding in cache testing

Author: grantnelson-wf

build/build.go

@@ -758,25 +758,32 @@ type Session struct {
 	UpToDateArchives map[string]*compiler.Archive
 	Types            map[string]*types.Package
 	Watcher          *fsnotify.Watcher
-
-	counters map[string]int
 }
 
 func (s *Session) CounterString() string {
-	keys := make([]string, 0, len(s.counters))
+	counters := s.buildCache.Counters
+	if len(counters) == 0 {
+		return "gn-counters: no counters"
+	}
+
+	keys := make([]string, 0, len(counters))
 	width := 0
-	for k := range s.counters {
+	for k := range counters {
 		keys = append(keys, k)
 		if len(k) > width {
 			width = len(k)
 		}
 	}
 	sort.Strings(keys)
-	b := &strings.Builder{}
-	for _, k := range keys {
-		fmt.Fprintf(b, "gn-counters: %-*s\t%d\n", width, k, s.counters[k])
+
+	buf := &strings.Builder{}
+	for i, k := range keys {
+		if i > 0 {
+			fmt.Fprint(buf, "\n")
+		}
+		fmt.Fprintf(buf, "gn-counters: %-*s\t%d", width, k, counters[k])
 	}
-	return b.String()
+	return buf.String()
 }
 
 // NewSession creates a new GopherJS build session.
@@ -786,7 +793,6 @@ func NewSession(options *Options) (*Session, error) {
 	s := &Session{
 		options:          options,
 		UpToDateArchives: make(map[string]*compiler.Archive),
-		counters:         map[string]int{},
 	}
 	s.xctx = NewBuildContext(s.InstallSuffix(), s.options.BuildTags)
 	env := s.xctx.Env()
@@ -804,6 +810,7 @@ func NewSession(options *Options) (*Session, error) {
 		BuildTags:     append([]string{}, env.BuildTags...),
 		Minify:        options.Minify,
 		TestedPackage: options.TestedPackage,
+		Counters:      map[string]int{},
 	}
 	s.Types = make(map[string]*types.Package)
 	if options.Watch {
@@ -1003,15 +1010,13 @@ func (s *Session) BuildPackage(pkg *PackageData) (*compiler.Archive, error) {
 				if err := archive.RegisterTypes(s.Types); err != nil {
 					panic(fmt.Errorf("failed to load type information from %v: %w", archive, err))
 				}
-				s.counters["cache hit"]++
+				s.buildCache.Counters["cache hit"]++
 				s.UpToDateArchives[pkg.ImportPath] = archive
 				// Existing archive is up to date, no need to build it from scratch.
 				return archive, nil
 			} else {
-				s.counters["cache old"]++
+				s.buildCache.Counters["cache old"]++
 			}
-		} else {
-			s.counters["cache miss"]++
 		}
 	}
 

build/cache/cache.go

@@ -82,6 +82,8 @@ type BuildCache struct {
 	// may be imported by other packages in the binary we can't reuse the "normal"
 	// cache.
 	TestedPackage string
+
+	Counters map[string]int
 }
 
 func (bc BuildCache) String() string {
@@ -97,17 +99,20 @@ func (bc *BuildCache) StoreArchive(a *compiler.Archive) {
 	path := cachedPath(bc.archiveKey(a.ImportPath))
 	if err := os.MkdirAll(filepath.Dir(path), 0o750); err != nil {
 		log.Warningf("Failed to create build cache directory: %v", err)
+		bc.Counters["failed to make cache dir"]++
 		return
 	}
 	// Write the archive in a temporary file first to avoid concurrency errors.
 	f, err := os.CreateTemp(filepath.Dir(path), filepath.Base(path))
 	if err != nil {
 		log.Warningf("Failed to temporary build cache file: %v", err)
+		bc.Counters["failed to create temp cache file"]++
 		return
 	}
 	defer f.Close()
 	if err := compiler.WriteArchive(a, f); err != nil {
 		log.Warningf("Failed to write build cache archive %q: %v", a, err)
+		bc.Counters["failed to write temp cache file"]++
 		// Make sure we don't leave a half-written archive behind.
 		os.Remove(f.Name())
 		return
@@ -116,8 +121,10 @@ func (bc *BuildCache) StoreArchive(a *compiler.Archive) {
 	// Rename fully written file into its permanent name.
 	if err := os.Rename(f.Name(), path); err != nil {
 		log.Warningf("Failed to rename build cache archive to %q: %v", path, err)
+		bc.Counters["failed to move cache file"]++
 	}
 	log.Infof("Successfully stored build archive %q as %q.", a, path)
+	bc.Counters["wrote cache file"]++
 }
 
 // LoadArchive returns a previously cached archive of the given package or nil
@@ -133,18 +140,22 @@ func (bc *BuildCache) LoadArchive(importPath string) *compiler.Archive {
 	f, err := os.Open(path)
 	if err != nil {
 		if os.IsNotExist(err) {
+			bc.Counters["cache miss"]++
 			log.Infof("No cached package archive for %q.", importPath)
 		} else {
+			bc.Counters["error opening cache file"]++
 			log.Warningf("Failed to open cached package archive for %q: %v", importPath, err)
 		}
 		return nil // Cache miss.
 	}
 	defer f.Close()
 	a, err := compiler.ReadArchive(importPath, f)
 	if err != nil {
+		bc.Counters["failed to read cache file"]++
 		log.Warningf("Failed to read cached package archive for %q: %v", importPath, err)
 		return nil // Invalid/corrupted archive, cache miss.
 	}
+	bc.Counters["cache file loaded"]++
 	log.Infof("Found cached package archive for %q, built at %v.", importPath, a.BuildTime)
 	return a
 }

tool.go

@@ -54,15 +54,25 @@ func (s *timeKeeper) Mark(name string) {
 }
 
 func (s *timeKeeper) String() string {
+	if len(s.durNames) == 0 {
+		return "gn-timeKeeper: no times"
+	}
+
 	width := 0
 	for _, name := range s.durNames {
 		if len(name) > width {
 			width = len(name)
 		}
 	}
 	buf := &bytes.Buffer{}
+	var priorDur time.Duration
 	for i, name := range s.durNames {
-		fmt.Fprintf(buf, "gn-timeKeeper: %-*s\t%s\n", width, name, s.durations[i])
+		if i == 0 {
+			fmt.Fprintf(buf, "gn-timeKeeper: %-*s\t%s", width, name, s.durations[i])
+		} else {
+			fmt.Fprintf(buf, "\ngn-timeKeeper: %-*s\t%s\t+%s", width, name, s.durations[i], s.durations[i]-priorDur)
+		}
+		priorDur = s.durations[i]
 	}
 	return buf.String()
 }
@@ -460,8 +470,12 @@ func main() {
 				return err
 			}
 			tK.Mark("write command")
+
+			fmt.Println("---[build stats]---")
+			fmt.Println(pkg.ImportPath)
 			fmt.Println(tK.String())
 			fmt.Println(s.CounterString())
+			fmt.Println("-------------------")
 
 			if *compileOnly {
 				continue