cuelang.org/go@v0.10.1/internal/core/adt/debug.go (about)

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