Skip to content

Commit 8e30ff3

Browse files
LNK-4857: Fix Op Outcome retries (RELEASE BRANCH) (#1469)
* Fix Op Outcome retries * LNK-4857 * add better handling for 404 and 410 * retrigger codeql * Update PatientDataService.cs * Update PatientDataServiceTests.cs
1 parent c7cc0ca commit 8e30ff3

13 files changed

Lines changed: 763 additions & 29 deletions

File tree

DotNet/Admin.BFF/Admin.BFF.csproj

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
<Project Sdk="Microsoft.NET.Sdk.Web">
1+
<Project Sdk="Microsoft.NET.Sdk.Web">
22

33
<PropertyGroup>
44
<TargetFramework>net8.0</TargetFramework>
@@ -34,7 +34,7 @@
3434
<PackageReference Include="Microsoft.EntityFrameworkCore.InMemory" Version="8.*" />
3535
<PackageReference Include="Microsoft.Extensions.Caching.StackExchangeRedis" Version="8.*" />
3636
<PackageReference Include="Microsoft.Extensions.Compliance.Redaction" Version="8.*" />
37-
<PackageReference Include="Microsoft.Extensions.Telemetry" Version="8.*" />
37+
<PackageReference Include="Microsoft.Extensions.Telemetry" Version="10.1.0" />
3838
<PackageReference Include="Microsoft.VisualStudio.Azure.Containers.Tools.Targets" Version="1.*" />
3939
<PackageReference Include="Serilog" Version="4.*" />
4040
<PackageReference Include="Serilog.AspNetCore" Version="8.*" />

DotNet/Audit/Audit.csproj

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
<Project Sdk="Microsoft.NET.Sdk.Web">
1+
<Project Sdk="Microsoft.NET.Sdk.Web">
22

33
<PropertyGroup>
44
<TargetFramework>net8.0</TargetFramework>
@@ -33,7 +33,7 @@
3333
</PackageReference>
3434
<PackageReference Include="Microsoft.EntityFrameworkCore.SqlServer" Version="8.*" />
3535
<PackageReference Include="Microsoft.Extensions.Compliance.Redaction" Version="8.*" />
36-
<PackageReference Include="Microsoft.Extensions.Telemetry" Version="8.*" />
36+
<PackageReference Include="Microsoft.Extensions.Telemetry" Version="10.1.0" />
3737
<PackageReference Include="Microsoft.VisualStudio.Azure.Containers.Tools.Targets" Version="1.*" />
3838
<PackageReference Include="Serilog.AspNetCore" Version="8.*" />
3939
<PackageReference Include="Serilog.Enrichers.Span" Version="3.*" />
Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,21 @@
1+
using System;
2+
using System.Net;
3+
using Hl7.Fhir.Rest;
4+
5+
namespace LantanaGroup.Link.DataAcquisition.Domain.Application.Models.Exceptions
6+
{
7+
public class OpOutcomeException : FhirOperationException
8+
{
9+
public HttpStatusCode? StatusCode { get; }
10+
11+
public OpOutcomeException(string message, FhirOperationException innerException) : base(message, innerException.Status, innerException.Outcome)
12+
{
13+
StatusCode = innerException.Status;
14+
Data.Add("InnerException", innerException);
15+
}
16+
17+
public new FhirOperationException? InnerException => Data.Contains("InnerException") ? Data["InnerException"] as FhirOperationException : null;
18+
19+
public override string? StackTrace => InnerException is not null ? $"{base.StackTrace}\n---> Inner Exception: {InnerException.Message}\n{InnerException.StackTrace}" : base.StackTrace;
20+
}
21+
}

DotNet/DataAcquisition.Domain/Application/Queries/DataAcquisitionLogQueries.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -202,7 +202,7 @@ public async Task<int> GetCountOfNonRefLogsIncompleteAsync(string facilityId, st
202202
where l.FacilityId == facilityId
203203
&& l.ReportTrackingId == reportTrackingId
204204
&& l.CorrelationId == correlationId
205-
&& !(l.Status == RequestStatus.Completed || l.Status == RequestStatus.MaxRetriesReached)
205+
&& !(l.Status == RequestStatus.Completed || l.Status == RequestStatus.MaxRetriesReached || l.Status == RequestStatus.Skipped)
206206
&& !l.TailSent
207207
&& l.FhirQueries.Any(fq => fq.IsReference == false)
208208
select l).CountAsync(cancellationToken);

DotNet/DataAcquisition.Domain/Application/Services/FhirApi/FhirApiService.cs

Lines changed: 44 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77
using Hl7.Fhir.Model;
88
using Hl7.Fhir.Rest;
99
using LantanaGroup.Link.DataAcquisition.Domain.Application.Managers;
10+
using Microsoft.Extensions.Logging;
1011
using LantanaGroup.Link.DataAcquisition.Domain.Application.Models;
1112
using LantanaGroup.Link.DataAcquisition.Domain.Application.Models.Exceptions;
1213
using LantanaGroup.Link.DataAcquisition.Domain.Application.Models.Factory;
@@ -43,21 +44,24 @@ public class FhirApiService : IFhirApiService
4344
private readonly IReadFhirCommand _readFhirCommand;
4445
private readonly ISearchFhirCommand _searchFhirCommand;
4546
private readonly IProducer<ResourceKey, ResourceAcquired> _kafkaProducer;
47+
private readonly ILogger<FhirApiService> _logger;
4648

4749
public FhirApiService(
4850
IReferenceResourcesManager referenceResourceManager,
4951
IReferenceResourcesQueries referenceResourcesQueries,
5052
IReferenceResourceService referenceResourceService,
5153
ISearchFhirCommand searchFhirCommand,
5254
IReadFhirCommand readFhirCommand,
53-
IProducer<ResourceKey, ResourceAcquired> kafkaProducer)
55+
IProducer<ResourceKey, ResourceAcquired> kafkaProducer,
56+
ILogger<FhirApiService> logger)
5457
{
5558
_referenceResourceManager = referenceResourceManager;
5659
_referenceResourcesQueries = referenceResourcesQueries;
5760
_referenceResourceService = referenceResourceService;
5861
_searchFhirCommand = searchFhirCommand;
5962
_readFhirCommand = readFhirCommand;
6063
_kafkaProducer = kafkaProducer;
64+
_logger = logger;
6165
}
6266

6367
#region Interface Implementation
@@ -139,10 +143,16 @@ await GenerateResourceAcquiredMessage(new ResourceAcquired
139143
{
140144
return resourceIds;
141145
}
142-
if (ex.Outcome != null)
146+
147+
if (ex.Status == HttpStatusCode.NotFound || ex.Status == HttpStatusCode.Gone || ex.Outcome != null)
143148
{
144-
string json = JsonSerializer.Serialize(ex.Outcome, _options);
145-
(log.Notes ?? []).Add($"OperationOutcome returned for HTTP {ex.Status}: {json}");
149+
string note = ex.Outcome != null
150+
? $"OperationOutcome returned for HTTP {ex.Status}: {JsonSerializer.Serialize(ex.Outcome, _options)}"
151+
: $"HTTP {ex.Status} returned for Read operation.";
152+
153+
log.Notes ??= new List<string>();
154+
log.Notes.Add(note);
155+
throw new OpOutcomeException(note, ex);
146156
}
147157
throw;
148158
}
@@ -215,7 +225,27 @@ private async Task<List<string>> ExecutePagingSearch(DataAcquisitionLogModel log
215225

216226
await _referenceResourceService.ProcessReferences(log, refResources, cancellationToken);
217227

218-
var resources = bundle.Entry.Select(e => e.Resource).ToList();
228+
var resources = bundle.Entry
229+
.Where(e => e.Resource != null && e.Resource.TypeName != "OperationOutcome")
230+
.Select(e => e.Resource)
231+
.ToList();
232+
233+
var outcomes = bundle.Entry
234+
.Where(e => e.Resource is OperationOutcome)
235+
.Select(e => (OperationOutcome)e.Resource)
236+
.ToList();
237+
238+
if (outcomes.Any())
239+
{
240+
log.Notes ??= new List<string>();
241+
foreach (var outcome in outcomes)
242+
{
243+
string outcomeNote = $"OperationOutcome found in search bundle: {JsonSerializer.Serialize(outcome, _options)}";
244+
log.Notes.Add(outcomeNote);
245+
_logger.LogInformation("OperationOutcome found in successful search bundle for log {LogId}: {outcomeNote}", log.Id, outcomeNote);
246+
}
247+
}
248+
219249
resourceIds.AddRange(resources.Select(r => $"{r.TypeName}/{r.Id}"));
220250

221251
foreach (var resource in resources)
@@ -247,10 +277,16 @@ await GenerateResourceAcquiredMessage(new ResourceAcquired
247277
}
248278
catch (FhirOperationException ex)
249279
{
250-
if (ex.Outcome != null)
280+
if (ex.Status == HttpStatusCode.NotFound || ex.Status == HttpStatusCode.Gone || ex.Outcome != null)
251281
{
252-
string json = JsonSerializer.Serialize(ex.Outcome, _options);
253-
(log.Notes ?? []).Add($"OperationOutcome returned for HTTP {ex.Status}: {json}");
282+
string note = ex.Outcome != null
283+
? $"OperationOutcome returned for HTTP {ex.Status}: {JsonSerializer.Serialize(ex.Outcome, _options)}"
284+
: $"HTTP {ex.Status} returned for Search operation.";
285+
286+
log.Notes ??= new List<string>();
287+
log.Notes.Add(note);
288+
_logger.LogWarning("Expected FHIR error encountered for search: {note}", note);
289+
throw new OpOutcomeException(note, ex);
254290
}
255291
throw;
256292
}

DotNet/DataAcquisition.Domain/Application/Services/PatientDataService.cs

Lines changed: 34 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@
2121
using Medallion.Threading;
2222
using Microsoft.Extensions.Logging;
2323
using System.Diagnostics;
24+
using System.Net;
2425
using RequestStatus = LantanaGroup.Link.DataAcquisition.Domain.Infrastructure.Models.Enums.RequestStatus;
2526
using ResourceType = Hl7.Fhir.Model.ResourceType;
2627
using StringComparison = System.StringComparison;
@@ -601,6 +602,38 @@ await _dataAcquisitionLogQueries.UpdateAsync(new UpdateDataAcquisitionLogModel
601602
}, cancellationToken);
602603
}
603604
}
605+
catch (OpOutcomeException ex)
606+
{
607+
_logger.LogWarning(ex, "OperationOutcome encountered for facility {FacilityId}", log.FacilityId.Sanitize());
608+
609+
log.Notes ??= new List<string>();
610+
611+
if (ex.StatusCode is HttpStatusCode.NotFound or HttpStatusCode.Gone)
612+
{
613+
log.Status = RequestStatus.Completed;
614+
log.CompletionDate = DateTime.UtcNow;
615+
}
616+
else
617+
{
618+
log.RetryAttempts ??= 0;
619+
log.RetryAttempts++;
620+
log.Status = RequestStatus.Pending;
621+
log.Notes.Add($"[{DateTime.UtcNow}] OperationOutcome encountered (HTTP {ex.StatusCode}): Retrying. Attempt {log.RetryAttempts}.");
622+
}
623+
624+
await _dataAcquisitionLogQueries.UpdateAsync(new UpdateDataAcquisitionLogModel
625+
{
626+
Id = log.Id,
627+
RetryAttempts = log.RetryAttempts,
628+
ResourceAcquiredIds = log.ResourceAcquiredIds,
629+
CompletionDate = log.CompletionDate,
630+
CompletionTimeMilliseconds = log.CompletionTimeMilliseconds,
631+
TraceId = log.TraceId,
632+
ExecutionDate = log.ExecutionDate,
633+
Notes = log.Notes,
634+
Status = log.Status,
635+
}, cancellationToken);
636+
}
604637
catch (ProcessingDelayException ex)
605638
{
606639
log!.Notes ??= new List<string>();
@@ -632,7 +665,7 @@ await _dataAcquisitionLogQueries.UpdateAsync(new UpdateDataAcquisitionLogModel
632665
log.RetryAttempts ??= 0;
633666

634667
log.ExecutionDate = DateTime.UtcNow.Add(ex.RetryAfter);
635-
log.Status = RequestStatus.Pending; //Don't count this as a failure
668+
log.Status = RequestStatus.Failed; //Don't count this as a failure
636669
log.Notes.Add(
637670
$"[{DateTime.UtcNow}] Throttled (429): Retrying after {ex.RetryAfter.TotalSeconds}s. Attempt {log.RetryAttempts}.");
638671

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,21 @@
1+
using Microsoft.EntityFrameworkCore.Migrations;
2+
3+
#nullable disable
4+
5+
namespace LantanaGroup.Link.DataAcquisition.Domain.Migrations
6+
{
7+
public partial class RemoveInoperableStatus : Migration
8+
{
9+
protected override void Up(MigrationBuilder migrationBuilder)
10+
{
11+
migrationBuilder.Sql("UPDATE [DataAcquisitionLogs] SET [Status] = 'Completed' WHERE [Status] = 'Inoperable'");
12+
}
13+
14+
protected override void Down(MigrationBuilder migrationBuilder)
15+
{
16+
// Note: We cannot easily distinguish which 'Completed' logs were originally 'Inoperable'
17+
// but for downgrade purposes we can just leave them as 'Completed' or if really needed
18+
// we could have added a note to the log during Up migration.
19+
}
20+
}
21+
}

0 commit comments

Comments
 (0)