Fix inter-woven output during start

cf/api/fakes/fake_logs_repository.go

@@ -1,57 +1,118 @@
+// This file was generated by counterfeiter
 package fakes
 
 import (
+	"sync"
+
+	"github.com/cloudfoundry/cli/cf/api"
 	"github.com/cloudfoundry/loggregatorlib/logmessage"
 )
 
 type FakeLogsRepository struct {
-	AppLoggedGuid string
-	RecentLogs    []*logmessage.LogMessage
-	RecentLogErr  error
-
-	TailLogMessages []*logmessage.LogMessage
-	TailLogErr      error
-
-	TailLogStopCalled bool
+	RecentLogsForStub        func(appGuid string) ([]*logmessage.LogMessage, error)
+	recentLogsForMutex       sync.RWMutex
+	recentLogsForArgsForCall []struct {
+		appGuid string
+	}
+	recentLogsForReturns struct {
+		result1 []*logmessage.LogMessage
+		result2 error
+	}
+	TailLogsForStub        func(appGuid string, onConnect func(), onMessage func(*logmessage.LogMessage)) error
+	tailLogsForMutex       sync.RWMutex
+	tailLogsForArgsForCall []struct {
+		appGuid   string
+		onConnect func()
+		onMessage func(*logmessage.LogMessage)
+	}
+	tailLogsForReturns struct {
+		result1 error
+	}
+	CloseStub        func()
+	closeMutex       sync.RWMutex
+	closeArgsForCall []struct{}
 }
 
-func (l *FakeLogsRepository) RecentLogsFor(appGuid string) ([]*logmessage.LogMessage, error) {
-	l.AppLoggedGuid = appGuid
-	return l.RecentLogs, l.RecentLogErr
+func (fake *FakeLogsRepository) RecentLogsFor(appGuid string) ([]*logmessage.LogMessage, error) {
+	fake.recentLogsForMutex.Lock()
+	defer fake.recentLogsForMutex.Unlock()
+	fake.recentLogsForArgsForCall = append(fake.recentLogsForArgsForCall, struct {
+		appGuid string
+	}{appGuid})
+	if fake.RecentLogsForStub != nil {
+		return fake.RecentLogsForStub(appGuid)
+	} else {
+		return fake.recentLogsForReturns.result1, fake.recentLogsForReturns.result2
+	}
 }
 
-func (l *FakeLogsRepository) TailLogsFor(appGuid string, onConnect func(), onMessage func(*logmessage.LogMessage)) (err error) {
-	l.AppLoggedGuid = appGuid
+func (fake *FakeLogsRepository) RecentLogsForCallCount() int {
+	fake.recentLogsForMutex.RLock()
+	defer fake.recentLogsForMutex.RUnlock()
+	return len(fake.recentLogsForArgsForCall)
+}
 
-	err = l.TailLogErr
-	if err != nil {
-		return
-	}
+func (fake *FakeLogsRepository) RecentLogsForArgsForCall(i int) string {
+	fake.recentLogsForMutex.RLock()
+	defer fake.recentLogsForMutex.RUnlock()
+	return fake.recentLogsForArgsForCall[i].appGuid
+}
 
-	onConnect()
+func (fake *FakeLogsRepository) RecentLogsForReturns(result1 []*logmessage.LogMessage, result2 error) {
+	fake.RecentLogsForStub = nil
+	fake.recentLogsForReturns = struct {
+		result1 []*logmessage.LogMessage
+		result2 error
+	}{result1, result2}
+}
 
-	for _, msg := range l.TailLogMessages {
-		onMessage(msg)
+func (fake *FakeLogsRepository) TailLogsFor(appGuid string, onConnect func(), onMessage func(*logmessage.LogMessage)) error {
+	fake.tailLogsForMutex.Lock()
+	defer fake.tailLogsForMutex.Unlock()
+	fake.tailLogsForArgsForCall = append(fake.tailLogsForArgsForCall, struct {
+		appGuid   string
+		onConnect func()
+		onMessage func(*logmessage.LogMessage)
+	}{appGuid, onConnect, onMessage})
+	if fake.TailLogsForStub != nil {
+		return fake.TailLogsForStub(appGuid, onConnect, onMessage)
+	} else {
+		return fake.tailLogsForReturns.result1
 	}
+}
 
-	return
+func (fake *FakeLogsRepository) TailLogsForCallCount() int {
+	fake.tailLogsForMutex.RLock()
+	defer fake.tailLogsForMutex.RUnlock()
+	return len(fake.tailLogsForArgsForCall)
 }
 
-func (l *FakeLogsRepository) Close() {
-	l.TailLogStopCalled = true
+func (fake *FakeLogsRepository) TailLogsForArgsForCall(i int) (string, func(), func(*logmessage.LogMessage)) {
+	fake.tailLogsForMutex.RLock()
+	defer fake.tailLogsForMutex.RUnlock()
+	return fake.tailLogsForArgsForCall[i].appGuid, fake.tailLogsForArgsForCall[i].onConnect, fake.tailLogsForArgsForCall[i].onMessage
 }
 
-func (l *FakeLogsRepository) logsFor(appGuid string, logMessages []*logmessage.LogMessage, onConnect func(), logChan chan *logmessage.LogMessage, stopLoggingChan chan bool) {
-	l.AppLoggedGuid = appGuid
-	onConnect()
+func (fake *FakeLogsRepository) TailLogsForReturns(result1 error) {
+	fake.TailLogsForStub = nil
+	fake.tailLogsForReturns = struct {
+		result1 error
+	}{result1}
+}
 
-	for _, logMsg := range logMessages {
-		logChan <- logMsg
+func (fake *FakeLogsRepository) Close() {
+	fake.closeMutex.Lock()
+	defer fake.closeMutex.Unlock()
+	fake.closeArgsForCall = append(fake.closeArgsForCall, struct{}{})
+	if fake.CloseStub != nil {
+		fake.CloseStub()
 	}
+}
 
-	go func() {
-		l.TailLogStopCalled = <-stopLoggingChan
-	}()
-
-	return
+func (fake *FakeLogsRepository) CloseCallCount() int {
+	fake.closeMutex.RLock()
+	defer fake.closeMutex.RUnlock()
+	return len(fake.closeArgsForCall)
 }
+
+var _ api.LogsRepository = new(FakeLogsRepository)

cf/commands/application/logs_test.go

@@ -78,15 +78,22 @@ var _ = Describe("logs command", func() {
 			}
 
 			requirementsFactory.Application = app
-			logsRepo.RecentLogs = recentLogs
-			logsRepo.TailLogMessages = appLogs
+			logsRepo.RecentLogsForReturns(recentLogs, nil)
+
+			logsRepo.TailLogsForStub = func(appGuid string, onConnect func(), onMessage func(*logmessage.LogMessage)) error {
+				onConnect()
+				for _, log := range appLogs {
+					onMessage(log)
+				}
+				return nil
+			}
 		})
 
 		It("shows the recent logs when the --recent flag is provided", func() {
 			runCommand("--recent", "my-app")
 
 			Expect(requirementsFactory.ApplicationName).To(Equal("my-app"))
-			Expect(app.Guid).To(Equal(logsRepo.AppLoggedGuid))
+			Expect(app.Guid).To(Equal(logsRepo.RecentLogsForArgsForCall(0)))
 			Expect(ui.Outputs).To(ContainSubstrings(
 				[]string{"Connected, dumping recent logs for app", "my-app", "my-org", "my-space", "my-user"},
 				[]string{"Log Line 1"},
@@ -96,9 +103,9 @@ var _ = Describe("logs command", func() {
 
 		Context("when the log messages contain format string identifiers", func() {
 			BeforeEach(func() {
-				logsRepo.RecentLogs = []*logmessage.LogMessage{
+				logsRepo.RecentLogsForReturns([]*logmessage.LogMessage{
 					testlogs.NewLogMessage("hello%2Bworld%v", app.Guid, "DEA", time.Now()),
-				}
+				}, nil)
 			})
 
 			It("does not treat them as format strings", func() {
@@ -111,7 +118,8 @@ var _ = Describe("logs command", func() {
 			runCommand("my-app")
 
 			Expect(requirementsFactory.ApplicationName).To(Equal("my-app"))
-			Expect(app.Guid).To(Equal(logsRepo.AppLoggedGuid))
+			appGuid, _, _ := logsRepo.TailLogsForArgsForCall(0)
+			Expect(app.Guid).To(Equal(appGuid))
 			Expect(ui.Outputs).To(ContainSubstrings(
 				[]string{"Connected, tailing logs for app", "my-app", "my-org", "my-space", "my-user"},
 				[]string{"Log Line 1"},
@@ -121,7 +129,7 @@ var _ = Describe("logs command", func() {
 		Context("when the loggregator server has an invalid cert", func() {
 			Context("when the skip-ssl-validation flag is not set", func() {
 				It("fails and informs the user about the skip-ssl-validation flag", func() {
-					logsRepo.TailLogErr = errors.NewInvalidSSLCert("https://example.com", "it don't work good")
+					logsRepo.TailLogsForReturns(errors.NewInvalidSSLCert("https://example.com", "it don't work good"))
 					runCommand("my-app")
 
 					Expect(ui.Outputs).To(ContainSubstrings(
@@ -131,7 +139,7 @@ var _ = Describe("logs command", func() {
 				})
 
 				It("informs the user of the error when they include the --recent flag", func() {
-					logsRepo.RecentLogErr = errors.NewInvalidSSLCert("https://example.com", "how does SSL work???")
+					logsRepo.RecentLogsForReturns(nil, errors.NewInvalidSSLCert("https://example.com", "how does SSL work???"))
 					runCommand("--recent", "my-app")
 
 					Expect(ui.Outputs).To(ContainSubstrings(

cf/commands/application/start.go

@@ -134,9 +134,13 @@ func (cmd *Start) ApplicationStart(app models.Application) (updatedApp models.Ap
 func (cmd *Start) ApplicationWatchStaging(app models.Application, start func(app models.Application) (models.Application, error)) (updatedApp models.Application, err error) {
 	stopLoggingChan := make(chan bool, 1)
 	loggingStartedChan := make(chan bool)
+	doneLoggingChan := make(chan bool)
 
-	go cmd.tailStagingLogs(app, loggingStartedChan, stopLoggingChan)
-
+	go cmd.tailStagingLogs(app, loggingStartedChan, doneLoggingChan)
+	go func() {
+		<-stopLoggingChan
+		cmd.logRepo.Close()
+	}()
 	<-loggingStartedChan // block until we have established connection to Loggregator
 
 	updatedApp, apiErr := start(app)
@@ -149,6 +153,7 @@ func (cmd *Start) ApplicationWatchStaging(app models.Application, start func(app
 
 	cmd.waitForInstancesToStage(updatedApp)
 	stopLoggingChan <- true
+	<-doneLoggingChan
 
 	cmd.ui.Say("")
 
@@ -173,19 +178,14 @@ func simpleLogMessageOutput(logMsg *logmessage.LogMessage) (msgText string) {
 	return
 }
 
-func (cmd Start) tailStagingLogs(app models.Application, startChan chan bool, stopChan chan bool) {
+func (cmd Start) tailStagingLogs(app models.Application, startChan, doneChan chan bool) {
 	onConnect := func() {
 		startChan <- true
 	}
 
 	err := cmd.logRepo.TailLogsFor(app.Guid, onConnect, func(msg *logmessage.LogMessage) {
-		select {
-		case <-stopChan:
-			cmd.logRepo.Close()
-		default:
-			if msg.GetSourceName() == LogMessageTypeStaging {
-				cmd.ui.Say(simpleLogMessageOutput(msg))
-			}
+		if msg.GetSourceName() == LogMessageTypeStaging {
+			cmd.ui.Say(simpleLogMessageOutput(msg))
 		}
 	})
 
@@ -194,6 +194,8 @@ func (cmd Start) tailStagingLogs(app models.Application, startChan chan bool, st
 		cmd.ui.Say("%s", err)
 		startChan <- true
 	}
+
+	close(doneChan)
 }
 
 func isStagingError(err error) bool {