From b743c9abbd45cd9bf49eee97120e715c18ecdf39 Mon Sep 17 00:00:00 2001 From: David Justo Date: Mon, 15 Apr 2024 22:26:53 -0700 Subject: [PATCH] log backoff in WaitingForMoreMessages --- src/DurableTask.AzureStorage/AnalyticsEventSource.cs | 5 ++++- src/DurableTask.AzureStorage/BackoffPollingHelper.cs | 5 +++++ src/DurableTask.AzureStorage/Logging/LogEvents.cs | 10 ++++++++-- src/DurableTask.AzureStorage/Logging/LogHelper.cs | 6 ++++-- src/DurableTask.AzureStorage/Messaging/ControlQueue.cs | 3 ++- 5 files changed, 23 insertions(+), 6 deletions(-) diff --git a/src/DurableTask.AzureStorage/AnalyticsEventSource.cs b/src/DurableTask.AzureStorage/AnalyticsEventSource.cs index 25fc7f0a8..76ccadb52 100644 --- a/src/DurableTask.AzureStorage/AnalyticsEventSource.cs +++ b/src/DurableTask.AzureStorage/AnalyticsEventSource.cs @@ -14,6 +14,7 @@ namespace DurableTask.AzureStorage { using System; + using System.Collections.Specialized; using System.Diagnostics.Tracing; using System.Runtime.CompilerServices; using DurableTask.AzureStorage.Logging; @@ -507,11 +508,12 @@ public void PendingOrchestratorMessageLimitReached( ExtensionVersion); } - [Event(EventIds.WaitingForMoreMessages, Level = EventLevel.Informational, Version = 2)] + [Event(EventIds.WaitingForMoreMessages, Level = EventLevel.Informational, Version = 3)] public void WaitingForMoreMessages( string Account, string TaskHub, string PartitionId, + string Details, string AppName, string ExtensionVersion) { @@ -520,6 +522,7 @@ public void WaitingForMoreMessages( Account, TaskHub, PartitionId, + Details, AppName, ExtensionVersion); } diff --git a/src/DurableTask.AzureStorage/BackoffPollingHelper.cs b/src/DurableTask.AzureStorage/BackoffPollingHelper.cs index 53b4ac072..f0fdb8cb4 100644 --- a/src/DurableTask.AzureStorage/BackoffPollingHelper.cs +++ b/src/DurableTask.AzureStorage/BackoffPollingHelper.cs @@ -36,6 +36,11 @@ public void Reset() this.resetEvent.Set(); } + public TimeSpan GetCurrentDelay() + { + return this.backoffStrategy.CurrentInterval; + } + public async Task WaitAsync(CancellationToken hostCancellationToken) { bool signaled = await this.resetEvent.WaitAsync(this.backoffStrategy.CurrentInterval, hostCancellationToken); diff --git a/src/DurableTask.AzureStorage/Logging/LogEvents.cs b/src/DurableTask.AzureStorage/Logging/LogEvents.cs index d7e4af427..682e91a4c 100644 --- a/src/DurableTask.AzureStorage/Logging/LogEvents.cs +++ b/src/DurableTask.AzureStorage/Logging/LogEvents.cs @@ -1266,11 +1266,13 @@ internal class WaitingForMoreMessages : StructuredLogEvent, IEventSourceEvent public WaitingForMoreMessages( string account, string taskHub, - string partitionId) + string partitionId, + string details) { this.Account = account; this.TaskHub = taskHub; this.PartitionId = partitionId; + this.Details = details; } [StructuredLogField] @@ -1282,6 +1284,9 @@ public WaitingForMoreMessages( [StructuredLogField] public string PartitionId { get; } + [StructuredLogField] + public string Details { get; } + public override EventId EventId => new EventId( EventIds.WaitingForMoreMessages, nameof(EventIds.WaitingForMoreMessages)); @@ -1289,12 +1294,13 @@ public WaitingForMoreMessages( public override LogLevel Level => LogLevel.Information; protected override string CreateLogMessage() => - $"{this.PartitionId}: No new messages were found - backing off"; + $"{this.PartitionId}: No new messages were found - backing off. Details: ${this.Details}"; void IEventSourceEvent.WriteEventSource() => AnalyticsEventSource.Log.WaitingForMoreMessages( this.Account, this.TaskHub, this.PartitionId, + this.Details, Utils.AppName, Utils.ExtensionVersion); } diff --git a/src/DurableTask.AzureStorage/Logging/LogHelper.cs b/src/DurableTask.AzureStorage/Logging/LogHelper.cs index 929fa20f9..7e6bc4dbf 100644 --- a/src/DurableTask.AzureStorage/Logging/LogHelper.cs +++ b/src/DurableTask.AzureStorage/Logging/LogHelper.cs @@ -420,12 +420,14 @@ internal void PendingOrchestratorMessageLimitReached( internal void WaitingForMoreMessages( string account, string taskHub, - string partitionId) + string partitionId, + string details) { var logEvent = new LogEvents.WaitingForMoreMessages( account, taskHub, - partitionId); + partitionId, + details); this.WriteStructuredLog(logEvent); } diff --git a/src/DurableTask.AzureStorage/Messaging/ControlQueue.cs b/src/DurableTask.AzureStorage/Messaging/ControlQueue.cs index 4484c3ee9..c8c09f178 100644 --- a/src/DurableTask.AzureStorage/Messaging/ControlQueue.cs +++ b/src/DurableTask.AzureStorage/Messaging/ControlQueue.cs @@ -90,7 +90,8 @@ public async Task> GetMessagesAsync(CancellationToken this.settings.Logger.WaitingForMoreMessages( this.storageAccountName, this.settings.TaskHubName, - this.storageQueue.Name); + this.storageQueue.Name, + $"Backoff is {this.backoffHelper.GetCurrentDelay().TotalMilliseconds} ms"); } await this.backoffHelper.WaitAsync(linkedCts.Token);