Merge pull request #1409 from rneugeba/build

Add logging to "moby build"

src/cmd/moby/build.go

@@ -7,9 +7,9 @@ import (
 	"fmt"
 	"io"
 	"io/ioutil"
-	"log"
 	"path/filepath"
 
+	log "github.com/Sirupsen/logrus"
 	"github.com/docker/moby/src/initrd"
 )
 
@@ -92,6 +92,7 @@ func build(name string, pull bool, args []string) {
 	containers := []*bytes.Buffer{}
 
 	if pull {
+		log.Infof("Pull kernel image: %s", m.Kernel.Image)
 		err := dockerPull(m.Kernel.Image)
 		if err != nil {
 			log.Fatalf("Could not pull image %s: %v", m.Kernel.Image, err)
@@ -99,6 +100,7 @@ func build(name string, pull bool, args []string) {
 	}
 	// get kernel bzImage and initrd tarball from container
 	// TODO examine contents to see what names they might have
+	log.Infof("Extract kernel image: %s", m.Kernel.Image)
 	const (
 		bzimageName = "bzImage"
 		ktarName    = "kernel.tar"
@@ -116,11 +118,13 @@ func build(name string, pull bool, args []string) {
 
 	// convert init image to tarball
 	if pull {
+		log.Infof("Pull init: %s", m.Init)
 		err := dockerPull(m.Init)
 		if err != nil {
 			log.Fatalf("Could not pull image %s: %v", m.Init, err)
 		}
 	}
+	log.Infof("Process init: %s", m.Init)
 	init, err := ImageExtract(m.Init, "")
 	if err != nil {
 		log.Fatalf("Failed to build init tarball: %v", err)
@@ -128,13 +132,16 @@ func build(name string, pull bool, args []string) {
 	buffer := bytes.NewBuffer(init)
 	containers = append(containers, buffer)
 
+	log.Infof("Add system containers:")
 	for i, image := range m.System {
 		if pull {
+			log.Infof("  Pull: %s", image.Image)
 			err := dockerPull(image.Image)
 			if err != nil {
 				log.Fatalf("Could not pull image %s: %v", image.Image, err)
 			}
 		}
+		log.Infof("  Create OCI config for %s", image.Image)
 		config, err := ConfigToOCI(&image)
 		if err != nil {
 			log.Fatalf("Failed to run riddler to get config.json for %s: %v", image.Image, err)
@@ -149,13 +156,16 @@ func build(name string, pull bool, args []string) {
 		containers = append(containers, buffer)
 	}
 
+	log.Infof("Add daemon containers:")
 	for _, image := range m.Daemon {
 		if pull {
+			log.Infof("  Pull: %s", image.Image)
 			err := dockerPull(image.Image)
 			if err != nil {
 				log.Fatalf("Could not pull image %s: %v", image.Image, err)
 			}
 		}
+		log.Infof("  Create OCI config for %s", image.Image)
 		config, err := ConfigToOCI(&image)
 		if err != nil {
 			log.Fatalf("Failed to run riddler to get config.json for %s: %v", image.Image, err)
@@ -176,11 +186,13 @@ func build(name string, pull bool, args []string) {
 	}
 	containers = append(containers, buffer)
 
+	log.Infof("Create initial ram disk")
 	initrd, err := containersInitrd(containers)
 	if err != nil {
 		log.Fatalf("Failed to make initrd %v", err)
 	}
 
+	log.Infof("Create outputs:")
 	err = outputs(m, name, bzimage.Bytes(), initrd.Bytes())
 	if err != nil {
 		log.Fatalf("Error writing outputs: %v", err)

src/cmd/moby/config.go

@@ -9,6 +9,7 @@ import (
 	"strconv"
 	"strings"
 
+	log "github.com/Sirupsen/logrus"
 	"gopkg.in/yaml.v2"
 )
 
@@ -119,7 +120,9 @@ func filesystem(m *Moby) (*bytes.Buffer, error) {
 	tw := tar.NewWriter(buf)
 	defer tw.Close()
 
+	log.Infof("Add files:")
 	for _, f := range m.Files {
+		log.Infof("  %s", f.Path)
 		if f.Path == "" {
 			return buf, errors.New("Did not specify path for file")
 		}

src/cmd/moby/docker.go

@@ -10,9 +10,12 @@ import (
 	"io/ioutil"
 	"os/exec"
 	"strings"
+
+	log "github.com/Sirupsen/logrus"
 )
 
 func dockerRun(args ...string) ([]byte, error) {
+	log.Debugf("docker run: %s", strings.Join(args, " "))
 	docker, err := exec.LookPath("docker")
 	if err != nil {
 		return []byte{}, errors.New("Docker does not seem to be installed")
@@ -50,10 +53,12 @@ func dockerRun(args ...string) ([]byte, error) {
 		return []byte{}, fmt.Errorf("%v: %s", err, stderr)
 	}
 
+	log.Debugf("docker run: %s...Done", strings.Join(args, " "))
 	return stdout, nil
 }
 
 func dockerRunInput(input io.Reader, args ...string) ([]byte, error) {
+	log.Debugf("docker run (input): %s", strings.Join(args, " "))
 	docker, err := exec.LookPath("docker")
 	if err != nil {
 		return []byte{}, errors.New("Docker does not seem to be installed")
@@ -92,10 +97,12 @@ func dockerRunInput(input io.Reader, args ...string) ([]byte, error) {
 		return []byte{}, fmt.Errorf("%v: %s", err, stderr)
 	}
 
+	log.Debugf("docker run (input): %s...Done", strings.Join(args, " "))
 	return stdout, nil
 }
 
 func dockerCreate(image string) (string, error) {
+	log.Debugf("docker create: %s", image)
 	docker, err := exec.LookPath("docker")
 	if err != nil {
 		return "", errors.New("Docker does not seem to be installed")
@@ -135,10 +142,12 @@ func dockerCreate(image string) (string, error) {
 	}
 
 	container := strings.TrimSpace(string(stdout))
+	log.Debugf("docker create: %s...Done", image)
 	return container, nil
 }
 
 func dockerExport(container string) ([]byte, error) {
+	log.Debugf("docker export: %s", container)
 	docker, err := exec.LookPath("docker")
 	if err != nil {
 		return []byte{}, errors.New("Docker does not seem to be installed")
@@ -176,10 +185,12 @@ func dockerExport(container string) ([]byte, error) {
 		return []byte{}, fmt.Errorf("%v: %s", err, stderr)
 	}
 
+	log.Debugf("docker export: %s...Done", container)
 	return stdout, nil
 }
 
 func dockerRm(container string) error {
+	log.Debugf("docker rm: %s", container)
 	docker, err := exec.LookPath("docker")
 	if err != nil {
 		return errors.New("Docker does not seem to be installed")
@@ -217,10 +228,12 @@ func dockerRm(container string) error {
 		return fmt.Errorf("%v: %s", err, stderr)
 	}
 
+	log.Debugf("docker rm: %s...Done", container)
 	return nil
 }
 
 func dockerPull(image string) error {
+	log.Debugf("docker pull: %s", image)
 	docker, err := exec.LookPath("docker")
 	if err != nil {
 		return errors.New("Docker does not seem to be installed")
@@ -258,5 +271,6 @@ func dockerPull(image string) error {
 		return fmt.Errorf("%v: %s", err, stderr)
 	}
 
+	log.Debugf("docker pull: %s...Done", image)
 	return nil
 }

src/cmd/moby/image.go

@@ -7,6 +7,8 @@ import (
 	"io"
 	"io/ioutil"
 	"strings"
+
+	log "github.com/Sirupsen/logrus"
 )
 
 // This uses Docker to convert a Docker image into a tarball. It would be an improvement if we
@@ -39,6 +41,7 @@ nameserver 2001:4860:4860::8844
 
 // ImageExtract extracts the filesystem from an image and returns a tarball with the files prefixed by the given path
 func ImageExtract(image, prefix string) ([]byte, error) {
+	log.Debugf("image extract: %s %s", image, prefix)
 	out := new(bytes.Buffer)
 	tw := tar.NewWriter(out)
 	err := tarPrefix(prefix, tw)
@@ -83,6 +86,7 @@ func tarPrefix(path string, tw *tar.Writer) error {
 }
 
 func imageTar(image, prefix string, tw *tar.Writer) error {
+	log.Debugf("image tar: %s %s", image, prefix)
 	if prefix != "" && prefix[len(prefix)-1] != byte('/') {
 		return fmt.Errorf("prefix does not end with /: %s", prefix)
 	}
@@ -113,16 +117,19 @@ func imageTar(image, prefix string, tw *tar.Writer) error {
 			return err
 		}
 		if exclude[hdr.Name] {
+			log.Debugf("image tar: %s %s exclude %s", image, prefix, hdr.Name)
 			io.Copy(ioutil.Discard, tr)
 		} else if replace[hdr.Name] != "" {
 			contents := replace[hdr.Name]
 			hdr.Size = int64(len(contents))
 			hdr.Name = prefix + hdr.Name
+			log.Debugf("image tar: %s %s add %s", image, prefix, hdr.Name)
 			tw.WriteHeader(hdr)
 			buf := bytes.NewBufferString(contents)
 			io.Copy(tw, buf)
 			io.Copy(ioutil.Discard, tr)
 		} else {
+			log.Debugf("image tar: %s %s add %s", image, prefix, hdr.Name)
 			hdr.Name = prefix + hdr.Name
 			tw.WriteHeader(hdr)
 			io.Copy(tw, tr)
@@ -137,6 +144,7 @@ func imageTar(image, prefix string, tw *tar.Writer) error {
 
 // ImageBundle produces an OCI bundle at the given path in a tarball, given an image and a config.json
 func ImageBundle(path, image, config string) ([]byte, error) {
+	log.Debugf("image bundle: %s %s cfg: %s", path, image, config)
 	out := new(bytes.Buffer)
 	tw := tar.NewWriter(out)
 	err := tarPrefix(path+"/rootfs/", tw)

src/cmd/moby/main.go

@@ -4,18 +4,41 @@ import (
 	"flag"
 	"fmt"
 	"os"
+
+	log "github.com/Sirupsen/logrus"
 )
 
+var (
+	defaultLogFormatter = &log.TextFormatter{}
+)
+
+// infoFormatter overrides the default format for Info() log events to
+// provide an easier to read output
+type infoFormatter struct {
+}
+
+func (f *infoFormatter) Format(entry *log.Entry) ([]byte, error) {
+	if entry.Level == log.InfoLevel {
+		return append([]byte(entry.Message), '\n'), nil
+	}
+	return defaultLogFormatter.Format(entry)
+}
+
 func main() {
 	flag.Usage = func() {
-		fmt.Printf("USAGE: %s COMMAND\n\n", os.Args[0])
+		fmt.Printf("USAGE: %s [options] COMMAND\n\n", os.Args[0])
 		fmt.Printf("Commands:\n")
 		fmt.Printf("  build       Build a Moby image from a YAML file\n")
 		fmt.Printf("  run         Run a Moby image on a local hypervisor\n")
 		fmt.Printf("  help        Print this message\n")
 		fmt.Printf("\n")
 		fmt.Printf("Run '%s COMMAND --help' for more information on the command\n", os.Args[0])
+		fmt.Printf("\n")
+		fmt.Printf("Options:\n")
+		flag.PrintDefaults()
 	}
+	flagQuiet := flag.Bool("q", false, "Quiet execution")
+	flagVerbose := flag.Bool("v", false, "Verbose execution")
 
 	buildCmd := flag.NewFlagSet("build", flag.ExitOnError)
 	buildCmd.Usage = func() {
@@ -44,23 +67,41 @@ func main() {
 	runDiskSz := runCmd.Int("disk-size", 0, "Size of Disk in MB")
 	runDisk := runCmd.String("disk", "", "Path to disk image to used")
 
-	if len(os.Args) < 2 {
+	// Set up logging
+	log.SetFormatter(new(infoFormatter))
+	log.SetLevel(log.InfoLevel)
+	flag.Parse()
+	if *flagQuiet && *flagVerbose {
+		fmt.Printf("Can't set quiet and verbose flag at the same time\n")
+		os.Exit(1)
+	}
+	if *flagQuiet {
+		log.SetLevel(log.ErrorLevel)
+	}
+	if *flagVerbose {
+		// Switch back to the standard formatter
+		log.SetFormatter(defaultLogFormatter)
+		log.SetLevel(log.DebugLevel)
+	}
+
+	args := flag.Args()
+	if len(args) < 1 {
 		fmt.Printf("Please specify a command.\n\n")
 		flag.Usage()
 		os.Exit(1)
 	}
 
-	switch os.Args[1] {
+	switch args[0] {
 	case "build":
-		buildCmd.Parse(os.Args[2:])
+		buildCmd.Parse(args[1:])
 		build(*buildName, *buildPull, buildCmd.Args())
 	case "run":
-		runCmd.Parse(os.Args[2:])
+		runCmd.Parse(args[1:])
 		run(*runCPUs, *runMem, *runDiskSz, *runDisk, runCmd.Args())
 	case "help":
 		flag.Usage()
 	default:
-		fmt.Printf("%q is not valid command.\n\n", os.Args[1])
+		fmt.Printf("%q is not valid command.\n\n", args[0])
 		flag.Usage()
 		os.Exit(1)
 	}

src/cmd/moby/output.go

@@ -6,6 +6,8 @@ import (
 	"fmt"
 	"io/ioutil"
 	"os"
+
+	log "github.com/Sirupsen/logrus"
 )
 
 const (
@@ -18,6 +20,7 @@ const (
 )
 
 func outputs(m *Moby, base string, bzimage []byte, initrd []byte) error {
+	log.Debugf("output: %s %s", m.Outputs, base)
 	for _, o := range m.Outputs {
 		switch o.Format {
 		case "kernel+initrd":
@@ -129,6 +132,8 @@ func tarInitrdKernel(bzimage, initrd []byte) (*bytes.Buffer, error) {
 }
 
 func outputImg(image, filename string, bzimage []byte, initrd []byte, args ...string) error {
+	log.Debugf("output img: %s %s", image, filename)
+	log.Infof("  %s", filename)
 	buf, err := tarInitrdKernel(bzimage, initrd)
 	if err != nil {
 		return err
@@ -141,11 +146,12 @@ func outputImg(image, filename string, bzimage []byte, initrd []byte, args ...st
 	if err != nil {
 		return err
 	}
-	fmt.Println(filename)
 	return nil
 }
 
 func outputISO(image, filename string, bzimage []byte, initrd []byte, args ...string) error {
+	log.Debugf("output iso: %s %s", image, filename)
+	log.Infof("  %s", filename)
 	buf, err := tarInitrdKernel(bzimage, initrd)
 	if err != nil {
 		return err
@@ -158,11 +164,12 @@ func outputISO(image, filename string, bzimage []byte, initrd []byte, args ...st
 	if err != nil {
 		return err
 	}
-	fmt.Println(filename)
 	return nil
 }
 
 func outputKernelInitrd(base string, bzimage []byte, initrd []byte, cmdline string) error {
+	log.Debugf("output kernel/initrd: %s %s", base, cmdline)
+	log.Infof("  %s %s %s", base+"-bzImage", base+"-initrd.img", base+"-cmdline")
 	err := ioutil.WriteFile(base+"-initrd.img", initrd, os.FileMode(0644))
 	if err != nil {
 		return err
@@ -175,6 +182,5 @@ func outputKernelInitrd(base string, bzimage []byte, initrd []byte, cmdline stri
 	if err != nil {
 		return err
 	}
-	fmt.Println(base + "-bzImage " + base + "-initrd.img " + base + "-cmdline")
 	return nil
 }

src/cmd/moby/run_darwin.go

@@ -4,10 +4,10 @@ package main
 
 import (
 	"io/ioutil"
-	"log"
 	"os"
 	"os/user"
 
+	log "github.com/Sirupsen/logrus"
 	"github.com/docker/hyperkit/go"
 )
 

src/cmd/moby/run_fallback.go

@@ -3,7 +3,7 @@
 package main
 
 import (
-	"log"
+	log "github.com/Sirupsen/logrus"
 )
 
 func run(cpus, mem, diskSz int, userData string, args []string) {