Skip to content

Commit a6aac43

Browse files
Removing Task.Delay() (#10876)
* Removing Task.Delay()
1 parent 943b9fb commit a6aac43

File tree

3 files changed

+95
-82
lines changed

3 files changed

+95
-82
lines changed

src/WebJobs.Script.WebHost/Diagnostics/DeferredLoggerProvider.cs

Lines changed: 56 additions & 65 deletions
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,6 @@ public sealed class DeferredLoggerProvider : ILoggerProvider, ISupportExternalSc
2020
SingleWriter = false
2121
});
2222

23-
private readonly TimeSpan _deferredLogDelay = TimeSpan.FromSeconds(10);
2423
private readonly IEnvironment _environment;
2524
private IExternalScopeProvider _scopeProvider;
2625
private bool _isEnabled = true;
@@ -37,91 +36,83 @@ public ILogger CreateLogger(string categoryName)
3736
return _isEnabled ? new DeferredLogger(_channel, categoryName, _scopeProvider, _environment) : NullLogger.Instance;
3837
}
3938

40-
public void ProcessBufferedLogs(IReadOnlyCollection<ILoggerProvider> forwardingProviders, bool runImmediately = false)
39+
public async Task ProcessBufferedLogsAsync(IReadOnlyCollection<ILoggerProvider> forwardingProviders)
4140
{
4241
// Forward all buffered logs to the new provider
43-
Task.Run(async () =>
42+
try
4443
{
45-
if (!runImmediately)
44+
if (forwardingProviders is null || forwardingProviders.Count == 0)
4645
{
47-
// Wait for 10 seconds, this will increase the probability of these logs appearing in live metrics.
48-
await Task.Delay(_deferredLogDelay);
49-
}
50-
51-
try
52-
{
53-
if (forwardingProviders is null || forwardingProviders.Count == 0)
46+
// No providers, just drain the messages without logging and disable the channel.
47+
_isEnabled = false;
48+
_channel.Writer.TryComplete();
49+
while (_channel.Reader.TryRead(out _))
5450
{
55-
// No providers, just drain the messages without logging and disable the channel.
56-
_isEnabled = false;
57-
_channel.Writer.TryComplete();
58-
while (_channel.Reader.TryRead(out _))
59-
{
60-
// Drain the channel
61-
}
62-
return;
51+
// Drain the channel
6352
}
53+
return;
54+
}
6455

65-
while (await _channel.Reader.WaitToReadAsync())
56+
while (await _channel.Reader.WaitToReadAsync())
57+
{
58+
while (_channel.Reader.TryRead(out var log))
6659
{
67-
while (_channel.Reader.TryRead(out var log))
60+
foreach (var forwardingProvider in forwardingProviders)
6861
{
69-
foreach (var forwardingProvider in forwardingProviders)
62+
var logger = forwardingProvider.CreateLogger(log.Category);
63+
if (log.ScopeStorage?.Count > 0)
7064
{
71-
var logger = forwardingProvider.CreateLogger(log.Category);
72-
List<IDisposable> scopes = null;
73-
74-
if (log.ScopeStorage?.Count > 0)
75-
{
76-
try
77-
{
78-
// Create a scope for each object in ScopeObject
79-
scopes ??= new List<IDisposable>();
80-
foreach (var scope in log.ScopeStorage)
81-
{
82-
// Create and store each scope
83-
scopes.Add(logger.BeginScope(scope));
84-
}
85-
86-
// Log the message
87-
logger.Log(log.LogLevel, log.EventId, log.Exception, log.Message);
88-
}
89-
finally
90-
{
91-
if (scopes is not null)
92-
{
93-
// Dispose all scopes in reverse order to properly unwind them
94-
for (int i = scopes.Count - 1; i >= 0; i--)
95-
{
96-
scopes[i].Dispose();
97-
}
98-
}
99-
}
100-
}
101-
else
102-
{
103-
// No scopes, avoid try-finally block
104-
logger.Log(log.LogLevel, log.EventId, log.Exception, log.Message);
105-
}
65+
ProcessLogWithScope(logger, log);
66+
}
67+
else
68+
{
69+
// No scopes
70+
logger.Log(log.LogLevel, log.EventId, log.Exception, log.Message);
10671
}
10772
}
10873
}
10974
}
110-
catch (Exception ex)
111-
{
112-
if (ex.IsFatal())
113-
{
114-
throw;
115-
}
116-
}
117-
});
75+
}
76+
catch (Exception ex) when (!ex.IsFatal())
77+
{
78+
// Ignore exceptions
79+
}
11880
}
11981

12082
public void SetScopeProvider(IExternalScopeProvider scopeProvider)
12183
{
12284
_scopeProvider = scopeProvider;
12385
}
12486

87+
private static void ProcessLogWithScope(ILogger logger, DeferredLogEntry log)
88+
{
89+
List<IDisposable> scopes = null;
90+
try
91+
{
92+
// Create a scope for each object in ScopeObject
93+
scopes ??= new List<IDisposable>();
94+
foreach (var scope in log.ScopeStorage)
95+
{
96+
// Create and store each scope
97+
scopes.Add(logger.BeginScope(scope));
98+
}
99+
100+
// Log the message
101+
logger.Log(log.LogLevel, log.EventId, log.Exception, log.Message);
102+
}
103+
finally
104+
{
105+
if (scopes is not null)
106+
{
107+
// Dispose all scopes in reverse order to properly unwind them
108+
for (int i = scopes.Count - 1; i >= 0; i--)
109+
{
110+
scopes[i].Dispose();
111+
}
112+
}
113+
}
114+
}
115+
125116
public void Dispose()
126117
{
127118
_isEnabled = false;

src/WebJobs.Script.WebHost/WebJobsScriptHostService.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -367,7 +367,7 @@ private async Task UnsynchronizedStartHostAsync(ScriptHostStartupOperation activ
367367
if (deferredLogProvider is not null)
368368
{
369369
var selectedProviders = loggerProviders.Where(provider => provider is ApplicationInsightsLoggerProvider or OpenTelemetryLoggerProvider).ToArray();
370-
deferredLogProvider.ProcessBufferedLogs(selectedProviders);
370+
_ = Task.Run(() => deferredLogProvider.ProcessBufferedLogsAsync(selectedProviders));
371371
}
372372
}
373373

test/WebJobs.Script.Tests/Eventing/DeferredLoggerProviderTests.cs

Lines changed: 38 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -40,9 +40,8 @@ public async Task CreateLogger_ReturnsNullLogger_WhenDisabled()
4040

4141
// Arrange
4242
var provider = new DeferredLoggerProvider(testEnvironment);
43-
provider.ProcessBufferedLogs(new List<ILoggerProvider>(), true); // Disable the provider
43+
await provider.ProcessBufferedLogsAsync(new List<ILoggerProvider>());
4444

45-
await Task.Delay(1000);
4645
// Act
4746
var logger = provider.CreateLogger("TestCategory");
4847

@@ -63,10 +62,7 @@ public async Task ProcessBufferedLogs_DrainsChannelWithoutProviders()
6362
logger.LogInformation("Test Log Message");
6463

6564
// Act
66-
provider.ProcessBufferedLogs(new List<ILoggerProvider>(), true); // Process immediately
67-
68-
// Wait for forwarding task to complete
69-
await Task.Delay(100); // Small delay to ensure the logs are processed
65+
await provider.ProcessBufferedLogsAsync(new List<ILoggerProvider>());
7066

7167
// Assert
7268
Assert.Equal(0, provider.Count); // Ensure channel is drained
@@ -84,11 +80,7 @@ public async Task Dispose_DisablesProviderAndCompletesChannel()
8480
logger.LogInformation("Log before disposal");
8581

8682
// Act
87-
provider.ProcessBufferedLogs(new List<ILoggerProvider>(), true); // Process immediately
88-
provider.Dispose();
89-
90-
// Wait a short period to ensure the channel is completed
91-
await Task.Delay(100);
83+
await provider.ProcessBufferedLogsAsync(new List<ILoggerProvider>());
9284

9385
// Assert
9486
Assert.False(provider.CreateLogger("TestCategory") is DeferredLogger);
@@ -130,7 +122,7 @@ public void Dispose_CanBeCalledMultipleTimesWithoutException()
130122
}
131123

132124
[Fact]
133-
public void ProcessBufferedLogs_ThrowsNoExceptionsWhenChannelIsEmpty()
125+
public async Task ProcessBufferedLogs_ThrowsNoExceptionsWhenChannelIsEmpty()
134126
{
135127
var testEnvironment = new TestEnvironment();
136128
testEnvironment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1");
@@ -139,8 +131,14 @@ public void ProcessBufferedLogs_ThrowsNoExceptionsWhenChannelIsEmpty()
139131
var provider = new DeferredLoggerProvider(testEnvironment);
140132
var mockLoggerProvider = new Mock<ILoggerProvider>();
141133

134+
var task = provider.ProcessBufferedLogsAsync(new[] { mockLoggerProvider.Object });
135+
136+
// Close the channel so that ProcessBufferedLogsAsync can complete
137+
provider.Dispose();
138+
142139
// Act & Assert (no exceptions should be thrown)
143-
provider.ProcessBufferedLogs(new[] { mockLoggerProvider.Object }, true);
140+
var exception = await Record.ExceptionAsync(() => task);
141+
Assert.Null(exception);
144142
}
145143

146144
[Fact]
@@ -163,15 +161,39 @@ public async Task Dispose_DoNotDisablesProviderAndCompletesChannel()
163161
testLoggerProvider.SetScopeProvider(new LoggerExternalScopeProvider());
164162

165163
// Act
166-
provider.ProcessBufferedLogs(new List<ILoggerProvider>() { testLoggerProvider }, true); // Process immediately
164+
var task = provider.ProcessBufferedLogsAsync(new List<ILoggerProvider>() { testLoggerProvider });
167165

168-
// Wait a short period to ensure the channel is completed
169-
await Task.Delay(100);
166+
// Close the channel so that ProcessBufferedLogsAsync can complete
167+
provider.Dispose();
168+
await task;
170169
Assert.Equal(0, provider.Count); // Ensure channel is drained
171170

172171
// Assert that the log was forwarded to the testLoggerProvider
173172
Assert.Equal(1, testLoggerProvider.GetAllLogMessages().Count);
174173
Assert.Equal(Assert.Single(testLoggerProvider.GetAllLogMessages()).FormattedMessage, "Error Log");
174+
}
175+
176+
[Fact]
177+
public void Dispose_DoNotDisablesProvider()
178+
{
179+
var testEnvironment = new TestEnvironment();
180+
testEnvironment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "0");
181+
182+
// Arrange
183+
var provider = new DeferredLoggerProvider(testEnvironment);
184+
var logger = provider.CreateLogger("TestCategory");
185+
logger.LogError("Error Log");
186+
187+
// Create an instance of IOptionsMonitor<OpenTelemetryLoggerOptions>
188+
var optionsMonitor = Mock.Of<IOptionsMonitor<OpenTelemetryLoggerOptions>>();
189+
190+
// Pass the optionsMonitor to the OpenTelemetryLoggerProvider constructor
191+
//OpenTelemetryLoggerProvider openTelemetryLoggerProvider = new(optionsMonitor);
192+
TestLoggerProvider testLoggerProvider = new TestLoggerProvider();
193+
testLoggerProvider.SetScopeProvider(new LoggerExternalScopeProvider());
194+
195+
// Act
196+
_ = provider.ProcessBufferedLogsAsync(new List<ILoggerProvider>() { testLoggerProvider });
175197

176198
// Ensure that the LoggerProvider is not disabled and still returns DeferredLogger
177199
Assert.True(provider.CreateLogger("TestCategory") is DeferredLogger);

0 commit comments

Comments
 (0)