diff --git a/dag/dag.go b/dag/dag.go index 5d1ca8d95..3fd9e48f1 100644 --- a/dag/dag.go +++ b/dag/dag.go @@ -103,7 +103,7 @@ func (g *AcyclicGraph) TransitiveReduction() { // v such that the edge (u,v) exists (v is a direct descendant of u). // // For each v-prime reachable from v, remove the edge (u, v-prime). - defer g.debug.BeginReduction().End() + defer g.debug.BeginOperation("TransitiveReduction", "").End("") for _, u := range g.Vertices() { uTargets := g.DownEdges(u) @@ -167,7 +167,7 @@ func (g *AcyclicGraph) Cycles() [][]Vertex { // This will walk nodes in parallel if it can. Because the walk is done // in parallel, the error returned will be a multierror. func (g *AcyclicGraph) Walk(cb WalkFunc) error { - defer g.debug.BeginWalk().End() + defer g.debug.BeginOperation("Walk", "").End("") // Cache the vertices since we use it multiple times vertices := g.Vertices() @@ -278,7 +278,7 @@ type vertexAtDepth struct { // the vertices in start. This is not exported now but it would make sense // to export this publicly at some point. func (g *AcyclicGraph) DepthFirstWalk(start []Vertex, f DepthWalkFunc) error { - defer g.debug.BeginDepthFirstWalk().End() + defer g.debug.BeginOperation("DepthFirstWalk", "").End("") seen := make(map[Vertex]struct{}) frontier := make([]*vertexAtDepth, len(start)) @@ -322,7 +322,7 @@ func (g *AcyclicGraph) DepthFirstWalk(start []Vertex, f DepthWalkFunc) error { // reverseDepthFirstWalk does a depth-first walk _up_ the graph starting from // the vertices in start. func (g *AcyclicGraph) ReverseDepthFirstWalk(start []Vertex, f DepthWalkFunc) error { - defer g.debug.BeginReverseDepthFirstWalk().End() + defer g.debug.BeginOperation("ReverseDepthFirstWalk", "").End("") seen := make(map[Vertex]struct{}) frontier := make([]*vertexAtDepth, len(start)) diff --git a/dag/graph.go b/dag/graph.go index 9d6ef2da4..fa33409cf 100644 --- a/dag/graph.go +++ b/dag/graph.go @@ -139,7 +139,7 @@ func (g *Graph) Replace(original, replacement Vertex) bool { return false } - defer g.debug.BeginReplace().End() + defer g.debug.BeginOperation("Replace", "").End("") // If they're the same, then don't do anything if original == replacement { @@ -357,6 +357,21 @@ func (g *Graph) DebugEdgeInfo(e Edge, info string) { g.debug.Encode(ea) } +// DebugOperation marks the start of a set of graph transformations in +// the debug log, and returns a DebugOperationEnd func, which marks the end of +// the operation in the log. Additional information can be added to the log via +// the info parameter. +// +// The returned func's End method allows this method to be called from a single +// defer statement: +// defer g.DebugOperationBegin("OpName", "operating").End("") +// +// The returned function must be called to properly close the logical operation +// in the logs. +func (g *Graph) DebugOperation(operation string, info string) DebugOperationEnd { + return g.debug.BeginOperation(operation, info) +} + // VertexName returns the name of a vertex. func VertexName(raw Vertex) string { switch v := raw.(type) { diff --git a/dag/marshal.go b/dag/marshal.go index 7e18ed0fc..32e1e945d 100644 --- a/dag/marshal.go +++ b/dag/marshal.go @@ -230,10 +230,13 @@ func marshalSubgrapher(v Vertex) (*Graph, bool) { return nil, false } -// ender provides a way to call any End* method expression via an End method -type ender func() +// The DebugOperationEnd func type provides a way to call an End function via a +// method call, allowing for the chaining of methods in a defer statement. +type DebugOperationEnd func(string) -func (e ender) End() { e() } +// End calls function e with the info parameter, marking the end of this +// operation in the logs. +func (e DebugOperationEnd) End(info string) { e(info) } // encoder provides methods to write debug data to an io.Writer, and is a noop // when no writer is present @@ -290,89 +293,26 @@ func (e *encoder) RemoveEdge(edge Edge) { }) } -// BeginReplace marks the start of a replace operation, and returns the encoder -// to chain the EndReplace call. -func (e *encoder) BeginReplace() ender { +// BeginOperation marks the start of set of graph transformations, and returns +// an EndDebugOperation func to be called once the opration is complete. +func (e *encoder) BeginOperation(op string, info string) DebugOperationEnd { + if e == nil { + return func(string) {} + } + e.Encode(marshalOperation{ Type: "Operation", - Begin: newString("Replace"), + Begin: op, + Info: info, }) - return e.EndReplace -} -func (e *encoder) EndReplace() { - e.Encode(marshalOperation{ - Type: "Operation", - End: newString("Replace"), - }) -} - -// BeginReduction marks the start of a replace operation, and returns the encoder -// to chain the EndReduction call. -func (e *encoder) BeginReduction() ender { - e.Encode(marshalOperation{ - Type: "Operation", - Begin: newString("Reduction"), - }) - return e.EndReduction -} - -func (e *encoder) EndReduction() { - e.Encode(marshalOperation{ - Type: "Operation", - End: newString("Reduction"), - }) -} - -// BeginDepthFirstWalk marks the start of a replace operation, and returns the -// encoder to chain the EndDepthFirstWalk call. -func (e *encoder) BeginDepthFirstWalk() ender { - e.Encode(marshalOperation{ - Type: "Operation", - Begin: newString("DepthFirstWalk"), - }) - return e.EndDepthFirstWalk -} - -func (e *encoder) EndDepthFirstWalk() { - e.Encode(marshalOperation{ - Type: "Operation", - End: newString("DepthFirstWalk"), - }) -} - -// BeginReverseDepthFirstWalk marks the start of a replace operation, and -// returns the encoder to chain the EndReverseDepthFirstWalk call. -func (e *encoder) BeginReverseDepthFirstWalk() ender { - e.Encode(marshalOperation{ - Type: "Operation", - Begin: newString("ReverseDepthFirstWalk"), - }) - return e.EndReverseDepthFirstWalk -} - -func (e *encoder) EndReverseDepthFirstWalk() { - e.Encode(marshalOperation{ - Type: "Operation", - End: newString("ReverseDepthFirstWalk"), - }) -} - -// BeginWalk marks the start of a replace operation, and returns the encoder -// to chain the EndWalk call. -func (e *encoder) BeginWalk() ender { - e.Encode(marshalOperation{ - Type: "Operation", - Begin: newString("Walk"), - }) - return e.EndWalk -} - -func (e *encoder) EndWalk() { - e.Encode(marshalOperation{ - Type: "Operation", - End: newString("Walk"), - }) + return func(info string) { + e.Encode(marshalOperation{ + Type: "Operation", + End: op, + Info: info, + }) + } } // structure for recording graph transformations @@ -424,15 +364,11 @@ func (s *streamDecode) UnmarshalJSON(d []byte) error { // graph state. type marshalOperation struct { Type string - Begin *string `json:",omitempty"` - End *string `json:",omitempty"` - Info *string `json:".omitempty"` + Begin string `json:",omitempty"` + End string `json:",omitempty"` + Info string `json:",omitempty"` } -func newBool(b bool) *bool { return &b } - -func newString(s string) *string { return &s } - // decodeGraph decodes a marshalGraph from an encoded graph stream. func decodeGraph(r io.Reader) (*marshalGraph, error) { dec := json.NewDecoder(r) diff --git a/dag/marshal_test.go b/dag/marshal_test.go index f9628e27a..1bff410a1 100644 --- a/dag/marshal_test.go +++ b/dag/marshal_test.go @@ -207,6 +207,77 @@ func TestGraphJSON_debugInfo(t *testing.T) { } } +// Verify that debug operations appear in the debug output +func TestGraphJSON_debugOperations(t *testing.T) { + var g Graph + var buf bytes.Buffer + g.SetDebugWriter(&buf) + + debugOp := g.DebugOperation("AddOne", "adding node 1") + g.Add(1) + debugOp.End("done adding node 1") + + // use an immediate closure to test defers + func() { + defer g.DebugOperation("AddTwo", "adding nodes 2 and 3").End("done adding 2 and 3") + g.Add(2) + defer g.DebugOperation("NestedAddThree", "second defer").End("done adding node 3") + g.Add(3) + }() + + g.Connect(BasicEdge(1, 2)) + + dec := json.NewDecoder(bytes.NewReader(buf.Bytes())) + + var ops []string + for dec.More() { + var d streamDecode + + err := dec.Decode(&d) + if err != nil { + t.Fatal(err) + } + + if d.Type != "Operation" { + continue + } + + o := &marshalOperation{} + err = json.Unmarshal(d.JSON, o) + if err != nil { + t.Fatal(err) + } + + switch { + case o.Begin == "AddOne": + ops = append(ops, "BeginAddOne") + case o.End == "AddOne": + ops = append(ops, "EndAddOne") + case o.Begin == "AddTwo": + ops = append(ops, "BeginAddTwo") + case o.End == "AddTwo": + ops = append(ops, "EndAddTwo") + case o.Begin == "NestedAddThree": + ops = append(ops, "BeginAddThree") + case o.End == "NestedAddThree": + ops = append(ops, "EndAddThree") + } + } + + expectedOps := []string{ + "BeginAddOne", + "EndAddOne", + "BeginAddTwo", + "BeginAddThree", + "EndAddThree", + "EndAddTwo", + } + + if strings.Join(ops, ",") != strings.Join(expectedOps, ",") { + t.Fatalf("incorrect order of operations: %v", ops) + } +} + const testGraphJSONEmptyStr = `{ "Type": "Graph", "Name": "root", diff --git a/terraform/graph_builder.go b/terraform/graph_builder.go index a7f892ac9..9f2d9e97f 100644 --- a/terraform/graph_builder.go +++ b/terraform/graph_builder.go @@ -49,8 +49,15 @@ func (b *BasicGraphBuilder) Build(path []string) (*Graph, error) { stepName = stepName[dot+1:] } + debugOp := g.DebugOperation(stepName, "") err := step.Transform(g) + errMsg := "" + if err != nil { + errMsg = err.Error() + } + debugOp.End(errMsg) + // always log the graph state to see what transformations may have happened debugName := "build-" + stepName if b.Name != "" {