Add more logging to export-installation

- Indicate to the user that is waiting for Ops Manager to respond to its
  request

acceptance/export_installation_test.go

@@ -8,6 +8,7 @@ import (
 	"net/http/httputil"
 	"os"
 	"os/exec"
+	"time"
 
 	"github.com/onsi/gomega/gbytes"
 	"github.com/onsi/gomega/gexec"
@@ -47,6 +48,7 @@ var _ = Describe("export-installation command", func() {
 					return
 				}
 				responseString = "some-installation"
+				time.Sleep(2 * time.Second)
 			default:
 				out, err := httputil.DumpRequest(req, true)
 				Expect(err).NotTo(HaveOccurred())
@@ -74,9 +76,10 @@ var _ = Describe("export-installation command", func() {
 		session, err := gexec.Start(command, GinkgoWriter, GinkgoWriter)
 		Expect(err).NotTo(HaveOccurred())
 
-		Eventually(session).Should(gexec.Exit(0))
-		Eventually(session.Out).Should(gbytes.Say("exporting installation"))
-		Eventually(session.Out).Should(gbytes.Say("finished exporting installation"))
+		Eventually(session, 5).Should(gexec.Exit(0))
+		Eventually(session.Out, 5).Should(gbytes.Say("exporting installation"))
+		Eventually(session.Out, 5).Should(gbytes.Say("2s elapsed, waiting for response"))
+		Eventually(session.Out, 5).Should(gbytes.Say("finished exporting installation"))
 
 		content, err := ioutil.ReadFile(outputFileName)
 		Expect(err).NotTo(HaveOccurred())
@@ -98,8 +101,8 @@ var _ = Describe("export-installation command", func() {
 				session, err := gexec.Start(command, GinkgoWriter, GinkgoWriter)
 				Expect(err).NotTo(HaveOccurred())
 
-				Eventually(session).Should(gexec.Exit(1))
-				Eventually(session.Out).Should(gbytes.Say("request failed: cannot write to output file: open"))
+				Eventually(session, 5).Should(gexec.Exit(1))
+				Eventually(session.Out, 5).Should(gbytes.Say("request failed: cannot write to output file: open"))
 			})
 		})
 	})

api/installation_asset_service.go

@@ -6,6 +6,9 @@ import (
 	"io/ioutil"
 	"net/http"
 	"net/http/httputil"
+	"time"
+
+	"github.com/pivotal-cf/om/common"
 )
 
 type ImportInstallationInput struct {
@@ -17,12 +20,14 @@ type ImportInstallationInput struct {
 type InstallationAssetService struct {
 	client   httpClient
 	progress progress
+	logger   common.Logger
 }
 
-func NewInstallationAssetService(client httpClient, progress progress) InstallationAssetService {
+func NewInstallationAssetService(client httpClient, progress progress, logger common.Logger) InstallationAssetService {
 	return InstallationAssetService{
 		client:   client,
 		progress: progress,
+		logger:   logger,
 	}
 }
 
@@ -32,7 +37,23 @@ func (ia InstallationAssetService) Export(outputFile string) error {
 		return err
 	}
 
+	respChan := make(chan error)
+	go func() {
+		var elapsedTime int
+		for {
+			select {
+			case _ = <-respChan:
+				return
+			default:
+				time.Sleep(1 * time.Second)
+				elapsedTime++
+				ia.logger.Printf("\r%ds elapsed, waiting for response...", elapsedTime)
+			}
+		}
+	}()
+
 	resp, err := ia.client.Do(req)
+	respChan <- err
 	if err != nil {
 		return fmt.Errorf("could not make api request to installation_asset_collection endpoint: %s", err)
 	}

api/installation_asset_service_test.go

@@ -2,13 +2,16 @@ package api_test
 
 import (
 	"errors"
+	"fmt"
 	"io/ioutil"
 	"net/http"
 	"os"
 	"strings"
+	"time"
 
 	"github.com/pivotal-cf/om/api"
 	"github.com/pivotal-cf/om/api/fakes"
+	commonfakes "github.com/pivotal-cf/om/common/fakes"
 
 	. "github.com/onsi/ginkgo"
 	. "github.com/onsi/gomega"
@@ -20,11 +23,13 @@ var _ = Describe("InstallationAssetService", func() {
 			client     *fakes.HttpClient
 			outputFile *os.File
 			bar        *fakes.Progress
+			logger     *commonfakes.OtherLogger
 		)
 
 		BeforeEach(func() {
 			var err error
 			client = &fakes.HttpClient{}
+			logger = &commonfakes.OtherLogger{}
 			outputFile, err = ioutil.TempFile("", "")
 			Expect(err).NotTo(HaveOccurred())
 			bar = &fakes.Progress{}
@@ -43,7 +48,7 @@ var _ = Describe("InstallationAssetService", func() {
 			}, nil)
 
 			bar.NewBarReaderReturns(strings.NewReader("some-fake-installation"))
-			service := api.NewInstallationAssetService(client, bar)
+			service := api.NewInstallationAssetService(client, bar, logger)
 
 			err := service.Export(outputFile.Name())
 			Expect(err).NotTo(HaveOccurred())
@@ -67,11 +72,36 @@ var _ = Describe("InstallationAssetService", func() {
 			Expect(bar.EndCallCount()).To(Equal(1))
 		})
 
+		It("logs while waiting for a response from the Ops Manager", func() {
+			client.DoStub = func(req *http.Request) (*http.Response, error) {
+				if req.URL.Path == "/api/v0/installation_asset_collection" {
+					time.Sleep(5 * time.Second)
+					return &http.Response{
+						StatusCode: http.StatusOK,
+						Body:       ioutil.NopCloser(strings.NewReader("some-installation")),
+					}, nil
+				}
+				return nil, nil
+			}
+
+			bar.NewBarReaderReturns(strings.NewReader("some-fake-installation"))
+			service := api.NewInstallationAssetService(client, bar, logger)
+
+			err := service.Export(outputFile.Name())
+			Expect(err).NotTo(HaveOccurred())
+
+			Expect(logger.PrintfCallCount()).To(Equal(5))
+			for i := 0; i < 5; i++ {
+				format, v := logger.PrintfArgsForCall(i)
+				Expect(fmt.Sprintf(format, v...)).To(ContainSubstring(fmt.Sprintf("%ds elapsed", i+1)))
+			}
+		})
+
 		Context("when an error occurs", func() {
 			Context("when the client errors before the request", func() {
 				It("returns an error", func() {
 					client.DoReturns(&http.Response{}, errors.New("some client error"))
-					service := api.NewInstallationAssetService(client, bar)
+					service := api.NewInstallationAssetService(client, bar, logger)
 
 					err := service.Export("fake-file")
 					Expect(err).To(MatchError("could not make api request to installation_asset_collection endpoint: some client error"))
@@ -82,9 +112,9 @@ var _ = Describe("InstallationAssetService", func() {
 				It("returns an error", func() {
 					client.DoReturns(&http.Response{
 						StatusCode: http.StatusInternalServerError,
-						Body:       ioutil.NopCloser(strings.NewReader("{}")),
+						Body:       ioutil.NopCloser(strings.NewReader("")),
 					}, nil)
-					service := api.NewInstallationAssetService(client, bar)
+					service := api.NewInstallationAssetService(client, bar, logger)
 
 					err := service.Export("fake-file")
 					Expect(err).To(MatchError(ContainSubstring("request failed: unexpected response")))
@@ -98,7 +128,7 @@ var _ = Describe("InstallationAssetService", func() {
 						Body:       ioutil.NopCloser(strings.NewReader("{}")),
 					}, nil)
 					bar.NewBarReaderReturns(strings.NewReader("some-fake-installation"))
-					service := api.NewInstallationAssetService(client, bar)
+					service := api.NewInstallationAssetService(client, bar, logger)
 
 					err := service.Export("fake-dir/fake-file")
 					Expect(err).To(MatchError(ContainSubstring("no such file")))
@@ -111,10 +141,12 @@ var _ = Describe("InstallationAssetService", func() {
 		var (
 			client *fakes.HttpClient
 			bar    *fakes.Progress
+			logger *commonfakes.OtherLogger
 		)
 
 		BeforeEach(func() {
 			client = &fakes.HttpClient{}
+			logger = &commonfakes.OtherLogger{}
 			bar = &fakes.Progress{}
 		})
 
@@ -125,7 +157,7 @@ var _ = Describe("InstallationAssetService", func() {
 			}, nil)
 
 			bar.NewBarReaderReturns(strings.NewReader("some other installation"))
-			service := api.NewInstallationAssetService(client, bar)
+			service := api.NewInstallationAssetService(client, bar, logger)
 
 			err := service.Import(api.ImportInstallationInput{
 				ContentLength: 10,
@@ -158,7 +190,7 @@ var _ = Describe("InstallationAssetService", func() {
 			Context("when the client errors before the request", func() {
 				It("returns an error", func() {
 					client.DoReturns(&http.Response{}, errors.New("some client error"))
-					service := api.NewInstallationAssetService(client, bar)
+					service := api.NewInstallationAssetService(client, bar, logger)
 
 					err := service.Import(api.ImportInstallationInput{})
 					Expect(err).To(MatchError("could not make api request to installation_asset_collection endpoint: some client error"))
@@ -171,7 +203,7 @@ var _ = Describe("InstallationAssetService", func() {
 						StatusCode: http.StatusInternalServerError,
 						Body:       ioutil.NopCloser(strings.NewReader("{}")),
 					}, nil)
-					service := api.NewInstallationAssetService(client, bar)
+					service := api.NewInstallationAssetService(client, bar, logger)
 
 					err := service.Import(api.ImportInstallationInput{})
 					Expect(err).To(MatchError(ContainSubstring("request failed: unexpected response")))

commands/apply_changes.go

@@ -8,11 +8,12 @@ import (
 	"time"
 
 	"github.com/pivotal-cf/om/api"
+	"github.com/pivotal-cf/om/common"
 )
 
 type ApplyChanges struct {
 	installationsService installationsService
-	logger               logger
+	logger               common.Logger
 	logWriter            logWriter
 	waitDuration         int
 	Options              struct{}
@@ -30,7 +31,7 @@ type logWriter interface {
 	Flush(logs string) error
 }
 
-func NewApplyChanges(installationsService installationsService, logWriter logWriter, logger logger, waitDuration int) ApplyChanges {
+func NewApplyChanges(installationsService installationsService, logWriter logWriter, logger common.Logger, waitDuration int) ApplyChanges {
 	return ApplyChanges{
 		installationsService: installationsService,
 		logger:               logger,

commands/apply_changes_test.go

@@ -5,12 +5,12 @@ import (
 	"fmt"
 	"io"
 
+	. "github.com/onsi/ginkgo"
+	. "github.com/onsi/gomega"
 	"github.com/pivotal-cf/om/api"
 	"github.com/pivotal-cf/om/commands"
 	"github.com/pivotal-cf/om/commands/fakes"
-
-	. "github.com/onsi/ginkgo"
-	. "github.com/onsi/gomega"
+	commonfakes "github.com/pivotal-cf/om/common/fakes"
 )
 
 type netError struct {
@@ -28,7 +28,7 @@ func (ne netError) Timeout() bool {
 var _ = Describe("ApplyChanges", func() {
 	var (
 		service       *fakes.InstallationsService
-		logger        *fakes.OtherLogger
+		logger        *commonfakes.OtherLogger
 		writer        *fakes.LogWriter
 		statusOutputs []api.InstallationsServiceOutput
 		statusErrors  []error
@@ -40,7 +40,7 @@ var _ = Describe("ApplyChanges", func() {
 
 	BeforeEach(func() {
 		service = &fakes.InstallationsService{}
-		logger = &fakes.OtherLogger{}
+		logger = &commonfakes.OtherLogger{}
 		writer = &fakes.LogWriter{}
 
 		statusCount = 0

commands/configure_authentication.go

@@ -4,6 +4,7 @@ import (
 	"fmt"
 
 	"github.com/pivotal-cf/om/api"
+	"github.com/pivotal-cf/om/common"
 	"github.com/pivotal-cf/om/flags"
 )
 
@@ -14,15 +15,15 @@ type setupService interface {
 
 type ConfigureAuthentication struct {
 	service setupService
-	logger  logger
+	logger  common.Logger
 	Options struct {
 		Username             string `short:"u"  long:"username"              description:"admin username"`
 		Password             string `short:"p"  long:"password"              description:"admin password"`
 		DecryptionPassphrase string `short:"dp" long:"decryption-passphrase" description:"passphrase used to encrypt the installation"`
 	}
 }
 
-func NewConfigureAuthentication(service setupService, logger logger) ConfigureAuthentication {
+func NewConfigureAuthentication(service setupService, logger common.Logger) ConfigureAuthentication {
 	return ConfigureAuthentication{
 		service: service,
 		logger:  logger,

commands/configure_authentication_test.go

@@ -6,6 +6,7 @@ import (
 	"github.com/pivotal-cf/om/api"
 	"github.com/pivotal-cf/om/commands"
 	"github.com/pivotal-cf/om/commands/fakes"
+	commonfakes "github.com/pivotal-cf/om/common/fakes"
 
 	. "github.com/onsi/ginkgo"
 	. "github.com/onsi/gomega"
@@ -21,7 +22,7 @@ var _ = Describe("ConfigureAuthentication", func() {
 				{Status: api.EnsureAvailabilityStatusPending},
 				{Status: api.EnsureAvailabilityStatusComplete},
 			}
-			logger := &fakes.Logger{}
+			logger := &commonfakes.Logger{}
 
 			command := commands.NewConfigureAuthentication(service, logger)
 			err := command.Execute([]string{
@@ -56,7 +57,7 @@ var _ = Describe("ConfigureAuthentication", func() {
 				service.EnsureAvailabilityCall.Returns.Outputs = []api.EnsureAvailabilityOutput{
 					{Status: api.EnsureAvailabilityStatusComplete},
 				}
-				logger := &fakes.Logger{}
+				logger := &commonfakes.Logger{}
 
 				command := commands.NewConfigureAuthentication(service, logger)
 				err := command.Execute([]string{
@@ -78,7 +79,7 @@ var _ = Describe("ConfigureAuthentication", func() {
 		Context("failure cases", func() {
 			Context("when an unknown flag is provided", func() {
 				It("returns an error", func() {
-					command := commands.NewConfigureAuthentication(&fakes.SetupService{}, &fakes.Logger{})
+					command := commands.NewConfigureAuthentication(&fakes.SetupService{}, &commonfakes.Logger{})
 					err := command.Execute([]string{"--banana"})
 					Expect(err).To(MatchError("could not parse configure-authentication flags: flag provided but not defined: -banana"))
 				})
@@ -89,7 +90,7 @@ var _ = Describe("ConfigureAuthentication", func() {
 					service := &fakes.SetupService{}
 					service.EnsureAvailabilityCall.Returns.Errors = []error{errors.New("failed to fetch status")}
 
-					command := commands.NewConfigureAuthentication(service, &fakes.Logger{})
+					command := commands.NewConfigureAuthentication(service, &commonfakes.Logger{})
 					err := command.Execute([]string{
 						"--username", "some-username",
 						"--password", "some-password",
@@ -107,7 +108,7 @@ var _ = Describe("ConfigureAuthentication", func() {
 					}
 					service.SetupCall.Returns.Error = errors.New("could not setup")
 
-					command := commands.NewConfigureAuthentication(service, &fakes.Logger{})
+					command := commands.NewConfigureAuthentication(service, &commonfakes.Logger{})
 					err := command.Execute([]string{
 						"--username", "some-username",
 						"--password", "some-password",
@@ -125,7 +126,7 @@ var _ = Describe("ConfigureAuthentication", func() {
 					}
 					service.EnsureAvailabilityCall.Returns.Errors = []error{nil, nil, nil, errors.New("failed to fetch status")}
 
-					command := commands.NewConfigureAuthentication(service, &fakes.Logger{})
+					command := commands.NewConfigureAuthentication(service, &commonfakes.Logger{})
 					err := command.Execute([]string{
 						"--username", "some-username",
 						"--password", "some-password",

commands/export_installation.go

@@ -4,11 +4,12 @@ import (
 	"errors"
 	"fmt"
 
+	"github.com/pivotal-cf/om/common"
 	"github.com/pivotal-cf/om/flags"
 )
 
 type ExportInstallation struct {
-	logger                           logger
+	logger                           common.Logger
 	installationAssetExporterService installationAssetExporterService
 	Options                          struct {
 		OutputFile string `short:"o"  long:"output-file"  description:"output path to write installation to"`
@@ -20,7 +21,7 @@ type installationAssetExporterService interface {
 	Export(string) error
 }
 
-func NewExportInstallation(installationAssetExporterService installationAssetExporterService, logger logger) ExportInstallation {
+func NewExportInstallation(installationAssetExporterService installationAssetExporterService, logger common.Logger) ExportInstallation {
 	return ExportInstallation{
 		logger: logger,
 		installationAssetExporterService: installationAssetExporterService,