Source file src/cmd/compile/internal/logopt/log_opts.go
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