...

Source file src/cmd/compile/internal/logopt/log_opts.go

Documentation: cmd/compile/internal/logopt

     1  // Copyright 2019 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package logopt
     6  
     7  import (
     8  	"cmd/internal/obj"
     9  	"cmd/internal/src"
    10  	"encoding/json"
    11  	"fmt"
    12  	"internal/buildcfg"
    13  	"io"
    14  	"log"
    15  	"net/url"
    16  	"os"
    17  	"path/filepath"
    18  	"sort"
    19  	"strconv"
    20  	"strings"
    21  	"sync"
    22  	"unicode"
    23  )
    24  
    25  // This implements (non)optimization logging for -json option to the Go compiler
    26  // The option is -json 0,<destination>.
    27  //
    28  // 0 is the version number; to avoid the need for synchronized updates, if
    29  // new versions of the logging appear, the compiler will support both, for a while,
    30  // and clients will specify what they need.
    31  //
    32  // <destination> is a directory.
    33  // Directories are specified with a leading / or os.PathSeparator,
    34  // or more explicitly with file://directory.  The second form is intended to
    35  // deal with corner cases on Windows, and to allow specification of a relative
    36  // directory path (which is normally a bad idea, because the local directory
    37  // varies a lot in a build, especially with modules and/or vendoring, and may
    38  // not be writeable).
    39  //
    40  // For each package pkg compiled, a url.PathEscape(pkg)-named subdirectory
    41  // is created.  For each source file.go in that package that generates
    42  // diagnostics (no diagnostics means no file),
    43  // a url.PathEscape(file)+".json"-named file is created and contains the
    44  // logged diagnostics.
    45  //
    46  // For example, "cmd%2Finternal%2Fdwarf/%3Cautogenerated%3E.json"
    47  // for "cmd/internal/dwarf" and <autogenerated> (which is not really a file, but the compiler sees it)
    48  //
    49  // If the package string is empty, it is replaced internally with string(0) which encodes to %00.
    50  //
    51  // Each log file begins with a JSON record identifying version,
    52  // platform, and other context, followed by optimization-relevant
    53  // LSP Diagnostic records, one per line (LSP version 3.15, no difference from 3.14 on the subset used here
    54  // see https://microsoft.github.io/language-server-protocol/specifications/specification-3-15/ )
    55  //
    56  // The fields of a Diagnostic are used in the following way:
    57  // Range: the outermost source position, for now begin and end are equal.
    58  // Severity: (always) SeverityInformation (3)
    59  // Source: (always) "go compiler"
    60  // Code: a string describing the missed optimization, e.g., "nilcheck", "cannotInline", "isInBounds", "escape"
    61  // Message: depending on code, additional information, e.g., the reason a function cannot be inlined.
    62  // RelatedInformation: if the missed optimization actually occurred at a function inlined at Range,
    63  //    then the sequence of inlined locations appears here, from (second) outermost to innermost,
    64  //    each with message="inlineLoc".
    65  //
    66  //    In the case of escape analysis explanations, after any outer inlining locations,
    67  //    the lines of the explanation appear, each potentially followed with its own inlining
    68  //    location if the escape flow occurred within an inlined function.
    69  //
    70  // For example <destination>/cmd%2Fcompile%2Finternal%2Fssa/prove.json
    71  // might begin with the following line (wrapped for legibility):
    72  //
    73  // {"version":0,"package":"cmd/compile/internal/ssa","goos":"darwin","goarch":"amd64",
    74  //  "gc_version":"devel +e1b9a57852 Fri Nov 1 15:07:00 2019 -0400",
    75  //  "file":"/Users/drchase/work/go/src/cmd/compile/internal/ssa/prove.go"}
    76  //
    77  // and later contain (also wrapped for legibility):
    78  //
    79  // {"range":{"start":{"line":191,"character":24},"end":{"line":191,"character":24}},
    80  //  "severity":3,"code":"nilcheck","source":"go compiler","message":"",
    81  //  "relatedInformation":[
    82  //    {"location":{"uri":"file:///Users/drchase/work/go/src/cmd/compile/internal/ssa/func.go",
    83  //                 "range":{"start":{"line":153,"character":16},"end":{"line":153,"character":16}}},
    84  //     "message":"inlineLoc"}]}
    85  //
    86  // That is, at prove.go (implicit from context, provided in both filename and header line),
    87  // line 191, column 24, a nilcheck occurred in the generated code.
    88  // The relatedInformation indicates that this code actually came from
    89  // an inlined call to func.go, line 153, character 16.
    90  //
    91  // prove.go:191:
    92  // 	ft.orderS = f.newPoset()
    93  // func.go:152 and 153:
    94  //  func (f *Func) newPoset() *poset {
    95  //	    if len(f.Cache.scrPoset) > 0 {
    96  //
    97  // In the case that the package is empty, the string(0) package name is also used in the header record, for example
    98  //
    99  //  go tool compile -json=0,file://logopt x.go       # no -p option to set the package
   100  //  head -1 logopt/%00/x.json
   101  //  {"version":0,"package":"\u0000","goos":"darwin","goarch":"amd64","gc_version":"devel +86487adf6a Thu Nov 7 19:34:56 2019 -0500","file":"x.go"}
   102  
   103  type VersionHeader struct {
   104  	Version   int    `json:"version"`
   105  	Package   string `json:"package"`
   106  	Goos      string `json:"goos"`
   107  	Goarch    string `json:"goarch"`
   108  	GcVersion string `json:"gc_version"`
   109  	File      string `json:"file,omitempty"` // LSP requires an enclosing resource, i.e., a file
   110  }
   111  
   112  // DocumentURI, Position, Range, Location, Diagnostic, DiagnosticRelatedInformation all reuse json definitions from gopls.
   113  // See https://github.com/golang/tools/blob/22afafe3322a860fcd3d88448768f9db36f8bc5f/internal/lsp/protocol/tsprotocol.go
   114  
   115  type DocumentURI string
   116  
   117  type Position struct {
   118  	Line      uint `json:"line"`      // gopls uses float64, but json output is the same for integers
   119  	Character uint `json:"character"` // gopls uses float64, but json output is the same for integers
   120  }
   121  
   122  // A Range in a text document expressed as (zero-based) start and end positions.
   123  // A range is comparable to a selection in an editor. Therefore the end position is exclusive.
   124  // If you want to specify a range that contains a line including the line ending character(s)
   125  // then use an end position denoting the start of the next line.
   126  type Range struct {
   127  	/*Start defined:
   128  	 * The range's start position
   129  	 */
   130  	Start Position `json:"start"`
   131  
   132  	/*End defined:
   133  	 * The range's end position
   134  	 */
   135  	End Position `json:"end"` // exclusive
   136  }
   137  
   138  // A Location represents a location inside a resource, such as a line inside a text file.
   139  type Location struct {
   140  	// URI is
   141  	URI DocumentURI `json:"uri"`
   142  
   143  	// Range is
   144  	Range Range `json:"range"`
   145  }
   146  
   147  /* DiagnosticRelatedInformation defined:
   148   * Represents a related message and source code location for a diagnostic. This should be
   149   * used to point to code locations that cause or related to a diagnostics, e.g when duplicating
   150   * a symbol in a scope.
   151   */
   152  type DiagnosticRelatedInformation struct {
   153  
   154  	/*Location defined:
   155  	 * The location of this related diagnostic information.
   156  	 */
   157  	Location Location `json:"location"`
   158  
   159  	/*Message defined:
   160  	 * The message of this related diagnostic information.
   161  	 */
   162  	Message string `json:"message"`
   163  }
   164  
   165  // DiagnosticSeverity defines constants
   166  type DiagnosticSeverity uint
   167  
   168  const (
   169  	/*SeverityInformation defined:
   170  	 * Reports an information.
   171  	 */
   172  	SeverityInformation DiagnosticSeverity = 3
   173  )
   174  
   175  // DiagnosticTag defines constants
   176  type DiagnosticTag uint
   177  
   178  /*Diagnostic defined:
   179   * Represents a diagnostic, such as a compiler error or warning. Diagnostic objects
   180   * are only valid in the scope of a resource.
   181   */
   182  type Diagnostic struct {
   183  
   184  	/*Range defined:
   185  	 * The range at which the message applies
   186  	 */
   187  	Range Range `json:"range"`
   188  
   189  	/*Severity defined:
   190  	 * The diagnostic's severity. Can be omitted. If omitted it is up to the
   191  	 * client to interpret diagnostics as error, warning, info or hint.
   192  	 */
   193  	Severity DiagnosticSeverity `json:"severity,omitempty"` // always SeverityInformation for optimizer logging.
   194  
   195  	/*Code defined:
   196  	 * The diagnostic's code, which usually appear in the user interface.
   197  	 */
   198  	Code string `json:"code,omitempty"` // LSP uses 'number | string' = gopls interface{}, but only string here, e.g. "boundsCheck", "nilcheck", etc.
   199  
   200  	/*Source defined:
   201  	 * A human-readable string describing the source of this
   202  	 * diagnostic, e.g. 'typescript' or 'super lint'. It usually
   203  	 * appears in the user interface.
   204  	 */
   205  	Source string `json:"source,omitempty"` // "go compiler"
   206  
   207  	/*Message defined:
   208  	 * The diagnostic's message. It usually appears in the user interface
   209  	 */
   210  	Message string `json:"message"` // sometimes used, provides additional information.
   211  
   212  	/*Tags defined:
   213  	 * Additional metadata about the diagnostic.
   214  	 */
   215  	Tags []DiagnosticTag `json:"tags,omitempty"` // always empty for logging optimizations.
   216  
   217  	/*RelatedInformation defined:
   218  	 * An array of related diagnostic information, e.g. when symbol-names within
   219  	 * a scope collide all definitions can be marked via this property.
   220  	 */
   221  	RelatedInformation []DiagnosticRelatedInformation `json:"relatedInformation,omitempty"`
   222  }
   223  
   224  // A LoggedOpt is what the compiler produces and accumulates,
   225  // to be converted to JSON for human or IDE consumption.
   226  type LoggedOpt struct {
   227  	pos          src.XPos      // Source code position at which the event occurred. If it is inlined, outer and all inlined locations will appear in JSON.
   228  	lastPos      src.XPos      // Usually the same as pos; current exception is for reporting entire range of transformed loops
   229  	compilerPass string        // Compiler pass.  For human/adhoc consumption; does not appear in JSON (yet)
   230  	functionName string        // Function name.  For human/adhoc consumption; does not appear in JSON (yet)
   231  	what         string        // The (non) optimization; "nilcheck", "boundsCheck", "inline", "noInline"
   232  	target       []interface{} // Optional target(s) or parameter(s) of "what" -- what was inlined, why it was not, size of copy, etc. 1st is most important/relevant.
   233  }
   234  
   235  type logFormat uint8
   236  
   237  const (
   238  	None  logFormat = iota
   239  	Json0           // version 0 for LSP 3.14, 3.15; future versions of LSP may change the format and the compiler may need to support both as clients are updated.
   240  )
   241  
   242  var Format = None
   243  var dest string
   244  
   245  // LogJsonOption parses and validates the version,directory value attached to the -json compiler flag.
   246  func LogJsonOption(flagValue string) {
   247  	version, directory := parseLogFlag("json", flagValue)
   248  	if version != 0 {
   249  		log.Fatal("-json version must be 0")
   250  	}
   251  	dest = checkLogPath(directory)
   252  	Format = Json0
   253  }
   254  
   255  // parseLogFlag checks the flag passed to -json
   256  // for version,destination format and returns the two parts.
   257  func parseLogFlag(flag, value string) (version int, directory string) {
   258  	if Format != None {
   259  		log.Fatal("Cannot repeat -json flag")
   260  	}
   261  	commaAt := strings.Index(value, ",")
   262  	if commaAt <= 0 {
   263  		log.Fatalf("-%s option should be '<version>,<destination>' where <version> is a number", flag)
   264  	}
   265  	v, err := strconv.Atoi(value[:commaAt])
   266  	if err != nil {
   267  		log.Fatalf("-%s option should be '<version>,<destination>' where <version> is a number: err=%v", flag, err)
   268  	}
   269  	version = v
   270  	directory = value[commaAt+1:]
   271  	return
   272  }
   273  
   274  // isWindowsDriveURIPath returns true if the file URI is of the format used by
   275  // Windows URIs. The url.Parse package does not specially handle Windows paths
   276  // (see golang/go#6027), so we check if the URI path has a drive prefix (e.g. "/C:").
   277  // (copied from tools/internal/span/uri.go)
   278  // this is less comprehensive that the processing in filepath.IsAbs on Windows.
   279  func isWindowsDriveURIPath(uri string) bool {
   280  	if len(uri) < 4 {
   281  		return false
   282  	}
   283  	return uri[0] == '/' && unicode.IsLetter(rune(uri[1])) && uri[2] == ':'
   284  }
   285  
   286  func parseLogPath(destination string) (string, string) {
   287  	if filepath.IsAbs(destination) {
   288  		return filepath.Clean(destination), ""
   289  	}
   290  	if strings.HasPrefix(destination, "file://") { // IKWIAD, or Windows C:\foo\bar\baz
   291  		uri, err := url.Parse(destination)
   292  		if err != nil {
   293  			return "", fmt.Sprintf("optimizer logging destination looked like file:// URI but failed to parse: err=%v", err)
   294  		}
   295  		destination = uri.Host + uri.Path
   296  		if isWindowsDriveURIPath(destination) {
   297  			// strip leading / from /C:
   298  			// unlike tools/internal/span/uri.go, do not uppercase the drive letter -- let filepath.Clean do what it does.
   299  			destination = destination[1:]
   300  		}
   301  		return filepath.Clean(destination), ""
   302  	}
   303  	return "", fmt.Sprintf("optimizer logging destination %s was neither %s-prefixed directory nor file://-prefixed file URI", destination, string(filepath.Separator))
   304  }
   305  
   306  // checkLogPath does superficial early checking of the string specifying
   307  // the directory to which optimizer logging is directed, and if
   308  // it passes the test, stores the string in LO_dir.
   309  func checkLogPath(destination string) string {
   310  	path, complaint := parseLogPath(destination)
   311  	if complaint != "" {
   312  		log.Fatalf(complaint)
   313  	}
   314  	err := os.MkdirAll(path, 0755)
   315  	if err != nil {
   316  		log.Fatalf("optimizer logging destination '<version>,<directory>' but could not create <directory>: err=%v", err)
   317  	}
   318  	return path
   319  }
   320  
   321  var loggedOpts []*LoggedOpt
   322  var mu = sync.Mutex{} // mu protects loggedOpts.
   323  
   324  // NewLoggedOpt allocates a new LoggedOpt, to later be passed to either NewLoggedOpt or LogOpt as "args".
   325  // Pos is the source position (including inlining), what is the message, pass is which pass created the message,
   326  // funcName is the name of the function
   327  // A typical use for this to accumulate an explanation for a missed optimization, for example, why did something escape?
   328  func NewLoggedOpt(pos, lastPos src.XPos, what, pass, funcName string, args ...interface{}) *LoggedOpt {
   329  	pass = strings.Replace(pass, " ", "_", -1)
   330  	return &LoggedOpt{pos, lastPos, pass, funcName, what, args}
   331  }
   332  
   333  // LogOpt logs information about a (usually missed) optimization performed by the compiler.
   334  // Pos is the source position (including inlining), what is the message, pass is which pass created the message,
   335  // funcName is the name of the function.
   336  func LogOpt(pos src.XPos, what, pass, funcName string, args ...interface{}) {
   337  	if Format == None {
   338  		return
   339  	}
   340  	lo := NewLoggedOpt(pos, pos, what, pass, funcName, args...)
   341  	mu.Lock()
   342  	defer mu.Unlock()
   343  	// Because of concurrent calls from back end, no telling what the order will be, but is stable-sorted by outer Pos before use.
   344  	loggedOpts = append(loggedOpts, lo)
   345  }
   346  
   347  // LogOptRange is the same as LogOpt, but includes the ability to express a range of positions,
   348  // not just a point.
   349  func LogOptRange(pos, lastPos src.XPos, what, pass, funcName string, args ...interface{}) {
   350  	if Format == None {
   351  		return
   352  	}
   353  	lo := NewLoggedOpt(pos, lastPos, what, pass, funcName, args...)
   354  	mu.Lock()
   355  	defer mu.Unlock()
   356  	// Because of concurrent calls from back end, no telling what the order will be, but is stable-sorted by outer Pos before use.
   357  	loggedOpts = append(loggedOpts, lo)
   358  }
   359  
   360  // Enabled returns whether optimization logging is enabled.
   361  func Enabled() bool {
   362  	switch Format {
   363  	case None:
   364  		return false
   365  	case Json0:
   366  		return true
   367  	}
   368  	panic("Unexpected optimizer-logging level")
   369  }
   370  
   371  // byPos sorts diagnostics by source position.
   372  type byPos struct {
   373  	ctxt *obj.Link
   374  	a    []*LoggedOpt
   375  }
   376  
   377  func (x byPos) Len() int { return len(x.a) }
   378  func (x byPos) Less(i, j int) bool {
   379  	return x.ctxt.OutermostPos(x.a[i].pos).Before(x.ctxt.OutermostPos(x.a[j].pos))
   380  }
   381  func (x byPos) Swap(i, j int) { x.a[i], x.a[j] = x.a[j], x.a[i] }
   382  
   383  func writerForLSP(subdirpath, file string) io.WriteCloser {
   384  	basename := file
   385  	lastslash := strings.LastIndexAny(basename, "\\/")
   386  	if lastslash != -1 {
   387  		basename = basename[lastslash+1:]
   388  	}
   389  	lastdot := strings.LastIndex(basename, ".go")
   390  	if lastdot != -1 {
   391  		basename = basename[:lastdot]
   392  	}
   393  	basename = url.PathEscape(basename)
   394  
   395  	// Assume a directory, make a file
   396  	p := filepath.Join(subdirpath, basename+".json")
   397  	w, err := os.Create(p)
   398  	if err != nil {
   399  		log.Fatalf("Could not create file %s for logging optimizer actions, %v", p, err)
   400  	}
   401  	return w
   402  }
   403  
   404  func fixSlash(f string) string {
   405  	if os.PathSeparator == '/' {
   406  		return f
   407  	}
   408  	return strings.Replace(f, string(os.PathSeparator), "/", -1)
   409  }
   410  
   411  func uriIfy(f string) DocumentURI {
   412  	url := url.URL{
   413  		Scheme: "file",
   414  		Path:   fixSlash(f),
   415  	}
   416  	return DocumentURI(url.String())
   417  }
   418  
   419  // Return filename, replacing a first occurrence of $GOROOT with the
   420  // actual value of the GOROOT (because LSP does not speak "$GOROOT").
   421  func uprootedPath(filename string) string {
   422  	if filename == "" {
   423  		return "__unnamed__"
   424  	}
   425  	if buildcfg.GOROOT == "" || !strings.HasPrefix(filename, "$GOROOT/") {
   426  		return filename
   427  	}
   428  	return buildcfg.GOROOT + filename[len("$GOROOT"):]
   429  }
   430  
   431  // FlushLoggedOpts flushes all the accumulated optimization log entries.
   432  func FlushLoggedOpts(ctxt *obj.Link, slashPkgPath string) {
   433  	if Format == None {
   434  		return
   435  	}
   436  
   437  	sort.Stable(byPos{ctxt, loggedOpts}) // Stable is necessary to preserve the per-function order, which is repeatable.
   438  	switch Format {
   439  
   440  	case Json0: // LSP 3.15
   441  		var posTmp, lastTmp []src.Pos
   442  		var encoder *json.Encoder
   443  		var w io.WriteCloser
   444  
   445  		if slashPkgPath == "" {
   446  			slashPkgPath = "\000"
   447  		}
   448  		subdirpath := filepath.Join(dest, url.PathEscape(slashPkgPath))
   449  		err := os.MkdirAll(subdirpath, 0755)
   450  		if err != nil {
   451  			log.Fatalf("Could not create directory %s for logging optimizer actions, %v", subdirpath, err)
   452  		}
   453  		diagnostic := Diagnostic{Source: "go compiler", Severity: SeverityInformation}
   454  
   455  		// For LSP, make a subdirectory for the package, and for each file foo.go, create foo.json in that subdirectory.
   456  		currentFile := ""
   457  		for _, x := range loggedOpts {
   458  			posTmp, p0 := parsePos(ctxt, x.pos, posTmp)
   459  			lastTmp, l0 := parsePos(ctxt, x.lastPos, lastTmp) // These match posTmp/p0 except for most-inline, and that often also matches.
   460  			p0f := uprootedPath(p0.Filename())
   461  
   462  			if currentFile != p0f {
   463  				if w != nil {
   464  					w.Close()
   465  				}
   466  				currentFile = p0f
   467  				w = writerForLSP(subdirpath, currentFile)
   468  				encoder = json.NewEncoder(w)
   469  				encoder.Encode(VersionHeader{Version: 0, Package: slashPkgPath, Goos: buildcfg.GOOS, Goarch: buildcfg.GOARCH, GcVersion: buildcfg.Version, File: currentFile})
   470  			}
   471  
   472  			// The first "target" is the most important one.
   473  			var target string
   474  			if len(x.target) > 0 {
   475  				target = fmt.Sprint(x.target[0])
   476  			}
   477  
   478  			diagnostic.Code = x.what
   479  			diagnostic.Message = target
   480  			diagnostic.Range = newRange(p0, l0)
   481  			diagnostic.RelatedInformation = diagnostic.RelatedInformation[:0]
   482  
   483  			appendInlinedPos(posTmp, lastTmp, &diagnostic)
   484  
   485  			// Diagnostic explanation is stored in RelatedInformation after inlining info
   486  			if len(x.target) > 1 {
   487  				switch y := x.target[1].(type) {
   488  				case []*LoggedOpt:
   489  					for _, z := range y {
   490  						posTmp, p0 := parsePos(ctxt, z.pos, posTmp)
   491  						lastTmp, l0 := parsePos(ctxt, z.lastPos, lastTmp)
   492  						loc := newLocation(p0, l0)
   493  						msg := z.what
   494  						if len(z.target) > 0 {
   495  							msg = msg + ": " + fmt.Sprint(z.target[0])
   496  						}
   497  
   498  						diagnostic.RelatedInformation = append(diagnostic.RelatedInformation, DiagnosticRelatedInformation{Location: loc, Message: msg})
   499  						appendInlinedPos(posTmp, lastTmp, &diagnostic)
   500  					}
   501  				}
   502  			}
   503  
   504  			encoder.Encode(diagnostic)
   505  		}
   506  		if w != nil {
   507  			w.Close()
   508  		}
   509  	}
   510  }
   511  
   512  // newRange returns a single-position Range for the compiler source location p.
   513  func newRange(p, last src.Pos) Range {
   514  	return Range{Start: Position{p.Line(), p.Col()},
   515  		End: Position{last.Line(), last.Col()}}
   516  }
   517  
   518  // newLocation returns the Location for the compiler source location p.
   519  func newLocation(p, last src.Pos) Location {
   520  	loc := Location{URI: uriIfy(uprootedPath(p.Filename())), Range: newRange(p, last)}
   521  	return loc
   522  }
   523  
   524  // appendInlinedPos extracts inlining information from posTmp and append it to diagnostic.
   525  func appendInlinedPos(posTmp, lastTmp []src.Pos, diagnostic *Diagnostic) {
   526  	for i := 1; i < len(posTmp); i++ {
   527  		loc := newLocation(posTmp[i], lastTmp[i])
   528  		diagnostic.RelatedInformation = append(diagnostic.RelatedInformation, DiagnosticRelatedInformation{Location: loc, Message: "inlineLoc"})
   529  	}
   530  }
   531  
   532  // parsePos expands a src.XPos into a slice of src.Pos, with the outermost first.
   533  // It returns the slice, and the outermost.
   534  func parsePos(ctxt *obj.Link, pos src.XPos, posTmp []src.Pos) ([]src.Pos, src.Pos) {
   535  	posTmp = posTmp[:0]
   536  	ctxt.AllPos(pos, func(p src.Pos) {
   537  		posTmp = append(posTmp, p)
   538  	})
   539  	return posTmp, posTmp[0]
   540  }
   541  

View as plain text