debug.go

Documentation: cuelang.org/go/internal/core/adt

     1  // Copyright 2023 CUE Authors
     2  //
     3  // Licensed under the Apache License, Version 2.0 (the "License");
     4  // you may not use this file except in compliance with the License.
     5  // You may obtain a copy of the License at
     6  //
     7  //     http://www.apache.org/licenses/LICENSE-2.0
     8  //
     9  // Unless required by applicable law or agreed to in writing, software
    10  // distributed under the License is distributed on an "AS IS" BASIS,
    11  // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    12  // See the License for the specific language governing permissions and
    13  // limitations under the License.
    14  
    15  package adt
    16  
    17  import (
    18  	"bytes"
    19  	"fmt"
    20  	"html/template"
    21  	"io"
    22  	"log"
    23  	"os"
    24  	"os/exec"
    25  	"path/filepath"
    26  	"runtime"
    27  	"strings"
    28  )
    29  
    30  // RecordDebugGraph records debug output in ctx if there was an anomaly
    31  // discovered.
    32  func RecordDebugGraph(ctx *OpContext, v *Vertex, name string) {
    33  	graph, hasError := CreateMermaidGraph(ctx, v, true)
    34  	if hasError {
    35  		if ctx.ErrorGraphs == nil {
    36  			ctx.ErrorGraphs = map[string]string{}
    37  		}
    38  		path := ctx.PathToString(v.Path())
    39  		ctx.ErrorGraphs[path] = graph
    40  	}
    41  }
    42  
    43  // OpenNodeGraph takes a given mermaid graph and opens it in the system default
    44  // browser.
    45  func OpenNodeGraph(title, path, code, out, graph string) {
    46  	err := os.MkdirAll(path, 0755)
    47  	if err != nil {
    48  		log.Fatal(err)
    49  	}
    50  	url := filepath.Join(path, "graph.html")
    51  
    52  	w, err := os.Create(url)
    53  	if err != nil {
    54  		log.Fatal(err)
    55  	}
    56  	defer w.Close()
    57  
    58  	data := struct {
    59  		Title string
    60  		Code  string
    61  		Out   string
    62  		Graph string
    63  	}{
    64  		Title: title,
    65  		Code:  code,
    66  		Out:   out,
    67  		Graph: graph,
    68  	}
    69  
    70  	tmpl := template.Must(template.New("").Parse(`
    71  	<!DOCTYPE html>
    72  	<html>
    73  	<head>
    74  		<title>{{.Title}}</title>
    75  		<script src="https://cdn.jsdelivr.net/npm/mermaid/dist/mermaid.min.js"></script>
    76  		<script>mermaid.initialize({startOnLoad:true});</script>
    77  		<style>
    78  			.container {
    79  				display: flex;
    80  				flex-direction: column;
    81  				align-items: stretch;
    82  			}
    83  			.row {
    84  				display: flex;
    85  				flex-direction: row;
    86  			}
    87  			// ...
    88  		</style>
    89  	</head>
    90  	<body>
    91  		<div class="mermaid">{{.Graph}}</div>
    92  		<div class="row">
    93  			<div class="column">
    94  				<h1><b>Input</b></h1>
    95  				<pre>{{.Code}}</pre>
    96  			</div>
    97  			<div class="column">
    98  				<h1><b>Output</b></h1>
    99  				<pre>{{.Out}}</pre>
   100  			</div>
   101  		</div>
   102  	</body>
   103  	</html>
   104  `))
   105  
   106  	err = tmpl.Execute(w, data)
   107  	if err != nil {
   108  		log.Fatal(err)
   109  	}
   110  
   111  	openBrowser(url)
   112  }
   113  
   114  // openDebugGraph opens a browser with a graph of the state of the given Vertex
   115  // and all its dependencies that have not completed processing.
   116  // DO NOT DELETE: this is used to insert during debugging of the evaluator
   117  // to inspect a node.
   118  func openDebugGraph(ctx *OpContext, v *Vertex, name string) {
   119  	graph, _ := CreateMermaidGraph(ctx, v, true)
   120  	path := filepath.Join(".debug", "TestX", name)
   121  	OpenNodeGraph(name, path, "in", "out", graph)
   122  }
   123  
   124  // depKind is a type of dependency that is tracked with incDependent and
   125  // decDependent. For each there should be matching pairs passed to these
   126  // functions. The debugger, when used, tracks and verifies that these
   127  // dependencies are balanced.
   128  type depKind int
   129  
   130  const (
   131  	// PARENT dependencies are used to track the completion of parent
   132  	// closedContexts within the closedness tree.
   133  	PARENT depKind = iota + 1
   134  
   135  	// ARC dependencies are used to track the completion of corresponding
   136  	// closedContexts in parent Vertices.
   137  	ARC
   138  
   139  	// NOTIFY dependencies keep a note while dependent conjuncts are collected
   140  	NOTIFY // root node of source
   141  
   142  	// TASK dependencies are used to track the completion of a task.
   143  	TASK
   144  
   145  	// EVAL tracks that the conjunct associated with a closeContext has been
   146  	// inserted using scheduleConjunct. A closeContext may not be deleted
   147  	// as long as the conjunct has not been evaluated yet.
   148  	// This prevents a node from being released if an ARC decrement happens
   149  	// before a node is evaluated.
   150  	EVAL
   151  
   152  	// ROOT dependencies are used to track that all nodes of parents are
   153  	// added to a tree.
   154  	ROOT // Always refers to self.
   155  
   156  	// INIT dependencies are used to hold ownership of a closeContext during
   157  	// initialization and prevent it from being finalized when scheduling a
   158  	// node's conjuncts.
   159  	INIT
   160  
   161  	// DEFER is used to track recursive processing of a node.
   162  	DEFER // Always refers to self.
   163  
   164  	// TEST is used for testing notifications.
   165  	TEST // Always refers to self.
   166  )
   167  
   168  func (k depKind) String() string {
   169  	switch k {
   170  	case PARENT:
   171  		return "PARENT"
   172  	case ARC:
   173  		return "ARC"
   174  	case NOTIFY:
   175  		return "NOTIFY"
   176  	case TASK:
   177  		return "TASK"
   178  	case EVAL:
   179  		return "EVAL"
   180  	case ROOT:
   181  		return "ROOT"
   182  
   183  	case INIT:
   184  		return "INIT"
   185  	case DEFER:
   186  		return "DEFER"
   187  	case TEST:
   188  		return "TEST"
   189  	}
   190  	panic("unreachable")
   191  }
   192  
   193  // ccDep is used to record counters which is used for debugging only.
   194  // It is purpose is to be precise about matching inc/dec as well as to be able
   195  // to traverse dependency.
   196  type ccDep struct {
   197  	dependency  *closeContext
   198  	kind        depKind
   199  	decremented bool
   200  
   201  	// task keeps a reference to a task for TASK dependencies.
   202  	task *task
   203  	// taskID indicates the sequence number of a task within a scheduler.
   204  	taskID int
   205  }
   206  
   207  // DebugDeps enables dependency tracking for debugging purposes.
   208  // It is off by default, as it adds a significant overhead.
   209  //
   210  // TODO: hook this init CUE_DEBUG, once we have set this up as a single
   211  // environment variable. For instance, CUE_DEBUG=matchdeps=1.
   212  var DebugDeps = false
   213  
   214  func (c *closeContext) addDependent(kind depKind, dependant *closeContext) *ccDep {
   215  	if !DebugDeps {
   216  		return nil
   217  	}
   218  
   219  	if dependant == nil {
   220  		dependant = c
   221  	}
   222  
   223  	if Verbosity > 1 {
   224  		var state *nodeContext
   225  		if c.src != nil && c.src.state != nil {
   226  			state = c.src.state
   227  		} else if dependant != nil && dependant.src != nil && dependant.src.state != nil {
   228  			state = dependant.src.state
   229  		}
   230  		if state != nil {
   231  			state.Logf("INC(%s, %d) %v; %p (parent: %p) <= %p\n", kind, c.conjunctCount, c.Label(), c, c.parent, dependant)
   232  		} else {
   233  			log.Printf("INC(%s) %v %p parent: %p %d\n", kind, c.Label(), c, c.parent, c.conjunctCount)
   234  		}
   235  	}
   236  
   237  	dep := &ccDep{kind: kind, dependency: dependant}
   238  	c.dependencies = append(c.dependencies, dep)
   239  
   240  	return dep
   241  }
   242  
   243  // matchDecrement checks that this decrement matches a previous increment.
   244  func (c *closeContext) matchDecrement(v *Vertex, kind depKind, dependant *closeContext) {
   245  	if !DebugDeps {
   246  		return
   247  	}
   248  
   249  	if dependant == nil {
   250  		dependant = c
   251  	}
   252  
   253  	if Verbosity > 1 {
   254  		if v.state != nil {
   255  			v.state.Logf("DEC(%s) %v %p %d\n", kind, c.Label(), c, c.conjunctCount)
   256  		} else {
   257  			log.Printf("DEC(%s) %v %p %d\n", kind, c.Label(), c, c.conjunctCount)
   258  		}
   259  	}
   260  
   261  	for _, d := range c.dependencies {
   262  		if d.kind != kind {
   263  			continue
   264  		}
   265  		if d.dependency != dependant {
   266  			continue
   267  		}
   268  		// Only one typ-dependant pair possible.
   269  		if d.decremented {
   270  			// There might be a duplicate entry, so continue searching.
   271  			continue
   272  		}
   273  
   274  		d.decremented = true
   275  		return
   276  	}
   277  
   278  	panic(fmt.Sprintf("unmatched decrement: %s", kind))
   279  }
   280  
   281  // mermaidContext is used to create a dependency analysis for a node.
   282  type mermaidContext struct {
   283  	ctx *OpContext
   284  	v   *Vertex
   285  
   286  	all bool
   287  
   288  	hasError bool
   289  
   290  	// roots maps the root closeContext of any Vertex to the analysis data
   291  	// for that Vertex.
   292  	roots map[*closeContext]*mermaidVertex
   293  
   294  	// processed indicates whether the node in question has been processed
   295  	// by the dependency analysis.
   296  	processed map[*closeContext]bool
   297  
   298  	// inConjuncts indicates whether a node is explicitly referenced by
   299  	// a Conjunct. These nodes are visualized with an additional circle.
   300  	inConjuncts map[*closeContext]bool
   301  
   302  	// ccID maps a closeContext to a unique ID.
   303  	ccID map[*closeContext]string
   304  
   305  	w io.Writer
   306  
   307  	// vertices lists an analysis of all nodes related to the analyzed node.
   308  	// The first node is the node being analyzed itself.
   309  	vertices []*mermaidVertex
   310  }
   311  
   312  type mermaidVertex struct {
   313  	f     Feature
   314  	w     *bytes.Buffer
   315  	tasks *bytes.Buffer
   316  	intra *bytes.Buffer
   317  }
   318  
   319  // CreateMermaidGraph creates an analysis of relations and values involved in
   320  // nodes with unbalanced increments. The graph is in Mermaid format.
   321  func CreateMermaidGraph(ctx *OpContext, v *Vertex, all bool) (graph string, hasError bool) {
   322  	if !DebugDeps {
   323  		return "", false
   324  	}
   325  
   326  	buf := &strings.Builder{}
   327  
   328  	m := &mermaidContext{
   329  		ctx:         ctx,
   330  		v:           v,
   331  		roots:       map[*closeContext]*mermaidVertex{},
   332  		processed:   map[*closeContext]bool{},
   333  		inConjuncts: map[*closeContext]bool{},
   334  		ccID:        map[*closeContext]string{},
   335  		w:           buf,
   336  		all:         all,
   337  	}
   338  
   339  	io.WriteString(m.w, "graph TD\n")
   340  	io.WriteString(m.w, "   classDef err fill:#e01010,stroke:#000000,stroke-width:3,font-size:medium\n")
   341  
   342  	indent(m.w, 1)
   343  	fmt.Fprintf(m.w, "style %s stroke-width:5\n\n", m.vertexID(v))
   344  	// Trigger descent on first vertex. This may include other vertices when
   345  	// traversing closeContexts if they have dependencies on such vertices.
   346  	m.vertex(v)
   347  
   348  	// Close and flush all collected vertices.
   349  	for i, v := range m.vertices {
   350  		v.closeVertex()
   351  		if i == 0 || len(m.ccID) > 0 {
   352  			m.w.Write(v.w.Bytes())
   353  		}
   354  	}
   355  
   356  	return buf.String(), m.hasError
   357  }
   358  
   359  // vertex creates a blob of Mermaid graph representing one vertex. It has
   360  // the following shape (where ptr(x) means pointer of x):
   361  //
   362  //		subgraph ptr(v)
   363  //		   %% root note if ROOT has not been decremented.
   364  //		   root((cc1)) -|R|-> ptr(cc1)
   365  //
   366  //		   %% closedness graph dependencies
   367  //		   ptr(cc1)
   368  //		   ptr(cc2) -|P|-> ptr(cc1)
   369  //		   ptr(cc2) -|E|-> ptr(cc1) %% mid schedule
   370  //
   371  //		   %% tasks
   372  //		   subgraph tasks
   373  //		      ptr(cc3)
   374  //		      ptr(cc4)
   375  //		      ptr(cc5)
   376  //		   end
   377  //
   378  //		   %% outstanding tasks and the contexts they depend on
   379  //		   ptr(cc3) -|T|-> ptr(cc2)
   380  //
   381  //		   subgraph notifications
   382  //		      ptr(cc6)
   383  //		      ptr(cc7)
   384  //		   end
   385  //		end
   386  //		%% arcs from nodes to nodes in other vertices
   387  //		ptr(cc1) -|A|-> ptr(cc10)
   388  //		ptr(vx) -|N|-> ptr(cc11)
   389  //
   390  //
   391  //	 A vertex has the following name: path(v); done
   392  //
   393  //	 Each closeContext has the following info: ptr(cc); cc.count
   394  func (m *mermaidContext) vertex(v *Vertex) *mermaidVertex {
   395  	root := v.rootCloseContext()
   396  
   397  	vc := m.roots[root]
   398  	if vc != nil {
   399  		return vc
   400  	}
   401  
   402  	vc = &mermaidVertex{
   403  		f:     v.Label,
   404  		w:     &bytes.Buffer{},
   405  		intra: &bytes.Buffer{},
   406  	}
   407  	m.vertices = append(m.vertices, vc)
   408  
   409  	m.tagReferencedConjuncts(v.Conjuncts)
   410  
   411  	m.roots[root] = vc
   412  	w := vc.w
   413  
   414  	var status string
   415  	switch {
   416  	case v.status == finalized:
   417  		status = "finalized"
   418  	case v.state == nil:
   419  		status = "ready"
   420  	default:
   421  		status = v.state.scheduler.state.String()
   422  	}
   423  	path := m.vertexPath(v)
   424  	if v.ArcType != ArcMember {
   425  		path += fmt.Sprintf("/%v", v.ArcType)
   426  	}
   427  
   428  	indentOnNewline(w, 1)
   429  	fmt.Fprintf(w, "subgraph %s[%s: %s]\n", m.vertexID(v), path, status)
   430  
   431  	m.cc(root)
   432  
   433  	return vc
   434  }
   435  
   436  func (m *mermaidContext) tagReferencedConjuncts(a []Conjunct) {
   437  	for _, c := range a {
   438  		m.inConjuncts[c.CloseInfo.cc] = true
   439  
   440  		if g, ok := c.x.(*ConjunctGroup); ok {
   441  			m.tagReferencedConjuncts([]Conjunct(*g))
   442  		}
   443  	}
   444  }
   445  
   446  func (v *mermaidVertex) closeVertex() {
   447  	w := v.w
   448  
   449  	if v.tasks != nil {
   450  		indent(v.tasks, 2)
   451  		fmt.Fprintf(v.tasks, "end\n")
   452  		w.Write(v.tasks.Bytes())
   453  	}
   454  
   455  	// TODO: write all notification sources (or is this just the node?)
   456  
   457  	indent(w, 1)
   458  	fmt.Fprintf(w, "end\n")
   459  }
   460  
   461  func (m *mermaidContext) task(d *ccDep) string {
   462  	v := d.dependency.src
   463  
   464  	// This must already exist.
   465  	vc := m.vertex(v)
   466  
   467  	if vc.tasks == nil {
   468  		vc.tasks = &bytes.Buffer{}
   469  		indentOnNewline(vc.tasks, 2)
   470  		fmt.Fprintf(vc.tasks, "subgraph %s_tasks[tasks]\n", m.vertexID(v))
   471  	}
   472  
   473  	if v != d.task.node.node {
   474  		panic("inconsistent task")
   475  	}
   476  	taskID := fmt.Sprintf("%s_%d", m.vertexID(v), d.taskID)
   477  	var state string
   478  	var completes condition
   479  	var kind string
   480  	if d.task != nil {
   481  		state = d.task.state.String()[:2]
   482  		completes = d.task.completes
   483  		kind = d.task.run.name
   484  	}
   485  	indentOnNewline(vc.tasks, 3)
   486  	fmt.Fprintf(vc.tasks, "%s(%d", taskID, d.taskID)
   487  	indentOnNewline(vc.tasks, 4)
   488  	io.WriteString(vc.tasks, state)
   489  	indentOnNewline(vc.tasks, 4)
   490  	io.WriteString(vc.tasks, kind)
   491  	indentOnNewline(vc.tasks, 4)
   492  	fmt.Fprintf(vc.tasks, "%x)\n", completes)
   493  
   494  	if s := d.task.blockedOn; s != nil {
   495  		m.vertex(s.node.node)
   496  		fmt.Fprintf(m.w, "%s_tasks == BLOCKED ==> %s\n", m.vertexID(s.node.node), taskID)
   497  	}
   498  
   499  	return taskID
   500  }
   501  
   502  func (m *mermaidContext) cc(cc *closeContext) {
   503  	if m.processed[cc] {
   504  		return
   505  	}
   506  	m.processed[cc] = true
   507  
   508  	// This must already exist.
   509  	v := m.vertex(cc.src)
   510  
   511  	// Dependencies at different scope levels.
   512  	global := m.w
   513  	node := v.w
   514  
   515  	for _, d := range cc.dependencies {
   516  		indentLevel := 2
   517  		var w io.Writer
   518  		var name, link string
   519  
   520  		switch {
   521  		case !d.decremented:
   522  			link = fmt.Sprintf(`--%s-->`, d.kind.String())
   523  		case m.all:
   524  			link = fmt.Sprintf("-. %s .->", d.kind.String()[0:1])
   525  		default:
   526  			continue
   527  		}
   528  
   529  		// Only include still outstanding nodes.
   530  		switch d.kind {
   531  		case PARENT:
   532  			w = node
   533  			name = m.pstr(d.dependency)
   534  		case EVAL:
   535  			if cc.Label().IsLet() {
   536  				// Do not show eval links for let nodes, as they never depend
   537  				// on the parent node. Alternatively, link them to the root
   538  				// node instead.
   539  				return
   540  			}
   541  			fallthrough
   542  		case ARC, NOTIFY:
   543  			w = global
   544  			indentLevel = 1
   545  			name = m.pstr(d.dependency)
   546  
   547  		case TASK:
   548  			w = node
   549  			taskID := m.task(d)
   550  			name = fmt.Sprintf("%s((%d))", taskID, d.taskID)
   551  		case ROOT, INIT:
   552  			w = node
   553  			src := cc.src
   554  			if v.f != src.Label {
   555  				panic("incompatible labels")
   556  			}
   557  			name = fmt.Sprintf("root_%s", m.vertexID(src))
   558  		}
   559  
   560  		if w != nil {
   561  			dst := m.pstr(cc)
   562  			indent(w, indentLevel)
   563  			fmt.Fprintf(w, "%s %s %s\n", name, link, dst)
   564  		}
   565  
   566  		// If the references count is 0, all direct dependencies must have
   567  		// completed as well. In this case, descending into each of them should
   568  		// not end up printing anything. In case of any bugs, these nodes will
   569  		// show up as unattached nodes.
   570  
   571  		if dep := d.dependency; dep != nil && dep != cc {
   572  			m.cc(dep)
   573  		}
   574  	}
   575  }
   576  
   577  func (m *mermaidContext) vertexPath(v *Vertex) string {
   578  	path := m.ctx.PathToString(v.Path())
   579  	if path == "" {
   580  		return "_"
   581  	}
   582  	return path
   583  }
   584  
   585  const sigPtrLen = 6
   586  
   587  func (m *mermaidContext) vertexID(v *Vertex) string {
   588  	s := fmt.Sprintf("%p", v)
   589  	return "v" + s[len(s)-sigPtrLen:]
   590  }
   591  
   592  func (m *mermaidContext) pstr(cc *closeContext) string {
   593  	if id, ok := m.ccID[cc]; ok {
   594  		return id
   595  	}
   596  
   597  	ptr := fmt.Sprintf("%p", cc)
   598  	ptr = ptr[len(ptr)-sigPtrLen:]
   599  	id := fmt.Sprintf("cc%s", ptr)
   600  	m.ccID[cc] = id
   601  
   602  	v := m.vertex(cc.src)
   603  
   604  	w := v.w
   605  
   606  	indent(w, 2)
   607  	w.WriteString(id)
   608  
   609  	var open, close = "((", "))"
   610  	if m.inConjuncts[cc] {
   611  		open, close = "(((", ")))"
   612  	}
   613  
   614  	w.WriteString(open)
   615  	w.WriteString("cc")
   616  	if cc.conjunctCount > 0 {
   617  		fmt.Fprintf(w, " c:%d", cc.conjunctCount)
   618  	}
   619  	indentOnNewline(w, 3)
   620  	w.WriteString(ptr)
   621  
   622  	flags := &bytes.Buffer{}
   623  	addFlag := func(test bool, flag byte) {
   624  		if test {
   625  			flags.WriteByte(flag)
   626  		}
   627  	}
   628  	addFlag(cc.isDef, '#')
   629  	addFlag(cc.isEmbed, 'E')
   630  	addFlag(cc.isClosed, 'c')
   631  	addFlag(cc.isClosedOnce, 'C')
   632  	addFlag(cc.hasEllipsis, 'o')
   633  	io.Copy(w, flags)
   634  
   635  	w.WriteString(close)
   636  
   637  	if cc.conjunctCount > 0 {
   638  		fmt.Fprintf(w, ":::err")
   639  		if cc.src == m.v {
   640  			m.hasError = true
   641  		}
   642  	}
   643  
   644  	w.WriteString("\n")
   645  
   646  	return id
   647  }
   648  
   649  func indentOnNewline(w io.Writer, level int) {
   650  	w.Write([]byte{'\n'})
   651  	indent(w, level)
   652  }
   653  
   654  func indent(w io.Writer, level int) {
   655  	for i := 0; i < level; i++ {
   656  		io.WriteString(w, "   ")
   657  	}
   658  }
   659  
   660  // openBrowser opens the given URL in the default browser.
   661  func openBrowser(url string) {
   662  	var cmd *exec.Cmd
   663  
   664  	switch runtime.GOOS {
   665  	case "windows":
   666  		cmd = exec.Command("cmd", "/c", "start", url)
   667  	case "darwin":
   668  		cmd = exec.Command("open", url)
   669  	default:
   670  		cmd = exec.Command("xdg-open", url)
   671  	}
   672  
   673  	err := cmd.Start()
   674  	if err != nil {
   675  		log.Fatal(err)
   676  	}
   677  	go cmd.Wait()
   678  }
   679
View as plain text