Start working on logging across the board

command/build/command.go

@@ -5,7 +5,6 @@ import "github.com/mitchellh/packer/packer"
 type Command byte
 
 func (Command) Run(env packer.Environment, arg []string) int {
-	env.Ui().Say("BUILDING!")
 	return 0
 }
 

packer.go

@@ -5,6 +5,7 @@ import (
 	"github.com/mitchellh/packer/packer"
 	"github.com/mitchellh/packer/packer/plugin"
 	"fmt"
+	"log"
 	"os"
 	"os/exec"
 )
@@ -22,8 +23,10 @@ func main() {
 	envConfig := packer.DefaultEnvironmentConfig()
 	envConfig.Commands = commandKeys
 	envConfig.CommandFunc = func(n string) (packer.Command, error) {
+		log.Printf("Loading command: %s\n", n)
 		commandBin, ok := commands[n]
 		if !ok {
+			log.Printf("Command not found: %s\n", n)
 			return nil, nil
 		}
 

packer/plugin/command.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"errors"
 	"github.com/mitchellh/packer/packer"
+	"log"
 	"net/rpc"
 	"os/exec"
 	packrpc "github.com/mitchellh/packer/packer/rpc"
@@ -25,19 +26,23 @@ func Command(cmd *exec.Cmd) (result packer.Command, err error) {
 		"PACKER_PLUGIN_MAX_PORT=25000",
 	}
 
-	out := new(bytes.Buffer)
+	stdout := new(bytes.Buffer)
+	stderr := new(bytes.Buffer)
 	cmd.Env = append(cmd.Env, env...)
-	cmd.Stdout = out
+	cmd.Stderr = stderr
+	cmd.Stdout = stdout
 	err = cmd.Start()
 	if err != nil {
 		return
 	}
 
-	// Make sure the command is properly cleaned up in the case of
-	// an error.
 	defer func() {
+		// Make sure the command is properly killed in the case of an error
 		if err != nil {
 			cmd.Process.Kill()
+
+			// Log the stderr, which should include any logs from the subprocess
+			log.Print(stderr.String())
 		}
 	}()
 
@@ -63,7 +68,7 @@ func Command(cmd *exec.Cmd) (result packer.Command, err error) {
 		default:
 		}
 
-		if line, lerr := out.ReadBytes('\n'); lerr == nil {
+		if line, lerr := stdout.ReadBytes('\n'); lerr == nil {
 			// Trim the address and reset the err since we were able
 			// to read some sort of address.
 			address = strings.TrimSpace(string(line))

packer/plugin/plugin.go

@@ -10,6 +10,7 @@ package plugin
 import (
 	"fmt"
 	"github.com/mitchellh/packer/packer"
+	"log"
 	"net"
 	"net/rpc"
 	"os"
@@ -30,6 +31,9 @@ func serve(server *rpc.Server) (err error) {
 		return
 	}
 
+	log.Printf("Plugin minimum port: %d\n", minPort)
+	log.Printf("Plugin maximum port: %d\n", minPort)
+
 	var address string
 	var listener net.Listener
 	for port := minPort; port <= maxPort; port++ {
@@ -45,26 +49,34 @@ func serve(server *rpc.Server) (err error) {
 	defer listener.Close()
 
 	// Output the address to stdout
+	log.Printf("Plugin address: %s\n", address)
 	fmt.Println(address)
 	os.Stdout.Sync()
 
 	// Accept a connection
+	log.Println("Waiting for connection...")
 	conn, err := listener.Accept()
 	if err != nil {
+		log.Printf("Error accepting connection: %s\n", err.Error())
 		return
 	}
 
 	// Serve a single connection
+	log.Println("Serving a plugin connection...")
 	server.ServeConn(conn)
 	return
 }
 
 // Serves a command from a plugin.
 func ServeCommand(command packer.Command) {
+	log.Println("Preparing to serve a command plugin...")
+
 	server := rpc.NewServer()
 	packrpc.RegisterCommand(server, command)
 
 	if err := serve(server); err != nil {
-		panic(err)
+		log.Panic(err)
 	}
+
+	log.Println("Command successfully served. Exiting.")
 }