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
5package logopt
6
7import (
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
103type 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
115type DocumentURI string
116
117type 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.
126type 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.
139type 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 */
152type 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
166type DiagnosticSeverity uint
167
168const (
169	/*SeverityInformation defined:
170	 * Reports an information.
171	 */
172	SeverityInformation DiagnosticSeverity = 3
173)
174
175// DiagnosticTag defines constants
176type 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 */
182type 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.
226type 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
235type logFormat uint8
236
237const (
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
242var Format = None
243var dest string
244
245// LogJsonOption parses and validates the version,directory value attached to the -json compiler flag.
246func 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.
257func 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.
279func 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
286func 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.
309func 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
321var loggedOpts []*LoggedOpt
322var 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?
328func 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.
336func 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.
349func 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.
361func 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.
372type byPos struct {
373	ctxt *obj.Link
374	a    []*LoggedOpt
375}
376
377func (x byPos) Len() int { return len(x.a) }
378func (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}
381func (x byPos) Swap(i, j int) { x.a[i], x.a[j] = x.a[j], x.a[i] }
382
383func 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
404func fixSlash(f string) string {
405	if os.PathSeparator == '/' {
406		return f
407	}
408	return strings.Replace(f, string(os.PathSeparator), "/", -1)
409}
410
411func 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").
421func 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.
432func 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.
513func 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.
519func 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.
525func 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.
534func 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