Add telemetry reporting through checkpoint

Will report builders/provisioner/post-processor types used per build,
and whether or not the build passed.

Will also report any panics we see.

You may opt out of this reporting by setting the environment variable
`CHECKPOINT_DISABLE`.

main.go

@@ -73,6 +73,14 @@ func realMain() int {
 		outR, outW := io.Pipe()
 		go copyOutput(outR, doneCh)
 
+		// Enable checkpoint for panic reporting
+		config, err := loadConfig()
+		if err == nil {
+			if !config.DisableCheckpoint {
+				packer.CheckpointReporter.Enable(config.DisableCheckpointSignature)
+			}
+		}
+
 		// Create the configuration for panicwrap and wrap our executable
 		wrapConfig.Handler = panicHandler(logTempFile)
 		wrapConfig.Writer = io.MultiWriter(logTempFile, logWriter)
@@ -117,9 +125,11 @@ func wrappedMain() int {
 	log.Printf("Packer Target OS/Arch: %s %s", runtime.GOOS, runtime.GOARCH)
 	log.Printf("Built with Go Version: %s", runtime.Version())
 
+	inPlugin := os.Getenv(plugin.MagicCookieKey) == plugin.MagicCookieValue
+
 	// Prepare stdin for plugin usage by switching it to a pipe
 	// But do not switch to pipe in plugin
-	if os.Getenv(plugin.MagicCookieKey) != plugin.MagicCookieValue {
+	if !inPlugin {
 		setupStdin()
 	}
 
@@ -132,6 +142,9 @@ func wrappedMain() int {
 
 	// Fire off the checkpoint.
 	go runCheckpoint(config)
+	if !config.DisableCheckpoint {
+		packer.CheckpointReporter.Enable(config.DisableCheckpointSignature)
+	}
 
 	cacheDir := os.Getenv("PACKER_CACHE_DIR")
 	if cacheDir == "" {
@@ -196,6 +209,12 @@ func wrappedMain() int {
 	}
 
 	exitCode, err := cli.Run()
+	if !inPlugin {
+		if err := packer.CheckpointReporter.Finalize(cli.Subcommand(), exitCode, err); err != nil {
+			log.Printf("Error finalizing telemetry report. This is safe to ignore. %s", err.Error())
+		}
+	}
+
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "Error executing CLI: %s\n", err)
 		return 1

packer/build.go

@@ -115,6 +115,7 @@ type coreBuildPostProcessor struct {
 // Keeps track of the provisioner and the configuration of the provisioner
 // within the build.
 type coreBuildProvisioner struct {
+	pType       string
 	provisioner Provisioner
 	config      []interface{}
 }
@@ -193,17 +194,13 @@ func (b *coreBuild) Run(originalUi Ui, cache Cache) ([]Artifact, error) {
 
 	// Add a hook for the provisioners if we have provisioners
 	if len(b.provisioners) > 0 {
-		provisioners := make([]Provisioner, len(b.provisioners))
-		for i, p := range b.provisioners {
-			provisioners[i] = p.provisioner
-		}
 
 		if _, ok := hooks[HookProvision]; !ok {
 			hooks[HookProvision] = make([]Hook, 0, 1)
 		}
 
 		hooks[HookProvision] = append(hooks[HookProvision], &ProvisionHook{
-			Provisioners: provisioners,
+			Provisioners: b.provisioners,
 		})
 	}
 
@@ -217,7 +214,9 @@ func (b *coreBuild) Run(originalUi Ui, cache Cache) ([]Artifact, error) {
 	}
 
 	log.Printf("Running builder: %s", b.builderType)
+	ts := CheckpointReporter.AddSpan(b.builderType, "builder")
 	builderArtifact, err := b.builder.Run(builderUi, hook, cache)
+	ts.End(err)
 	if err != nil {
 		return nil, err
 	}
@@ -242,7 +241,9 @@ PostProcessorRunSeqLoop:
 			}
 
 			builderUi.Say(fmt.Sprintf("Running post-processor: %s", corePP.processorType))
+			ts := CheckpointReporter.AddSpan(corePP.processorType, "post-processor")
 			artifact, keep, err := corePP.processor.PostProcess(ppUi, priorArtifact)
+			ts.End(err)
 			if err != nil {
 				errors = append(errors, fmt.Errorf("Post-processor failed: %s", err))
 				continue PostProcessorRunSeqLoop

packer/core.go

@@ -154,6 +154,7 @@ func (c *Core) Build(n string) (Build, error) {
 		}
 
 		provisioners = append(provisioners, coreBuildProvisioner{
+			pType:       rawP.Type,
 			provisioner: provisioner,
 			config:      config,
 		})

packer/provisioner.go

@@ -30,7 +30,7 @@ type Provisioner interface {
 type ProvisionHook struct {
 	// The provisioners to run as part of the hook. These should already
 	// be prepared (by calling Prepare) at some earlier stage.
-	Provisioners []Provisioner
+	Provisioners []coreBuildProvisioner
 
 	lock               sync.Mutex
 	runningProvisioner Provisioner
@@ -59,10 +59,13 @@ func (h *ProvisionHook) Run(name string, ui Ui, comm Communicator, data interfac
 
 	for _, p := range h.Provisioners {
 		h.lock.Lock()
-		h.runningProvisioner = p
+		h.runningProvisioner = p.provisioner
 		h.lock.Unlock()
 
-		if err := p.Provision(ui, comm); err != nil {
+		ts := CheckpointReporter.AddSpan(p.pType, "provisioner")
+		err := p.provisioner.Provision(ui, comm)
+		ts.End(err)
+		if err != nil {
 			return err
 		}
 	}

packer/telemetry.go

@@ -0,0 +1,133 @@
+package packer
+
+import (
+	"fmt"
+	"log"
+	"os"
+	"path/filepath"
+	"time"
+
+	checkpoint "github.com/hashicorp/go-checkpoint"
+	packerVersion "github.com/hashicorp/packer/version"
+)
+
+const TelemetryVersion string = "beta/packer/4"
+const TelemetryPanicVersion string = "beta/packer_panic/4"
+
+var CheckpointReporter CheckpointTelemetry
+
+func init() {
+	CheckpointReporter.startTime = time.Now().UTC()
+}
+
+type PackerReport struct {
+	Spans    []*TelemetrySpan `json:"spans"`
+	ExitCode int              `json:"exit_code"`
+	Error    string           `json:"error"`
+	Command  string           `json:"command"`
+}
+
+type CheckpointTelemetry struct {
+	enabled       bool
+	spans         []*TelemetrySpan
+	signatureFile string
+	startTime     time.Time
+}
+
+func (c *CheckpointTelemetry) Enable(disableSignature bool) {
+	configDir, err := ConfigDir()
+	if err != nil {
+		log.Printf("[ERR] Checkpoint telemetry setup error: %s", err)
+		return
+	}
+
+	signatureFile := ""
+	if disableSignature {
+		log.Printf("[INFO] Checkpoint telemetry signature disabled")
+	} else {
+		signatureFile = filepath.Join(configDir, "checkpoint_signature")
+	}
+
+	c.signatureFile = signatureFile
+	c.enabled = true
+}
+
+func (c *CheckpointTelemetry) baseParams(prefix string) *checkpoint.ReportParams {
+	version := packerVersion.Version
+	if packerVersion.VersionPrerelease != "" {
+		version += fmt.Sprintf("-%s", packerVersion.VersionPrerelease)
+	}
+
+	return &checkpoint.ReportParams{
+		Product:       "packer",
+		SchemaVersion: prefix,
+		StartTime:     c.startTime,
+		Version:       version,
+		RunID:         os.Getenv("PACKER_RUN_UUID"),
+		SignatureFile: c.signatureFile,
+	}
+}
+
+func (c *CheckpointTelemetry) log(m string, args ...interface{}) {
+}
+
+func (c *CheckpointTelemetry) ReportPanic(m string) error {
+	if !c.enabled {
+		return nil
+	}
+	log.Printf("[TELEMETRY] Add panic: %s", m)
+	panicParams := c.baseParams(TelemetryPanicVersion)
+	panicParams.Payload = m
+	panicParams.EndTime = time.Now().UTC()
+	return checkpoint.Report(panicParams)
+}
+
+func (c *CheckpointTelemetry) AddSpan(name, pluginType string) *TelemetrySpan {
+	log.Printf("[TELEMETRY] Starting %s %s", pluginType, name)
+	ts := &TelemetrySpan{
+		Name:      name,
+		Type:      pluginType,
+		StartTime: time.Now().UTC(),
+	}
+	c.spans = append(c.spans, ts)
+	return ts
+}
+
+func (c *CheckpointTelemetry) Finalize(command string, errCode int, err error) error {
+	if !c.enabled {
+		return nil
+	}
+
+	log.Printf("[TELEMETRY] finalize: %#v", c)
+	params := c.baseParams(TelemetryVersion)
+	params.EndTime = time.Now().UTC()
+
+	extra := &PackerReport{
+		Spans:    c.spans,
+		ExitCode: errCode,
+		Command:  command,
+	}
+	if err != nil {
+		extra.Error = err.Error()
+	}
+	params.Payload = extra
+
+	return checkpoint.Report(params)
+}
+
+type TelemetrySpan struct {
+	Name      string    `json:"name"`
+	Type      string    `json:"type"`
+	StartTime time.Time `json:"start_time"`
+	EndTime   time.Time `json:"end_time"`
+	Error     string    `json:"error"`
+}
+
+func (s *TelemetrySpan) End(err error) {
+	s.EndTime = time.Now().UTC()
+	log.Printf("[TELEMETRY] ending %s", s.Name)
+	if err != nil {
+		s.Error = err.Error()
+		log.Printf("[TELEMETRY] ERROR: %s", err.Error())
+	}
+}

panic.go

@@ -6,6 +6,7 @@ import (
 	"os"
 	"strings"
 
+	"github.com/hashicorp/packer/packer"
 	"github.com/mitchellh/panicwrap"
 )
 
@@ -34,6 +35,10 @@ func panicHandler(logF *os.File) panicwrap.HandlerFunc {
 		// shown in case anything below fails.
 		fmt.Fprintf(os.Stderr, fmt.Sprintf("%s\n", m))
 
+		if err := packer.CheckpointReporter.ReportPanic(m); err != nil {
+			fmt.Fprintf(os.Stderr, "Failed to report panic. This is safe to ignore: %s", err)
+		}
+
 		// Create the crash log file where we'll write the logs
 		f, err := os.Create("crash.log")
 		if err != nil {