Run GetStatus check twice when complete on SSV1

source/Octopus.Tentacle.Client.Tests/ScriptServiceV1ExecutorTests.cs

@@ -0,0 +1,139 @@
+using System;
+using System.Collections.Generic;
+using System.Threading;
+using System.Threading.Tasks;
+using FluentAssertions;
+using Halibut.ServiceModel;
+using NSubstitute;
+using NUnit.Framework;
+using Octopus.Tentacle.Client.EventDriven;
+using Octopus.Tentacle.Client.Execution;
+using Octopus.Tentacle.Client.Observability;
+using Octopus.Tentacle.Client.Scripts;
+using Octopus.Tentacle.Contracts;
+using Octopus.Tentacle.Contracts.ClientServices;
+using Octopus.Tentacle.Contracts.Logging;
+using Octopus.Tentacle.Contracts.Observability;
+
+namespace Octopus.Tentacle.Client.Tests
+{
+    [TestFixture]
+    public class ScriptServiceV1ExecutorTests
+    {
+        /// <summary>
+        /// In ScriptServiceV1, it is possible that additional logs may be returned after the
+        /// first call to GetStatus responds with a completed status. The script executor
+        /// mitigates against this by checking a second time if the script is completed.
+        /// </summary>
+        [Test]
+        public async Task GetStatusWillDoubleCheckIfProcessIsCompleted()
+        {
+            // Arrange
+            var scriptService = Substitute.For<IAsyncClientScriptService>();
+            scriptService.GetStatusAsync(Arg.Any<ScriptStatusRequest>(), Arg.Any<HalibutProxyRequestOptions>())
+                .Returns(
+                    x => Task.FromResult(new ScriptStatusResponse(
+                        x.Arg<ScriptStatusRequest>().Ticket,
+                        ProcessState.Complete,
+                        nextLogSequence: 1,
+                        exitCode: 0,
+                        logs: new List<ProcessOutput>
+                        {
+                            new(ProcessOutputSource.StdOut, "First log line"),
+                        })),
+                    x => Task.FromResult(new ScriptStatusResponse(
+                        x.Arg<ScriptStatusRequest>().Ticket,
+                        ProcessState.Complete,
+                        nextLogSequence: 2,
+                        exitCode: 0,
+                        logs: new List<ProcessOutput>
+                        {
+                            new(ProcessOutputSource.StdOut, "Second log line"),
+                        }))
+                );
+
+            var scriptExecutor = new ScriptServiceV1Executor(
+                scriptService,
+                RpcCallExecutorFactory.Create(TimeSpan.Zero, Substitute.For<ITentacleClientObserver>()),
+                ClientOperationMetricsBuilder.Start(),
+                Substitute.For<ITentacleClientTaskLog>()
+            );
+
+
+            var context = new CommandContext(
+                scriptTicket: new ScriptTicket("TestTicket"),
+                nextLogSequence: 0,
+                ScriptServiceVersion.ScriptServiceVersion1
+            );
+
+            // Act
+            var result = await scriptExecutor.GetStatus(context, CancellationToken.None);
+
+            // Assert
+            result.ScriptStatus.Should().NotBeNull();
+            result.ScriptStatus.ExitCode.Should().Be(0);
+            result.ScriptStatus.Logs.Should().HaveCount(2);
+            result.ScriptStatus.Logs[0].Source.Should().Be(ProcessOutputSource.StdOut);
+            result.ScriptStatus.Logs[0].Text.Should().Be("First log line");
+            result.ScriptStatus.Logs[1].Source.Should().Be(ProcessOutputSource.StdOut);
+            result.ScriptStatus.Logs[1].Text.Should().Be("Second log line");
+            result.ScriptStatus.State.Should().Be(ProcessState.Complete);
+        }
+
+        [Test]
+        public async Task GetStatusWillOnlyCheckOnceIfProcessIsNotComplete()
+        {
+            // Arrange
+            var scriptService = Substitute.For<IAsyncClientScriptService>();
+            scriptService.GetStatusAsync(Arg.Any<ScriptStatusRequest>(), Arg.Any<HalibutProxyRequestOptions>())
+                .Returns(
+                    x => Task.FromResult(
+                        new ScriptStatusResponse(
+                            x.Arg<ScriptStatusRequest>().Ticket,
+                            ProcessState.Running,
+                            nextLogSequence: 1,
+                            exitCode: 0,
+                            logs: new List<ProcessOutput>
+                            {
+                                new(ProcessOutputSource.StdOut, "First log line"),
+                            }
+                        )
+                    ),
+                    x => Task.FromResult(
+                        new ScriptStatusResponse(
+                            x.Arg<ScriptStatusRequest>().Ticket,
+                            ProcessState.Complete,
+                            nextLogSequence: 2,
+                            exitCode: 0,
+                            logs: new List<ProcessOutput>
+                            {
+                                new(ProcessOutputSource.StdOut, "This line should not be returned"),
+                            }
+                        )
+                    )
+                );
+            var scriptExecutor = new ScriptServiceV1Executor(
+                scriptService,
+                RpcCallExecutorFactory.Create(TimeSpan.Zero, Substitute.For<ITentacleClientObserver>()),
+                ClientOperationMetricsBuilder.Start(),
+                Substitute.For<ITentacleClientTaskLog>()
+            );
+            var context = new CommandContext(
+                scriptTicket: new ScriptTicket("TestTicket"),
+                nextLogSequence: 0,
+                scripServiceVersionUsed: ScriptServiceVersion.ScriptServiceVersion1
+            );
+
+            // Act
+            var result = await scriptExecutor.GetStatus(context, CancellationToken.None);
+
+            // Assert
+            result.ScriptStatus.Should().NotBeNull();
+            result.ScriptStatus.ExitCode.Should().Be(0);
+            result.ScriptStatus.Logs.Should().HaveCount(1);
+            result.ScriptStatus.Logs[0].Source.Should().Be(ProcessOutputSource.StdOut);
+            result.ScriptStatus.Logs[0].Text.Should().Be("First log line");
+            result.ScriptStatus.State.Should().Be(ProcessState.Running);
+        }
+    }
+}

source/Octopus.Tentacle.Client/Scripts/ScriptServiceV1Executor.cs

@@ -1,5 +1,6 @@
 using System;
 using System.Collections.Generic;
+using System.Linq;
 using System.Threading;
 using System.Threading.Tasks;
 using Halibut.ServiceModel;
@@ -57,6 +58,21 @@ static ScriptOperationExecutionResult Map(ScriptStatusResponse scriptStatusRespo
                 new CommandContext(scriptStatusResponse.Ticket, scriptStatusResponse.NextLogSequence, ScriptServiceVersion.ScriptServiceVersion1));
         }
 
+        static ScriptOperationExecutionResult AggregateAndMap(ScriptStatusResponse initialResponse, ScriptStatusResponse subsequentResponse)
+        {
+            var aggregatedLogs = initialResponse.Logs.Concat(subsequentResponse.Logs).ToList();
+
+            var aggregatedResponse = new ScriptStatusResponse(
+                ticket: initialResponse.Ticket,
+                state: subsequentResponse.State,
+                exitCode: subsequentResponse.ExitCode,
+                logs: aggregatedLogs,
+                nextLogSequence: subsequentResponse.NextLogSequence
+            );
+
+            return Map(aggregatedResponse);
+        }
+
         static ScriptStatus MapToScriptStatus(ScriptStatusResponse scriptStatusResponse)
         {
             return new ScriptStatus(scriptStatusResponse.State, scriptStatusResponse.ExitCode, scriptStatusResponse.Logs);
@@ -89,6 +105,25 @@ public async Task<ScriptOperationExecutionResult> StartScript(ExecuteScriptComma
         }
 
         public async Task<ScriptOperationExecutionResult> GetStatus(CommandContext commandContext, CancellationToken scriptExecutionCancellationToken)
+        {
+            var scriptStatusResponseV1 = await GetStatusV1(commandContext, scriptExecutionCancellationToken).ConfigureAwait(false);
+
+            if (scriptStatusResponseV1.State != ProcessState.Complete)
+            {
+                return Map(scriptStatusResponseV1);
+            }
+
+            // Build a new CommandContext to return any remaining logs
+            var nextCommandContext = new CommandContext(
+                scriptTicket: scriptStatusResponseV1.Ticket,
+                nextLogSequence: scriptStatusResponseV1.NextLogSequence,
+                scripServiceVersionUsed: ScriptServiceVersion.ScriptServiceVersion1
+            );
+            var nextScriptStatusResponseV1 = await GetStatusV1(nextCommandContext, scriptExecutionCancellationToken).ConfigureAwait(false);
+            return AggregateAndMap(scriptStatusResponseV1, nextScriptStatusResponseV1);
+        }
+
+        async Task<ScriptStatusResponse> GetStatusV1(CommandContext commandContext, CancellationToken scriptExecutionCancellationToken)
         {
             var scriptStatusResponseV1 = await rpcCallExecutor.ExecuteWithNoRetries(
                 RpcCall.Create<IScriptService>(nameof(IScriptService.GetStatus)),
@@ -102,8 +137,7 @@ public async Task<ScriptOperationExecutionResult> GetStatus(CommandContext comma
                 logger,
                 clientOperationMetricsBuilder,
                 scriptExecutionCancellationToken).ConfigureAwait(false);
-
-            return Map(scriptStatusResponseV1);
+            return scriptStatusResponseV1;
         }
 
         public async Task<ScriptOperationExecutionResult> CancelScript(CommandContext commandContext)

source/Octopus.Tentacle.Tests.Integration/ClientScriptExecutorObservesScriptObserverBackoffStrategy.cs

@@ -32,11 +32,15 @@ public async Task TheScriptObserverBackoffShouldBeRespected(TentacleConfiguratio
 
             var (_, logs) = await clientTentacle.TentacleClient.ExecuteScript(startScriptCommand, CancellationToken);
 
+            var maxGetStatusCalls = tentacleConfigurationTestCase.ScriptServiceToTest == TentacleConfigurationTestCases.ScriptServiceV1Type
+                ? 4 // When using ScriptServiceV1 we check the final status twice on completion
+                : 3;
+
             recordedUsages.For(nameof(IAsyncClientScriptServiceV2.GetStatusAsync)).Started
                 .Should()
                 .BeGreaterThan(0)
                 .And
-                .BeLessThan(3);
+                .BeLessThan(maxGetStatusCalls);
         }
     }
 }