Skip to content

Commit 4f67fe8

Browse files
authored
Run GetStatus check twice when complete on SSV1 (#1116)
* 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. * Fix test to accommodate new behaviour Resolves #1117
1 parent 5b23e74 commit 4f67fe8

File tree

3 files changed

+180
-3
lines changed

3 files changed

+180
-3
lines changed
Lines changed: 139 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,139 @@
1+
using System;
2+
using System.Collections.Generic;
3+
using System.Threading;
4+
using System.Threading.Tasks;
5+
using FluentAssertions;
6+
using Halibut.ServiceModel;
7+
using NSubstitute;
8+
using NUnit.Framework;
9+
using Octopus.Tentacle.Client.EventDriven;
10+
using Octopus.Tentacle.Client.Execution;
11+
using Octopus.Tentacle.Client.Observability;
12+
using Octopus.Tentacle.Client.Scripts;
13+
using Octopus.Tentacle.Contracts;
14+
using Octopus.Tentacle.Contracts.ClientServices;
15+
using Octopus.Tentacle.Contracts.Logging;
16+
using Octopus.Tentacle.Contracts.Observability;
17+
18+
namespace Octopus.Tentacle.Client.Tests
19+
{
20+
[TestFixture]
21+
public class ScriptServiceV1ExecutorTests
22+
{
23+
/// <summary>
24+
/// In ScriptServiceV1, it is possible that additional logs may be returned after the
25+
/// first call to GetStatus responds with a completed status. The script executor
26+
/// mitigates against this by checking a second time if the script is completed.
27+
/// </summary>
28+
[Test]
29+
public async Task GetStatusWillDoubleCheckIfProcessIsCompleted()
30+
{
31+
// Arrange
32+
var scriptService = Substitute.For<IAsyncClientScriptService>();
33+
scriptService.GetStatusAsync(Arg.Any<ScriptStatusRequest>(), Arg.Any<HalibutProxyRequestOptions>())
34+
.Returns(
35+
x => Task.FromResult(new ScriptStatusResponse(
36+
x.Arg<ScriptStatusRequest>().Ticket,
37+
ProcessState.Complete,
38+
nextLogSequence: 1,
39+
exitCode: 0,
40+
logs: new List<ProcessOutput>
41+
{
42+
new(ProcessOutputSource.StdOut, "First log line"),
43+
})),
44+
x => Task.FromResult(new ScriptStatusResponse(
45+
x.Arg<ScriptStatusRequest>().Ticket,
46+
ProcessState.Complete,
47+
nextLogSequence: 2,
48+
exitCode: 0,
49+
logs: new List<ProcessOutput>
50+
{
51+
new(ProcessOutputSource.StdOut, "Second log line"),
52+
}))
53+
);
54+
55+
var scriptExecutor = new ScriptServiceV1Executor(
56+
scriptService,
57+
RpcCallExecutorFactory.Create(TimeSpan.Zero, Substitute.For<ITentacleClientObserver>()),
58+
ClientOperationMetricsBuilder.Start(),
59+
Substitute.For<ITentacleClientTaskLog>()
60+
);
61+
62+
63+
var context = new CommandContext(
64+
scriptTicket: new ScriptTicket("TestTicket"),
65+
nextLogSequence: 0,
66+
ScriptServiceVersion.ScriptServiceVersion1
67+
);
68+
69+
// Act
70+
var result = await scriptExecutor.GetStatus(context, CancellationToken.None);
71+
72+
// Assert
73+
result.ScriptStatus.Should().NotBeNull();
74+
result.ScriptStatus.ExitCode.Should().Be(0);
75+
result.ScriptStatus.Logs.Should().HaveCount(2);
76+
result.ScriptStatus.Logs[0].Source.Should().Be(ProcessOutputSource.StdOut);
77+
result.ScriptStatus.Logs[0].Text.Should().Be("First log line");
78+
result.ScriptStatus.Logs[1].Source.Should().Be(ProcessOutputSource.StdOut);
79+
result.ScriptStatus.Logs[1].Text.Should().Be("Second log line");
80+
result.ScriptStatus.State.Should().Be(ProcessState.Complete);
81+
}
82+
83+
[Test]
84+
public async Task GetStatusWillOnlyCheckOnceIfProcessIsNotComplete()
85+
{
86+
// Arrange
87+
var scriptService = Substitute.For<IAsyncClientScriptService>();
88+
scriptService.GetStatusAsync(Arg.Any<ScriptStatusRequest>(), Arg.Any<HalibutProxyRequestOptions>())
89+
.Returns(
90+
x => Task.FromResult(
91+
new ScriptStatusResponse(
92+
x.Arg<ScriptStatusRequest>().Ticket,
93+
ProcessState.Running,
94+
nextLogSequence: 1,
95+
exitCode: 0,
96+
logs: new List<ProcessOutput>
97+
{
98+
new(ProcessOutputSource.StdOut, "First log line"),
99+
}
100+
)
101+
),
102+
x => Task.FromResult(
103+
new ScriptStatusResponse(
104+
x.Arg<ScriptStatusRequest>().Ticket,
105+
ProcessState.Complete,
106+
nextLogSequence: 2,
107+
exitCode: 0,
108+
logs: new List<ProcessOutput>
109+
{
110+
new(ProcessOutputSource.StdOut, "This line should not be returned"),
111+
}
112+
)
113+
)
114+
);
115+
var scriptExecutor = new ScriptServiceV1Executor(
116+
scriptService,
117+
RpcCallExecutorFactory.Create(TimeSpan.Zero, Substitute.For<ITentacleClientObserver>()),
118+
ClientOperationMetricsBuilder.Start(),
119+
Substitute.For<ITentacleClientTaskLog>()
120+
);
121+
var context = new CommandContext(
122+
scriptTicket: new ScriptTicket("TestTicket"),
123+
nextLogSequence: 0,
124+
scripServiceVersionUsed: ScriptServiceVersion.ScriptServiceVersion1
125+
);
126+
127+
// Act
128+
var result = await scriptExecutor.GetStatus(context, CancellationToken.None);
129+
130+
// Assert
131+
result.ScriptStatus.Should().NotBeNull();
132+
result.ScriptStatus.ExitCode.Should().Be(0);
133+
result.ScriptStatus.Logs.Should().HaveCount(1);
134+
result.ScriptStatus.Logs[0].Source.Should().Be(ProcessOutputSource.StdOut);
135+
result.ScriptStatus.Logs[0].Text.Should().Be("First log line");
136+
result.ScriptStatus.State.Should().Be(ProcessState.Running);
137+
}
138+
}
139+
}

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

Lines changed: 36 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
using System;
22
using System.Collections.Generic;
3+
using System.Linq;
34
using System.Threading;
45
using System.Threading.Tasks;
56
using Halibut.ServiceModel;
@@ -57,6 +58,21 @@ static ScriptOperationExecutionResult Map(ScriptStatusResponse scriptStatusRespo
5758
new CommandContext(scriptStatusResponse.Ticket, scriptStatusResponse.NextLogSequence, ScriptServiceVersion.ScriptServiceVersion1));
5859
}
5960

61+
static ScriptOperationExecutionResult AggregateAndMap(ScriptStatusResponse initialResponse, ScriptStatusResponse subsequentResponse)
62+
{
63+
var aggregatedLogs = initialResponse.Logs.Concat(subsequentResponse.Logs).ToList();
64+
65+
var aggregatedResponse = new ScriptStatusResponse(
66+
ticket: initialResponse.Ticket,
67+
state: subsequentResponse.State,
68+
exitCode: subsequentResponse.ExitCode,
69+
logs: aggregatedLogs,
70+
nextLogSequence: subsequentResponse.NextLogSequence
71+
);
72+
73+
return Map(aggregatedResponse);
74+
}
75+
6076
static ScriptStatus MapToScriptStatus(ScriptStatusResponse scriptStatusResponse)
6177
{
6278
return new ScriptStatus(scriptStatusResponse.State, scriptStatusResponse.ExitCode, scriptStatusResponse.Logs);
@@ -89,6 +105,25 @@ public async Task<ScriptOperationExecutionResult> StartScript(ExecuteScriptComma
89105
}
90106

91107
public async Task<ScriptOperationExecutionResult> GetStatus(CommandContext commandContext, CancellationToken scriptExecutionCancellationToken)
108+
{
109+
var scriptStatusResponseV1 = await GetStatusV1(commandContext, scriptExecutionCancellationToken).ConfigureAwait(false);
110+
111+
if (scriptStatusResponseV1.State != ProcessState.Complete)
112+
{
113+
return Map(scriptStatusResponseV1);
114+
}
115+
116+
// Build a new CommandContext to return any remaining logs
117+
var nextCommandContext = new CommandContext(
118+
scriptTicket: scriptStatusResponseV1.Ticket,
119+
nextLogSequence: scriptStatusResponseV1.NextLogSequence,
120+
scripServiceVersionUsed: ScriptServiceVersion.ScriptServiceVersion1
121+
);
122+
var nextScriptStatusResponseV1 = await GetStatusV1(nextCommandContext, scriptExecutionCancellationToken).ConfigureAwait(false);
123+
return AggregateAndMap(scriptStatusResponseV1, nextScriptStatusResponseV1);
124+
}
125+
126+
async Task<ScriptStatusResponse> GetStatusV1(CommandContext commandContext, CancellationToken scriptExecutionCancellationToken)
92127
{
93128
var scriptStatusResponseV1 = await rpcCallExecutor.ExecuteWithNoRetries(
94129
RpcCall.Create<IScriptService>(nameof(IScriptService.GetStatus)),
@@ -102,8 +137,7 @@ public async Task<ScriptOperationExecutionResult> GetStatus(CommandContext comma
102137
logger,
103138
clientOperationMetricsBuilder,
104139
scriptExecutionCancellationToken).ConfigureAwait(false);
105-
106-
return Map(scriptStatusResponseV1);
140+
return scriptStatusResponseV1;
107141
}
108142

109143
public async Task<ScriptOperationExecutionResult> CancelScript(CommandContext commandContext)

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

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,11 +32,15 @@ public async Task TheScriptObserverBackoffShouldBeRespected(TentacleConfiguratio
3232

3333
var (_, logs) = await clientTentacle.TentacleClient.ExecuteScript(startScriptCommand, CancellationToken);
3434

35+
var maxGetStatusCalls = tentacleConfigurationTestCase.ScriptServiceToTest == TentacleConfigurationTestCases.ScriptServiceV1Type
36+
? 4 // When using ScriptServiceV1 we check the final status twice on completion
37+
: 3;
38+
3539
recordedUsages.For(nameof(IAsyncClientScriptServiceV2.GetStatusAsync)).Started
3640
.Should()
3741
.BeGreaterThan(0)
3842
.And
39-
.BeLessThan(3);
43+
.BeLessThan(maxGetStatusCalls);
4044
}
4145
}
4246
}

0 commit comments

Comments
 (0)