Skip to content

Commit

Permalink
add logging and metrics on transcoding instances and their size (#3024)
Browse files Browse the repository at this point in the history 
* add logging and metrics on transcoding instances and their size

* log and emit metrics for rendered and frame as well

* refactor

* return content length from getting blob for frames so we can log

* use frame length

* shuffle log lines
  • Loading branch information
@esmadau
esmadau authored Sep 13, 2023
1 parent 8eab9b3 commit 7b348dc
Show file tree
Hide file tree
Showing 7 changed files with 82 additions and 23 deletions.
5 changes: 4 additions & 1 deletion src/Microsoft.Health.Dicom.Core.UnitTests/Features/Retrieve/RetrieveRenderedServiceTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
using Microsoft.Health.Dicom.Core.Features.Model;
using Microsoft.Health.Dicom.Core.Features.Partitioning;
using Microsoft.Health.Dicom.Core.Features.Retrieve;
using Microsoft.Health.Dicom.Core.Features.Telemetry;
using Microsoft.Health.Dicom.Core.Messages;
using Microsoft.Health.Dicom.Core.Messages.Retrieve;
using Microsoft.Health.Dicom.Tests.Common;
Expand All @@ -40,9 +41,9 @@ public class RetrieveRenderedServiceTests
private readonly ILogger<RetrieveRenderedService> _logger;
private readonly string _studyInstanceUid = TestUidGenerator.Generate();
private readonly string _firstSeriesInstanceUid = TestUidGenerator.Generate();
private readonly string _secondSeriesInstanceUid = TestUidGenerator.Generate();
private readonly string _sopInstanceUid = TestUidGenerator.Generate();
private static readonly CancellationToken DefaultCancellationToken = new CancellationTokenSource().Token;
private readonly RetrieveMeter _retrieveMeter;


public RetrieveRenderedServiceTests(ITestOutputHelper output)
Expand All @@ -53,6 +54,7 @@ public RetrieveRenderedServiceTests(ITestOutputHelper output)
_dicomRequestContextAccessor.RequestContext.DataPartition = Partition.Default;
var retrieveConfigurationSnapshot = Substitute.For<IOptionsSnapshot<RetrieveConfiguration>>();
retrieveConfigurationSnapshot.Value.Returns(new RetrieveConfiguration());
_retrieveMeter = new RetrieveMeter();

_logger = output.ToLogger<RetrieveRenderedService>();

Expand All @@ -63,6 +65,7 @@ public RetrieveRenderedServiceTests(ITestOutputHelper output)
_dicomRequestContextAccessor,
retrieveConfigurationSnapshot,
_recyclableMemoryStreamManager,
_retrieveMeter,
_logger
);

Expand Down
39 changes: 22 additions & 17 deletions src/Microsoft.Health.Dicom.Core.UnitTests/Features/Retrieve/RetrieveResourceServiceTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@
using Microsoft.Health.Dicom.Core.Features.Model;
using Microsoft.Health.Dicom.Core.Features.Partitioning;
using Microsoft.Health.Dicom.Core.Features.Retrieve;
using Microsoft.Health.Dicom.Core.Features.Telemetry;
using Microsoft.Health.Dicom.Core.Messages;
using Microsoft.Health.Dicom.Core.Messages.Retrieve;
using Microsoft.Health.Dicom.Core.Web;
Expand Down Expand Up @@ -55,6 +56,7 @@ public class RetrieveResourceServiceTests
private static readonly CancellationToken DefaultCancellationToken = new CancellationTokenSource().Token;
private readonly IInstanceMetadataCache _instanceMetadataCache;
private readonly IFramesRangeCache _framesRangeCache;
private readonly RetrieveMeter _retrieveMeter;

public RetrieveResourceServiceTests()
{
Expand All @@ -71,6 +73,7 @@ public RetrieveResourceServiceTests()
retrieveConfigurationSnapshot.Value.Returns(new RetrieveConfiguration());
_instanceMetadataCache = Substitute.For<IInstanceMetadataCache>();
_framesRangeCache = Substitute.For<IFramesRangeCache>();
_retrieveMeter = new RetrieveMeter();

_metadataStore = Substitute.For<IMetadataStore>();
_retrieveResourceService = new RetrieveResourceService(
Expand All @@ -84,6 +87,7 @@ public RetrieveResourceServiceTests()
_instanceMetadataCache,
_framesRangeCache,
retrieveConfigurationSnapshot,
_retrieveMeter,
_logger);
}

Expand Down Expand Up @@ -173,10 +177,6 @@ public async Task GivenStoredInstancesWithOriginalVersion_WhenRetrieveRequestFor

await response.GetStreamsAsync();

await _fileStore
.Received(3)
.GetFilePropertiesAsync(Arg.Is<long>(x => x == 5), Partition.DefaultName, DefaultCancellationToken);

await _fileStore
.Received(3)
.GetStreamingFileAsync(Arg.Is<long>(x => x == 5), Partition.DefaultName, DefaultCancellationToken);
Expand All @@ -198,10 +198,6 @@ public async Task GivenStoredInstancesWithOriginalVersion_WhenRetrieveRequestFor

await response.GetStreamsAsync();

await _fileStore
.Received(1)
.GetFilePropertiesAsync(Arg.Is<long>(x => x == 0), Partition.DefaultName, DefaultCancellationToken);

await _fileStore
.Received(1)
.GetStreamingFileAsync(Arg.Is<long>(x => x == 0), Partition.DefaultName, DefaultCancellationToken);
Expand All @@ -211,11 +207,12 @@ await _fileStore
public async Task GivenInstancesWithOriginalVersion_WhenRetrieveRequestForStudyForOriginalWithTranscoding_ThenInstancesAreReturned()
{
// Add multiple instances to validate that we return the requested instance and ignore the other(s).
int originalVersion = 5;
List<InstanceMetadata> versionedInstanceIdentifiers = SetupInstanceIdentifiersList(
ResourceType.Instance,
instanceProperty: new InstanceProperties() { HasFrameMetadata = true, OriginalVersion = 5, TransferSyntaxUid = "1.2.840.10008.1.2.4.90" });

_fileStore.GetFilePropertiesAsync(Arg.Any<long>(), Partition.DefaultName, DefaultCancellationToken).Returns(new FileProperties { ContentLength = 1000 });
instanceProperty: new InstanceProperties() { HasFrameMetadata = true, OriginalVersion = originalVersion, TransferSyntaxUid = "1.2.840.10008.1.2.4.90" });
_fileStore.GetFilePropertiesAsync(originalVersion, versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken)
.Returns(new FileProperties { ContentLength = new RetrieveConfiguration().MaxDicomFileSize });

// For each instance identifier, set up the fileStore to return a stream containing a file associated with the identifier.
var streamsAndStoredFiles = versionedInstanceIdentifiers.Select(
Expand All @@ -236,15 +233,15 @@ public async Task GivenInstancesWithOriginalVersion_WhenRetrieveRequestForStudyF

await _fileStore
.Received(1)
.GetFilePropertiesAsync(Arg.Is<long>(x => x == 5), Partition.DefaultName, DefaultCancellationToken);
.GetFilePropertiesAsync(Arg.Is<long>(x => x == originalVersion), versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken);

await _fileStore
.DidNotReceive()
.GetStreamingFileAsync(Arg.Any<long>(), Partition.DefaultName, DefaultCancellationToken);
.GetStreamingFileAsync(Arg.Any<long>(), versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken);

await _fileStore
.Received(1)
.GetFileAsync(Arg.Is<long>(x => x == 5), Partition.DefaultName, DefaultCancellationToken);
.GetFileAsync(Arg.Is<long>(x => x == originalVersion), versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken);
}

[Fact]
Expand Down Expand Up @@ -365,6 +362,7 @@ public async Task GivenStoredInstancesWithMissingFile_WhenRetrieveRequestForInst
{
// Add multiple instances to validate that we return the requested instance and ignore the other(s).
List<InstanceMetadata> versionedInstanceIdentifiers = SetupInstanceIdentifiersList(ResourceType.Instance);
_fileStore.GetFilePropertiesAsync(Arg.Any<long>(), Partition.DefaultName, DefaultCancellationToken).Returns(new FileProperties { ContentLength = 1000 });

// For the first instance identifier, set up the fileStore to throw a store exception with the status code 404 (NotFound).
_fileStore.GetStreamingFileAsync(versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Version, versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken).Throws(new InstanceNotFoundException());
Expand Down Expand Up @@ -642,6 +640,8 @@ public async Task GetFrames_WithNoTranscode_HitsCache()
// arrange
List<InstanceMetadata> versionedInstanceIdentifiers = SetupInstanceIdentifiersList(ResourceType.Frames, instanceProperty: new InstanceProperties() { HasFrameMetadata = true });
var framesToRequest = new List<int> { 1 };
_fileStore.GetFilePropertiesAsync(versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Version, versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken)
.Returns(new FileProperties { ContentLength = new RetrieveConfiguration().MaxDicomFileSize });

// act
await _retrieveResourceService.GetInstanceResourceAsync(
Expand All @@ -662,6 +662,8 @@ public async Task GetFrames_WithNoTranscode_ReturnsFramesFromCurrentVersion()
ResourceType.Frames,
instanceProperty: new InstanceProperties() { HasFrameMetadata = true });
var framesToRequest = new List<int> { 1 };
_fileStore.GetFilePropertiesAsync(versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Version, versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken)
.Returns(new FileProperties { ContentLength = new RetrieveConfiguration().MaxDicomFileSize });

// act
await _retrieveResourceService.GetInstanceResourceAsync(
Expand All @@ -687,11 +689,14 @@ await _fileStore.GetFileFrameAsync(
[Fact]
public async Task GetFrames_WithUpdatedInstanceAndWithNoTranscode_ReturnsFramesFromOriginalVersion()
{
int originalVersion = 1;
// arrange
List<InstanceMetadata> versionedInstanceIdentifiers = SetupInstanceIdentifiersList(
ResourceType.Frames,
instanceProperty: new InstanceProperties() { HasFrameMetadata = true, OriginalVersion = 1 });
instanceProperty: new InstanceProperties() { HasFrameMetadata = true, OriginalVersion = originalVersion });
var framesToRequest = new List<int> { 1 };
_fileStore.GetFilePropertiesAsync(originalVersion, versionedInstanceIdentifiers.First().VersionedInstanceIdentifier.Partition.Name, DefaultCancellationToken)
.Returns(new FileProperties { ContentLength = new RetrieveConfiguration().MaxDicomFileSize });

// act
await _retrieveResourceService.GetInstanceResourceAsync(
Expand All @@ -703,12 +708,12 @@ await _retrieveResourceService.GetInstanceResourceAsync(
await _instanceMetadataCache.Received(1).GetAsync(Arg.Any<object>(), identifier, Arg.Any<Func<InstanceIdentifier, CancellationToken, Task<InstanceMetadata>>>(), Arg.Any<CancellationToken>());
await _framesRangeCache.Received(1).GetAsync(
Arg.Any<object>(),
Arg.Is<long>(x => x == 1),
Arg.Is<long>(x => x == originalVersion),
Arg.Any<Func<long, CancellationToken, Task<IReadOnlyDictionary<int, FrameRange>>>>(),
Arg.Any<CancellationToken>());

await _fileStore.GetFileFrameAsync(
Arg.Is<long>(x => x == 1),
Arg.Is<long>(x => x == originalVersion),
Partition.DefaultName,
Arg.Any<FrameRange>(),
Arg.Any<CancellationToken>());
Expand Down
2 changes: 1 addition & 1 deletion src/Microsoft.Health.Dicom.Core/Features/Retrieve/RetrieveMetadataService.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -96,7 +96,7 @@ public async Task<RetrieveMetadataResponse> RetrieveSopInstanceMetadataAsync(str
private RetrieveMetadataResponse RetrieveMetadata(IReadOnlyList<InstanceMetadata> instancesToRetrieve, bool isCacheValid, string eTag, bool isOriginalVersionRequested, CancellationToken cancellationToken)
{
_contextAccessor.RequestContext.PartCount = instancesToRetrieve.Count;
_retrieveMeter.RetrieveInstanceCount.Add(instancesToRetrieve.Count);
_retrieveMeter.RetrieveInstanceMetadataCount.Add(instancesToRetrieve.Count);

// Retrieve metadata instances only if cache is not valid.
IAsyncEnumerable<DicomDataset> instanceMetadata = isCacheValid
Expand Down
10 changes: 10 additions & 0 deletions src/Microsoft.Health.Dicom.Core/Features/Retrieve/RetrieveRenderedService.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
using Microsoft.Health.Dicom.Core.Features.Common;
using Microsoft.Health.Dicom.Core.Features.Context;
using Microsoft.Health.Dicom.Core.Features.Model;
using Microsoft.Health.Dicom.Core.Features.Telemetry;
using Microsoft.Health.Dicom.Core.Messages;
using Microsoft.Health.Dicom.Core.Messages.Retrieve;
using Microsoft.Health.Dicom.Core.Web;
Expand All @@ -38,20 +39,23 @@ public class RetrieveRenderedService : IRetrieveRenderedService
private readonly RetrieveConfiguration _retrieveConfiguration;
private readonly RecyclableMemoryStreamManager _recyclableMemoryStreamManager;
private readonly ILogger<RetrieveRenderedService> _logger;
private readonly RetrieveMeter _retrieveMeter;

public RetrieveRenderedService(
IInstanceStore instanceStore,
IFileStore blobDataStore,
IDicomRequestContextAccessor dicomRequestContextAccessor,
IOptionsSnapshot<RetrieveConfiguration> retrieveConfiguration,
RecyclableMemoryStreamManager recyclableMemoryStreamManager,
RetrieveMeter retrieveMeter,
ILogger<RetrieveRenderedService> logger)
{
EnsureArg.IsNotNull(instanceStore, nameof(instanceStore));
EnsureArg.IsNotNull(blobDataStore, nameof(blobDataStore));
EnsureArg.IsNotNull(dicomRequestContextAccessor, nameof(dicomRequestContextAccessor));
EnsureArg.IsNotNull(retrieveConfiguration?.Value, nameof(retrieveConfiguration));
EnsureArg.IsNotNull(recyclableMemoryStreamManager, nameof(recyclableMemoryStreamManager));
_retrieveMeter = EnsureArg.IsNotNull(retrieveMeter, nameof(retrieveMeter));
EnsureArg.IsNotNull(logger, nameof(logger));

_instanceStore = instanceStore;
Expand Down Expand Up @@ -85,6 +89,12 @@ public async Task<RetrieveRenderedResponse> RetrieveRenderedImageAsync(RetrieveR
ResourceType.Instance, partition, request.StudyInstanceUid, request.SeriesInstanceUid, request.SopInstanceUid, cancellationToken))[0];

FileProperties fileProperties = await RetrieveHelpers.CheckFileSize(_blobDataStore, _retrieveConfiguration.MaxDicomFileSize, instance.VersionedInstanceIdentifier.Version, partition.Name, true, cancellationToken);
_logger.LogInformation(
"Retrieving rendered Instance for watermark {Watermark} of size {ContentLength}", instance.VersionedInstanceIdentifier.Version, fileProperties.ContentLength);
_retrieveMeter.RetrieveInstanceCount.Add(
1,
RetrieveMeter.RetrieveInstanceCountTelemetryDimension(fileProperties.ContentLength, _retrieveConfiguration.MaxDicomFileSize, isRendered: true));

using Stream stream = await _blobDataStore.GetFileAsync(instance.VersionedInstanceIdentifier.Version, instance.VersionedInstanceIdentifier.Partition.Name, cancellationToken);
sw.Start();

Expand Down
Loading

0 comments on commit 7b348dc

Please sign in to comment.