I have a background service that periodically reads (not peeks) a message from an Azure storage queue and call an API to get values (that could returns 204 and will be retired), and then once gets values from an API. It will update two database columns accordingly (call to UpdateWorkerReportOfInjuryMetaData), and then try to publish another message to another queue to be processed by another BG service.
The weird part: the code works intermittently for some messages everything works fine up to the call to UpdateWorkerReportOfInjuryMetaData for updating those columns, and nothing after that! Even none of the Azure logs happens and I don't see anything in the logs to troubleshoot. I am super confused.
It seems something is happening silently behind the scenes! Any advise?
public class ClaimRetrievalBackgroundService : BackgroundService
{
private readonly ILogger<ClaimRetrievalBackgroundService> _logger;
private readonly IServiceProvider _serviceProvider;
private readonly ISerializer<ClaimRetreivalQueueMessage> _serializer;
private readonly ICmsReportInjuryClient _cmsReportInjuryClient;
private readonly TimeSpan _queueCallDelayInSeconds = TimeSpan.FromSeconds(2);
public ClaimRetrievalBackgroundService(ILogger<ClaimRetrievalBackgroundService> logger,
IServiceProvider serviceProvider,
ISerializer<ClaimRetreivalQueueMessage> serializer,
ICmsReportInjuryClient cmsReportInjuryClient)
{
_logger = logger;
_serviceProvider = serviceProvider;
_serializer = serializer;
_cmsReportInjuryClient = cmsReportInjuryClient;
}
protected override async Task ExecuteAsync(CancellationToken stoppingToken)
{
_logger.LogInformation("Starting the claim retrieval and cnn from CMS background service");
await LookForClaimRetrievalRequestsAsync(stoppingToken);
}
public async Task LookForClaimRetrievalRequestsAsync(CancellationToken cancellationToken, bool isUnitTest = false)
{
while (!cancellationToken.IsCancellationRequested)
{
try
{
await ProcessNextClaimRetrievalRequestAsync(cancellationToken);
}
catch (Exception ex)
{
_logger.LogError(ex, "Unknown error occurred in LookForClaimRetrievalRequestsAsync");
}
await Task.Delay(_queueCallDelayInSeconds, cancellationToken);
}
}
private async Task ProcessNextClaimRetrievalRequestAsync(CancellationToken cancellationToken, bool isUnitTest = false)
{
await using var scope = _serviceProvider.CreateAsyncScope();
var services = scope.ResolveServices();
if (isUnitTest)
{
return;
}
var queueMessages = await services.QueueService.DequeueMessagesAsync(services.AzureSettings.CmsClaimNumberRetreivalQueueName,
count: 1,
cancellationToken: cancellationToken);
if (queueMessages.Length == 0)
{
return;
}
_logger.LogInformation("Found [{Count}] CSM retrieval requests", queueMessages.Length);
var message = queueMessages[0];
var claimRequest = DeserializeQueueMessage(message);
if (claimRequest == null)
{
return;
}
await ProcessClaimRetrievalRequestAsync(services, claimRequest, message, cancellationToken);
}
private async Task ProcessClaimRetrievalRequestAsync(ServiceBundle services,
ClaimRetreivalQueueMessage claimRequest,
QueueMessage queueMessage,
CancellationToken cancellationToken)
{
_logger.LogInformation("Processing claim retrieval for CmsRef: {CmsRef}, MetaDataId: {MetaDataId}",
claimRequest.CmsReferenceNumber, claimRequest.MetaDataId);
if (!int.TryParse(claimRequest.MetaDataId, out int id))
{
throw new InvalidDataException($"Failed to parse metadata {claimRequest.MetaDataId}");
}
var metaDataRecord = await services.MetaDataService.GetWorkerMetaDataByIdAsync(id, cancellationToken);
if (metaDataRecord.IsError)
{
_logger.LogWarning("Failed to retrieve metadata for ID: {MetaDataId}", claimRequest.MetaDataId);
throw new InvalidOperationException($"Failed to retrieve metadata for ID: {claimRequest.MetaDataId}");
}
var wroiMetaData = metaDataRecord.Value.Data;
if (wroiMetaData is null)
{
_logger.LogWarning("Metadata record is null for ID: {MetaDataId}", claimRequest.MetaDataId);
throw new InvalidOperationException($"Metadata record is null for ID: {claimRequest.MetaDataId}");
}
// Get claim and CCN data
var claimAndCcnResponse = await GetClaimNumberAndCcnAsync(claimRequest,
services.GeneralSettings.WaitForCmsClaimCcnCallSeconds,
cancellationToken);
if (claimAndCcnResponse != null)
{
_logger.LogInformation("Retrieved claim data for {Ref}: ClaimNumber={ClaimNumber}, CCN={CCN}",
claimRequest.CmsReferenceNumber,
claimAndCcnResponse.ClaimNumber,
claimAndCcnResponse.CustomerCareNumber);
var updatedDemography = JsonConvert.DeserializeObject<Demographics>(wroiMetaData.DemographicsPayload);
if (updatedDemography == null)
{
_logger.LogWarning("Failed to deserialize demographics payload for MetaDataId: {MetaDataId}/ {Ref}", claimRequest.MetaDataId,
claimRequest.CmsReferenceNumber);
throw new InvalidOperationException($"Failed to deserialize demographics for ID: {claimRequest.MetaDataId}");
}
if (long.TryParse(claimAndCcnResponse.CustomerCareNumber, out long ccn))
{
_logger.LogInformation("Successfully parsed CCN: {CCN} for {Ref}", ccn, claimRequest.CmsReferenceNumber);
}
else
{
_logger.LogWarning("Failed to parse CustomerCareNumber: {CCN} for {Ref}",
claimAndCcnResponse.CustomerCareNumber, claimRequest.CmsReferenceNumber);
}
updatedDemography.CustomerCareNumber = ccn;
try
{
await UpdateWorkerReportOfInjuryMetaData(
services.MetaDataService,
claimAndCcnResponse,
updatedDemography,
null,
metaDataRecord.Value.Data!,
default);
_logger.LogInformation("Successfully updated metadata for {Ref}", claimRequest.CmsReferenceNumber);
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to update worker report metadata for {Ref}", claimRequest.CmsReferenceNumber);
throw;
}
try
{
_logger.LogInformation("Enqueue the {Ref} for worker profile API call", claimRequest.CmsReferenceNumber);
if (services.QueueWorkerProfileUpdate == null)
{
_logger.LogError("QueueWorkerProfileUpdate service is null for {Ref}", claimRequest.CmsReferenceNumber);
throw new InvalidOperationException("QueueWorkerProfileUpdate service is not available");
}
if (string.IsNullOrEmpty(services.AzureSettings.WorkerProfileSubmissionQueueName))
{
_logger.LogError("WorkerProfileSubmissionQueueName is not configured for {Ref}", claimRequest.CmsReferenceNumber);
throw new InvalidOperationException("WorkerProfileSubmissionQueueName is not configured");
}
var workerProfileUpdateQueueMessage = new WorkerProfileUpdateQueueMessage() { MetaDataId = id };
_logger.LogInformation("Created queue message for {Ref} with MetaDataId: {MetaDataId}",
claimRequest.CmsReferenceNumber, id);
await services.QueueWorkerProfileUpdate.EnqueueMessageAsync(workerProfileUpdateQueueMessage,
services.AzureSettings.WorkerProfileSubmissionQueueName,
default);
_logger.LogInformation("Successfully enqueued worker profile update for {Ref}", claimRequest.CmsReferenceNumber);
_logger.LogInformation("Delete message for {Ref} from first queue", claimRequest.CmsReferenceNumber);
await services.QueueService.DeleteMessageAsync(
queueMessage.MessageId,
queueMessage.PopReceipt,
services.AzureSettings.CmsClaimNumberRetreivalQueueName,
default);
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to enqueue worker profile update for {Ref} - original message not deleted",
claimRequest.CmsReferenceNumber);
throw;
}
return;
}
else
{
_logger.LogInformation("CMS data not yet available for {Ref} - message will be retried",
claimRequest.CmsReferenceNumber);
}
}
private ClaimRetreivalQueueMessage? DeserializeQueueMessage(QueueMessage message)
{
var claimRetreivalQueueMessage = _serializer.DeserializeMessage(message.Body.ToString());
if (claimRetreivalQueueMessage is null || string.IsNullOrEmpty(claimRetreivalQueueMessage.CmsReferenceNumber))
{
_logger.LogWarning("Queue message is null or CmsReferenceNumber has no value!");
return null;
}
return claimRetreivalQueueMessage;
}
private static async Task UpdateWorkerReportOfInjuryMetaData(IWorkerMetaDataService roiMetaDataService,
ClaimAndCustomerCareNumberResponse claimResponse,
Demographics? demographics,
bool? submittedToWorkerProfileApi,
WroiMetaData wroiMetaData,
CancellationToken cancellationToken)
{
ArgumentNullException.ThrowIfNull(roiMetaDataService);
ArgumentNullException.ThrowIfNull(claimResponse);
wroiMetaData!.ClaimNumber = claimResponse!.ClaimNumber;
wroiMetaData!.WorkerCcn = long.Parse(claimResponse.CustomerCareNumber);
wroiMetaData.ModifiedDtm = DateTime.UtcNow;
var updatedProperties = new List<Expression<Func<WroiMetaData, object>>>
{
w => w.ClaimNumber!,
w => w.WorkerCcn!,
w => w.ModifiedDtm!
};
if (!FeatureFlags.SkipDemographic)
{
wroiMetaData!.DemographySubmissionStatus = submittedToWorkerProfileApi;
wroiMetaData.DemographicsPayload = JsonConvert.SerializeObject(demographics);
updatedProperties.Add(w => w.DemographicsPayload);
updatedProperties.Add(w => w.DemographySubmissionStatus);
}
await roiMetaDataService.UpdateWorkerMetaDataAsync(wroiMetaData!, cancellationToken, [.. updatedProperties]);
}
private async Task<ClaimAndCustomerCareNumberResponse?> GetClaimNumberAndCcnAsync(
ClaimRetreivalQueueMessage? claimRetreivalQueueMessage,
int waitForCallInSeconds,
CancellationToken cancellationToken)
{
const int maxRetries = 3;
int attempt = 0;
int RetryWaitBaseTimeMs = 1500;
if (claimRetreivalQueueMessage == null)
{
_logger.LogWarning("Parameter {ParamName} can not be null!", nameof(claimRetreivalQueueMessage));
return null;
}
_logger.LogInformation("Starting CMS API call for ref: {Ref} (Max {MaxRetries} attempts, {TimeoutSeconds}s timeout each)",
claimRetreivalQueueMessage.CmsReferenceNumber, maxRetries, waitForCallInSeconds);
// CMS API call manual retry because it returns 204 if not found and polly does not catch it as error to retry
while (attempt < maxRetries)
{
attempt++;
try
{
_logger.LogInformation("CMS API attempt {Method}/{Attempt}/{MaxRetries} for ref: {Ref}", nameof(GetClaimNumberAndCcnAsync),
attempt, maxRetries, claimRetreivalQueueMessage.CmsReferenceNumber);
//using var linkedCancellationTokenSource = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken);
//linkedCancellationTokenSource.CancelAfter(TimeSpan.FromSeconds(waitForCallInSeconds));
_ = long.TryParse(claimRetreivalQueueMessage.CmsReferenceNumber, out long _longReferenceNumber);
var cmsClaimRetrievalCallTask = _cmsReportInjuryClient.TryGetClaimAndCustomerCareNumbersAsync(_longReferenceNumber, default);
var cmsClaimRetrievalTaskCallResult = await cmsClaimRetrievalCallTask;
if (!cmsClaimRetrievalTaskCallResult.IsError && cmsClaimRetrievalTaskCallResult.Value != null)
{
_logger.LogInformation("CMS API succeeded on attempt {Attempt} for ref: {Ref}",
attempt, claimRetreivalQueueMessage.CmsReferenceNumber);
return cmsClaimRetrievalTaskCallResult.Value;
}
else
{
_logger.LogWarning("CMS API failed in {Method} on attempt {Attempt}/{MaxRetries} for ref: {Ref}. IsError: {IsError}, HasValue: {HasValue}",
nameof(GetClaimNumberAndCcnAsync), attempt, maxRetries, claimRetreivalQueueMessage.CmsReferenceNumber,
cmsClaimRetrievalTaskCallResult.IsError, cmsClaimRetrievalTaskCallResult.Value != null);
if (attempt >= maxRetries)
{
_logger.LogError("All {MaxRetries} CMS API attempts failed in {Method} for ref: {Ref} - returning null",
maxRetries, nameof(GetClaimNumberAndCcnAsync), claimRetreivalQueueMessage.CmsReferenceNumber);
return null;
}
}
}
catch (OperationCanceledException ex) when (ex.CancellationToken == cancellationToken)
{
return null;
}
catch (OperationCanceledException ex)
{
if (attempt >= maxRetries)
{
_logger.LogError(ex, "All {MaxRetries} CMS API attempts timed out for ref: {Ref}", maxRetries, claimRetreivalQueueMessage.CmsReferenceNumber);
return null;
}
}
catch (Exception ex)
{
if (attempt >= maxRetries)
{
_logger.LogError(ex, "All {MaxRetries} CMS API attempts failed with exceptions for ref: {Ref}",
maxRetries, claimRetreivalQueueMessage.CmsReferenceNumber);
return null;
}
}
if (attempt < maxRetries)
{
var delayMs = (int)Math.Pow(2, attempt - 1) * RetryWaitBaseTimeMs;
_logger.LogInformation("Waiting {DelayMs}ms before CMS retry attempt {NextAttempt} for ref: {Ref} {Method}",
delayMs, attempt + 1, claimRetreivalQueueMessage.CmsReferenceNumber, nameof(GetClaimNumberAndCcnAsync));
try
{
await Task.Delay(delayMs, cancellationToken);
}
catch (OperationCanceledException)
{
_logger.LogWarning("CMS retry delay cancelled for ref: {Ref} {Method}", claimRetreivalQueueMessage.CmsReferenceNumber, nameof(GetClaimNumberAndCcnAsync));
return null;
}
}
}
_logger.LogError("Unexpected end of CMS retry loop for ref: {Ref} {Method}", claimRetreivalQueueMessage.CmsReferenceNumber, nameof(GetClaimNumberAndCcnAsync));
return null;
}
}
UpdateWorkerReportOfInjuryMetaDatafor updating those columns, and nothing after that!" Does the code work for some messages up to the mentioned method and not have any problems for the rest of the messages? Or do some work up to the mentioned message but nothing for the rest of the messages?