fix ssh logging

Ensure correct formatting and add a log level to all output.
This commit is contained in:
James Bardin 2018-04-05 10:22:30 -04:00
parent 060a3bc6d2
commit 3c30f04e0e
1 changed files with 22 additions and 18 deletions

View File

@ -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() c.conn, err = c.config.connection()
if err != nil { if err != nil {
// Explicitly set this to the REAL nil. Connection() can return // 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 // http://golang.org/doc/faq#nil_error
c.conn = nil c.conn = nil
log.Printf("connection error: %s", err) log.Printf("[ERROR] connection error: %s", err)
return 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) host := fmt.Sprintf("%s:%d", c.connInfo.Host, c.connInfo.Port)
sshConn, sshChan, req, err := ssh.NewClientConn(c.conn, host, c.config.config) sshConn, sshChan, req, err := ssh.NewClientConn(c.conn, host, c.config.config)
if err != nil { 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") err = session.Start(strings.TrimSpace(cmd.Command) + "\n")
if err != nil { if err != nil {
return err return err
@ -293,7 +293,7 @@ func (c *Communicator) Start(cmd *remote.Cmd) error {
} }
cmd.SetExitStatus(exitStatus, err) 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 return nil
@ -375,7 +375,7 @@ func (c *Communicator) UploadScript(path string, input io.Reader) error {
// UploadDir implementation of communicator.Communicator interface // UploadDir implementation of communicator.Communicator interface
func (c *Communicator) UploadDir(dst string, src string) error { 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 { scpFunc := func(w io.Writer, r *bufio.Reader) error {
uploadEntries := func() error { uploadEntries := func() error {
f, err := os.Open(src) f, err := os.Open(src)
@ -393,7 +393,7 @@ func (c *Communicator) UploadDir(dst string, src string) error {
} }
if src[len(src)-1] != '/' { 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) return scpUploadDirProtocol(filepath.Base(src), w, r, uploadEntries)
} }
// Trailing slash, so only upload the contents // Trailing slash, so only upload the contents
@ -404,7 +404,7 @@ func (c *Communicator) UploadDir(dst string, src string) error {
} }
func (c *Communicator) newSession() (session *ssh.Session, err 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 { if c.client == nil {
err = errors.New("client not available") err = errors.New("client not available")
} else { } else {
@ -412,7 +412,7 @@ func (c *Communicator) newSession() (session *ssh.Session, err error) {
} }
if err != nil { 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 { if err := c.Connect(nil); err != nil {
return nil, err 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 // Start the sink mode on the other side
// TODO(mitchellh): There are probably issues with shell escaping the path // 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 { if err := session.Start(scpCommand); err != nil {
return err 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 // Call our callback that executes in the context of SCP. We ignore
// EOF errors if they occur because it usually means that SCP prematurely // EOF errors if they occur because it usually means that SCP prematurely
// ended on the other side. // 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 { if err := f(stdinW, stdoutR); err != nil && err != io.EOF {
return err 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 // 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 // our defer func doesn't close it again since that is unsafe with
// the Go SSH package. // the Go SSH package.
log.Println("SCP session complete, closing stdin pipe.") log.Println("[DEBUG] SCP session complete, closing stdin pipe.")
stdinW.Close() stdinW.Close()
stdinW = nil stdinW = nil
// Wait for the SCP connection to close, meaning it has consumed all // Wait for the SCP connection to close, meaning it has consumed all
// our data and has completed. Or has errored. // 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() err = session.Wait()
if err != nil { if err != nil {
if exitErr, ok := err.(*ssh.ExitError); ok { if exitErr, ok := err.(*ssh.ExitError); ok {
// Otherwise, we have an ExitErorr, meaning we can just read // Otherwise, we have an ExitErorr, meaning we can just read
// the exit status // the exit status
log.Printf(exitErr.String()) log.Printf("[ERROR] %s", exitErr)
// If we exited with status 127, it means SCP isn't available. // If we exited with status 127, it means SCP isn't available.
// Return a more descriptive error for that. // 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 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 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 os.Remove(tf.Name())
defer tf.Close() 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 { if _, err := io.Copy(tf, src); err != nil {
return err return err
} }
@ -562,7 +566,7 @@ func scpUploadFile(dst string, src io.Reader, w io.Writer, r *bufio.Reader, size
} }
// Start the protocol // Start the protocol
log.Println("Beginning file upload...") log.Println("[DEBUG] Beginning file upload...")
fmt.Fprintln(w, "C0644", size, dst) fmt.Fprintln(w, "C0644", size, dst)
if err := checkSCPStatus(r); err != nil { if err := checkSCPStatus(r); err != nil {
return err 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 { 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) fmt.Fprintln(w, "D0755 0", name)
err := checkSCPStatus(r) err := checkSCPStatus(r)
if err != nil { if err != nil {