Add Graph.DebugOperation

The method marks the start of a set of operations on the Graph, with
extra information optionally provided in the second paramter. This
returns a function with a single End method to mark the end of the set
in the logs.

Refactor the existing graph Begin/End Operation calls to use this single
method. Remove the *string types in the marshal structs, these are
strictly informational and don't need to differentiate empty vs unset
strings.

Add calls to DebugOperation for each step while building the graph.

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))

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) {

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 {
-	e.Encode(marshalOperation{
-		Type:  "Operation",
-		Begin: newString("Replace"),
-	})
-	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"),
-	})
-}
+// 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) {}
+	}
 
-// 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"),
+		Begin: op,
+		Info:  info,
 	})
-	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)

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 != "" {