From 463438d1f00aa6470c963655c4f438d8a6f1df34 Mon Sep 17 00:00:00 2001 From: Rolf Neugebauer Date: Tue, 28 Mar 2017 21:01:38 +0100 Subject: [PATCH 1/5] moby: Switch to use logrus instead of default logger logrus offers better control over log-levels. Signed-off-by: Rolf Neugebauer --- src/cmd/moby/build.go | 2 +- src/cmd/moby/run_darwin.go | 2 +- src/cmd/moby/run_fallback.go | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/cmd/moby/build.go b/src/cmd/moby/build.go index 5c81819d6..8b3711abc 100644 --- a/src/cmd/moby/build.go +++ b/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" ) diff --git a/src/cmd/moby/run_darwin.go b/src/cmd/moby/run_darwin.go index 7d8676c35..1c28a05e6 100644 --- a/src/cmd/moby/run_darwin.go +++ b/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" ) diff --git a/src/cmd/moby/run_fallback.go b/src/cmd/moby/run_fallback.go index 04ba9a6e0..65402e4a9 100644 --- a/src/cmd/moby/run_fallback.go +++ b/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) { From adb0f9db3ded534fd1d375fe71f9753f976291fa Mon Sep 17 00:00:00 2001 From: Rolf Neugebauer Date: Tue, 28 Mar 2017 21:40:17 +0100 Subject: [PATCH 2/5] moby: Add verbose and quiet flags to moby commandline These set the log level to Debug and Error. The default log level is set to Info. Signed-off-by: Rolf Neugebauer --- src/cmd/moby/main.go | 35 +++++++++++++++++++++++++++++------ 1 file changed, 29 insertions(+), 6 deletions(-) diff --git a/src/cmd/moby/main.go b/src/cmd/moby/main.go index a054edc2f..17ad9f10b 100644 --- a/src/cmd/moby/main.go +++ b/src/cmd/moby/main.go @@ -4,18 +4,25 @@ import ( "flag" "fmt" "os" + + log "github.com/Sirupsen/logrus" ) 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 +51,39 @@ 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(&log.TextFormatter{}) + 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 { + 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) } From 37545913a69858ce86a09ff124afb8c468a01ec1 Mon Sep 17 00:00:00 2001 From: Rolf Neugebauer Date: Tue, 28 Mar 2017 22:26:31 +0100 Subject: [PATCH 3/5] moby: Add debug logging to "moby build" code Signed-off-by: Rolf Neugebauer --- src/cmd/moby/docker.go | 14 ++++++++++++++ src/cmd/moby/image.go | 8 ++++++++ src/cmd/moby/output.go | 6 ++++++ 3 files changed, 28 insertions(+) diff --git a/src/cmd/moby/docker.go b/src/cmd/moby/docker.go index e3673cb55..096f11347 100644 --- a/src/cmd/moby/docker.go +++ b/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 } diff --git a/src/cmd/moby/image.go b/src/cmd/moby/image.go index ea95c929c..c7c303e2e 100644 --- a/src/cmd/moby/image.go +++ b/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) diff --git a/src/cmd/moby/output.go b/src/cmd/moby/output.go index 47ea740fe..909c6c1ee 100644 --- a/src/cmd/moby/output.go +++ b/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,7 @@ 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) buf, err := tarInitrdKernel(bzimage, initrd) if err != nil { return err @@ -146,6 +150,7 @@ func outputImg(image, filename string, bzimage []byte, initrd []byte, args ...st } func outputISO(image, filename string, bzimage []byte, initrd []byte, args ...string) error { + log.Debugf("output iso: %s %s", image, filename) buf, err := tarInitrdKernel(bzimage, initrd) if err != nil { return err @@ -163,6 +168,7 @@ func outputISO(image, filename string, bzimage []byte, initrd []byte, args ...st } func outputKernelInitrd(base string, bzimage []byte, initrd []byte, cmdline string) error { + log.Debugf("output kernel/initrd: %s %s", base, cmdline) err := ioutil.WriteFile(base+"-initrd.img", initrd, os.FileMode(0644)) if err != nil { return err From e39b1ddffc80dfd695699797453aac321787f7e6 Mon Sep 17 00:00:00 2001 From: Rolf Neugebauer Date: Wed, 29 Mar 2017 10:53:18 +0100 Subject: [PATCH 4/5] moby: Add informational output to build This adds log.Info() to the main steps of the "moby build" process. By default the Info() output is shown to the user so it provides some idea of progress and what is happening. Signed-off-by: Rolf Neugebauer --- src/cmd/moby/build.go | 12 ++++++++++++ src/cmd/moby/config.go | 3 +++ src/cmd/moby/output.go | 6 +++--- 3 files changed, 18 insertions(+), 3 deletions(-) diff --git a/src/cmd/moby/build.go b/src/cmd/moby/build.go index 8b3711abc..7d7d6f61f 100644 --- a/src/cmd/moby/build.go +++ b/src/cmd/moby/build.go @@ -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) diff --git a/src/cmd/moby/config.go b/src/cmd/moby/config.go index 58fbbcfdd..0f19c0514 100644 --- a/src/cmd/moby/config.go +++ b/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") } diff --git a/src/cmd/moby/output.go b/src/cmd/moby/output.go index 909c6c1ee..609b1b311 100644 --- a/src/cmd/moby/output.go +++ b/src/cmd/moby/output.go @@ -133,6 +133,7 @@ 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 @@ -145,12 +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 @@ -163,12 +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 @@ -181,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 } From 8c012b75ff9f5c8700cd5718a33eb9b28d99f465 Mon Sep 17 00:00:00 2001 From: Rolf Neugebauer Date: Wed, 29 Mar 2017 11:43:32 +0100 Subject: [PATCH 5/5] moby: Create custom formatter for Info() log events This formatter strips the prefix from Info() events to make the default output of "moby build" more readable. Signed-off-by: Rolf Neugebauer --- src/cmd/moby/main.go | 20 +++++++++++++++++++- 1 file changed, 19 insertions(+), 1 deletion(-) diff --git a/src/cmd/moby/main.go b/src/cmd/moby/main.go index 17ad9f10b..18845426d 100644 --- a/src/cmd/moby/main.go +++ b/src/cmd/moby/main.go @@ -8,6 +8,22 @@ import ( 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 [options] COMMAND\n\n", os.Args[0]) @@ -52,7 +68,7 @@ func main() { runDisk := runCmd.String("disk", "", "Path to disk image to used") // Set up logging - log.SetFormatter(&log.TextFormatter{}) + log.SetFormatter(new(infoFormatter)) log.SetLevel(log.InfoLevel) flag.Parse() if *flagQuiet && *flagVerbose { @@ -63,6 +79,8 @@ func main() { log.SetLevel(log.ErrorLevel) } if *flagVerbose { + // Switch back to the standard formatter + log.SetFormatter(defaultLogFormatter) log.SetLevel(log.DebugLevel) }