From 5d5189a9a20dfce9432f6fea502d0b3f56331560 Mon Sep 17 00:00:00 2001 From: Megan Marsh Date: Mon, 9 Dec 2019 12:10:07 -0800 Subject: [PATCH 1/5] only log when external plugin is used, since this is the much rarer event --- config.go | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/config.go b/config.go index 1b7946b24..173d4ece0 100644 --- a/config.go +++ b/config.go @@ -208,29 +208,32 @@ func (c *config) discoverInternal() error { for builder := range command.Builders { _, found := (c.Builders)[builder] if !found { - log.Printf("Using internal plugin for %s", builder) (c.Builders)[builder] = fmt.Sprintf("%s%splugin%spacker-builder-%s", packerPath, PACKERSPACE, PACKERSPACE, builder) + } else { + log.Printf("Using external plugin for %s", builder) } } for provisioner := range command.Provisioners { _, found := (c.Provisioners)[provisioner] if !found { - log.Printf("Using internal plugin for %s", provisioner) (c.Provisioners)[provisioner] = fmt.Sprintf( "%s%splugin%spacker-provisioner-%s", packerPath, PACKERSPACE, PACKERSPACE, provisioner) + } else { + log.Printf("Using external plugin for %s", provisioner) } } for postProcessor := range command.PostProcessors { _, found := (c.PostProcessors)[postProcessor] if !found { - log.Printf("Using internal plugin for %s", postProcessor) (c.PostProcessors)[postProcessor] = fmt.Sprintf( "%s%splugin%spacker-post-processor-%s", packerPath, PACKERSPACE, PACKERSPACE, postProcessor) + } else { + log.Printf("Using external plugin for %s", postProcessor) } } From a14498ff001dd0717e550755a6c7d5467ac6e973 Mon Sep 17 00:00:00 2001 From: Megan Marsh Date: Mon, 9 Dec 2019 12:13:18 -0800 Subject: [PATCH 2/5] remove timestamps from logger inside of subprocesses to prevent double logging; also remove some cruft and fix spelling in some logs --- main.go | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/main.go b/main.go index 4078d306f..b24ee229b 100644 --- a/main.go +++ b/main.go @@ -62,8 +62,6 @@ func realMain() int { packer.LogSecretFilter.SetOutput(logWriter) - //packer.LogSecrets. - // Disable logging here log.SetOutput(ioutil.Discard) @@ -137,12 +135,16 @@ func wrappedMain() int { packer.LogSecretFilter.SetOutput(os.Stderr) log.SetOutput(&packer.LogSecretFilter) + inPlugin := os.Getenv(plugin.MagicCookieKey) == plugin.MagicCookieValue + if inPlugin { + // This prevents double-logging timestamps + log.SetFlags(0) + } + log.Printf("[INFO] Packer version: %s", version.FormattedVersion()) 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 - config, err := loadConfig() if err != nil { fmt.Fprintf(os.Stderr, "Error loading configuration: \n\n%s\n", err) @@ -195,7 +197,7 @@ func wrappedMain() int { currentPID := os.Getpid() backgrounded, err := checkProcess(currentPID) if err != nil { - fmt.Fprintf(os.Stderr, "cannot determind if process is in "+ + fmt.Fprintf(os.Stderr, "cannot determine if process is in "+ "background: %s\n", err) } if backgrounded { From a02a95e9924030024291160ee2f7cd4f3abe797b Mon Sep 17 00:00:00 2001 From: Megan Marsh Date: Mon, 9 Dec 2019 12:17:23 -0800 Subject: [PATCH 3/5] Move port logging to inside of appropriate functions; log the actual plugin being called if it is part of the main packer binary, rather than the meaningless information 'packer'. --- packer/plugin/client.go | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/packer/plugin/client.go b/packer/plugin/client.go index 7cfcb8e21..33fcf7f75 100644 --- a/packer/plugin/client.go +++ b/packer/plugin/client.go @@ -327,8 +327,10 @@ func (c *Client) Start() (addr net.Addr, err error) { switch parts[1] { case "tcp": addr, err = net.ResolveTCPAddr("tcp", parts[2]) + log.Printf("Received tcp RPC address for %s: addr is %s", cmd.Path, addr) case "unix": addr, err = net.ResolveUnixAddr("unix", parts[2]) + log.Printf("Received unix RPC address for %s: addr is %s", cmd.Path, addr) default: err = fmt.Errorf("Unknown address type: %s", parts[1]) } @@ -339,6 +341,13 @@ func (c *Client) Start() (addr net.Addr, err error) { } func (c *Client) logStderr(r io.Reader) { + logPrefix := filepath.Base(c.config.Cmd.Path) + if logPrefix == "packer" { + // we just called the normal packer binary with the plugin arg. + // grab the last arg from the list which will match the plugin name. + logPrefix = c.config.Cmd.Args[len(c.config.Cmd.Args)-1] + } + bufR := bufio.NewReader(r) for { line, err := bufR.ReadString('\n') @@ -346,7 +355,8 @@ func (c *Client) logStderr(r io.Reader) { c.config.Stderr.Write([]byte(line)) line = strings.TrimRightFunc(line, unicode.IsSpace) - log.Printf("%s: %s", filepath.Base(c.config.Cmd.Path), line) + + log.Printf("%s plugin: %s", logPrefix, line) } if err == io.EOF { From 8b50f0305621928a5a6950a444b96f92aadd056f Mon Sep 17 00:00:00 2001 From: Megan Marsh Date: Mon, 9 Dec 2019 12:21:45 -0800 Subject: [PATCH 4/5] Only log min and max port when connecting via TCP; move port determination inside of the TCP function --- packer/plugin/server.go | 34 +++++++++++++++++----------------- 1 file changed, 17 insertions(+), 17 deletions(-) diff --git a/packer/plugin/server.go b/packer/plugin/server.go index 0efefb7e5..749875b75 100644 --- a/packer/plugin/server.go +++ b/packer/plugin/server.go @@ -51,20 +51,7 @@ func Server() (*packrpc.Server, error) { runtime.GOMAXPROCS(runtime.NumCPU()) } - minPort, err := strconv.ParseInt(os.Getenv("PACKER_PLUGIN_MIN_PORT"), 10, 32) - if err != nil { - return nil, err - } - - maxPort, err := strconv.ParseInt(os.Getenv("PACKER_PLUGIN_MAX_PORT"), 10, 32) - if err != nil { - return nil, err - } - - log.Printf("Plugin minimum port: %d\n", minPort) - log.Printf("Plugin maximum port: %d\n", maxPort) - - listener, err := serverListener(minPort, maxPort) + listener, err := serverListener() if err != nil { return nil, err } @@ -104,15 +91,28 @@ func Server() (*packrpc.Server, error) { return packrpc.NewServer(conn) } -func serverListener(minPort, maxPort int64) (net.Listener, error) { +func serverListener() (net.Listener, error) { if runtime.GOOS == "windows" { - return serverListener_tcp(minPort, maxPort) + return serverListener_tcp() } return serverListener_unix() } -func serverListener_tcp(minPort, maxPort int64) (net.Listener, error) { +func serverListener_tcp() (net.Listener, error) { + minPort, err := strconv.ParseInt(os.Getenv("PACKER_PLUGIN_MIN_PORT"), 10, 32) + if err != nil { + return nil, err + } + + maxPort, err := strconv.ParseInt(os.Getenv("PACKER_PLUGIN_MAX_PORT"), 10, 32) + if err != nil { + return nil, err + } + + log.Printf("Plugin minimum port: %d/%d\n", minPort) + log.Printf("Plugin maximum port: %d/%d\n", maxPort) + for port := minPort; port <= maxPort; port++ { address := fmt.Sprintf("127.0.0.1:%d", port) listener, err := net.Listen("tcp", address) From 2447c9b2805a9db531a801434bd541704413c754 Mon Sep 17 00:00:00 2001 From: Megan Marsh Date: Mon, 9 Dec 2019 12:30:14 -0800 Subject: [PATCH 5/5] typo --- packer/plugin/server.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packer/plugin/server.go b/packer/plugin/server.go index 749875b75..e30de6fb0 100644 --- a/packer/plugin/server.go +++ b/packer/plugin/server.go @@ -110,8 +110,8 @@ func serverListener_tcp() (net.Listener, error) { return nil, err } - log.Printf("Plugin minimum port: %d/%d\n", minPort) - log.Printf("Plugin maximum port: %d/%d\n", maxPort) + log.Printf("Plugin minimum port: %d\n", minPort) + log.Printf("Plugin maximum port: %d\n", maxPort) for port := minPort; port <= maxPort; port++ { address := fmt.Sprintf("127.0.0.1:%d", port)