Enable panicwrap and put crash logs in crash.log

CHANGELOG.md

@@ -5,6 +5,8 @@ FEATURES:
 * New command: `packer inspect`. This command tells you the components of
   a template. It respects the `-machine-readable` flag as well so you can
   parse out components of a template.
+* Packer will detect its own crashes (always a bug) and save a "crash.log"
+  file.
 
 IMPROVEMENTS:
 

packer.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"github.com/mitchellh/packer/packer"
 	"github.com/mitchellh/packer/packer/plugin"
+	"github.com/mitchellh/panicwrap"
 	"io"
 	"io/ioutil"
 	"log"
@@ -15,32 +16,68 @@ import (
 )
 
 func main() {
-	// Setup logging if PACKER_LOG is set.
-	// Log to PACKER_LOG_PATH if it is set, otherwise default to stderr.
-	var logOutput io.Writer = ioutil.Discard
-	if os.Getenv("PACKER_LOG") != "" {
-		logOutput = os.Stderr
+	// Call realMain instead of doing the work here so we can use
+	// `defer` statements within the function and have them work properly.
+	// (defers aren't called with os.Exit)
+	os.Exit(realMain())
+}
 
-		if logPath := os.Getenv("PACKER_LOG_PATH"); logPath != "" {
-			var err error
-			logOutput, err = os.Create(logPath)
+// realMain is executed from main and returns the exit status to exit with.
+func realMain() int {
+	// If there is no explicit number of Go threads to use, then set it
+	if os.Getenv("GOMAXPROCS") == "" {
+		runtime.GOMAXPROCS(runtime.NumCPU())
+	}
+
+	// Determine where logs should go in general (requested by the user)
+	logWriter, err := logOutput()
 	if err != nil {
-				fmt.Fprintf(
-					os.Stderr,
-					"Couldn't open '%s' for logging: %s",
-					logPath, err)
-				os.Exit(1)
+		fmt.Fprintf(os.Stderr, "Couldn't setup log output: %s", err)
+		return 1
 	}
+
+	// We also always send logs to a temporary file that we use in case
+	// there is a panic. Otherwise, we delete it.
+	logTempFile, err := ioutil.TempFile("", "packer-log")
+	if err != nil {
+		fmt.Fprintf(os.Stderr, "Couldn't setup logging tempfile: %s", err)
+		return 1
 	}
+	defer os.Remove(logTempFile.Name())
+	defer logTempFile.Close()
+
+	// Reset the log variables to minimize work in the subprocess
+	os.Setenv("PACKER_LOG", "")
+	os.Setenv("PACKER_LOG_FILE", "")
+
+	// Create the configuration for panicwrap and wrap our executable
+	wrapConfig := &panicwrap.WrapConfig{
+		Handler: panicHandler(logTempFile),
+		Writer:  io.MultiWriter(logTempFile, logWriter),
 	}
 
-	log.SetOutput(logOutput)
+	exitStatus, err := panicwrap.Wrap(wrapConfig)
+	if err != nil {
+		fmt.Fprintf(os.Stderr, "Couldn't start Packer: %s", err)
+		return 1
+	}
 
-	// If there is no explicit number of Go threads to use, then set it
-	if os.Getenv("GOMAXPROCS") == "" {
-		runtime.GOMAXPROCS(runtime.NumCPU())
+	if exitStatus >= 0 {
+		return exitStatus
 	}
 
+	// We're the child, so just close the tempfile we made in order to
+	// save file handles since the tempfile is only used by the parent.
+	logTempFile.Close()
+
+	return wrappedMain()
+}
+
+// wrappedMain is called only when we're wrapped by panicwrap and
+// returns the exit status to exit with.
+func wrappedMain() int {
+	log.SetOutput(os.Stderr)
+
 	log.Printf(
 		"Packer Version: %s %s %s",
 		packer.Version, packer.VersionPrerelease, packer.GitCommit)
@@ -52,7 +89,7 @@ func main() {
 	config, err := loadConfig()
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "Error loading configuration: \n\n%s\n", err)
-		os.Exit(1)
+		return 1
 	}
 
 	log.Printf("Packer config: %+v", config)
@@ -65,12 +102,12 @@ func main() {
 	cacheDir, err = filepath.Abs(cacheDir)
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "Error preparing cache directory: \n\n%s\n", err)
-		os.Exit(1)
+		return 1
 	}
 
 	if err := os.MkdirAll(cacheDir, 0755); err != nil {
 		fmt.Fprintf(os.Stderr, "Error preparing cache directory: \n\n%s\n", err)
-		os.Exit(1)
+		return 1
 	}
 
 	log.Printf("Setting cache directory: %s", cacheDir)
@@ -100,8 +137,7 @@ func main() {
 	env, err := packer.NewEnvironment(envConfig)
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "Packer initialization error: \n\n%s\n", err)
-		plugin.CleanupClients()
-		os.Exit(1)
+		return 1
 	}
 
 	setupSignalHandlers(env)
@@ -109,12 +145,10 @@ func main() {
 	exitCode, err := env.Cli(args)
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "Error executing CLI: %s\n", err.Error())
-		plugin.CleanupClients()
-		os.Exit(1)
+		return 1
 	}
 
-	plugin.CleanupClients()
-	os.Exit(exitCode)
+	return exitCode
 }
 
 // extractMachineReadable checks the args for the machine readable
@@ -178,3 +212,21 @@ func loadConfig() (*config, error) {
 
 	return &config, nil
 }
+
+// logOutput determines where we should send logs (if anywhere).
+func logOutput() (logOutput io.Writer, err error) {
+	logOutput = ioutil.Discard
+	if os.Getenv("PACKER_LOG") != "" {
+		logOutput = os.Stderr
+
+		if logPath := os.Getenv("PACKER_LOG_PATH"); logPath != "" {
+			var err error
+			logOutput, err = os.Create(logPath)
+			if err != nil {
+				return nil, err
+			}
+		}
+	}
+
+	return
+}

panic.go

+package main
+
+import (
+	"fmt"
+	"github.com/mitchellh/panicwrap"
+	"io"
+	"os"
+	"strings"
+)
+
+// This is output if a panic happens.
+const panicOutput = `
+
+!!!!!!!!!!!!!!!!!!!!!!!!!!! PACKER CRASH !!!!!!!!!!!!!!!!!!!!!!!!!!!!
+
+Packer crashed! This is always indicative of a bug within Packer.
+A crash log has been placed at "crash.log" relative to your current
+working directory. It would be immensely helpful if you could please
+report the crash with Packer[1] so that we can fix this.
+
+!!!!!!!!!!!!!!!!!!!!!!!!!!! PACKER CRASH !!!!!!!!!!!!!!!!!!!!!!!!!!!!
+`
+
+// panicHandler is what is called by panicwrap when a panic is encountered
+// within Packer. It is guaranteed to run after the resulting process has
+// exited so we can take the log file, add in the panic, and store it
+// somewhere locally.
+func panicHandler(logF *os.File) panicwrap.HandlerFunc {
+	return func(m string) {
+		// Write away just output this thing on stderr so that it gets
+		// shown in case anything below fails.
+		fmt.Fprintf(os.Stderr, fmt.Sprintf("%s\n", m))
+
+		// Create the crash log file where we'll write the logs
+		f, err := os.Create("crash.log")
+		if err != nil {
+			fmt.Fprintf(os.Stderr, "Failed to create crash log file: %s", err)
+			return
+		}
+		defer f.Close()
+
+		// Seek the log file back to the beginning
+		if _, err = logF.Seek(0, 0); err != nil {
+			fmt.Fprintf(os.Stderr, "Failed to seek log file for crash: %s", err)
+			return
+		}
+
+		// Copy the contents to the crash file. This will include
+		// the panic that just happened.
+		if _, err = io.Copy(f, logF); err != nil {
+			fmt.Fprintf(os.Stderr, "Failed to write crash log: %s", err)
+			return
+		}
+
+		// Tell the user a crash occurred in some helpful way that
+		// they'll hopefully notice.
+		fmt.Printf("\n\n")
+		fmt.Println(strings.TrimSpace(panicOutput))
+	}
+}