diff --git a/terraform/context.go b/terraform/context.go index 7720bd8ac..914dd19dc 100644 --- a/terraform/context.go +++ b/terraform/context.go @@ -697,11 +697,9 @@ func (c *Context) walk( log.Printf("[DEBUG] Starting graph walk: %s", operation.String()) - dg, _ := NewDebugGraph("walk", graph, nil) walker := &ContextGraphWalker{ - Context: realCtx, - Operation: operation, - DebugGraph: dg, + Context: realCtx, + Operation: operation, } // Watch for a stop so we can call the provider Stop() API. @@ -728,20 +726,13 @@ func (c *Context) walk( // If we have a shadow graph, wait for that to complete. if shadowCloser != nil { - // create a debug graph for this walk - dg, err := NewDebugGraph("walk-shadow", shadow, nil) - if err != nil { - log.Printf("[ERROR] %v", err) - } - // Build the graph walker for the shadow. We also wrap this in // a panicwrap so that panics are captured. For the shadow graph, // we just want panics to be normal errors rather than to crash // Terraform. shadowWalker := GraphWalkerPanicwrap(&ContextGraphWalker{ - Context: shadowCtx, - Operation: operation, - DebugGraph: dg, + Context: shadowCtx, + Operation: operation, }) // Kick off the shadow walk. This will block on any operations diff --git a/terraform/debug.go b/terraform/debug.go index 84471b34e..c2bd223f0 100644 --- a/terraform/debug.go +++ b/terraform/debug.go @@ -166,6 +166,41 @@ func (d *debugInfo) Close() error { return nil } +// debug buffer is an io.WriteCloser that will write itself to the debug +// archive when closed. +type debugBuffer struct { + debugInfo *debugInfo + name string + buf bytes.Buffer +} + +func (b *debugBuffer) Write(d []byte) (int, error) { + return b.buf.Write(d) +} + +func (b *debugBuffer) Close() error { + return b.debugInfo.WriteFile(b.name, b.buf.Bytes()) +} + +// ioutils only has a noop ReadCloser +type nopWriteCloser struct{} + +func (nopWriteCloser) Write([]byte) (int, error) { return 0, nil } +func (nopWriteCloser) Close() error { return nil } + +// NewFileWriter returns an io.WriteClose that will be buffered and written to +// the debug archive when closed. +func (d *debugInfo) NewFileWriter(name string) io.WriteCloser { + if d == nil { + return nopWriteCloser{} + } + + return &debugBuffer{ + debugInfo: d, + name: name, + } +} + type syncer interface { Sync() error } @@ -192,15 +227,10 @@ func (d *debugInfo) flush() { // WriteGraph takes a DebugGraph and writes both the DebugGraph as a dot file // in the debug archive, and extracts any logs that the DebugGraph collected // and writes them to a log file in the archive. -func (d *debugInfo) WriteGraph(dg *DebugGraph) error { - if d == nil { +func (d *debugInfo) WriteGraph(name string, g *Graph) error { + if d == nil || g == nil { return nil } - - if dg == nil { - return nil - } - d.Lock() defer d.Unlock() @@ -209,12 +239,10 @@ func (d *debugInfo) WriteGraph(dg *DebugGraph) error { // sync'ed. defer d.flush() - d.writeFile(dg.Name, dg.LogBytes()) - - dotPath := fmt.Sprintf("%s/graphs/%d-%s-%s.dot", d.name, d.step, d.phase, dg.Name) + dotPath := fmt.Sprintf("%s/graphs/%d-%s-%s.dot", d.name, d.step, d.phase, name) d.step++ - dotBytes := dg.DotBytes() + dotBytes := g.Dot(nil) hdr := &tar.Header{ Name: dotPath, Mode: 0644, diff --git a/terraform/debug_test.go b/terraform/debug_test.go index 5f8cbb18b..342a86b98 100644 --- a/terraform/debug_test.go +++ b/terraform/debug_test.go @@ -16,7 +16,7 @@ func TestDebugInfo_nil(t *testing.T) { var d *debugInfo d.SetPhase("none") - d.WriteGraph(nil) + d.WriteGraph("", nil) d.WriteFile("none", nil) d.Close() } @@ -122,6 +122,7 @@ func TestDebug_plan(t *testing.T) { files := 0 graphs := 0 + json := 0 for { hdr, err := tr.Next() if err == io.EOF { @@ -139,6 +140,10 @@ func TestDebug_plan(t *testing.T) { if strings.HasSuffix(hdr.Name, ".dot") { graphs++ } + + if strings.HasSuffix(hdr.Name, "graph.json") { + json++ + } } } @@ -146,13 +151,13 @@ func TestDebug_plan(t *testing.T) { t.Fatal("no files with data found") } - /* - TODO: once @jbardin finishes the dot refactor, uncomment this. This - won't pass since the new graph doesn't implement the dot nodes. - if graphs == 0 { - t.Fatal("no no-empty graphs found") - } - */ + if graphs == 0 { + t.Fatal("no no-empty graphs found") + } + + if json == 0 { + t.Fatal("no json graphs") + } } // verify that no hooks panic on nil input diff --git a/terraform/graph.go b/terraform/graph.go index 5174ef925..af7b8012e 100644 --- a/terraform/graph.go +++ b/terraform/graph.go @@ -40,6 +40,11 @@ type Graph struct { // edges. dependableMap map[string]dag.Vertex + // debugName is a name for reference in the debug output. This is usually + // to indicate what topmost builder was, and if this graph is a shadow or + // not. + debugName string + once sync.Once } @@ -201,7 +206,6 @@ func (g *Graph) Dependable(n string) dag.Vertex { // will be walked with full parallelism, so the walker should expect // to be called in concurrently. func (g *Graph) Walk(walker GraphWalker) error { - defer dbug.WriteGraph(walker.Debug()) return g.walk(walker) } @@ -229,6 +233,15 @@ func (g *Graph) walk(walker GraphWalker) error { panicwrap = nil // just to be sure } + debugName := "walk-graph.json" + if g.debugName != "" { + debugName = g.debugName + "-" + debugName + } + + debugBuf := dbug.NewFileWriter(debugName) + g.SetDebugWriter(debugBuf) + defer debugBuf.Close() + // Walk the graph. var walkFn dag.WalkFunc walkFn = func(v dag.Vertex) (rerr error) { @@ -258,10 +271,7 @@ func (g *Graph) walk(walker GraphWalker) error { }() walker.EnterVertex(v) - defer func() { - walker.Debug().DebugNode(v) - walker.ExitVertex(v, rerr) - }() + defer walker.ExitVertex(v, rerr) // vertexCtx is the context that we use when evaluating. This // is normally the context of our graph but can be overridden @@ -283,7 +293,10 @@ func (g *Graph) walk(walker GraphWalker) error { // Allow the walker to change our tree if needed. Eval, // then callback with the output. log.Printf("[DEBUG] vertex '%s.%s': evaluating", path, dag.VertexName(v)) - walker.Debug().Printf("[DEBUG] vertex %T(%s.%s): evaluating\n", v, path, dag.VertexName(v)) + + // TODO: replace these debug calls with Graph native methods + //walker.Debug().Printf("[DEBUG] vertex %T(%s.%s): evaluating\n", v, path, dag.VertexName(v)) + tree = walker.EnterEvalTree(v, tree) output, err := Eval(tree, vertexCtx) if rerr = walker.ExitEvalTree(v, output, err); rerr != nil { @@ -297,7 +310,7 @@ func (g *Graph) walk(walker GraphWalker) error { "[DEBUG] vertex '%s.%s': expanding/walking dynamic subgraph", path, dag.VertexName(v)) - walker.Debug().Printf("[DEBUG] vertex %T(%s.%s): expanding\n", v, path, dag.VertexName(v)) + //walker.Debug().Printf("[DEBUG] vertex %T(%s.%s): expanding\n", v, path, dag.VertexName(v)) g, err := ev.DynamicExpand(vertexCtx) if err != nil { rerr = err @@ -318,8 +331,8 @@ func (g *Graph) walk(walker GraphWalker) error { path, dag.VertexName(v)) - walker.Debug().Printf( - "[DEBUG] vertex %T(%s.%s): subgraph\n", v, path, dag.VertexName(v)) + //walker.Debug().Printf( + // "[DEBUG] vertex %T(%s.%s): subgraph\n", v, path, dag.VertexName(v)) if rerr = sn.Subgraph().(*Graph).walk(walker); rerr != nil { return diff --git a/terraform/graph_builder.go b/terraform/graph_builder.go index 161bd1038..a7f892ac9 100644 --- a/terraform/graph_builder.go +++ b/terraform/graph_builder.go @@ -29,6 +29,15 @@ type BasicGraphBuilder struct { func (b *BasicGraphBuilder) Build(path []string) (*Graph, error) { g := &Graph{Path: path} + + debugName := "build-graph.json" + if b.Name != "" { + debugName = b.Name + "-" + debugName + } + debugBuf := dbug.NewFileWriter(debugName) + g.SetDebugWriter(debugBuf) + defer debugBuf.Close() + for _, step := range b.Steps { if step == nil { continue @@ -52,8 +61,8 @@ func (b *BasicGraphBuilder) Build(path []string) (*Graph, error) { "[TRACE] Graph after step %T:\n\n%s", step, g.StringWithNodeTypes()) - dg, _ := NewDebugGraph(debugName, g, nil) - dbug.WriteGraph(dg) + // TODO: replace entirely with the json logs + dbug.WriteGraph(debugName, g) if err != nil { return g, err diff --git a/terraform/graph_debug.go b/terraform/graph_debug.go deleted file mode 100644 index 5deb6a81e..000000000 --- a/terraform/graph_debug.go +++ /dev/null @@ -1,111 +0,0 @@ -package terraform - -import ( - "bytes" - "fmt" - "sync" - - "github.com/davecgh/go-spew/spew" - "github.com/hashicorp/terraform/dag" - "github.com/mitchellh/copystructure" -) - -// The NodeDebug method outputs debug information to annotate the graphs -// stored in the DebugInfo -type GraphNodeDebugger interface { - NodeDebug() string -} - -type GraphNodeDebugOrigin interface { - DotOrigin() bool -} -type DebugGraph struct { - sync.Mutex - Name string - - ord int - buf bytes.Buffer - - Graph *Graph - - dotOpts *dag.DotOpts -} - -// DebugGraph holds a dot representation of the Terraform graph, and can be -// written out to the DebugInfo log with DebugInfo.WriteGraph. A DebugGraph can -// log data to it's internal buffer via the Printf and Write methods, which -// will be also be written out to the DebugInfo archive. -func NewDebugGraph(name string, g *Graph, opts *dag.DotOpts) (*DebugGraph, error) { - dg := &DebugGraph{ - Name: name, - Graph: g, - dotOpts: opts, - } - - dbug.WriteFile(dg.Name, g.Dot(opts)) - return dg, nil -} - -// Printf to the internal buffer -func (dg *DebugGraph) Printf(f string, args ...interface{}) (int, error) { - if dg == nil { - return 0, nil - } - dg.Lock() - defer dg.Unlock() - return fmt.Fprintf(&dg.buf, f, args...) -} - -// Write to the internal buffer -func (dg *DebugGraph) Write(b []byte) (int, error) { - if dg == nil { - return 0, nil - } - dg.Lock() - defer dg.Unlock() - return dg.buf.Write(b) -} - -func (dg *DebugGraph) LogBytes() []byte { - if dg == nil { - return nil - } - dg.Lock() - defer dg.Unlock() - return dg.buf.Bytes() -} - -func (dg *DebugGraph) DotBytes() []byte { - if dg == nil { - return nil - } - dg.Lock() - defer dg.Unlock() - return dg.Graph.Dot(dg.dotOpts) -} - -func (dg *DebugGraph) DebugNode(v interface{}) { - if dg == nil { - return - } - dg.Lock() - defer dg.Unlock() - - // record the ordinal value for each node - ord := dg.ord - dg.ord++ - - name := dag.VertexName(v) - vCopy, _ := copystructure.Config{Lock: true}.Copy(v) - - // record as much of the node data structure as we can - spew.Fdump(&dg.buf, vCopy) - - dg.buf.WriteString(fmt.Sprintf("%d visited %s\n", ord, name)) - - // if the node provides debug output, insert it into the graph, and log it - if nd, ok := v.(GraphNodeDebugger); ok { - out := nd.NodeDebug() - dg.buf.WriteString(fmt.Sprintf("NodeDebug (%s):'%s'\n", name, out)) - } -} diff --git a/terraform/graph_walk.go b/terraform/graph_walk.go index 1e49f2162..34ce6f640 100644 --- a/terraform/graph_walk.go +++ b/terraform/graph_walk.go @@ -13,7 +13,6 @@ type GraphWalker interface { ExitVertex(dag.Vertex, error) EnterEvalTree(dag.Vertex, EvalNode) EvalNode ExitEvalTree(dag.Vertex, interface{}, error) error - Debug() *DebugGraph } // GrpahWalkerPanicwrapper can be optionally implemented to catch panics @@ -59,4 +58,3 @@ func (NullGraphWalker) EnterEvalTree(v dag.Vertex, n EvalNode) EvalNode { return func (NullGraphWalker) ExitEvalTree(dag.Vertex, interface{}, error) error { return nil } -func (NullGraphWalker) Debug() *DebugGraph { return nil } diff --git a/terraform/graph_walk_context.go b/terraform/graph_walk_context.go index 9f3051b1d..459fcdec9 100644 --- a/terraform/graph_walk_context.go +++ b/terraform/graph_walk_context.go @@ -15,9 +15,8 @@ type ContextGraphWalker struct { NullGraphWalker // Configurable values - Context *Context - Operation walkOperation - DebugGraph *DebugGraph + Context *Context + Operation walkOperation // Outputs, do not set these. Do not read these while the graph // is being walked. @@ -145,10 +144,6 @@ func (w *ContextGraphWalker) ExitEvalTree( return nil } -func (w *ContextGraphWalker) Debug() *DebugGraph { - return w.DebugGraph -} - func (w *ContextGraphWalker) init() { w.contexts = make(map[string]*BuiltinEvalContext, 5) w.providerCache = make(map[string]ResourceProvider, 5)