[dev.ssa] cmd/compile: enhance command line option processing for SSA

The -d compiler flag can also specify ssa phase and flag,
for example -d=ssa/generic_cse/time,ssa/generic_cse/stats

Spaces in the phase names can be specified with an
underscore.  Flags currently parsed (not necessarily
recognized by the phases yet) are:

   on, off, mem, time, debug, stats, and test

On, off and time are handled in the harness,
debug, stats, and test are interpreted by the phase itself.

The pass is now attached to the Func being compiled, and a
new method logStats(key, ...value) on *Func to encourage a
semi-standardized format for that output.  Output fields
are separated by tabs to ease digestion by awk and
spreadsheets.  For example,
	if f.pass.stats > 0 {
		f.logStat("CSE REWRITES", rewrites)
	}

Change-Id: I16db2b5af64c50ca9a47efeb51d961147a903abc
Reviewed-on: https://go-review.googlesource.com/19885
Reviewed-by: Keith Randall <khr@golang.org>
Reviewed-by: Todd Neal <todd@tneal.org>

src/cmd/compile/internal/gc/lex.go

@@ -55,7 +55,6 @@ var debugtab = []struct {
 	{"typeassert", &Debug_typeassert}, // print information about type assertion inlining
 	{"wb", &Debug_wb},                 // print information about write barriers
 	{"export", &Debug_export},         // print export data
-	{"ssa", &ssa.Debug},               // ssa debugging flag
 }
 
 const (
@@ -286,6 +285,23 @@ func Main() {
 					}
 				}
 			}
+			// special case for ssa for now
+			if strings.HasPrefix(name, "ssa/") {
+				// expect form ssa/phase/flag
+				// e.g. -d=ssa/generic_cse/time
+				// _ in phase name also matches space
+				phase := name[4:]
+				flag := "debug" // default flag is debug
+				if i := strings.Index(phase, "/"); i >= 0 {
+					flag = phase[i+1:]
+					phase = phase[:i]
+				}
+				err := ssa.PhaseOption(phase, flag, val)
+				if err != "" {
+					log.Fatalf(err)
+				}
+				continue Split
+			}
 			log.Fatalf("unknown debug key -d %s\n", name)
 		}
 	}

src/cmd/compile/internal/gc/ssa.go

@@ -6,7 +6,6 @@ package gc
 
 import (
 	"bytes"
-	"crypto/sha1"
 	"fmt"
 	"html"
 	"math"
@@ -24,6 +23,15 @@ const minZeroPage = 4096
 var ssaConfig *ssa.Config
 var ssaExp ssaExport
 
+func initssa() *ssa.Config {
+	ssaExp.unimplemented = false
+	ssaExp.mustImplement = true
+	if ssaConfig == nil {
+		ssaConfig = ssa.NewConfig(Thearch.Thestring, &ssaExp, Ctxt, Debug['N'] == 0)
+	}
+	return ssaConfig
+}
+
 func shouldssa(fn *Node) bool {
 	if Thearch.Thestring != "amd64" {
 		return false
@@ -67,42 +75,7 @@ func shouldssa(fn *Node) bool {
 		return localpkg.Name == pkg
 	}
 
-	gossahash := os.Getenv("GOSSAHASH")
+	return initssa().DebugHashMatch("GOSSAHASH", name)
-	if gossahash == "" || gossahash == "y" || gossahash == "Y" {
-		return true
-	}
-	if gossahash == "n" || gossahash == "N" {
-		return false
-	}
-
-	// Check the hash of the name against a partial input hash.
-	// We use this feature to do a binary search within a package to
-	// find a function that is incorrectly compiled.
-	hstr := ""
-	for _, b := range sha1.Sum([]byte(name)) {
-		hstr += fmt.Sprintf("%08b", b)
-	}
-
-	if strings.HasSuffix(hstr, gossahash) {
-		fmt.Printf("GOSSAHASH triggered %s\n", name)
-		return true
-	}
-
-	// Iteratively try additional hashes to allow tests for multi-point
-	// failure.
-	for i := 0; true; i++ {
-		ev := fmt.Sprintf("GOSSAHASH%d", i)
-		evv := os.Getenv(ev)
-		if evv == "" {
-			break
-		}
-		if strings.HasSuffix(hstr, evv) {
-			fmt.Printf("%s triggered %s\n", ev, name)
-			return true
-		}
-	}
-
-	return false
 }
 
 // buildssa builds an SSA function.
@@ -123,12 +96,8 @@ func buildssa(fn *Node) *ssa.Func {
 	// TODO(khr): build config just once at the start of the compiler binary
 
 	ssaExp.log = printssa
-	ssaExp.unimplemented = false
+
-	ssaExp.mustImplement = true
+	s.config = initssa()
-	if ssaConfig == nil {
-		ssaConfig = ssa.NewConfig(Thearch.Thestring, &ssaExp, Ctxt, Debug['N'] == 0)
-	}
-	s.config = ssaConfig
 	s.f = s.config.NewFunc()
 	s.f.Name = name
 	s.exitCode = fn.Func.Exit

src/cmd/compile/internal/ssa/compile.go

@@ -8,11 +8,10 @@ import (
 	"fmt"
 	"log"
 	"runtime"
+	"strings"
 	"time"
 )
 
-var Debug int
-
 // Compile is the main entry point for this package.
 // Compile modifies f so that on return:
 //   · all Values in f map to 0 or 1 assembly instructions of the target architecture
@@ -47,22 +46,23 @@ func Compile(f *Func) {
 		if !f.Config.optimize && !p.required {
 			continue
 		}
+		f.pass = &p
 		phaseName = p.name
 		if f.Log() {
 			f.Logf("  pass %s begin\n", p.name)
 		}
 		// TODO: capture logging during this pass, add it to the HTML
 		var mStart runtime.MemStats
-		if logMemStats {
+		if logMemStats || p.mem {
 			runtime.ReadMemStats(&mStart)
 		}
 
 		tStart := time.Now()
 		p.fn(f)
+		tEnd := time.Now()
 
+		// Need something less crude than "Log the whole intermediate result".
 		if f.Log() || f.Config.HTML != nil {
-			tEnd := time.Now()
-
 			time := tEnd.Sub(tStart).Nanoseconds()
 			var stats string
 			if logMemStats {
@@ -79,6 +79,20 @@ func Compile(f *Func) {
 			printFunc(f)
 			f.Config.HTML.WriteFunc(fmt.Sprintf("after %s <span class=\"stats\">%s</span>", phaseName, stats), f)
 		}
+		if p.time || p.mem {
+			// Surround timing information w/ enough context to allow comparisons.
+			time := tEnd.Sub(tStart).Nanoseconds()
+			if p.time {
+				f.logStat("TIME(ns)", time)
+			}
+			if p.mem {
+				var mEnd runtime.MemStats
+				runtime.ReadMemStats(&mEnd)
+				nBytes := mEnd.TotalAlloc - mStart.TotalAlloc
+				nAllocs := mEnd.Mallocs - mStart.Mallocs
+				f.logStat("TIME(ns):BYTES:ALLOCS", time, nBytes, nAllocs)
+			}
+		}
 		checkFunc(f)
 	}
 
@@ -90,39 +104,84 @@ type pass struct {
 	name     string
 	fn       func(*Func)
 	required bool
+	disabled bool
+	time     bool // report time to run pass
+	mem      bool // report mem stats to run pass
+	stats    int  // pass reports own "stats" (e.g., branches removed)
+	debug    int  // pass performs some debugging. =1 should be in error-testing-friendly Warnl format.
+	test     int  // pass-specific ad-hoc option, perhaps useful in development
+}
+
+// PhaseOption sets the specified flag in the specified ssa phase,
+// returning empty string if this was successful or a string explaining
+// the error if it was not.  A version of the phase name with "_"
+// replaced by " " is also checked for a match.
+// See gc/lex.go for dissection of the option string.  Example use:
+// GO_GCFLAGS=-d=ssa/generic_cse/time,ssa/generic_cse/stats,ssa/generic_cse/debug=3 ./make.bash ...
+//
+func PhaseOption(phase, flag string, val int) string {
+	underphase := strings.Replace(phase, "_", " ", -1)
+	for i, p := range passes {
+		if p.name == phase || p.name == underphase {
+			switch flag {
+			case "on":
+				p.disabled = val == 0
+			case "off":
+				p.disabled = val != 0
+			case "time":
+				p.time = val != 0
+			case "mem":
+				p.mem = val != 0
+			case "debug":
+				p.debug = val
+			case "stats":
+				p.stats = val
+			case "test":
+				p.test = val
+			default:
+				return fmt.Sprintf("Did not find a flag matching %s in -d=ssa/%s debug option", flag, phase)
+			}
+			if p.disabled && p.required {
+				return fmt.Sprintf("Cannot disable required SSA phase %s using -d=ssa/%s debug option", phase, phase)
+			}
+			passes[i] = p
+			return ""
+		}
+	}
+	return fmt.Sprintf("Did not find a phase matching %s in -d=ssa/... debug option", phase)
 }
 
 // list of passes for the compiler
 var passes = [...]pass{
 	// TODO: combine phielim and copyelim into a single pass?
-	{"early phielim", phielim, false},
+	{name: "early phielim", fn: phielim},
-	{"early copyelim", copyelim, false},
+	{name: "early copyelim", fn: copyelim},
-	{"early deadcode", deadcode, false}, // remove generated dead code to avoid doing pointless work during opt
+	{name: "early deadcode", fn: deadcode}, // remove generated dead code to avoid doing pointless work during opt
-	{"short circuit", shortcircuit, false},
+	{name: "short circuit", fn: shortcircuit},
-	{"decompose user", decomposeUser, true},
+	{name: "decompose user", fn: decomposeUser, required: true},
-	{"decompose builtin", decomposeBuiltIn, true},
+	{name: "decompose builtin", fn: decomposeBuiltIn, required: true},
-	{"opt", opt, true},                // TODO: split required rules and optimizing rules
+	{name: "opt", fn: opt, required: true},           // TODO: split required rules and optimizing rules
-	{"zero arg cse", zcse, true},      // required to merge OpSB values
+	{name: "zero arg cse", fn: zcse, required: true}, // required to merge OpSB values
-	{"opt deadcode", deadcode, false}, // remove any blocks orphaned during opt
+	{name: "opt deadcode", fn: deadcode},             // remove any blocks orphaned during opt
-	{"generic cse", cse, false},
+	{name: "generic cse", fn: cse},
-	{"nilcheckelim", nilcheckelim, false},
+	{name: "nilcheckelim", fn: nilcheckelim},
-	{"generic deadcode", deadcode, false},
+	{name: "generic deadcode", fn: deadcode},
-	{"fuse", fuse, false},
+	{name: "fuse", fn: fuse},
-	{"dse", dse, false},
+	{name: "dse", fn: dse},
-	{"tighten", tighten, false}, // move values closer to their uses
+	{name: "tighten", fn: tighten}, // move values closer to their uses
-	{"lower", lower, true},
+	{name: "lower", fn: lower, required: true},
-	{"lowered cse", cse, false},
+	{name: "lowered cse", fn: cse},
-	{"lowered deadcode", deadcode, true},
+	{name: "lowered deadcode", fn: deadcode, required: true},
-	{"checkLower", checkLower, true},
+	{name: "checkLower", fn: checkLower, required: true},
-	{"late phielim", phielim, false},
+	{name: "late phielim", fn: phielim},
-	{"late copyelim", copyelim, false},
+	{name: "late copyelim", fn: copyelim},
-	{"late deadcode", deadcode, false},
+	{name: "late deadcode", fn: deadcode},
-	{"critical", critical, true},   // remove critical edges
+	{name: "critical", fn: critical, required: true},   // remove critical edges
-	{"layout", layout, true},       // schedule blocks
+	{name: "layout", fn: layout, required: true},       // schedule blocks
-	{"schedule", schedule, true},   // schedule values
+	{name: "schedule", fn: schedule, required: true},   // schedule values
-	{"flagalloc", flagalloc, true}, // allocate flags register
+	{name: "flagalloc", fn: flagalloc, required: true}, // allocate flags register
-	{"regalloc", regalloc, true},   // allocate int & float registers + stack slots
+	{name: "regalloc", fn: regalloc, required: true},   // allocate int & float registers + stack slots
-	{"trim", trim, false},          // remove empty blocks
+	{name: "trim", fn: trim},                           // remove empty blocks
 }
 
 // Double-check phase ordering constraints.

src/cmd/compile/internal/ssa/config.go

@@ -4,7 +4,13 @@
 
 package ssa
 
-import "cmd/internal/obj"
+import (
+	"cmd/internal/obj"
+	"crypto/sha1"
+	"fmt"
+	"os"
+	"strings"
+)
 
 type Config struct {
 	arch       string                     // "amd64", etc.
@@ -20,6 +26,10 @@ type Config struct {
 
 	// TODO: more stuff.  Compiler flags of interest, ...
 
+	// Given an environment variable used for debug hash match,
+	// what file (if any) receives the yes/no logging?
+	logfiles map[string]*os.File
+
 	// Storage for low-numbered values and blocks.
 	values [2000]Value
 	blocks [200]Block
@@ -120,6 +130,8 @@ func NewConfig(arch string, fe Frontend, ctxt *obj.Link, optimize bool) *Config
 		c.blocks[i].ID = ID(i)
 	}
 
+	c.logfiles = make(map[string]*os.File)
+
 	return c
 }
 
@@ -145,3 +157,79 @@ func (c *Config) Unimplementedf(line int32, msg string, args ...interface{}) {
 }
 func (c *Config) Warnl(line int, msg string, args ...interface{}) { c.fe.Warnl(line, msg, args...) }
 func (c *Config) Debug_checknil() bool                            { return c.fe.Debug_checknil() }
+
+func (c *Config) logDebugHashMatch(evname, name string) {
+	var file *os.File
+	file = c.logfiles[evname]
+	if file == nil {
+		file = os.Stdout
+		tmpfile := os.Getenv("GSHS_LOGFILE")
+		if tmpfile != "" {
+			var ok error
+			file, ok = os.Create(tmpfile)
+			if ok != nil {
+				c.Fatalf(0, "Could not open hash-testing logfile %s", tmpfile)
+			}
+		}
+		c.logfiles[evname] = file
+	}
+	s := fmt.Sprintf("%s triggered %s\n", evname, name)
+	file.WriteString(s)
+	file.Sync()
+}
+
+// DebugHashMatch returns true if environment variable evname
+// 1) is empty (this is a special more-quickly implemented case of 3)
+// 2) is "y" or "Y"
+// 3) is a suffix of the sha1 hash of name
+// 4) is a suffix of the environment variable
+//    fmt.Sprintf("%s%d", evname, n)
+//    provided that all such variables are nonempty for 0 <= i <= n
+// Otherwise it returns false.
+// When true is returned the message
+//  "%s triggered %s\n", evname, name
+// is printed on the file named in environment variable
+//  GSHS_LOGFILE
+// or standard out if that is empty or there is an error
+// opening the file.
+
+func (c *Config) DebugHashMatch(evname, name string) bool {
+	evhash := os.Getenv(evname)
+	if evhash == "" {
+		return true // default behavior with no EV is "on"
+	}
+	if evhash == "y" || evhash == "Y" {
+		c.logDebugHashMatch(evname, name)
+		return true
+	}
+	if evhash == "n" || evhash == "N" {
+		return false
+	}
+	// Check the hash of the name against a partial input hash.
+	// We use this feature to do a binary search to
+	// find a function that is incorrectly compiled.
+	hstr := ""
+	for _, b := range sha1.Sum([]byte(name)) {
+		hstr += fmt.Sprintf("%08b", b)
+	}
+
+	if strings.HasSuffix(hstr, evhash) {
+		c.logDebugHashMatch(evname, name)
+		return true
+	}
+
+	// Iteratively try additional hashes to allow tests for multi-point
+	// failure.
+	for i := 0; true; i++ {
+		ev := fmt.Sprintf("%s%d", evname, i)
+		evv := os.Getenv(ev)
+		if evv == "" {
+			break
+		}
+		if strings.HasSuffix(hstr, evv) {
+			c.logDebugHashMatch(ev, name)
+			return true
+		}
+	}
+	return false
+}

src/cmd/compile/internal/ssa/cse.go

@@ -61,7 +61,7 @@ func cse(f *Func) {
 		}
 	}
 	for i, e := range partition {
-		if Debug > 1 && len(e) > 500 {
+		if f.pass.debug > 1 && len(e) > 500 {
 			fmt.Printf("CSE.large partition (%d): ", len(e))
 			for j := 0; j < 3; j++ {
 				fmt.Printf("%s ", e[j].LongString())
@@ -72,7 +72,7 @@ func cse(f *Func) {
 		for _, v := range e {
 			valueEqClass[v.ID] = ID(i)
 		}
-		if Debug > 2 && len(e) > 1 {
+		if f.pass.debug > 2 && len(e) > 1 {
 			fmt.Printf("CSE.partition #%d:", i)
 			for _, v := range e {
 				fmt.Printf(" %s", v.String())
@@ -163,7 +163,7 @@ func cse(f *Func) {
 		}
 	}
 
-	rewrites := 0
+	rewrites := int64(0)
 
 	// Apply substitutions
 	for _, b := range f.Blocks {
@@ -186,8 +186,8 @@ func cse(f *Func) {
 			}
 		}
 	}
-	if Debug > 0 && rewrites > 0 {
+	if f.pass.stats > 0 {
-		fmt.Printf("CSE: %d rewrites\n", rewrites)
+		f.logStat("CSE REWRITES", rewrites)
 	}
 }
 

src/cmd/compile/internal/ssa/func.go

@@ -4,12 +4,16 @@
 
 package ssa
 
-import "math"
+import (
+	"fmt"
+	"math"
+)
 
 // A Func represents a Go func declaration (or function literal) and
 // its body.  This package compiles each Func independently.
 type Func struct {
 	Config     *Config     // architecture information
+	pass       *pass       // current pass information (name, options, etc.)
 	Name       string      // e.g. bytes·Compare
 	Type       Type        // type signature of the function.
 	StaticData interface{} // associated static data, untouched by the ssa package
@@ -89,6 +93,20 @@ func (f *Func) newValue(op Op, t Type, b *Block, line int32) *Value {
 	return v
 }
 
+// logPassStat writes a string key and int value as a warning in a
+// tab-separated format easily handled by spreadsheets or awk.
+// file names, lines, and function names are included to provide enough (?)
+// context to allow item-by-item comparisons across runs.
+// For example:
+// awk 'BEGIN {FS="\t"} $3~/TIME/{sum+=$4} END{print "t(ns)=",sum}' t.log
+func (f *Func) logStat(key string, args ...interface{}) {
+	value := ""
+	for _, a := range args {
+		value += fmt.Sprintf("\t%v", a)
+	}
+	f.Config.Warnl(int(f.Entry.Line), "\t%s\t%s%s\t%s", f.pass.name, key, value, f.Name)
+}
+
 // freeValue frees a value.  It must no longer be referenced.
 func (f *Func) freeValue(v *Value) {
 	if v.Block == nil {

src/cmd/compile/internal/ssa/func_test.go

@@ -134,12 +134,18 @@ type fun struct {
 	values map[string]*Value
 }
 
+var emptyPass pass = pass{
+	name: "empty pass",
+}
+
 // Fun takes the name of an entry bloc and a series of Bloc calls, and
 // returns a fun containing the composed Func. entry must be a name
 // supplied to one of the Bloc functions. Each of the bloc names and
 // valu names should be unique across the Fun.
 func Fun(c *Config, entry string, blocs ...bloc) fun {
 	f := c.NewFunc()
+	f.pass = &emptyPass
+
 	blocks := make(map[string]*Block)
 	values := make(map[string]*Value)
 	// Create all the blocks and values.