Merge pull request #17788 from hashicorp/jbardin/communicators

get errors from winrm commands
2018-04-05 13:05:13 -04:00 · 2018-04-05 13:05:13 -04:00 · 79d0a5c4a4
parent d12a387cb6 dc8c1534fe
commit 79d0a5c4a4
4 changed files with 71 additions and 70 deletions
--- a/communicator/ssh/communicator.go
+++ b/communicator/ssh/communicator.go
@ -152,7 +152,7 @@ func (c *Communicator) Connect(o terraform.UIOutput) (err error) {
 		}
 	}

-	log.Printf("connecting to TCP connection for SSH")
+	log.Printf("[DEBUG] connecting to TCP connection for SSH")
 	c.conn, err = c.config.connection()
 	if err != nil {
 		// Explicitly set this to the REAL nil. Connection() can return
@ -163,11 +163,11 @@ func (c *Communicator) Connect(o terraform.UIOutput) (err error) {
 		// http://golang.org/doc/faq#nil_error
 		c.conn = nil

-		log.Printf("connection error: %s", err)
+		log.Printf("[ERROR] connection error: %s", err)
 		return err
 	}

-	log.Printf("handshaking with SSH")
+	log.Printf("[DEBUG] handshaking with SSH")
 	host := fmt.Sprintf("%s:%d", c.connInfo.Host, c.connInfo.Port)
 	sshConn, sshChan, req, err := ssh.NewClientConn(c.conn, host, c.config.config)
 	if err != nil {
@ -272,7 +272,7 @@ func (c *Communicator) Start(cmd *remote.Cmd) error {
 		}
 	}

-	log.Printf("starting remote command: %s", cmd.Command)
+	log.Printf("[DEBUG] starting remote command: %s", cmd.Command)
 	err = session.Start(strings.TrimSpace(cmd.Command) + "\n")
 	if err != nil {
 		return err
@ -293,7 +293,7 @@ func (c *Communicator) Start(cmd *remote.Cmd) error {
 		}

 		cmd.SetExitStatus(exitStatus, err)
-		log.Printf("remote command exited with '%d': %s", exitStatus, cmd.Command)
+		log.Printf("[DEBUG] remote command exited with '%d': %s", exitStatus, cmd.Command)
 	}()

 	return nil
@ -375,7 +375,7 @@ func (c *Communicator) UploadScript(path string, input io.Reader) error {

 // UploadDir implementation of communicator.Communicator interface
 func (c *Communicator) UploadDir(dst string, src string) error {
-	log.Printf("Uploading dir '%s' to '%s'", src, dst)
+	log.Printf("[DEBUG] Uploading dir '%s' to '%s'", src, dst)
 	scpFunc := func(w io.Writer, r *bufio.Reader) error {
 		uploadEntries := func() error {
 			f, err := os.Open(src)
@ -393,7 +393,7 @@ func (c *Communicator) UploadDir(dst string, src string) error {
 		}

 		if src[len(src)-1] != '/' {
-			log.Printf("No trailing slash, creating the source directory name")
+			log.Printf("[DEBUG] No trailing slash, creating the source directory name")
 			return scpUploadDirProtocol(filepath.Base(src), w, r, uploadEntries)
 		}
 		// Trailing slash, so only upload the contents
@ -404,15 +404,15 @@ func (c *Communicator) UploadDir(dst string, src string) error {
 }

 func (c *Communicator) newSession() (session *ssh.Session, err error) {
-	log.Println("opening new ssh session")
+	log.Println("[DEBUG] opening new ssh session")
 	if c.client == nil {
-		err = errors.New("client not available")
+		err = errors.New("ssh client is not connected")
 	} else {
 		session, err = c.client.NewSession()
 	}

 	if err != nil {
-		log.Printf("ssh session open error: '%s', attempting reconnect", err)
+		log.Printf("[WARN] ssh session open error: '%s', attempting reconnect", err)
 		if err := c.Connect(nil); err != nil {
 			return nil, err
 		}
@ -457,7 +457,7 @@ func (c *Communicator) scpSession(scpCommand string, f func(io.Writer, *bufio.Re

 	// Start the sink mode on the other side
 	// TODO(mitchellh): There are probably issues with shell escaping the path
-	log.Println("Starting remote scp process: ", scpCommand)
+	log.Println("[DEBUG] Starting remote scp process: ", scpCommand)
 	if err := session.Start(scpCommand); err != nil {
 		return err
 	}
@ -465,7 +465,7 @@ func (c *Communicator) scpSession(scpCommand string, f func(io.Writer, *bufio.Re
 	// Call our callback that executes in the context of SCP. We ignore
 	// EOF errors if they occur because it usually means that SCP prematurely
 	// ended on the other side.
-	log.Println("Started SCP session, beginning transfers...")
+	log.Println("[DEBUG] Started SCP session, beginning transfers...")
 	if err := f(stdinW, stdoutR); err != nil && err != io.EOF {
 		return err
 	}
@ -473,19 +473,19 @@ func (c *Communicator) scpSession(scpCommand string, f func(io.Writer, *bufio.Re
 	// Close the stdin, which sends an EOF, and then set w to nil so that
 	// our defer func doesn't close it again since that is unsafe with
 	// the Go SSH package.
-	log.Println("SCP session complete, closing stdin pipe.")
+	log.Println("[DEBUG] SCP session complete, closing stdin pipe.")
 	stdinW.Close()
 	stdinW = nil

 	// Wait for the SCP connection to close, meaning it has consumed all
 	// our data and has completed. Or has errored.
-	log.Println("Waiting for SSH session to complete.")
+	log.Println("[DEBUG] Waiting for SSH session to complete.")
 	err = session.Wait()
 	if err != nil {
 		if exitErr, ok := err.(*ssh.ExitError); ok {
 			// Otherwise, we have an ExitErorr, meaning we can just read
 			// the exit status
-			log.Printf(exitErr.String())
+			log.Printf("[ERROR] %s", exitErr)

 			// If we exited with status 127, it means SCP isn't available.
 			// Return a more descriptive error for that.
@ -499,7 +499,11 @@ func (c *Communicator) scpSession(scpCommand string, f func(io.Writer, *bufio.Re
 		return err
 	}

-	log.Printf("scp stderr (length %d): %s", stderr.Len(), stderr.String())
+	scpErr := stderr.String()
+	if len(scpErr) > 0 {
+		log.Printf("[ERROR] scp stderr: %q", stderr)
+	}
+
 	return nil
 }

@ -536,7 +540,7 @@ func scpUploadFile(dst string, src io.Reader, w io.Writer, r *bufio.Reader, size
 		defer os.Remove(tf.Name())
 		defer tf.Close()

-		log.Println("Copying input data into temporary file so we can read the length")
+		log.Println("[DEBUG] Copying input data into temporary file so we can read the length")
 		if _, err := io.Copy(tf, src); err != nil {
 			return err
 		}
@ -562,7 +566,7 @@ func scpUploadFile(dst string, src io.Reader, w io.Writer, r *bufio.Reader, size
 	}

 	// Start the protocol
-	log.Println("Beginning file upload...")
+	log.Println("[DEBUG] Beginning file upload...")
 	fmt.Fprintln(w, "C0644", size, dst)
 	if err := checkSCPStatus(r); err != nil {
 		return err
@ -581,7 +585,7 @@ func scpUploadFile(dst string, src io.Reader, w io.Writer, r *bufio.Reader, size
 }

 func scpUploadDirProtocol(name string, w io.Writer, r *bufio.Reader, f func() error) error {
-	log.Printf("SCP: starting directory upload: %s", name)
+	log.Printf("[DEBUG] SCP: starting directory upload: %s", name)
 	fmt.Fprintln(w, "D0755 0", name)
 	err := checkSCPStatus(r)
 	if err != nil {
--- a/communicator/winrm/communicator.go
+++ b/communicator/winrm/communicator.go
@ -7,16 +7,12 @@ import (
 	"math/rand"
 	"strconv"
 	"strings"
-	"sync"
 	"time"

 	"github.com/hashicorp/terraform/communicator/remote"
 	"github.com/hashicorp/terraform/terraform"
 	"github.com/masterzen/winrm"
 	"github.com/packer-community/winrmcp/winrmcp"
-
-	// This import is a bit strange, but it's needed so `make updatedeps` can see and download it
-	_ "github.com/dylanmei/winrmtest"
 )

 // Communicator represents the WinRM communicator
@ -94,16 +90,16 @@ func (c *Communicator) Connect(o terraform.UIOutput) error {
 		))
 	}

-	log.Printf("connecting to remote shell using WinRM")
+	log.Printf("[DEBUG] connecting to remote shell using WinRM")
 	shell, err := client.CreateShell()
 	if err != nil {
-		log.Printf("connection error: %s", err)
+		log.Printf("[ERROR] error creating shell: %s", err)
 		return err
 	}

 	err = shell.Close()
 	if err != nil {
-		log.Printf("error closing connection: %s", err)
+		log.Printf("[ERROR] error closing shell: %s", err)
 		return err
 	}

@ -137,55 +133,30 @@ func (c *Communicator) ScriptPath() string {
 // Start implementation of communicator.Communicator interface
 func (c *Communicator) Start(rc *remote.Cmd) error {
 	rc.Init()
+	log.Printf("[DEBUG] starting remote command: %s", rc.Command)

-	err := c.Connect(nil)
-	if err != nil {
+	// TODO: make sure communicators always connect first, so we can get output
+	// from the connection.
+	if c.client == nil {
+		log.Println("[WARN] winrm client not connected, attempting to connect")
+		if err := c.Connect(nil); err != nil {
 			return err
 		}
-
-	shell, err := c.client.CreateShell()
-	if err != nil {
-		return err
 	}

-	log.Printf("starting remote command: %s", rc.Command)
-	cmd, err := shell.Execute(rc.Command)
-	if err != nil {
-		return err
-	}
+	status, err := c.client.Run(rc.Command, rc.Stdout, rc.Stderr)
+	rc.SetExitStatus(status, err)

-	go runCommand(shell, cmd, rc)
 	return nil
 }

-func runCommand(shell *winrm.Shell, cmd *winrm.Command, rc *remote.Cmd) {
-	defer shell.Close()
-
-	var wg sync.WaitGroup
-	go func() {
-		wg.Add(1)
-		io.Copy(rc.Stdout, cmd.Stdout)
-		wg.Done()
-	}()
-	go func() {
-		wg.Add(1)
-		io.Copy(rc.Stderr, cmd.Stderr)
-		wg.Done()
-	}()
-
-	cmd.Wait()
-	wg.Wait()
-
-	rc.SetExitStatus(cmd.ExitCode(), nil)
-}
-
 // Upload implementation of communicator.Communicator interface
 func (c *Communicator) Upload(path string, input io.Reader) error {
 	wcp, err := c.newCopyClient()
 	if err != nil {
 		return err
 	}
-	log.Printf("Uploading file to '%s'", path)
+	log.Printf("[DEBUG] Uploading file to '%s'", path)
 	return wcp.Write(path, input)
 }

@ -196,7 +167,7 @@ func (c *Communicator) UploadScript(path string, input io.Reader) error {

 // UploadDir implementation of communicator.Communicator interface
 func (c *Communicator) UploadDir(dst string, src string) error {
-	log.Printf("Uploading dir '%s' to '%s'", src, dst)
+	log.Printf("[DEBUG] Uploading dir '%s' to '%s'", src, dst)
 	wcp, err := c.newCopyClient()
 	if err != nil {
 		return err
--- a/vendor/github.com/packer-community/winrmcp/winrmcp/cp.go
+++ b/vendor/github.com/packer-community/winrmcp/winrmcp/cp.go
@ -176,13 +176,35 @@ func cleanupContent(client *winrm.Client, filePath string) error {
 	}

 	defer shell.Close()
-	cmd, err := shell.Execute("powershell", "Remove-Item", filePath, "-ErrorAction SilentlyContinue")
+	script := fmt.Sprintf(`
+		$tmp_file_path = [System.IO.Path]::GetFullPath("%s")
+		if (Test-Path $tmp_file_path) {
+			Remove-Item $tmp_file_path -ErrorAction SilentlyContinue
+		}
+	`, filePath)
+
+	cmd, err := shell.Execute(winrm.Powershell(script))
 	if err != nil {
 		return err
 	}
+	defer cmd.Close()
+
+	var wg sync.WaitGroup
+	copyFunc := func(w io.Writer, r io.Reader) {
+		defer wg.Done()
+		io.Copy(w, r)
+	}
+
+	wg.Add(2)
+	go copyFunc(os.Stdout, cmd.Stdout)
+	go copyFunc(os.Stderr, cmd.Stderr)

 	cmd.Wait()
-	cmd.Close()
+	wg.Wait()
+
+	if cmd.ExitCode() != 0 {
+		return fmt.Errorf("cleanup operation returned code=%d", cmd.ExitCode())
+	}
 	return nil
 }

--- a/vendor/vendor.json
+++ b/vendor/vendor.json
@ -2107,14 +2107,18 @@
 		{
 			"checksumSHA1": "dIMJD0AZwSwmuOuTaGgqWZkzuPU=",
 			"path": "github.com/packer-community/winrmcp",
-			"revision": "078cc0a785c9da54158c0775f06f505fc1e867f8",
-			"revisionTime": "2017-06-07T14:21:56Z"
+			"revision": "81144009af586de8e7729b829266f09dd0d59701",
+			"revisionTime": "2018-01-02T16:08:24Z",
+			"version": "master",
+			"versionExact": "master"
 		},
 		{
-			"checksumSHA1": "iApv8tX8vuAvzyY6VkOvW+IzJF8=",
+			"checksumSHA1": "/NoE6t3UkW4/iKAtbf59GGv6tF8=",
 			"path": "github.com/packer-community/winrmcp/winrmcp",
-			"revision": "078cc0a785c9da54158c0775f06f505fc1e867f8",
-			"revisionTime": "2017-06-07T14:21:56Z"
+			"revision": "81144009af586de8e7729b829266f09dd0d59701",
+			"revisionTime": "2018-01-02T16:08:24Z",
+			"version": "master",
+			"versionExact": "master"
 		},
 		{
 			"checksumSHA1": "rJab1YdNhQooDiBWNnt7TLWPyBU=",