From 74420759ba518942ce8a043cbaff1417de760b91 Mon Sep 17 00:00:00 2001 From: Rhys Parry Date: Wed, 6 Aug 2025 13:09:40 +1000 Subject: [PATCH 1/2] Run GetStatus check twice when complete on SSV1 For ScriptServiceV1, a call to `GetStatus` may not return the full log information if the logs have not yet been flushed. This change updates the client to perform a second GetStatus check to attempt to fetch any additional logs. --- .../ScriptServiceV1ExecutorTests.cs | 139 ++++++++++++++++++ .../Scripts/ScriptServiceV1Executor.cs | 38 ++++- 2 files changed, 175 insertions(+), 2 deletions(-) create mode 100644 source/Octopus.Tentacle.Client.Tests/ScriptServiceV1ExecutorTests.cs diff --git a/source/Octopus.Tentacle.Client.Tests/ScriptServiceV1ExecutorTests.cs b/source/Octopus.Tentacle.Client.Tests/ScriptServiceV1ExecutorTests.cs new file mode 100644 index 000000000..60cb591b1 --- /dev/null +++ b/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 + { + /// + /// 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. + /// + [Test] + public async Task GetStatusWillDoubleCheckIfProcessIsCompleted() + { + // Arrange + var scriptService = Substitute.For(); + scriptService.GetStatusAsync(Arg.Any(), Arg.Any()) + .Returns( + x => Task.FromResult(new ScriptStatusResponse( + x.Arg().Ticket, + ProcessState.Complete, + nextLogSequence: 1, + exitCode: 0, + logs: new List + { + new(ProcessOutputSource.StdOut, "First log line"), + })), + x => Task.FromResult(new ScriptStatusResponse( + x.Arg().Ticket, + ProcessState.Complete, + nextLogSequence: 2, + exitCode: 0, + logs: new List + { + new(ProcessOutputSource.StdOut, "Second log line"), + })) + ); + + var scriptExecutor = new ScriptServiceV1Executor( + scriptService, + RpcCallExecutorFactory.Create(TimeSpan.Zero, Substitute.For()), + ClientOperationMetricsBuilder.Start(), + Substitute.For() + ); + + + 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(); + scriptService.GetStatusAsync(Arg.Any(), Arg.Any()) + .Returns( + x => Task.FromResult( + new ScriptStatusResponse( + x.Arg().Ticket, + ProcessState.Running, + nextLogSequence: 1, + exitCode: 0, + logs: new List + { + new(ProcessOutputSource.StdOut, "First log line"), + } + ) + ), + x => Task.FromResult( + new ScriptStatusResponse( + x.Arg().Ticket, + ProcessState.Complete, + nextLogSequence: 2, + exitCode: 0, + logs: new List + { + new(ProcessOutputSource.StdOut, "This line should not be returned"), + } + ) + ) + ); + var scriptExecutor = new ScriptServiceV1Executor( + scriptService, + RpcCallExecutorFactory.Create(TimeSpan.Zero, Substitute.For()), + ClientOperationMetricsBuilder.Start(), + Substitute.For() + ); + 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); + } + } +} diff --git a/source/Octopus.Tentacle.Client/Scripts/ScriptServiceV1Executor.cs b/source/Octopus.Tentacle.Client/Scripts/ScriptServiceV1Executor.cs index 0d2a89dce..ce79197bc 100644 --- a/source/Octopus.Tentacle.Client/Scripts/ScriptServiceV1Executor.cs +++ b/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 StartScript(ExecuteScriptComma } public async Task 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 GetStatusV1(CommandContext commandContext, CancellationToken scriptExecutionCancellationToken) { var scriptStatusResponseV1 = await rpcCallExecutor.ExecuteWithNoRetries( RpcCall.Create(nameof(IScriptService.GetStatus)), @@ -102,8 +137,7 @@ public async Task GetStatus(CommandContext comma logger, clientOperationMetricsBuilder, scriptExecutionCancellationToken).ConfigureAwait(false); - - return Map(scriptStatusResponseV1); + return scriptStatusResponseV1; } public async Task CancelScript(CommandContext commandContext) From 60241ec1ee1d09f859c71b060be1ade381228b3f Mon Sep 17 00:00:00 2001 From: Rhys Parry Date: Wed, 6 Aug 2025 14:47:57 +1000 Subject: [PATCH 2/2] Fix test to accommodate new behaviour --- ...ntScriptExecutorObservesScriptObserverBackoffStrategy.cs | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/source/Octopus.Tentacle.Tests.Integration/ClientScriptExecutorObservesScriptObserverBackoffStrategy.cs b/source/Octopus.Tentacle.Tests.Integration/ClientScriptExecutorObservesScriptObserverBackoffStrategy.cs index b61e5aeb0..967c2449a 100644 --- a/source/Octopus.Tentacle.Tests.Integration/ClientScriptExecutorObservesScriptObserverBackoffStrategy.cs +++ b/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); } } }