diff --git a/src/Microsoft.Health.Fhir.Core/Features/Search/SearchService.cs b/src/Microsoft.Health.Fhir.Core/Features/Search/SearchService.cs index 174a0bafda..523e1159ef 100644 --- a/src/Microsoft.Health.Fhir.Core/Features/Search/SearchService.cs +++ b/src/Microsoft.Health.Fhir.Core/Features/Search/SearchService.cs @@ -11,6 +11,7 @@ using System.Threading.Tasks; using EnsureThat; using Hl7.Fhir.Rest; +using Microsoft.Extensions.Logging; using Microsoft.Health.Core; using Microsoft.Health.Fhir.Core.Exceptions; using Microsoft.Health.Fhir.Core.Extensions; @@ -26,19 +27,23 @@ public abstract class SearchService : ISearchService { private readonly ISearchOptionsFactory _searchOptionsFactory; private readonly IFhirDataStore _fhirDataStore; + private readonly ILogger _logger; /// /// Initializes a new instance of the class. /// /// The search options factory. /// The data store - protected SearchService(ISearchOptionsFactory searchOptionsFactory, IFhirDataStore fhirDataStore) + /// Logger + protected SearchService(ISearchOptionsFactory searchOptionsFactory, IFhirDataStore fhirDataStore, ILogger logger) { EnsureArg.IsNotNull(searchOptionsFactory, nameof(searchOptionsFactory)); EnsureArg.IsNotNull(fhirDataStore, nameof(fhirDataStore)); + EnsureArg.IsNotNull(logger, nameof(logger)); _searchOptionsFactory = searchOptionsFactory; _fhirDataStore = fhirDataStore; + _logger = logger; } /// @@ -92,6 +97,7 @@ public async Task SearchHistoryAsync( if (since != null) { // _at and _since cannot be both specified. + _logger.LogWarning("Invalid Search Operation (_since)"); throw new InvalidSearchOperationException( string.Format( CultureInfo.InvariantCulture, @@ -102,7 +108,8 @@ public async Task SearchHistoryAsync( if (before != null) { - // _at and _since cannot be both specified. + // _at and _before cannot be both specified. + _logger.LogWarning("Invalid Search Operation (_before)"); throw new InvalidSearchOperationException( string.Format( CultureInfo.InvariantCulture, @@ -119,6 +126,7 @@ public async Task SearchHistoryAsync( if (beforeOffset.CompareTo(Clock.UtcNow) > 0) { // you cannot specify a value for _before in the future + _logger.LogWarning("Invalid Search Operation (_before in the future)"); throw new InvalidSearchOperationException( string.Format( CultureInfo.InvariantCulture, @@ -169,6 +177,7 @@ public async Task SearchHistoryAsync( { if (!string.Equals(sort.TrimStart('-'), KnownQueryParameterNames.LastUpdated, StringComparison.Ordinal)) { + _logger.LogWarning("Invalid Search Operation (SearchSortParameterNotSupported)"); throw new InvalidSearchOperationException( string.Format( CultureInfo.InvariantCulture, @@ -198,6 +207,7 @@ public async Task SearchHistoryAsync( if (resource == null) { + _logger.LogWarning("Resource Not Found (ResourceNotFoundById)"); throw new ResourceNotFoundException(string.Format(Core.Resources.ResourceNotFoundById, resourceType, resourceId)); } } diff --git a/src/Microsoft.Health.Fhir.CosmosDb/Features/Search/FhirCosmosSearchService.cs b/src/Microsoft.Health.Fhir.CosmosDb/Features/Search/FhirCosmosSearchService.cs index 992050d761..4e9f1f940b 100644 --- a/src/Microsoft.Health.Fhir.CosmosDb/Features/Search/FhirCosmosSearchService.cs +++ b/src/Microsoft.Health.Fhir.CosmosDb/Features/Search/FhirCosmosSearchService.cs @@ -55,7 +55,7 @@ public FhirCosmosSearchService( CompartmentSearchRewriter compartmentSearchRewriter, SmartCompartmentSearchRewriter smartCompartmentSearchRewriter, ILogger logger) - : base(searchOptionsFactory, fhirDataStore) + : base(searchOptionsFactory, fhirDataStore, logger) { EnsureArg.IsNotNull(fhirDataStore, nameof(fhirDataStore)); EnsureArg.IsNotNull(queryBuilder, nameof(queryBuilder)); @@ -129,6 +129,7 @@ public override async Task SearchAsync( if (includeExpressions.Any(e => e.Iterate) || revIncludeExpressions.Any(e => e.Iterate)) { // We haven't implemented this yet. + _logger.LogWarning("Bad Request (IncludeIterateNotSupported)"); throw new BadRequestException(Resources.IncludeIterateNotSupported); } } @@ -294,11 +295,13 @@ private async Task RecurseChainedExpression(ChainedExpression expres chainedOptions, queryTimeout.Token)) { + _logger.LogWarning("Invalid Search Operation (ChainedExpressionSubqueryLimit)"); throw new InvalidSearchOperationException(string.Format(CultureInfo.InvariantCulture, Resources.ChainedExpressionSubqueryLimit, _chainedSearchMaxSubqueryItemLimit)); } } catch (OperationCanceledException) { + _logger.LogWarning("Request Too Costly (ConditionalRequestTooCostly)"); throw new RequestTooCostlyException(Core.Resources.ConditionalRequestTooCostly); } @@ -496,6 +499,7 @@ protected override async Task SearchForReindexInternalAsync( } catch (ArgumentException) { + _logger.LogWarning("Bad Request (InvalidFeedRange)"); throw new BadRequestException(Resources.InvalidFeedRange); } } @@ -516,7 +520,7 @@ protected override async Task SearchForReindexInternalAsync( { // ExecuteDocumentQueryAsync gave up on filling the pages. This suggests that we would have been better off querying in parallel. - _logger.LogInformation( + _logger.LogWarning( "Failed to fill items, found {ItemCount}, needed {DesiredItemCount}. Physical partition count {PhysicalPartitionCount}", results.Count, desiredItemCount, @@ -553,6 +557,7 @@ private async Task ExecuteCountSearchAsync( OperationOutcomeConstants.IssueType.NotSupported, string.Format(Core.Resources.SearchCountResultsExceedLimit, count, int.MaxValue))); + _logger.LogWarning("Invalid Search Operation (SearchCountResultsExceedLimit)"); throw new InvalidSearchOperationException(string.Format(Core.Resources.SearchCountResultsExceedLimit, count, int.MaxValue)); } diff --git a/src/Microsoft.Health.Fhir.Shared.Core.UnitTests/Features/Search/SearchServiceTests.cs b/src/Microsoft.Health.Fhir.Shared.Core.UnitTests/Features/Search/SearchServiceTests.cs index 62b62ebcbb..861d49385e 100644 --- a/src/Microsoft.Health.Fhir.Shared.Core.UnitTests/Features/Search/SearchServiceTests.cs +++ b/src/Microsoft.Health.Fhir.Shared.Core.UnitTests/Features/Search/SearchServiceTests.cs @@ -12,6 +12,7 @@ using Hl7.Fhir.Model; using Hl7.Fhir.Rest; using Hl7.Fhir.Serialization; +using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Health.Fhir.Core.Exceptions; using Microsoft.Health.Fhir.Core.Extensions; using Microsoft.Health.Fhir.Core.Features; @@ -196,7 +197,7 @@ public async Task GivenCountOnlyValue_WhenSearchingReindexResults_ThenCountSearc private class TestSearchService : SearchService { public TestSearchService(ISearchOptionsFactory searchOptionsFactory, IFhirDataStore fhirDataStore) - : base(searchOptionsFactory, fhirDataStore) + : base(searchOptionsFactory, fhirDataStore, NullLogger.Instance) { SearchImplementation = options => null; } diff --git a/src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs b/src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs index 1744550429..77feee8dc3 100644 --- a/src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs +++ b/src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs @@ -89,7 +89,7 @@ public SqlServerSearchService( ICompressedRawResourceConverter compressedRawResourceConverter, ISqlQueryHashCalculator queryHashCalculator, ILogger logger) - : base(searchOptionsFactory, fhirDataStore) + : base(searchOptionsFactory, fhirDataStore, logger) { EnsureArg.IsNotNull(sqlRootExpressionRewriter, nameof(sqlRootExpressionRewriter)); EnsureArg.IsNotNull(chainFlatteningRewriter, nameof(chainFlatteningRewriter)); @@ -146,8 +146,8 @@ public override async Task SearchAsync(SearchOptions searchOptions // a "special" ct so that we the subsequent request will be handled correctly. var ct = new ContinuationToken(new object[] { - SqlSearchConstants.SortSentinelValueForCt, - 0, + SqlSearchConstants.SortSentinelValueForCt, + 0, }); searchResult = new SearchResult(searchResult.Results, ct.ToJson(), searchResult.SortOrder, searchResult.UnsupportedSearchParameters); @@ -266,6 +266,7 @@ private async Task SearchImpl(SqlSearchOptions sqlSearchOptions, s } else { + _logger.LogWarning("Bad Request (InvalidContinuationToken)"); throw new BadRequestException(Resources.InvalidContinuationToken); } } @@ -374,6 +375,7 @@ await _sqlRetryService.ExecuteSql( OperationOutcomeConstants.IssueType.NotSupported, string.Format(Core.Resources.SearchCountResultsExceedLimit, count, int.MaxValue))); + _logger.LogWarning("Invalid Search Operation (SearchCountResultsExceedLimit)"); throw new InvalidSearchOperationException(string.Format(Core.Resources.SearchCountResultsExceedLimit, count, int.MaxValue)); } @@ -507,6 +509,7 @@ await _sqlRetryService.ExecuteSql( if (isResultPartial) { + _logger.LogWarning("Bundle Partial Result (TruncatedIncludeMessage)"); _requestContextAccessor.RequestContext.BundleIssues.Add( new OperationOutcomeIssue( OperationOutcomeConstants.IssueSeverity.Warning, diff --git a/src/Microsoft.Health.Fhir.SqlServer/Features/Storage/SqlServerFhirDataStore.cs b/src/Microsoft.Health.Fhir.SqlServer/Features/Storage/SqlServerFhirDataStore.cs index 7a28e0f426..7856ee67aa 100644 --- a/src/Microsoft.Health.Fhir.SqlServer/Features/Storage/SqlServerFhirDataStore.cs +++ b/src/Microsoft.Health.Fhir.SqlServer/Features/Storage/SqlServerFhirDataStore.cs @@ -251,6 +251,7 @@ private async Task