Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Logging] Adding better logging to Bad Request #3856

Merged
merged 1 commit into from
May 15, 2024
Merged

[Logging] Adding better logging to Bad Request #3856

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 12 additions & 2 deletions src/Microsoft.Health.Fhir.Core/Features/Search/SearchService.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -26,19 +27,23 @@ public abstract class SearchService : ISearchService
{
private readonly ISearchOptionsFactory _searchOptionsFactory;
private readonly IFhirDataStore _fhirDataStore;
private readonly ILogger _logger;

/// <summary>
/// Initializes a new instance of the <see cref="SearchService"/> class.
/// </summary>
/// <param name="searchOptionsFactory">The search options factory.</param>
/// <param name="fhirDataStore">The data store</param>
protected SearchService(ISearchOptionsFactory searchOptionsFactory, IFhirDataStore fhirDataStore)
/// <param name="logger">Logger</param>
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;
}

/// <inheritdoc />
Expand Down Expand Up @@ -92,6 +97,7 @@ public async Task<SearchResult> SearchHistoryAsync(
if (since != null)
{
// _at and _since cannot be both specified.
_logger.LogWarning("Invalid Search Operation (_since)");
throw new InvalidSearchOperationException(
string.Format(
CultureInfo.InvariantCulture,
Expand All @@ -102,7 +108,8 @@ public async Task<SearchResult> 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,
Expand All @@ -119,6 +126,7 @@ public async Task<SearchResult> 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,
Expand Down Expand Up @@ -169,6 +177,7 @@ public async Task<SearchResult> SearchHistoryAsync(
{
if (!string.Equals(sort.TrimStart('-'), KnownQueryParameterNames.LastUpdated, StringComparison.Ordinal))
{
_logger.LogWarning("Invalid Search Operation (SearchSortParameterNotSupported)");
throw new InvalidSearchOperationException(
string.Format(
CultureInfo.InvariantCulture,
Expand Down Expand Up @@ -198,6 +207,7 @@ public async Task<SearchResult> SearchHistoryAsync(

if (resource == null)
{
_logger.LogWarning("Resource Not Found (ResourceNotFoundById)");
throw new ResourceNotFoundException(string.Format(Core.Resources.ResourceNotFoundById, resourceType, resourceId));
}
}
Expand Down
9 changes: 7 additions & 2 deletions src/Microsoft.Health.Fhir.CosmosDb/Features/Search/FhirCosmosSearchService.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ public FhirCosmosSearchService(
CompartmentSearchRewriter compartmentSearchRewriter,
SmartCompartmentSearchRewriter smartCompartmentSearchRewriter,
ILogger<FhirCosmosSearchService> logger)
: base(searchOptionsFactory, fhirDataStore)
: base(searchOptionsFactory, fhirDataStore, logger)
{
EnsureArg.IsNotNull(fhirDataStore, nameof(fhirDataStore));
EnsureArg.IsNotNull(queryBuilder, nameof(queryBuilder));
Expand Down Expand Up @@ -129,6 +129,7 @@ public override async Task<SearchResult> 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);
}
}
Expand Down Expand Up @@ -294,11 +295,13 @@ private async Task<Expression> 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);
}

Expand Down Expand Up @@ -496,6 +499,7 @@ protected override async Task<SearchResult> SearchForReindexInternalAsync(
}
catch (ArgumentException)
{
_logger.LogWarning("Bad Request (InvalidFeedRange)");
throw new BadRequestException(Resources.InvalidFeedRange);
}
}
Expand All @@ -516,7 +520,7 @@ protected override async Task<SearchResult> 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,
Expand Down Expand Up @@ -553,6 +557,7 @@ private async Task<int> 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));
}

Expand Down
3 changes: 2 additions & 1 deletion src/Microsoft.Health.Fhir.Shared.Core.UnitTests/Features/Search/SearchServiceTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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;
}
Expand Down
9 changes: 6 additions & 3 deletions src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ public SqlServerSearchService(
ICompressedRawResourceConverter compressedRawResourceConverter,
ISqlQueryHashCalculator queryHashCalculator,
ILogger<SqlServerSearchService> logger)
: base(searchOptionsFactory, fhirDataStore)
: base(searchOptionsFactory, fhirDataStore, logger)
{
EnsureArg.IsNotNull(sqlRootExpressionRewriter, nameof(sqlRootExpressionRewriter));
EnsureArg.IsNotNull(chainFlatteningRewriter, nameof(chainFlatteningRewriter));
Expand Down Expand Up @@ -146,8 +146,8 @@ public override async Task<SearchResult> 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);
Expand Down Expand Up @@ -266,6 +266,7 @@ private async Task<SearchResult> SearchImpl(SqlSearchOptions sqlSearchOptions, s
}
else
{
_logger.LogWarning("Bad Request (InvalidContinuationToken)");
throw new BadRequestException(Resources.InvalidContinuationToken);
}
}
Expand Down Expand Up @@ -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));
}

Expand Down Expand Up @@ -507,6 +509,7 @@ await _sqlRetryService.ExecuteSql(

if (isResultPartial)
{
_logger.LogWarning("Bundle Partial Result (TruncatedIncludeMessage)");
_requestContextAccessor.RequestContext.BundleIssues.Add(
new OperationOutcomeIssue(
OperationOutcomeConstants.IssueSeverity.Warning,
Expand Down
1 change: 1 addition & 0 deletions src/Microsoft.Health.Fhir.SqlServer/Features/Storage/SqlServerFhirDataStore.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -251,6 +251,7 @@ private async Task<IDictionary<DataStoreOperationIdentifier, DataStoreOperationO
continue;
}

_logger.LogInformation("BadRequest: IfMatchHeaderRequiredForResource");
results.Add(identifier, new DataStoreOperationOutcome(new BadRequestException(string.Format(Core.Resources.IfMatchHeaderRequiredForResource, resource.ResourceTypeName))));
continue;
}
Expand Down
Loading